Disabling NR APM causes trace concatenation in Datadog

[timmc-edx]

Ultimately, this ticket is for disabling New Relic APM across edxapp. We ran into trace related issues in DD when first attempting to disable NR APM. We later caused the same issue in Edge when simply disabling NR Tracing.

This bug has been observed in edxapp (LMS and CMS), enterprise-catalog, and registrar. It can be identified by searching for spans matching operation_name:django.request -@_top_level:*.

Acceptance criteria

• Understand and fix the trace concatenation issue
• Undo the below temporary changes, or make them more permanent or robust
• Replay NR disablement PR: feat: Disable New Relic for edxapp configuration#33

Things to try

• On the Celery hypothesis:
  • Add a workaround: When middleware discovers the root span is already finished, walk towards the root and call finish() on all celery.apply spans.
  • Try repro in devstack with Celery broker in place -- need to run tasks async for a repro, we think. May need to try it in registrar rather than edxapp, since registrar-worker already exists. Could point lms at registrar-worker. Check to see if celery.apply spans are created, even if we don't see anomalous traces.
• Create a forked ddtrace where tracer.start_span checks child_of for a finished span. Subject to Waffle flags, log the situation and/or set child_of to None.
• Hold off on these, as we have a lead on the Celery side of things:
  • Downgrade to ddtrace 2.7.9 to see if lazy tracing is the culprit
  • Disable distributed tracing via ddtrace.config.django['distributed_tracing_enabled']=False
  • Add more details to anomalous trace logging -- current span ID, parent span (ID, operation, resource -- maybe the whole thing)

Things we have already tried

These should be checked off once they have already been either reverted or made permanent:

• DD_TRACE_HEADER_TAGS and DD_DJANGO_INSTRUMENT_MIDDLEWARE were added in temp: Add temporary debugging headers for edxapp tracing configuration#41
• We've changed a number of monitors and dashboards from using Service Entry Spans to operation_name:django.request on All Spans since service entry spans were unreliable. Maybe we want to change that back, or maybe not.
• [reverted] We removed the NR license key for stage and edge LMS: temp: Try removing NR license key for edge LMS to see if DD is affected configuration#45
• We set up a free-tier key as a test in stage and edge LMS: temp: Try sending New Relic traces to a place they'll be thrown out configuration#48, https://github.com/edx/edx-internal/pull/11138, and https://github.com/edx/edge-internal/pull/727
  • We've reverted all uses of the key (EDXAPP_NEWRELIC_LICENSE_TEST_FREE) but we still need to remove it from AWS secrets manager: https://2u-internal.atlassian.net/servicedesk/customer/portal/15/DOS-4980
• Experimental patched newrelic agent (https://github.com/edx/edx-internal/pull/11156 in several environments) and the enablement flag (https://github.com/edx/edx-internal/pull/11157)
• Set DD_TRACE_PROPAGATION_STYLE_EXTRACT=none in feat: Stop accepting trace headers in DD for edge/stage LMS configuration#55
• DatadogDiagnostics plugin app: feat: Add datadog_diagnostics plugin app #722; its addition to stage and edge middleware remote-config; the waffle flags that activate it (datadog.diagnostics.log_root_span and datadog.diagnostics.detect_anomalous_trace)
• [reverted] Disable Celery instrumentation via DD_TRACE_CELERY_ENABLED=false, because some of the request spans in anomalous traces have missing parent spans that were celery-related: temp: Try disabling Datadog Celery instrumentation in LMS (stage, edge) configuration#62
  • Reverted in temp: Re-enable Datadog Celery instrumentation for NR-off test configuration#63
• [reverted] Debug logging of celery signals via DATADOG_DIAGNOSTICS_CELERY_LOG_SIGNALS (using edx-arch-experiments 4.3.0)
• [reverted] Log span ancestry on anomalous traces to find out what operations are involved.

Details

When we disabled NR APM in edxapp on June 6 we observed two anomalies with traces:

• At about 17:34, the rate of service entry spans (and traces) in service:edx-edxapp-lms env:prod dropped precipitously by 2-3x.
• At the same time, the rate of all spans increased by about 5x. (This anomaly appears to have disappeared, retroactively!)

However, we believe the actual traffic was unchanged. This is corroborated by the Django hit metrics remaining steady, as seen in the Service Catalog. We cannot find any relevant code or config changes that would have been deployed around that time.

Our current understanding is that the majority of Django web requests that are traced are not recorded as service entry spans, but are instead parented to a different trace. This causes several problems:

• Monitors and dashboards that are based on traces or service entry spans are unreliable.
• It's difficult to impossible to view most of our traces because they become concatenated into 50,000-span-long monsters that can't be loaded in the browser.

We can also reproduce this issue by setting "Tracing type: None" in the application settings in NR (usually set to Distributed Tracing).

Links

• Private support ticket: https://help.datadoghq.com/hc/en-us/requests/1722518
• Diagnostic dashboard: https://app.datadoghq.com/dashboard/fzr-3jk-nsf

[robrap]

Other notes:

• Here is a google doc of potential plan for debugging and resolving.
• The current plan is:
  • enable the new headers (2024-06-18: 20:49 UTC)
    • Config change went out in deploy 6f17017-5957
  • disable tracing in NR (2024-06-18: 21:30 UTC) and confirm that DD tracing is broken again.
    • Set "Transaction tracing: Off" and "Tracing type: None" in edge LMS
  • Leave broken for a short window before re-enabling tracing in NR (record time).
  • Disable NR frontends in Stage and Edge and ensure it doesn't break DD tracing.
    • feat: disable edxapp legacy browser in newrelic.ini.j2 stage and edge configuration#40 (disable legacy)
    • https://github.com/edx/edx-internal/pull/11100 (disable MFEs stage)
    • https://github.com/edx/edge-internal/pull/719 (disable MFEs edge)
      • Authn deployed to Edge
      • Learning deployed to Edge
      • Discussions deployed to Edge (waiting on owning team)
  • Confirm that DD tracing can still be broken with disabling tracking in NR (record times).

[robrap]

Additional thoughts, questions, ideas:

• We should double-check distributed tracing settings for tracing type (want updated Distributed Tracing).
  • No other settings were seen in doc.
• If we decide to try to use the NR test account, we should ensure it is safe. We can remove other users (if they are still there).
• What does the nginx request header set? Could this be interfering?
• APM Profiling caused a different problem with additional spans, but is it possible it could heal this issue without NR?
• If it comes to this, can we find a way to replicate locally?
• Could there be important information buried in the logs that we are no longer seeing? See Determine if Datadog trace-debug fix needs replacement #610.
• Could the invalid traceparent log messages be related? See Ensure "received invalid w3c traceparent" has resolved #665.

[robrap]

Currently, we're investigating if using a NR Free Tier account for edxapp is enough to get DD traces working.

Other possibilities may include trying to get tracing (or APM) disabled everywhere in Edge. This includes where Spans were found in the last day:

prod-edge-edxapp-cms 9.28 M
prod-edge-analytics-api 2.35 M
prod-edge-notes 2.3 M
prod-edge-edxapp-workers-lms 755 k
prod-edge-forum 675 k
prod-edge-edxapp-workers-cms 188 k

[robrap]

[idea] We might want 3 modes for our hacked NR agent:

1. Send no data to NR, but add tracing info (fixes DD traces).
2. Send no data to NR, and fake a bad account id so we don't even take a performance hit (breaks DD traces).
3. Send data to NR (costs money, but if we want to verify anything temporarily, we can.