Skip to content

Fix agent crashes and lost trace segments found in the plugin audit - #262

Merged
mrproliu merged 2 commits into
mainfrom
fix/agent-crashes-and-leaked-segments
Oct 19, 2026
Merged

mrproliu merged 2 commits into
mainfrom
fix/agent-crashes-and-leaked-segments

Conversation

@wu-sheng

Copy link
Copy Markdown
Member

This PR fixes the highest-severity agent bugs found in a full audit of the plugins and the runtime instrumentation. Every bug here either crashes the application, breaks a request that works without the agent, or leaves a span open. An open span means the whole trace segment is never reported, usually the segment of the incoming request, and a collector goroutine leaks.

All of these bugs predate the Go 1.26 move (#260). Each one was reproduced on unfixed main first, then shown fixed by the same check. Every fix has a regression test that fails on the old code, and most also add a case to the plugin scenario.

The fixes

Agent core

Bug What the user sees Cause Fix Evidence
Goroutine start can crash the process fatal error: semacquire not on the G stack, which can't be recovered. It happens when a goroutine starts while another goroutine holds the lock of the starting goroutine's active span, for example a worker tagging an async span through SpanRef. The trace context snapshot for the new goroutine was taken in a defer in runtime.newproc1, which runs on the system stack. Waiting for a contended sync.Mutex there is a fatal throw. The snapshot is taken in runtime.newproc and runtime.newcoro, right before they switch to the system stack, and stored in a new g field. newproc1 only moves the reference. The snapshot is skipped while the goroutine holds runtime locks, because the runtime starts its GC workers between acquirem and releasem, where blocking is fatal too. A stress app with workers tagging the active span crashed 3 of 3 times on Go 1.27 and 2 of 2 on Go 1.26.9; the stack confirms the cause. A second app raises GOMAXPROCS and runs runtime.GC() under the same contention, so GC workers start on the traced goroutine. Unfixed main: 15/15 semacquire not on the G stack. Without the runtime-lock guard: 15/15 schedule: holding locks. Fixed: 15/15 pass. After the fix, both apps pass on Go 1.26.9 and 1.27.1. Context still reaches new goroutines and iter.Pull coroutines. A unit test checks the rewritten runtime code.
Logging in a package init panics at startup logrus or zap logging from an init that runs before the agent core: nil pointer panic, and the process exits. GetLogContext called GetOperator().LogReporter(), but the operator is nil until agent core init. Return no log context when the operator is nil. The toolkit logging API gets the same check. Before: panic at skywalking_logrus_context.go:82 (logrus v1.10.2) and skywalking_zap_context.go:82 (zap v1.28.0). After: both apps exit 0. Unit tests in tools/go-agent/instrument/logger and plugins/toolkit-activation/logging.
Toolkit exit span with a failing injector The segment is never reported. CreateExitSpan registered the span, then returned nil, err without ending it. End the span before returning the error. TestCreateExitSpanInjectorError: 0 spans reported before, 2 after.

grpc (plugins/grpc and plugins/grpc-v184)

Bug What the user sees Cause Fix Evidence
Client stream Exit span never ends The trace segment is lost when NewStream fails, when a client stream interceptor wraps the stream (logging, metrics, retry, auth), or when the stream ends without a RecvMsg (cancel, connection closed, SendMsg error). AfterInvoke read the error from result[0]. AsyncFinish happened only for a bare *clientStream, and only after a RecvMsg had armed the clientStream.finish hook. A new hook on newClientStreamWithParams (same signature in v1.83.2 and v1.84.0) adds a grpc.OnFinish call option to the *clientStream that grpc creates, whatever wraps it. grpc calls it once, with the final status, after the stream finishes; the finish hook is gone. The agent's callback runs before the application's and can't panic into grpc. Each creation gets a generation, so the callback of a failed creation is ignored (grpc before v1.84 calls it). A mutex-guarded state machine ends the span exactly once, including when the stream finishes before NewStream returns. NewStream ends the span synchronously on an error, when no stream of the call was created, or when a stream interceptor panics after creating it. The stream snapshots are published under the lock, because an interceptor can use the stream on another goroutine before NewStream returns. The span records the final status, so a failed or canceled stream is an error span. Lifecycle tests per plugin replay grpc's call sequence. Before: reported spans = 0 for the failed, wrapped, canceled, send-error and early-finish cases. They are joined by tests for a cancel before the stream is attached, an interceptor that panics after creating the stream, a creation retried after a failure, and a panicking application OnFinish. Each fails on the code before its fix, and all pass with -race. Instrumented compile and run at v1.83.2 and v1.84.0 through a wrapping stream interceptor, with 0 interceptor errors.

HTTP servers

Bug What the user sees Cause Fix Evidence
http, mux, goframe writer wrappers hide optional interfaces Server-sent events fail (w.(http.Flusher) is false). http.NewResponseController returns ErrNotSupported. GoFrame WebSocket upgrades answer 500, because GoFrame's unchecked .(http.Hijacker) panics. The wrappers implemented neither Flush nor Unwrap, and the goframe wrapper didn't implement Hijack either. wrapResponseWriter picks a wrapper type that implements http.Flusher and http.Hijacker exactly when the wrapped writer does, so type assertions take the same branch as without the agent. Unwrap and FlushError serve http.ResponseController. Status capture is unchanged. Before: flusher=false, deadline=feature not supported, SSE 500, GoFrame upgrade 500 ... is not http.Hijacker. After: all pass, including a real GoFrame v2.10.3 WebSocket handshake. Compiled and run at the min and max version of each framework.
echov4 answers 500 to a bad sw8 Any request with an undecodable sw8 header (from another tracer or a broken proxy) gets HTTP 500, and anyone can trigger it remotely. The middleware returned the decode error without calling next(c). Log the error and serve the request untraced, as the http, gin, go-restful and kratos plugins already do. TestMalformedSW8HeaderIsServed: 500 before, 200 after. The scenario sends sw8: x.
echov4 handler panic leaks the span The segment is lost, and the span stays active, so it absorbs the next keep-alive request on that connection. span.End() wasn't deferred. A deferred function with a completion flag ends the span as an error when the handler panics or calls runtime.Goexit. It doesn't call recover, which would also stop a panic(nil) under GODEBUG=panicnil=1, so the panic propagates unchanged. TestPanicEndsSpan, TestPanicRecoveredByPreMiddleware, TestNilPanicIsNotSwallowed, TestGoexitEndsSpan: spans lost (and the nil panic swallowed by an intermediate fix) before, reported after.

Databases

Bug What the user sees Cause Fix Evidence
mongo partial CommandMonitor SetMonitor(&event.CommandMonitor{Succeeded: f}) crashes the process on the first command. A user Succeeded or Failed callback that panics leaves the command span open. The wrapper called the user's callbacks after only a struct nil check (the driver has no recover), then finished the span after them. Nil-check each user callback, and finish the span in a defer registered before calling the user's callback. TestPartialUserMonitor panics before; TestPanickingUserMonitorFinishesSpan reports 0 spans before. Both pass after. The scenario app panicked in publishStartedEvent before the fix.
sql Conn.Raw The segment is lost. The after-hook read results[1], but Raw returns only an error, so it panicked before End. Read results[0]. TestConnRawEndsSpan: index out of range before, passes after. The mysql scenario's /execute segment was never reported before the fix.
gorm span lost with a session scope, or on a hook panic With a scope that returns a session, such as tx.WithContext(ctx), every gorm operation's segment is lost. When a gorm hook such as AfterFind panics and the caller recovers, the segment is lost too. InstanceSet clones the statement when the *gorm.DB comes from a session and stores the span in the clone, where the end callback never finds it. gorm runs callbacks without defer, so a panic skips the end callback. Keep the span in the running statement's Settings, under the same statement-address key that InstanceSet uses. A new hook on (*processor).Execute, whose agent after-hook is deferred, ends a span the end callback left open and marks it as an error, without recovering the panic. TestScopeSessionSpanIsEnded and TestScopeSessionHookPanicEndsSpan: 0 spans with the old storage, pass after. TestHookPanicEndsSpan: 0 spans before, passes after, including the nested sql exit span.

Message queues

Bug What the user sees Cause Fix Evidence
pulsar SendAsync(ctx, msg, nil) The process crashes when the receipt arrives. The client itself allows a nil callback. The wrapper always called the user callback, on an SDK goroutine that has no recover. Call the user callback only when it is set. The async result is still traced. Unit test. The scenario process crashed with a nil pointer at connection.go:744 before the fix.
pulsar failed Receive The hook panics. Unchecked result[0].(pulsar.Message) on a nil message. A failed Receive received nothing and creates no span. An entry span would take over the caller's own entry span, such as the one of an HTTP request. TestReceiveFailedNoSpan under an HTTP entry span: the entry span is renamed before, unchanged after.
pulsar broker lookup per message Each send and receive sends an extra lookup request to the broker, blocks during broker trouble, and ignores the caller's context. A lookup failure drops the span. The span peer came from lookupService.Lookup. A NewClient hook stores the client's service URL. The peer and mq.broker are that URL, as in the Java agent; in a multi-broker cluster this changes them from the owning broker's address. Test*NoLookupRPC: lookups counted before, 0 after. The scenario's expected peer is unchanged.
rocketmq failed SendSync The segment is lost when the broker is down or returns an error. sendRet.MessageQueue.QueueId was read before End, but a failed send has a nil MessageQueue. defer span.End(), and guard the nil MessageQueue. TestSendSyncFailedEndsSpan. The scenario's /execute segment was never reported before the fix.
rocketmq empty send An agent panic is logged when a send has no messages. msgList[0] was read before the SDK's empty check. Return early. TestEmptySendNoPanic.

RPC

Bug What the user sees Cause Fix Evidence
kratos nil request header With kratos v2.7.2 or later, a body-less client call with khttp.Header(&h) and a nil h panics (assignment to entry in nil map) in middleware that has no recover. Since v2.7.2 kratos sends h as the request header, so the plugin's RequestHeader().Add wrote into a nil map. Write into the outgoing request's header, creating it when nil, as net/http does. Unit test, per kratos version: v2.7.2, v2.7.3, v2.8.4 and v2.9.2 panic with the agent and pass without it. v2.6.3 to v2.7.1 aren't affected.
go-micro tracing failure fails the call Call with an empty service and client.WithAddress returns peer is empty and is never sent. The same happens for Stream and Publish. The wrapper returned the CreateExitSpan error to the application. Log it and run the call untraced. The node selector no longer sets the selected node as the peer of the caller's span for such a call. TestUntraceableCallsAreDelegated, TestNextKeepsCallerPeerForUntracedCall. An instrumented app at v4.9.0 and v4.11.2 now really attempts the call.

Behavior changes to note

  • pulsar: the span peer and mq.broker are the client's service URL instead of the address of the broker that owns the topic.
  • grpc: a client stream that ends with an error status, including a canceled stream, now has an error Exit span.
  • echov4: the span log of a panicking handler no longer carries the panic value, since the middleware no longer recovers the panic.
  • http: on writers without http.Hijacker, such as HTTP/2, the http plugin's wrapper no longer has a Hijack method that returns an error. Applications now see the same as without the agent.
  • Runtime: goroutines that the runtime starts for debugger calls, for testing/synctest bubbles, and for GC workers no longer inherit the trace context.

Verification

  • go test -race, go vet, and golangci-lint v2.15.0 report 0 issues in all 16 touched modules.
  • Instrumented compile checks (-toolexec, GOWORK=off) at the lowest and highest supported version of every touched framework, and on both sides of the grpc v1.84.0 split. All were also run, with 0 interceptor errors.
  • Three rounds of review by GPT-6 Astra Max against the framework and Go runtime sources of the supported versions. The findings of each round are fixed in this PR; all three review scopes approve. One finding is left for a follow-up because it predates this PR and isn't made worse: an inline pulsar send failure clears the caller's tracing context.
  • Plugin scenarios: CI runs every scenario at every listed version. Local runs were limited because the Docker disk filled up and module downloads failed in the image builds. These passed locally:
    • cross-goroutine, trace-activation, kratosv2 (5 cases), and microv4 (6 cases);
    • mysql (4 Go 1.26 cases), postgres (3 Go 1.26 cases), and pulsar v0.12.0, before the review-round changes.

🤖 Generated with Claude Code

wu-sheng and others added 2 commits October 19, 2026 09:48
Fix the highest-severity agent bugs: an application crash, a request that
the agent breaks, or a span that never ends, so that the whole segment is
never reported.

- runtime: take the goroutine context snapshot on the creating goroutine's
  stack before the system stack switch, and not while it holds runtime locks;
  a contended span lock in newproc1 was a fatal "semacquire not on the G stack"
- logrus, zap, toolkit logging: no panic when logging before the agent core
  is initialized, for example from a package init function
- core: end the exit span when its injector fails
- grpc, grpc-v184: finish every client stream exit span exactly once from a
  grpc.OnFinish call option added in newClientStreamWithParams
- http, mux, goframe: keep the Flusher, Hijacker, and Unwrap interfaces of the
  response writer
- echov4: serve a request with an undecodable sw8 header untraced instead of
  answering 500; end the span on a panic or Goexit without recovering it
- mongo: no crash with a partial user CommandMonitor; finish the span when a
  user callback panics
- sql: end the span of Conn.Raw
- gorm: keep the span on the running statement, so a scope that returns a
  session does not lose it; end the span when a callback or hook panics
- pulsar: no crash on SendAsync with a nil callback, no panic or span on a
  failed Receive, no broker lookup RPC per message
- rocketmq: end the span of a failed SendSync; no panic on an empty send
- kratos: no panic on a nil request header (kratos v2.7.2 and later)
- go-micro: a tracing failure no longer fails the call

Every fix has a regression test that fails on the old code.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
gorm, gorm-postgres: the span of the operation whose hook panics carries the
error log of the Execute hook.

grpc: list the server segment of the wrapped stream after the other server
segments, in the order they are reported. The validator first matches
segments with a loose reference check (endpoint, service, address, type),
so listed first it matched the structurally identical server segment of the
earlier server-streaming call, and the strict reference check then failed.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@wu-sheng wu-sheng added this to the 0.8.0 milestone Oct 19, 2026
@wu-sheng wu-sheng added the bug Something isn't working label Oct 19, 2026
@wu-sheng
wu-sheng requested a review from mrproliu October 19, 2026 04:30
@mrproliu
mrproliu merged commit b4cb55d into main Oct 19, 2026
49 checks passed
@mrproliu
mrproliu deleted the fix/agent-crashes-and-leaked-segments branch October 19, 2026 16:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants