Excution plan takes a long time to drop for some reason

[cetra3]

Describe the bug

When using datafusion-tracing, dropping the execution plan can take a significantly long time and keep the CPU going. We've seen it take up to 10 seconds to just drop an execution plan

To Reproduce

Unfortunately it's very hard to repro, but I think it relates to maybe some sort of circular reference in the plan.

Expected behavior

No response

Additional context

No response

[geoffreyclaude]

Hi @cetra3 ,
Thanks for the bug report, it's super useful and might explain some similar behavior we are seeing in our own usage.
Would you be able to detail this a bit more? Do you have a typical query shape you could share? Are you keeping any reference to the execution plan alive during/after execution?
How are you sure that it eventually succeeds in dropping, even if after 10s?

[cetra3]

Only certain queries are causing this long pause on drop.

We do actually create a reference of an Arc<dyn ExecutionPlan> at the beginning before execution, and then drop it after execution. The plans themselves are not crazy elaborate, an aggregate with some filters.

Basically something like:

SELECT sum(numeric_value) FROM table WHERE 
(filter_column_1 = 'filter_value_1' AND filter_column_2 = 'filter_value_2')

To confirm it was a drop related issue, I created a bit of code that takes the Arc and then prints out some log lines:

let plan: Arc<dyn ExecutionPlan> = this.plan.clone();
std::thread::spawn(move || {
    logfire::info!("starting background thread drop");
    std::thread::sleep(Duration::from_secs(10));
    let strong_count = Arc::strong_count(&plan);
    let weak_count = Arc::weak_count(&plan);
    logfire::info!("dropping plan now, strong count: {strong_count}, weak count: {weak_count}");
    drop(plan);
    logfire::info!("background thread drop completed");
});

This prints out logs like so:

2025-10-25T02:19:01.989677Z  INFO ::tracing_record_batch_stream starting background thread drop
2025-10-25T02:19:11.989768Z  INFO ::tracing_record_batch_stream dropping plan now, strong count: 1, weak count: 0
2025-10-25T02:19:20.280561Z  INFO ::tracing_record_batch_stream background thread drop completed

[geoffreyclaude]

Which crate version are you using? And how are you configuring the instrumentation macro (InstrumentationOptions::builder()...; instrument_with_info_spans!(...)) and the OLTP collector?