Debug:Print trace as it is about to be flushed

[marcotc]

When enabling diagnostic logging, we can see all traces that are sent to the writer.

This is very helpful, but does not capture the complete story of a trace.

The trace will be modified by TraceFormatter, which does quiet a bit of work applying tags to the root span: the root span that we see today in diagnostic logs will be much different when actually flushed.

There's also the Processing Pipeline that can modify or drop traces.

This PR adds a debug-level log as late as possible: right before we mush our trace into unintelligible bytes.

The log line looks like this:

Flushing trace: [{"error":0,"meta":{"env":"test-env","language":"ruby","runtime-id":"24c8dbaf-bd09-407d-812d-a8737f4bcaf0"},"metrics":{"_dd.top_level":1.0,"_dd.agent_psr":1.0,"system.pid":70439.0,"_sampling_priority_v1":1.0},"name":"a","parent_id":0,"resource":"a","service":"test-app","span_id":1472066385686673140,"trace_id":3514006046188043380,"type":null,"start":1663889528517354000,"duration":4000}]

I did not remove the existing pre-writer logger because if the trace fails to serialize due to being too large, or is dropped by the Processing Pipeline, we won't get any signals with the log introduced in this PR.

I think we should perform an overhaul in our debug logs: we should be able to enable it and have virtually everything needed to debug any issues we are used to encountering, without asking user to add ad-hoc logging when issues arise.

[codecov-commenter]

Codecov Report

Merging #2290 (a8fa0f7) into master (c4e8a0a) will increase coverage by 0.00%.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##           master    #2290   +/-   ##
=======================================
  Coverage   97.58%   97.58%           
=======================================
  Files        1094     1094           
  Lines       57314    57315    +1     
=======================================
+ Hits        55929    55932    +3     
+ Misses       1385     1383    -2     

Impacted Files	Coverage Δ
lib/ddtrace/transport/traces.rb	97.82% <100.00%> (+0.02%)	⬆️
...adog/tracing/contrib/sidekiq/client_tracer_spec.rb	100.00% <0.00%> (+2.08%)	⬆️
lib/datadog/core/workers/polling.rb	100.00% <0.00%> (+3.44%)	⬆️

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

[ivoanjo]

👍 LGTM

I think we should perform an overhaul in our debug logs: we should be able to enable it and have virtually everything needed to debug any issues we are used to encountering, without asking user to add ad-hoc logging when issues arise.

Yes please! One other thing I'd like to see is the ability to have finer grained logging levels (ideally per-class, as is common on other language ecosystems).

For instance, the profiler is not that chatty so I often run with debug logging enabled; but tracing is extremely chatty due to all the trace-level information.

And that's completely fine! But the all-or-nothing approach we have right now means that there's no control at all, and it makes every logging decision harder.