sdk/trace: fix deadlock in RecordError on reentrant error formatting - #8846
sdk/trace: fix deadlock in RecordError on reentrant error formatting#8846sooraj-sky wants to merge 2 commits into
Conversation
RecordError acquired the span mutex before evaluating the caller-supplied error via err.Error(). If that method calls back into the same span (e.g. AddEvent), it deadlocks on the non-reentrant mutex. Evaluate err.Error() and the exception type before acquiring the lock so arbitrary caller code in Error() can safely record telemetry on the span. Fixes open-telemetry#8782 Signed-off-by: Sooraj Macbook <ops@skywalks.in>
Signed-off-by: Sooraj Macbook <ops@skywalks.in>
MrAlias
left a comment
MrAlias
left a comment
There was a problem hiding this comment.
The callback needs to remain outside the span mutex without changing RecordError's no-op contract; the regression coverage should pin both sides of that invariant.
| _, span := tp.Tracer(t.Name()).Start(t.Context(), "span") | ||
| t.Cleanup(func() { span.End() }) | ||
|
|
||
| span.RecordError(reentrantRecordError{span: span}) |
There was a problem hiding this comment.
This only proves that the call returns. It would also pass if RecordError became a no-op or stopped recording either the reentrant event or the exception event, so it does not protect the behavior this fix is changing. Could we inspect the recording span's events and assert that both "from Error" and semconv.ExceptionEventName are present, including the exception message?
| // err.Error() is arbitrary user code and may call back into this span | ||
| // (e.g. AddEvent), which would deadlock on the non-reentrant mutex below. | ||
| errType := typeStr(err) | ||
| errMsg := err.Error() |
There was a problem hiding this comment.
RecordError promises to do nothing when the span is not recording, but err.Error() now runs before that state is checked. After span.End(), this can execute arbitrary formatter side effects or panic even though the method should be a no-op. Could we perform an initial recording check, format without holding the mutex, and recheck under the lock before adding the event? A test with an ended span and an error that records whether Error() was called would pin this contract.
2 participants
Summary
recordingSpan.RecordErroracquired the span mutex before evaluating the caller-suppliederrorviaerr.Error(). If that method calls back into the same span (e.g.AddEvent), it deadlocks on the non-reentrant mutex.Span. #5874, which moved lock acquisition ahead of error formatting.err.Error()and the exception type before acquiring the lock, so arbitrary caller code inError()can safely record telemetry on the span without deadlocking.TestRecordErrorAllowsReentrantErrorFormatting), which times out onmainand passes after the fix.CHANGELOG.mdunderUnreleased/Fixed.Fixes #8782
Test plan
go test ./trace -run '^TestRecordErrorAllowsReentrantErrorFormatting$' -count=1— times out/deadlocks before the fix, passes aftergo test ./trace/... -count=1— all 365 tests passmake precommit— lint, generate, go-mod-tidy, license-check, misspell, verify-readmes, verify-mods, and the default test suite all pass