Repository navigation
fix(tls): count TLS capture losses and fix the gaps they exposed - #353
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.
![gemini-code-assist[bot]](https://avatars.githubusercontent.com/in/956858?s=60&v=4){kind=small}
There was a problem hiding this comment.
Code Review
This pull request improves TLS uprobe attachment, connection tracking, and self-observability metrics in the node agent. Key changes include handling connection events that arrive before process start events, re-checking TLS uprobes after a process executes a new binary, resolving reused file descriptor mismatches using kernel timestamps, and introducing new Prometheus metrics to track dropped L7 events and TLS plaintext. Additionally, mutexes are added to protect process-level statistics from concurrent access. The review feedback highlights a potential data race on Node.js and Python stats between the update methods and the Collect method, suggesting that these fields should be protected with a lock during scrapes.
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.
|
/gemini review |
There was a problem hiding this comment.
Code Review
This pull request enhances TLS and L7 event tracking by introducing metrics for TLS plaintext drops, L7 ring buffer drops, and TLS uprobe attachment outcomes. It improves Go TLS file descriptor extraction by unwrapping nested connection interfaces, handles process execs for re-attaching probes, and registers processes for socket events that arrive early. Additionally, it addresses concurrency by guarding process fields with a mutex. The reviewer feedback highlights a critical issue where stale HTTP/2 parsers are not cleaned up during file descriptor reuse, which can lead to HPACK decode errors, and suggests immediately deleting the stale parser when a connection is replaced.
…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.
|
Thanks for the quick turnaround. The NAT fix, the exec re-check on every new socket, and the parser drop on fd reuse all look right. I checked 1. The walk has only been loaded on kernel 6.10. 2. The walk can pick an unrelated socket. 3. Socket validation is silently off when BTF is missing. 4. A parser with no connection timestamp survives fd reuse. Metrics: making kernel-dependent behaviour visible Whether the walk validates its result, and whether socket-tuple fallbacks work at all, now depends on the node's kernel and BTF. I'd expose that next to the new counters, so a capture gap on one cluster can be told apart from a bug:
None of these are blockers if (1) is checked, but (3) and the metrics would let us see the difference between clusters rather than infer it. Minor: |
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.
|
Thanks. All four are addressed in eea8da1 and 4416bc8; details per point. 1. Loading on 5.4 and 5.10 I loaded the build with a new root-only test,
On 5.4 the collection fails before any program is verified, with Go TLS programs on 5.10 x86_64, xlated instructions / verifier-processed instructions:
arm64 is within a few instructions of these. The largest program overall is 2. The walk picking an unrelated socket Agreed. A level found without the itab now has to point to a
3. BTF missing The netFD check reads only the application's memory, so it applies with or without BTF. I ran 4. Parsers with no timestamp Not intended. Every event of a tracked connection carries its timestamp, so a parser with Metrics
Minor The gRPC syscallConn itab discovery is removed, and I also ran the agent on 6.1 with a Go HTTPS client, half its connections wrapped. In a build with the itab, they resolve as |
…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
|
Thanks, this addresses everything I raised. The netFD shape check closes the decoy case: an itab can never hold 2/10 then 1 at those offsets, and it works without BTF. The load results, the new metrics and the parser fix all look good. I also checked that the 56/64 defaults reach every version path and that Two follow-ups, neither blocking:
I'll open issues for those and for the remaining gaps (read-first memory-BIO servers, SSL_write emitted at entry, no Python/Node re-instrumentation after exec, per-binary attach) once this merges. |
main's tree equals the #353 branch this was built on, so this keeps the branch's tree and only records the merge.
main's tree equals the #353 branch this was built on, so this keeps the branch's tree and only records the merge.
|
On follow-up 1 (agent CPU of attaching at exec), measured locally (Docker VM, kernel 6.10). The figures are agent cgroup CPU over a 180s idle window, then 300s with a stripped Go CLI that links crypto/tls but never connects, exec'd ~3.3 times a second (the #352 setup):
|
#370) * cgroup: add podruntime.slice to recognized systemd slices (cherry picked from commit 5b2cb5f9f880c89ab3ac7983c0d6afa3643e47ad) * add php-fpm detection to application type matching (cherry picked from commit 91fdf8d97d177b2b380ba258a95869f00bf0b0ef) * feat: add custom CA file support for TLS cert verification (cherry picked from commit fa609dac7bce1a06b224dcf8aaeff03f8525e040) * send remote-write requests with an explicit Content-Length (cherry picked from commit a5999aff838846b8f5a460b141e534e16c89e204) * clean up stale container mounts to prevent duplicate disk metrics (cherry picked from commit 3d898f9b37b5972bc76447224d4d850fe888c135) Fork adaptation: upstream updates c.mounts in getMounts without a lock; here onFileOpen writes c.mounts under c.lock from the event goroutine, so the reconcile runs under c.lock and the statfs loop uses a snapshot. * fix: systemd services disappearing after a restart (cherry picked from commit 75d6656426ff5139443cfb2c9c06c3622ce013c4) Fork adaptation: only the process-registration half is taken here. The fork already had ensureProcess (#353); its lookup now holds c.lock. Start events keep calling onProcessStart, which replaces a reused pid. The createdAt fallback for --min-container-age comes with that flag (B2). * support multiple ephemeral port ranges (cherry picked from commit 2d90d4abb42df1dd2a8b8a8b8b060e04fcb87a30) * fix: don't get stuck on a bad spool chunk (cherry picked from commit 273c780a4eea756467de15c6b3d6fc4e3fe56cd6) * ebpftracer: report missing BPF tracing program types clearly On kernels built without CONFIG_BPF_EVENTS (e.g. NVIDIA JetPack 5 / L4T 5.10 with CONFIG_KPROBES=n), BPF_PROG_TYPE_TRACEPOINT and BPF_PROG_TYPE_KPROBE are compiled out and bpf(BPF_PROG_LOAD) fails with a bare EINVAL. The agent then exits with failed to load collection: program sched_process_exit: load program: invalid argument where the program name is whichever program happened to load first, and nothing points at the kernel configuration. Probe TracePoint and Kprobe support with cilium/ebpf/features before loading the collection and fail with an error naming the missing kernel option. Only a conclusive ebpf.ErrNotSupported is reported; any other probe result falls through to the real collection load so existing error paths are unchanged. Document the CONFIG_BPF_EVENTS requirement in the README. (cherry picked from commit f76895d48f7ee98da2224376140351e057c6c336) * fix(prom): tolerate spool files removed by the other loop sendLoop and truncateSpoolIfNeeded (scrape goroutine) both remove spool files. A file removed between listing and use made sendLoop back off (5s to 1m) instead of moving to the next file, and made truncateSpoolIfNeeded return an error, so writeToSpool dropped the payload it was about to spool. Both now skip a file that is gone. --------- Co-authored-by: Alexandre Proulx <alexandre.proulx.3@gmail.com> Co-authored-by: Nikolay Sivko <n.sivko@gmail.com> Co-authored-by: Vishnu Kvs <116954249+vishnukumarkvs@users.noreply.github.com> Co-authored-by: KR Ravindra <42912207+KR-Ravindra@users.noreply.github.com>
2 participants
Problem
When TLS capture fails, nothing says so at default verbosity. Attach failures are logged at
-v=2/-v=3or not at all. In the kernel, a TLS hook that cannot find its socket returns silently (bpf_printkonly in a debug build), and a full L7 ring buffer drops events uncounted. In the agent, L7 events that miss their connection are discarded with a-v=3line. Every recent capture gap was found by someone suspecting it and cross-checking by hand.A review of the TLS capture paths also turned up gaps of its own: short-lived processes were missed, one binary could hide another at the same path, exec wrappers were never re-probed, OpenSSL plaintext could be claimed by an unrelated socket, and a data race existed on the process's uprobe list.
Change
Visibility
node_agent_tls_attach_total{lib, result}counts every attach attempt:attached,attached_no_offsets,no_library,no_symbols,unsupported,process_exited,error,not_registered. This is the attach-outcome counter proposed in feat: add agent self-observability metrics #208.-v=2.node_agent_tls_plaintext_dropped_total{reason}counts TLS plaintext the kernel saw in a hook but could not attribute to a socket. The reasons arego_fd_unknown,ssl_read_fd_unknownandssl_write_unclaimed.node_agent_l7_ringbuf_drops_totalcounts L7 events lost to a full ring buffer.node_agent_l7_events_dropped_total{reason, protocol, tls}counts events dropped in the agent before parsing. The reasons areunknown_connection,stale_connection,unknown_process,retry_queue_full,retry_expiredandpanic.Fixes
onConnectionOpenignored the unknown pid, so the process's first connection was never tracked, and TLS attach waited for the start event.crypto/tlsat/app/serverused to stop every other container's/app/serverfrom being probed.SSL_writeand the ciphertext write used to take the plaintext and be marked TLS.Processstate shared between the instrumentation goroutine, the event loop and the scrape path is now under a mutex. That state is the uprobe list, the Go flag, the .NET monitor, the Node.js/Python stats and the GPU samples. Uprobes attached after the process closed are closed instead of leaked.LookupSymbols, cached per library file, like the Go and Node.js paths.connectionKey). They are the connection's open event, and the socket tuple of an L7 event that arrived first. The socket-tuple path takes its actual destination from the kernel's conntrack-derivedactual_destinationsmap, as open events do. Before this, now that those connections are kept, they would have tracked traffic to ignored destinations and labelled requests with a service's virtual IP as their actual destination.Deliberately unchanged
ensure_connection_trackedstill setsdport = 443(fix: GoTLS destination port hardcoded in eBPF probe #209). The value only feeds in-kernel protocol detection, and replacing it with the real port would turn off the port-gated HTTP/2 detection for preface-less gRPC on other ports. The comment now says why. Event labels already take the real port from the socket.crypto/tlsa wrappednet.Connwhose socket the probe cannot find, which shows asgo_fd_unknown. That reason also includes TLS over in-memory connections (net.Pipe, gRPC bufconn).ssl_read_fd_unknown).SSL_writecalls before one flush. A memory-BIO app that does this loses the first write's plaintext (ssl_write_unclaimed).SSL_writeentry, so a retry can duplicate HTTP/2 frames.tls_attach_total{result="process_exited"}).Verification
ebpftracer/tls_attach_test.go:gofmt,goimports,go vet ./..., golangci-lint (forcetypeassert) andgo test. Thecontainerspackage was also run locally.ebpftracer/ebpf.gois regenerated withmake build.Local end-to-end run
Local e2e: built the agent from this branch and ran it privileged in a local Linux VM (kernel 6.10, standalone mode) against a scenario set, then ran the same set against the current
mainimage.crypto/tlsand a Go TLS client at the same path in two containers;ssl.MemoryBIOclients, with and without a UDP send betweenSSL_writeand the socket write;net.Pipeafter one real request.container_http_requests_totalfor each client container.main-racebuildmainare the uprobe-list race fixed here. One side isinstrumentPythonappending in the instrumentation goroutine; the other isattachTlsUprobesin the event loop.-raceneeds-gcflags=all=-d=checkptr=0on both builds: checkptr aborts on an unsafe conversion inside the third-party taskstats client.go_fd_unknown= 120 for the TLS-over-pipe run (forced case);ssl_write_unclaimed= 19 for SSL_writes deliberately never sent (forced case);go_tls_offsets_mapback to 2 entries at the end;node_agent_l7_events_dropped_total{reason="stale_connection"}showed 268 TLS HTTP events and 814 DNS events dropped; after the fix it shows none in that scenario.Soak. The two images ran 10 minutes each under the same mixed load: the short-lived Go clients, a looping Python memory-BIO client with UDP sends, and a long-lived non-TLS Go client.
mainThe CPU difference is the cost of parsing about 18x more captured events.
The scenarios were re-run after 4a42db2 (stats read under the container lock) with the same results.
Cluster run. The branch ran on a multi-node Kubernetes cluster as a DaemonSet. Rates below are per minute over 5-minute windows taken after each rollout settled. TCP connects are shown as the load reference.
container_http_requests_total)container_dns_requests_total)stale_connectionThe middle column is why 0c8bf1a exists: without the shared filters and NAT lookup, the newly kept socket-tuple connections leaked ignored traffic and pre-NAT labels.
On 0.1.8, almost all DNS events were dropped as stale, which the agent relies on for IP-to-name resolution. All pods ran with 0 restarts and no scrape errors.