DEBUG-3327 DI progress logs

[p-datadog]

What does this PR do?
Adds logging of dynamic instrumentation operations for troubleshooting: more logging when probes are retrieved from remote config, probes being installed, probes being invoked, events being submitted to the remote worker, remote worker queue size per event type, remote worker working.

Motivation:
Currently when DI is not working there is no effective way to troubleshoot it since to the observer it just looks like nothing is happening. The logging added in this PR permits following DI along its steps to see how far it makes through its process.

Change log entry
Yes: add optional trace logging to dynamic instrumentation

Additional Notes:
The trace logging is conditioned on DD_TRACE_DEBUG environment variable used by the rest of dd-tlrace-rb and also by the newly added internal DI configuration variable. The config variable is intended to be (and is) checked by DI code, but I did not yet want to add another environment variable to enable DI logging specifically because in practice to debug DI we also need to verify that remote config is working, and that uses DD_TRACE_DEBUG.

This PR also adds a Datadog::DI::Logger class which is a facade over the "standard" logger adding a trace method. Without this the entire DI test suite would need to have expectations set on the trace output which is a lot of expectations that usually just add overhead for no benefit.

How to test the change?

[github-actions]

Thank you for updating Change log entry section 👏

^{Visited at: 2025-02-12 18:31:39 UTC}

[datadog-datadog-prod-us1]

Datadog Report

Branch report: di-progress-logs
Commit report: baa571f
Test service: dd-trace-rb

❌ 37 Failed (0 Known Flaky), 21910 Passed, 1476 Skipped, 6m 0.48s Total Time

❌ Failed Tests (37)

This report shows up to 5 failed tests.

• Datadog::DI::ProbeManager#add_probe log probe when instrumentation target is missing returns false and adds probe to the pending probe list - rspec - Details

  Expand for error

   ./lib/datadog/di/probe_manager.rb:118:in 'block in Datadog::DI::ProbeManager#add_probe'
   ./lib/datadog/di/probe_manager.rb:96:in 'Monitor#synchronize'
   ./lib/datadog/di/probe_manager.rb:96:in 'Datadog::DI::ProbeManager#add_probe'
   ./spec/datadog/di/probe_manager_spec.rb:88:in 'block (5 levels) in <top (required)>'
   ./spec/spec_helper.rb:238:in 'block (2 levels) in <top (required)>'
   ./spec/spec_helper.rb:123:in 'block (2 levels) in <top (required)>'
   /usr/local/bundle/gems/webmock-3.24.0/lib/webmock/rspec.rb:39:in 'block (2 levels) in <top (required)>'
   /usr/local/bundle/gems/rspec-wait-0.0.10/lib/rspec/wait.rb:47:in 'block (2 levels) in <top (required)>'
   ------------------
   --- Caused by: ---
   ...
  

• Datadog::DI::ProbeManager#add_probe log probe when probe is installed successfully returns true and adds probe to the installed probe list - rspec - Details

  Expand for error

   ./lib/datadog/di/probe_manager.rb:114:in 'block in Datadog::DI::ProbeManager#add_probe'
   ./lib/datadog/di/probe_manager.rb:96:in 'Monitor#synchronize'
   ./lib/datadog/di/probe_manager.rb:96:in 'Datadog::DI::ProbeManager#add_probe'
   ./spec/datadog/di/probe_manager_spec.rb:68:in 'block (5 levels) in <top (required)>'
   ./spec/spec_helper.rb:238:in 'block (2 levels) in <top (required)>'
   ./spec/spec_helper.rb:123:in 'block (2 levels) in <top (required)>'
   /usr/local/bundle/gems/webmock-3.24.0/lib/webmock/rspec.rb:39:in 'block (2 levels) in <top (required)>'
   /usr/local/bundle/gems/rspec-wait-0.0.10/lib/rspec/wait.rb:47:in 'block (2 levels) in <top (required)>'
  

• Datadog::DI::ProbeNotifierWorker started #add_snapshot sends the snapshot - rspec - Details

  Expand for error

   ./lib/datadog/di/probe_notifier_worker.rb:237:in 'block (2 levels) in <class:ProbeNotifierWorker>'
   ./lib/datadog/di/probe_notifier_worker.rb:267:in 'Datadog::DI::ProbeNotifierWorker#maybe_send'
   ./lib/datadog/di/probe_notifier_worker.rb:76:in 'block (2 levels) in Datadog::DI::ProbeNotifierWorker#start'
   ./lib/datadog/di/probe_notifier_worker.rb:49:in 'block in Datadog::DI::ProbeNotifierWorker#start'
   ./spec/spec_helper.rb:254:in 'block in DatadogThreadDebugger#initialize'
  

• Datadog::DI::ProbeNotifierWorker started #add_snapshot when three snapshots are added in quick succession sends two batches - rspec - Details

  Expand for error

   RSpec::Core::MultipleExceptionError
  

• DI integration from remote config method probe received matching a loaded class and target method is invoked notifies about execution - rspec - Details

  Expand for error

   expected "di: installed log probe 11" to match /received probe from RC:/
   Diff:
   @@ -1 +1 @@
   -/received probe from RC:/
   +"di: installed log probe 11"
   
   Failure/Error: expect(block.call).to match(expected_msg)
   
     expected "di: installed log probe 11" to match /received probe from RC:/
     Diff:
   ...
  

[pr-commenter]

Benchmarks

Benchmark execution time: 2025-02-12 18:47:19

Comparing candidate commit eb980d1 in PR branch di-progress-logs with baseline commit 20886bc in branch master.

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

[ivoanjo]

Current draft looks reasonable, left a small note

[datadog-datadog-prod-us1]

Datadog Report

Branch report: di-progress-logs
Commit report: eb980d1
Test service: dd-trace-rb

✅ 0 Failed, 22094 Passed, 1477 Skipped, 6m 16.48s Total Time

[p-datadog]

This PR now adds a Datadog::DI::Logger facade class that defines trace method on it which can be summarily ignored in the test suite (so that I do not need to add expectations on all of the trace output).

[codecov-commenter]

Codecov Report

Attention: Patch coverage is 88.88889% with 6 lines in your changes missing coverage. Please review.

Project coverage is 97.73%. Comparing base (20886bc) to head (eb980d1).

Files with missing lines	Patch %	Lines
lib/datadog/di/contrib.rb	0.00%	2 Missing ⚠️
lib/datadog/di.rb	50.00%	1 Missing ⚠️
lib/datadog/di/logger.rb	92.85%	1 Missing ⚠️
lib/datadog/di/probe_manager.rb	80.00%	1 Missing ⚠️
lib/datadog/di/probe_notifier_worker.rb	83.33%	1 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #4283      +/-   ##
==========================================
- Coverage   97.74%   97.73%   -0.01%     
==========================================
  Files        1351     1352       +1     
  Lines       82697    82729      +32     
  Branches     4198     4200       +2     
==========================================
+ Hits        80831    80856      +25     
- Misses       1866     1873       +7     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.