Find out why some otel spans are missing in monitoring

[phildarnowsky-broad]

As in the image, some spans are not getting logged to Trace Explorer. Per a helpful robot:

This message appears when:

• A parent-child relationship between spans was declared (through references)
• But one of the spans (in this case, the one with ID b84f47e9572c5512) is missing from the trace data

Possible Causes

1. Data Loss: The span was created but not successfully sent to or ingested by Cloud Trace
2. Timing Issues: The child span was recorded before its parent span
3. Cross-Service Tracing Problems: If you're tracing across multiple services, one service might have failed to properly propagate or report its spans
4. Sampling: If you're using sampling, some spans may be sampled out while others are kept
5. Instrumentation Problems: Incomplete or incorrect instrumentation of your application

How to Troubleshoot

1. Check your instrumentation: Ensure all services are properly configured to send traces
2. Examine sampling rates: If using sampling, consider increasing the sampling rate temporarily
3. Verify trace propagation: Make sure trace context is properly propagated between services
4. Look for errors in Cloud Logging: There might be related errors when spans failed to be reported
5. Check network connectivity: Services might have connectivity issues with Cloud Trace endpoints

Impact

This issue typically doesn't affect your application's functionality, but it does impact your ability to fully visualize and analyze the complete trace of a request through your system.

[phildarnowsky-broad]

Further investigation and research suggests:

• It's not a matter of sampling; the default sample rate, as we're using here, is 100%, i.e. there effectively is no sampling and every span gets logged.
• It's probably very seldom caused by early termination of an API request, but that's an edge case that's easy to cover and so we should anyway, against a day when that does become a more frequent occurrence.
• It could be the batch span processor is dropping spans due to hitting capacity on its queue, which is 2048 by default (see https://github.com/open-telemetry/opentelemetry-js/blob/main/experimental/packages/sdk-logs/src/types.ts#L46), so we can try bumping that, say to 4096. Nice round number.
• Sometimes, in a distributed system, it may be normal for spans to sometimes get lost.

So tl;dr we'll cover the case of an aborted request, and bump the queue size.

[phildarnowsky-broad]

Queue size bump, and adding callbacks on close and finished to explicitly close open spans at the end of a request, didn't help.

Notably, adding a ConsoleSpanExporter to duplicate all spans to the log doesn't log the missing spans either, so that suggests the spans in question are getting lost somewhere before that point (as opposed to the problem being, say, in the collector forwarding spans to GCP).

[phildarnowsky-broad]

These might be correlated with queries that time out.

[phildarnowsky-broad]

Adding a middleware to ensure all spans are closed should hypothetically work, but I've tried a number of variations on this, both using the onFinished hook and adding standard req.on('close') and req.on('finish)` callbacks--no luck.