Repository navigation
fix(ebpf): size L7 ring buffer records to their content - #356
mayankpande88 wants to merge 11 commits into
Conversation
TLS capture could fail at attach time, in the kernel, or in the agent with
nothing to show for it at default verbosity. This adds counters for each
stage and fixes the losses they revealed.
Visibility:
- node_agent_tls_attach_total{lib,result} for every attach attempt, and
one log line per binary and outcome instead of one per process.
- node_agent_tls_plaintext_dropped_total{reason}: TLS plaintext a library
hook saw but could not attribute to a socket.
- node_agent_l7_ringbuf_drops_total: L7 events lost to a full ring buffer.
- node_agent_l7_events_dropped_total{reason,protocol,tls}: events dropped
in the agent before protocol parsing.
Fixes:
- Register a process on its first socket event, so its first connection
is tracked and its TLS probes attach before its first request.
- Give a connection built from an event's socket tuple the event's
timestamp, and let a newer event replace the closed predecessor on a
reused fd. Both cases used to be dropped as stale.
- Key the cache of binaries that cannot be probed by file identity, not
by path, which is only meaningful inside one container.
- Re-attach after a process execs a different binary.
- Only a write that starts with a TLS record may claim pending OpenSSL
plaintext, and that write's ciphertext now counts toward bytes sent.
- Guard Process state shared between the instrumentation goroutine, the
event loop and the scrape path.
Collect read c.pythonStats and c.nodejsStats without c.lock while the registry's event loop updates them under it.
… tuples A connection created from an L7 event's socket tuple, because the event arrived before the connection's open event, skipped the filters and the NAT resolution onConnectionOpen applies. With these connections now kept (previous commit), that tracked traffic to ignored destinations and labelled requests with a service's virtual IP as their actual destination. - Both paths now share connectionKey: the same port, loopback, ignored workload and connection filters, and the same destination key. - The socket-tuple path takes the actual destination from the kernel's conntrack-derived actual_destinations map, as open events do. - An exec is re-checked on every new socket, not only when a throttle shared with the periodic sweep allows it. - The go_fd_unknown help text says it includes TLS over in-memory connections, which have no socket.
… wrapped Go connections (#354) * feat(tls): attribute TLS plaintext losses to the container and binary node_agent_tls_plaintext_dropped_total says how much TLS plaintext the kernel could not attribute to a socket, but not which process it came from, so a loss could not be traced to a workload without a debug build. - The TLS library uprobes also count losses per process and reason in an LRU map. The syscall programs are left alone. - The agent reads and clears those counts every stats tick, and drains a process's entries when it exits, since a short-lived process is gone before the next tick. - container_tls_plaintext_dropped_total{reason} counts them per container. - The first loss per binary and reason is logged once as a warning, naming the executable and what the reason usually means. * fix(ebpf): find the socket behind wrapped Go connections The Go TLS probe found a connection's socket only if crypto/tls ran directly over *net.TCPConn, or over a wrapper embedding the connection at offset 0, one level deep. Proxies and scrapers wrap deeper. One reverse proxy's TLS connections are three wrappers deep, each embedding the next at offset 0. A scraper's wrapper puts an int32 counter before the embedded net.Conn, at offset 8. All of their TLS plaintext was dropped. The probe now descends up to four levels, taking the embedded net.Conn at offset 0 or 8. A level is accepted when its type is the binary's *net.TCPConn itab. Otherwise, as in stripped binaries, or PIE binaries whose symbol table holds the itab unrelocated, the fd it yields is accepted only if it names an IPv4 or IPv6 socket of the process. gRPC's syscallConn has the same shape and goes through the same walk. TLS over in-memory connections still has no socket and is still counted as go_fd_unknown. * fix(tls): log drops of unknown processes once per container, not once per node An unknown process has no executable identity, so its log key was the zero value and the first such warning on a node silenced the rest. Also name the per-pid drop map key type.
…es it HTTP/2 parsers are keyed by pid+fd alone. When a recycled fd got a new connection, either from its open event or from an L7 event that arrived first, the new connection inherited the previous one's parser and its HPACK dynamic table. Its headers then failed to decode, or decoded wrong. The parser is now dropped when the fd's connection is replaced. A parser already tagged with the new connection's timestamp is kept: it was created for this connection by an L7 event that beat the open event.
A level of the walk that was not a *net.TCPConn was still read as one. For a
wrapper struct the first word is an itab pointer, so the "Sysfd" read was the
itab's type hash, and when a value read that way named another live socket of
the process, the socket check accepted it: the session's plaintext went to
that connection, and it was marked TLS, every time, for that binary. On
kernels without BTF the socket check was skipped, so all four levels were
trusted unchecked.
A level found without the itab must now point to a net.netFD whose family is
AF_INET or AF_INET6 and whose sotype is SOCK_STREAM. The check reads only the
application's memory, so it holds without kernel BTF. Where the kernel's
struct offsets are known, the fd must also be a SOCK_STREAM socket of that
family. The netFD offsets come from DWARF and default to 56 and 64, which
Go 1.17 through 1.26 share. The walk no longer reads the gRPC syscallConn
itab, so its discovery is gone.
New metrics make the kernel-dependent part visible:
- node_agent_go_tls_fd_resolved_total{method,depth}: method is itab, socket
(netFD check plus kernel check) or shape (netFD check only, no BTF)
- node_agent_ebpf_info{program_variant,btf,socket_offsets}
- node_agent_ebpf_program_instructions and
node_agent_ebpf_program_verified_instructions, per program
TestProgramsLoad loads the variant the running kernel gets and logs each
program's size and verifier cost. TestGoTLSFdWalk runs TLS over a plain, a
wrapped and a decoy connection and checks which socket each one is
attributed to. Both need root and VM=1.
…onnection takes its fd A parser without a connection timestamp was created by events from a socket the kernel was not tracking, such as a connection older than the agent. A connection opening on its fd is tracked, and the kernel stamps every event of a tracked connection with its timestamp, so the parser cannot be the new connection's. It was kept, and the new connection inherited its HPACK table.
…dropped (#355) * feat(tls): attach Go TLS probes at exec, and log where L7 events are dropped A process's Go TLS probes were attached on its first connection, after its connect event had been read. That was late for short-lived programs: many exited first, and the rest had made their first requests unprobed. A program that a wrapper exec'd kept probes for the wrapper's binary until a throttled re-check noticed the change. - A sched_process_exec tracepoint reports execs. The agent attaches Go TLS probes for the new image at once, and drops those of the old one. OpenSSL is still attached on the first connection, because the loader maps libssl after the exec. - Process events are read every 10 ms, like connect events, instead of every 100 ms. - The periodic executable re-check stays as a fallback for lost exec events, at a 10 s interval. - Every L7 event dropped before parsing is logged once per container, reason and protocol, with the pid, fd and destination, so the counter's reasons can be traced to a workload. * fix(containers): report L7 events on non-IP sockets as no_ip_socket Events on sockets without an IP tuple, such as gRPC over a Unix socket, were counted as unknown_connection, which reads as a capture loss. The agent does not track those sockets, so they now get their own reason. * chore(ebpf): regenerate ebpf.go after rebasing onto the review fixes
Every L7 event was reserved in the ring buffer at the full struct size: a header plus two MAX_PAYLOAD_SIZE buffers, about 8 KB, whatever it carried. HTTP/2 frames of a streaming response are mostly a few hundred bytes with no response part. A burst of them filled the 32 MB buffer with mostly empty slots, and later events were lost. On a test cluster the loss was 8-12% of L7 events on the two nodes running a streaming LLM service. Events are now built in a per-CPU scratch buffer and copied into the ring with bpf_ringbuf_output at their actual length. That length is the header plus the payload, or the header, the payload buffer and the response when there is one. Payload and response keep their fixed offsets, so userspace decodes a short record as before. Reads that build an event and then drop it no longer take ring space either. node_agent_l7_ringbuf_drops_total now counts only events that were sent and lost.
There was a problem hiding this comment.
Code Review
This pull request optimizes L7 event submission by building events in a per-CPU scratch map (l7_event_heap) and copying them to the ring buffer with a dynamic length based on the actual payload or response size, preventing the ring buffer from filling up with empty slots. However, a security review identified a potential information disclosure vulnerability: because the scratch event's payload buffer is not fully zeroed out during reservation, stale data from previous events on the same CPU can be copied into the ring buffer when a response is present.
Payload copies into event and request buffers stopped at MAX_PAYLOAD_SIZE-1 bytes, while payload_size and the decoder allow MAX_PAYLOAD_SIZE. A read or write of 4096 bytes or more was decoded with a last byte the event never wrote: before, a byte left in the ring buffer by an older record; since the scratch buffer, one left by the previous event on that CPU. Go's HTTP/2 reads and flushes through 4 KB buffers, so 4096-byte events are common, and the frame that crosses the end of one is reassembled with that byte. Inside a header block it produces a wrong header value or an HPACK decode error, and the decoder reset after an error loses the dynamic table for the rest of the connection. The clamp is inline asm: written in C, clang compared a copy of the size and the verifier lost the bound for the response buffer.
main's tree equals the #353 branch this was built on, so this keeps the branch's tree and only records the merge.
|
Folded into #364 with the rest of this stack, so it can be reviewed and merged as one unit (squash-only merges made each stacked merge conflict). The commit is unchanged there; its description and review thread here stay as the detailed write-up. |
Summary
Each L7 event took a full-size slot in the
l7_eventsring buffer: a header plus twoMAX_PAYLOAD_SIZEbuffers, about 8 KB, no matter how much data it carried. HTTP/2 frames of a streaming response are usually a few hundred bytes and have no response part. A burst of them filled the 32 MB buffer with mostly empty slots, and the events that came after were lost (node_agent_l7_ringbuf_drops_total). Losing a HEADERS frame also corrupts that connection's HPACK state, so every later stream on the connection fails to decode.l7_event_heappattern this file used before the ring-buffer switch.bpf_ringbuf_outputthen copies each event into the ring at its real length: the header plus the payload, or the header, the full payload buffer and the response when there is one.payloadandresponsestay at the same offsets, and the decoder already checks lengths against the record, so userspace is unchanged.node_agent_l7_ringbuf_drops_totalnow counts only events that were sent and lost.Also fixed, found while answering review: payload copies stopped at
MAX_PAYLOAD_SIZE-1bytes, butpayload_sizeand the decoder allowMAX_PAYLOAD_SIZE. So every read or write of 4096 bytes or more was decoded with a last byte the event never wrote. Go's HTTP/2 reads and flushes through 4 KB buffers, which makes 4096-byte events common. On a test cluster about 15% of HTTP/2 events were exactly 4096 bytes.The frame crossing the end of such an event was reassembled with the wrong byte. Inside a header block that gives a wrong header value or an HPACK decode error, and an error resets the decoder and loses the dynamic table for the rest of the connection. Copies now take the whole buffer.
Stacked on #353.
Engineering detail
lenprovably non-negative beforebpf_ringbuf_output. An&=mask (inline asm, so clang keeps it) followed by a cap atsizeof(struct l7_event)satisfies it.TestProgramsLoadandTestGoTLSFdWalkpass on 5.10 and 6.1. Processed instructions forsys_enter_sendmsgdrop from 284,752 to 192,565.Local A/B, Docker VM, kernel 6.10. Same workload against the parent commit and this branch, two rounds each, 60s, Go HTTP/2 over TLS:
The 5.1% in round 2 is HPACK loss. Once HEADERS frames are dropped, almost no stream on the connection completes.
4096-byte writes, local A/B. A Go client writes HTTP/2 requests in TLS writes of exactly 4096 bytes, so a HEADERS frame crosses the end of every write. All headers are never-indexed, so any decode error comes from the captured bytes. 60s per run, ~84k requests:
Most requests still go undecoded in both columns because of the parser's 100-active-stream cap: the client pipelines faster than responses are matched. That is unrelated to this change.
Feeding the parser the same byte stream in a unit test, a wrong last byte in each 4096-byte chunk produces 16 HPACK errors over 202 chunk boundaries. With correct bytes there are 0. Most of the corruption decodes silently as wrong header values.
The full-size clamp is inline asm. Written in C, the verifier lost the bound for the response buffer (
off=4192 size=8191). It loads on 5.10 and 6.1, and processed instructions forsys_enter_sendmsggo from 192,565 to 195,678.Test cluster, with all nodes on this branch, compared to the parent commit with all nodes on it before. Workload is not controlled and drops come in bursts:
Local e2e: built agent images for both commits of this branch and for its parent, and ran them in a local Docker VM (kernel 6.10) under Go HTTP/2-over-TLS workloads. Ring-buffer commit: drops fell from 3.8%/5.5% to 1.0%/0.25% under bulk plus streaming load, and from 637/2,378 to 0/0 under a small-response flood, at the same captured event volume. Full-size copy commit: with raw 4096-byte HTTP/2 writes, HPACK errors fell from 300/242 to 5/7. eBPF load tests pass on 5.10 and 6.1 VMs for both. Deployed the ring-buffer commit to a test cluster: it loads on every node with no restarts, and the drop rate went from 0.22% to 0.09%. The full-size copy commit is not on the cluster yet.