{"record":{"id":"03f7cad5397eafcf","repo":"BoundaryML/baml","slug":"batchprocessor-worker-thread-did-not-finish-in-time","errorCode":null,"errorMessage":"BatchProcessor worker thread did not finish in time","messagePattern":"BatchProcessor worker thread did not finish in time","errorType":"exception","errorClass":null,"httpStatus":null,"severity":"error","filePath":"engine/baml-runtime/src/tracing/threaded_tracer.rs","lineNumber":213,"sourceCode":"\n        let flush_start = Instant::now();\n\n        while flush_start.elapsed() < Duration::from_secs(60) {\n            {\n                match *self.stop_rx.borrow() {\n                    ProcessorStatus::Active => {}\n                    ProcessorStatus::Done(r_id) if r_id >= id => {\n                        return Ok(());\n                    }\n                    ProcessorStatus::Done(id) => {\n                        // Old flush, ignore\n                    }\n                }\n            }\n            std::thread::sleep(Duration::from_millis(100));\n        }\n\n        anyhow::bail!(\"BatchProcessor worker thread did not finish in time\")\n    }\n\n    pub fn set_log_event_callback(&self, log_event_callback: Option<LogEventCallbackSync>) {\n        // Get a mutable lock on the log_event_callback\n        let mut callback_lock = self.log_event_callback.lock().unwrap();\n\n        *callback_lock = log_event_callback;\n    }\n\n    pub fn submit(&self, mut event: LogSchema) -> Result<()> {\n        let callback = self.log_event_callback.lock().unwrap();\n        if let Some(ref callback) = *callback {\n            let event = event.clone();\n            let llm_output_model = event.metadata.as_ref().and_then(|m| match m {\n                MetadataType::Single(llm_event) => Some(llm_event),\n                // take the last element in the vector\n                MetadataType::Multi(llm_events) => llm_events.last(),\n            });","sourceCodeStart":195,"sourceCodeEnd":231,"githubUrl":"https://github.com/BoundaryML/baml/blob/bd85ce9dee1463ff04d27efd20531013a4ff46c1/engine/baml-runtime/src/tracing/threaded_tracer.rs#L195-L231","documentation":"In `BatchProcessor::flush` (threaded_tracer.rs:213), the worker thread did not drain the batch queue within the timeout loop (polling every 100ms). BAML bails instead of blocking indefinitely, which means buffered trace events may not have been submitted.","triggerScenarios":"Calling `flush` on the threaded tracer when the worker thread is stalled: the event callback or HTTP submission is blocked on a slow/hung network call to the collector, the queue keeps receiving events faster than they drain, or the worker thread panicked/deadlocked on a lock.","commonSituations":"Process shutdown with an unreachable or very slow BAML log endpoint; large burst of trace events at exit exceeding drain time; a log_event_callback that blocks; lock contention on log_event_callback or the queue.","solutions":["Check network reachability and latency of the trace collector endpoint; fix connectivity or increase its capacity.","Ensure the log event callback is fast and non-blocking; move slow work off the worker thread.","Retry flush after the endpoint recovers; some buffered events may still drain.","Reduce event volume or batch sizes so the worker can drain within the timeout.","Investigate deadlocks: no callback should acquire locks held elsewhere while flush is waiting."],"exampleFix":"// before: blocking callback stalls the worker\nlet callback = |event| { reqwest::blocking::post(url).body(event).send().unwrap(); };\n// after: enqueue locally, submit asynchronously\nlet callback = |event| { queue.lock().unwrap().push(event); };","handlingStrategy":"retry","validationCode":"// preflight: collector must be reachable before relying on flush\nlet reachable = std::net::TcpStream::connect_timeout(\n    &collector_addr, Duration::from_secs(2)).is_ok();\nif !reachable { log::warn!(\"trace collector unreachable; flush may time out\"); }","typeGuard":null,"tryCatchPattern":"if let Err(e) = batch_processor.flush() {\n    if e.to_string().contains(\"did not finish in time\") {\n        log::warn!(\"trace flush timed out; events may be lost: {e}\");\n        // optionally retry once after a delay\n    } else {\n        return Err(e);\n    }\n}","preventionTips":["Verify the trace collector endpoint is reachable and fast from the runtime environment.","Keep log event callbacks non-blocking and quick.","Avoid flooding the tracer with a huge burst right before shutdown.","Call flush during graceful shutdown with time budget, and retry on timeout.","Watch for deadlocks: never hold locks the worker thread needs inside callbacks."],"tags":["tracing","timeout","threads","flush"],"backgroundTag":"request-timeout","analyzedSha":"bd85ce9dee1463ff04d27efd20531013a4ff46c1","analyzedAt":"2026-09-12T03:38:25.718Z","contentChangedAt":"2026-09-12T03:38:25.718Z","schemaVersion":2},"datasetVersion":"2026-09-23T08:17:48.524Z"}