Flushing traces on application shutdown

[matthewwoodruff]

I'm building a spring boot application which implements and http api, carries out background jobs, and consumes messages from SQS. The app is configured to send any traces to honeycomb using the java agent.

However when the service is shutdown I am losing traces for currently running tasks. For example in-flight http requests, running jobs, consumption of messages from sqs. These traces are not appearing in honeycomb.

I have a simple app to recreate the problem here. When I terminate the app mid http requests I see the following output. In particular it looks like the SimpleSpanProcessor failed to export.

2025-03-06T14:22:10.286Z  INFO 29858 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
[otel.javaagent 2025-03-06 14:22:10:288 +0000] [SpringApplicationShutdownHook] DEBUG io.opentelemetry.javaagent.tooling.AgentInstaller$TransformLoggingListener - Transformed org.springframework.boot.web.embedded.tomcat.GracefulShutdown$$Lambda -- org.springframework.boot.loader.launch.LaunchedClassLoader@834e986
[otel.javaagent 2025-03-06 14:22:18:293 +0000] [http-nio-8080-exec-2] DEBUG io.opentelemetry.sdk.trace.export.SimpleSpanProcessor - Exporter failed
2025-03-06T14:22:18.324Z  INFO 29858 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete

Is there a way to ensure these traces are flushed before the application fully terminates?

Thanks!

[jack-berg]

Hey thanks for the reproduction! Super helpful.

Spans are only queued up to be exported once Span.end() is called. See BatchSpanProcessor source code for a reference. SimpleSpanProcessor behaves the same way.

In this case, when Thread.sleep(10000) is called in wait(), the span has been started, but end() isn't called until the response is returned. So even though the BatchSpanProcessor queue is flushed on shutdown, the span hasn't been added to the queue.

To see this in action:

• Set the batch span processor to have a long delay, such that it will only export on shutdown when flush is called - something likeotel.bsp.schedule.delay=10000000

• Modify the application code to start / end an internal span in wait() before calling Thread.sleep:

   @GetMapping("/wait")
   fun wait(): ResponseEntity<String> {
       GlobalOpenTelemetry.get().getTracer("foo").spanBuilder("span").startSpan().end()
       Thread.sleep(10000)
       return ResponseEntity.ok("success")
   }
  

• Run the app, curl the endpoint, and shutdown the app before the Thread.sleep ends

• Notice that the new internal span you've added is exported. Despite the BatchSpanProcessor having a long delay, this span was added to the queue and the queue is flushed on shutdown. However, the parent span representing the call to GET /wait is still not exported because it never ends

[trask]

Commencing graceful shutdown. Waiting for active requests to complete

I think tomcat waits for active requests to complete during a graceful shutdown.

@matthewwoodruff can you confirm whether Span.end() is called on that final request (parent span)? it could maybe be a shutdown hook ordering issue?