Fix flaky: SymDB Logger wrapper swallows target exceptions#5943
Fix flaky: SymDB Logger wrapper swallows target exceptions#5943p-datadog wants to merge 1 commit into
Conversation
Most @logger.debug / @logger.warn calls in SymbolDatabase::Component run
on the scheduler thread:
- extract_and_upload success-path log (component.rb:500)
- extract_and_upload's rescue handler (line 511)
- scheduler_loop's rescue handler (line 458)
- start_upload's rescue handler (line 202, called from main but
schedules the scheduler thread)
A misbehaving customer logger (custom Logger subclass, IO error,
frozen state, rspec-mocks stub) that raises from any of these sites
escapes scheduler_loop, terminating the scheduler thread. Component
#shutdown! invokes @scheduler_thread&.join(5), and Thread#join re-
raises the unhandled exception in the caller — standard Ruby semantics
across every supported version. The customer sees a SymDB exception at
shutdown!.
Fix at the wrapper level: SymbolDatabase::Logger#debug and #warn
now swallow exceptions from the wrapped target. #trace routes through
#debug so it inherits the protection. The same defense pattern that
install_hot_load_hook applies inline at component.rb:566-571 now
applies at every SymDB log site automatically.
Implementation: replaces Forwardable.def_delegators with explicit
methods. Forwardable's generated forwarders cannot rescue; the explicit
version uses bare rescue (StandardError) — IOError / Errno from a disk-
full or broken pipe logger are caught, SignalException / SystemExit
are not.
New spec covers debug / warn / trace under both success and target-
raises conditions.
The companion reproducer at spec/datadog/symbol_database/
logger_boom_reproducer_spec.rb is on the reproduce-symdb-scheduler-
logger-boom branch and demonstrates this fix neutralizing the bug.
Typing analysisNote: Ignored files are excluded from the next sections. Untyped methodsThis PR introduces 4 partially typed methods, and clears 4 partially typed methods. Partially typed methods (+4-4)❌ Introduced:Untyped other declarationsThis PR introduces 2 untyped other declarations, and clears 2 untyped other declarations. Untyped other declarations (+2-2)❌ Introduced:If you believe a method or an attribute is rightfully untyped or partially typed, you can add |
|
BenchmarksBenchmark execution time: 2026-06-23 18:15:13 Comparing candidate commit 6093b4e in PR branch Found 0 performance improvements and 0 performance regressions! Performance is the same for 48 metrics, 1 unstable metrics.
|
What does this PR do?
Fixes the Ruby 2.6 flake of
spec/datadog/symbol_database/component_spec.rb:752— "does not propagate exceptions when logger.debug itself raises" — observed in PR #5798 CI.Motivation:
Flaky test Ruby 2.6 / build & test (standard) [0] on 2026-06-15.
Failure:
The test sets up
allow(raw_logger).to receive(:debug).and_raise(RuntimeError.new('logger boom'))then defines a class to trigger the hot-loadTracePoint(:class). The reported failure points to the hot-load hook'slogger.debugcall site atcomponent.rb:567, suggesting the inner rescue atcomponent.rb:566-571failed to catch.Root cause:
The hot-load hook's inner rescue is not broken — it catches every time. Diagnostic STDERR.puts confirmed:
The
logger boomexception that surfaces in the test is from the scheduler thread, not the hook callback. The rspec-mocks stub is process-wide, so every@logger.debugcall inDatadog::SymbolDatabase::Componentraises — including the four scheduler-path sites that have no inner rescue:extract_and_uploadsuccess-path log atcomponent.rb:500extract_and_upload's rescue handler atcomponent.rb:511scheduler_loop's rescue handler atcomponent.rb:458start_upload's rescue handler atcomponent.rb:202Causal chain on the failing run:
Component.buildwithforce_upload = truestarts the scheduler thread, which entersextract_and_upload.extract_all(ObjectSpace walk) takes longer thanwait_for_idle(timeout: 5)in a loaded test environment.wait_for_idlereturnsfalse; the test ignores the return value.allow(raw_logger).to receive(:debug).and_raise(...)while the scheduler is still insideextract_and_upload.@logger.debug { "symdb: initial extracted ..." }→ stub raises.@logger.debugraises again, escapes to scheduler_loop's rescue at line 457, line 458 raises again, escapes scheduler_loop entirely.Thread.report_on_exception=trueprints the trace.ensurecallscomponent.shutdown!, which invokes@scheduler_thread&.join(5).Thread#joinre-raises the joined thread's unhandled exception in the caller — standard Ruby semantics, all MRI versions.ensure, surfaces as the example failure with the scheduler thread's backtrace.The flake is not Ruby-2.6-specific — every link in the chain (missing rescues,
Thread#joinre-raise) is identical across all supported MRI Rubies. The 2.6-only CI observation is a timing artefact: Ruby 2.6's slowerObjectSpaceiteration and no-JIT bytecode dispatch makeextract_allmore likely to exceed the 5-secondwait_for_idlebudget.Fix:
Datadog::SymbolDatabase::Loggeris a thin wrapper around the customer's logger. Its job is to be a defensive facade — but theForwardable.def_delegatorsit uses fordebugandwarnpropagates target exceptions verbatim. Replacedef_delegatorswith explicit methods that swallow exceptions:#tracealready routes through#debug, so it inherits the protection. Every@logger.debug/@logger.warn/@logger.tracecall site inDatadog::SymbolDatabase::*now silently tolerates a misbehaving target without further per-site rescues.Bare
rescue(StandardError) is intentional:IOError/Errnofrom a disk-full or broken-pipe logger are caught;SignalException/SystemExitare not.The existing inner rescue at
component.rb:566-571(aroundinstall_hot_load_hook'slogger.debug+telemetry.report) is left in place — it still protects againsttelemetry.reportraising, which the logger fix does not cover.Change log entry
None.
How to test the change?
bundle exec rspec spec/datadog/symbol_database/logger_spec.rb— 13 examples covering debug/warn/trace under both success and target-raises conditions.bundle exec rspec spec/datadog/symbol_database/— full symbol_database suite passes (374 examples) on Ruby 2.6.10, 3.0.7, 3.1.7, 3.3.10, 3.4.8.Companion PRs: