Skip to content

Validate fix for flaky: SymDB scheduler logger.debug#5944

Open
p-datadog wants to merge 4 commits into
masterfrom
validate-symdb-scheduler-logger-boom
Open

Validate fix for flaky: SymDB scheduler logger.debug#5944
p-datadog wants to merge 4 commits into
masterfrom
validate-symdb-scheduler-logger-boom

Conversation

@p-datadog

Copy link
Copy Markdown
Member

What does this PR do?

Validates that the fix in #5943 neutralizes the forced failure in #5942. This branch merges:

If CI passes, the fix addresses the exact failure mode the reproducer forces.
If CI fails, the fix is insufficient.

Do not merge — this PR exists for validation only.

Change log entry

None.

How to test the change?

CI passes = fix works against the forced failure. CI fails = fix is insufficient.

Companion PRs:

p-ddsign added 4 commits June 23, 2026 13:44
Hypothesis: when raw_logger.debug is stubbed to raise (as in PR #5871's
"does not propagate exceptions when logger.debug itself raises" test),
the scheduler thread's @logger.debug calls in extract_and_upload,
scheduler_loop's rescue, and start_upload's rescue have no inner rescue
and terminate the thread. Component#shutdown!'s @scheduler_thread.join
then re-raises the exception in the test thread (standard Thread#join
semantics, all Ruby versions).

Forces the race deterministically by holding the scheduler in
extract_all on a Queue, activating the stub, then releasing.

Reproduces on Ruby 2.6.10, 3.0.7, 3.1.7, 3.3.10, 3.4.8 locally.
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.
@p-datadog p-datadog added the AI Generated Largely based on code generated by an AI or LLM. This label is the same across all dd-trace-* repos label Jun 23, 2026
@dd-octo-sts dd-octo-sts Bot added the debugger Live Debugger (+Dynamic Instrumentation, +Symbol Database) label Jun 23, 2026
@dd-octo-sts

dd-octo-sts Bot commented Jun 23, 2026

Copy link
Copy Markdown
Contributor

Typing analysis

Note: Ignored files are excluded from the next sections.

Untyped methods

This PR introduces 4 partially typed methods, and clears 4 partially typed methods.

Partially typed methods (+4-4)Introduced:
sig/datadog/symbol_database/logger.rbs:8
└── def initialize: (untyped settings, ::Logger target) -> void
sig/datadog/symbol_database/logger.rbs:16
└── def debug: (?untyped? message) ?{ () -> untyped } -> void
sig/datadog/symbol_database/logger.rbs:17
└── def warn: (?untyped? message) ?{ () -> untyped } -> void
sig/datadog/symbol_database/logger.rbs:18
└── def trace: () { () -> untyped } -> void
Cleared:
sig/datadog/symbol_database/logger.rbs:10
└── def initialize: (untyped settings, ::Logger target) -> void
sig/datadog/symbol_database/logger.rbs:17
└── def debug: (?untyped? message) ?{ () -> untyped } -> void
sig/datadog/symbol_database/logger.rbs:18
└── def warn: (?untyped? message) ?{ () -> untyped } -> void
sig/datadog/symbol_database/logger.rbs:19
└── def trace: () { () -> untyped } -> void

Untyped other declarations

This PR introduces 2 untyped other declarations, and clears 2 untyped other declarations.

Untyped other declarations (+2-2)Introduced:
sig/datadog/symbol_database/logger.rbs:4
└── @settings: untyped
sig/datadog/symbol_database/logger.rbs:10
└── attr_reader settings: untyped
Cleared:
sig/datadog/symbol_database/logger.rbs:6
└── @settings: untyped
sig/datadog/symbol_database/logger.rbs:12
└── attr_reader settings: untyped

If you believe a method or an attribute is rightfully untyped or partially typed, you can add # untyped:accept on the line before the definition to remove it from the stats.

@datadog-datadog-prod-us1

datadog-datadog-prod-us1 Bot commented Jun 23, 2026

Copy link
Copy Markdown
Contributor

Pipelines  Tests

Fix all issues with BitsAI

⚠️ Warnings

🚦 3 Pipeline jobs failed

Check Pull Request CI Status | all-jobs-are-green   View in Datadog   GitHub Actions

Static Analysis | steep/typecheck   View in Datadog   GitHub Actions

Test Nix | Test Nix (arm64-darwin, 24.05)   View in Datadog   GitHub Actions

ℹ️ Info

No other issues found (see more)

🧪 All tests passed
❄️ No new flaky tests detected

🎯 Code Coverage (details)
Patch Coverage: 50.00%
Overall Coverage: 89.99% (-0.02%)

Useful? React with 👍 / 👎

This comment will be updated automatically if new data arrives.
🔗 Commit SHA: c719299 | Docs | Datadog PR Page | Give us feedback!

@pr-commenter

pr-commenter Bot commented Jun 23, 2026

Copy link
Copy Markdown

Benchmarks

Benchmark execution time: 2026-06-23 18:16:45

Comparing candidate commit c719299 in PR branch validate-symdb-scheduler-logger-boom with baseline commit fd1e1b0 in branch master.

Found 0 performance improvements and 0 performance regressions! Performance is the same for 48 metrics, 1 unstable metrics.

Explanation

This is an A/B test comparing a candidate commit's performance against that of a baseline commit. Performance changes are noted in the tables below as:

  • 🟩 = significantly better candidate vs. baseline
  • 🟥 = significantly worse candidate vs. baseline

We compute a confidence interval (CI) over the relative difference of means between metrics from the candidate and baseline commits, considering the baseline as the reference.

If the CI is entirely outside the configured SIGNIFICANT_IMPACT_THRESHOLD (or the deprecated UNCONFIDENCE_THRESHOLD), the change is considered significant.

Feel free to reach out to #apm-benchmarking-platform on Slack if you have any questions.

More details about the CI and significant changes

You can imagine this CI as a range of values that is likely to contain the true difference of means between the candidate and baseline commits.

CIs of the difference of means are often centered around 0%, because often changes are not that big:

---------------------------------(------|---^--------)-------------------------------->
                              -0.6%    0%  0.3%     +1.2%
                                 |          |        |
         lower bound of the CI --'          |        |
sample mean (center of the CI) -------------'        |
         upper bound of the CI ----------------------'

As described above, a change is considered significant if the CI is entirely outside the configured SIGNIFICANT_IMPACT_THRESHOLD (or the deprecated UNCONFIDENCE_THRESHOLD).

For instance, for an execution time metric, this confidence interval indicates a significantly worse performance:

----------------------------------------|---------|---(---------^---------)---------->
                                       0%        1%  1.3%      2.2%      3.1%
                                                  |   |         |         |
       significant impact threshold --------------'   |         |         |
                      lower bound of CI --------------'         |         |
       sample mean (center of the CI) --------------------------'         |
                      upper bound of CI ----------------------------------'

@p-datadog p-datadog marked this pull request as ready for review July 1, 2026 23:57
@p-datadog p-datadog requested a review from Copilot July 1, 2026 23:57
@p-datadog p-datadog requested a review from a team as a code owner July 1, 2026 23:57

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR validates that the SymDB flake fix (swallowing exceptions raised by a wrapped logger) neutralizes the deterministic reproducer that previously forced the scheduler-thread logger.debug race in CI.

Changes:

  • Add explicit Datadog::SymbolDatabase::Logger#debug / #warn implementations that rescue exceptions from the wrapped target logger.
  • Add unit coverage for the Logger wrapper’s forwarding and exception-swallowing behavior.
  • Add a deterministic reproducer spec that exercises the scheduler-thread path and asserts Component#shutdown! does not re-raise logger exceptions.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 4 comments.

File Description
lib/datadog/symbol_database/logger.rb Switches away from Forwardable delegation for debug/warn and adds exception swallowing in the wrapper.
sig/datadog/symbol_database/logger.rbs Updates RBS to reflect the logger wrapper’s behavior/documentation changes.
spec/datadog/symbol_database/logger_spec.rb New unit specs for forwarding semantics and swallowing exceptions for debug/warn/trace.
spec/datadog/symbol_database/logger_boom_reproducer_spec.rb New deterministic scheduler-thread reproducer ensuring shutdown doesn’t propagate logger failures.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +36 to +40
def debug(*args, &block)
@target.debug(*args, &block)
rescue
nil
end
Comment on lines +45 to +49
def warn(*args, &block)
@target.warn(*args, &block)
rescue
nil
end
Comment on lines +64 to +82
component = Datadog::SymbolDatabase::Component.build(settings, agent_settings, logger)

# Wait for the scheduler to enter extract_all.
Timeout.timeout(5) { entered_extract.pop }

# Stub raw_logger.debug to raise. The scheduler is blocked inside
# extract_all and has not yet reached its post-extraction debug log.
allow(raw_logger).to receive(:debug).and_raise(RuntimeError.new('logger boom'))

# Release extract_all. The scheduler proceeds to the success-path
# `@logger.debug { "symdb: initial extracted ..." }` call, which now
# raises through the wrapped Forwardable chain.
resume_extract.push(:go)

# `shutdown!` invokes `@scheduler_thread&.join(5)`. Without the fix,
# the scheduler thread has terminated with the unhandled `logger boom`
# exception, and `Thread#join` re-raises it here.
expect { component.shutdown! }.not_to raise_error
end
Comment on lines +73 to +76
# Release extract_all. The scheduler proceeds to the success-path
# `@logger.debug { "symdb: initial extracted ..." }` call, which now
# raises through the wrapped Forwardable chain.
resume_extract.push(:go)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

AI Generated Largely based on code generated by an AI or LLM. This label is the same across all dd-trace-* repos debugger Live Debugger (+Dynamic Instrumentation, +Symbol Database)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants