# \[Reactor\] Parallel Streams causes APM log spam and possibly missed spans **URL:** \ **Category:** APM\ **Tags:** docker, java\ **Created:** [September 20, 2024, 7:50pm UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890 "2024-09-20T19:50:17Z")\ **Posts on this page:** 6\ **Page:** 1
**Author:** ![pickypg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pickypg/32/62409_2.png) [@pickypg](https://discuss.elastic.co/u/pickypg)\ **Post date:** [September 20, 2024, 7:50pm UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/1 "2024-09-20T19:50:17Z")
**APM Agent language and version** : Java Agent 1.51.0 **Original install method (e.g. download page, yum, deb, from source, etc.) and version**: Manually via curl and run with `-javaagent`. It is also separately used within a Docker container where it uses the documented Docker method to run with the `-javaagent`. **Fresh install or upgraded from other version?** Problem also happened in 1.49.0. **Is there anything special in your setup?** Not with the way data flows to APM. **Description of the problem including expected versus actual behavior** : There should be no errors indicating that a `Span::end` has already been called by automatically generated handling. **Steps to reproduce** : Based on an attempt to reproduce this without Kafka, it appears that this problem relates specifically to `reactor-kafka` (as opposed to `reactor-core`). 1. With the Reactor framework, use a `.metrics().parallel().runOn(...)` and therefore scheduled pipeline. - Removing `.parallel().runOn(...)` resolves the issue 2. Observe automatic APM transaction generation results in log spam **Provide logs and/or server output (if relevant)**: These two logs are repeated over-and-over: ```auto 2024-09-19 14:34:39,512 [reactive-kafka-indexer-2] WARN co.elastic.apm.agent.impl.transaction.AbstractSpanImpl - End has already been called: 'Kafka record from metrics' 00-43a0fae3700192c45c4e3b66d9ab7fc6-b97bfcb6a5952a35-01 (1427a3aa) 2024-09-19 14:34:39,614 [reactive-kafka-indexer-2] ERROR co.elastic.apm.agent.bci.IndyBootstrap - Advice threw an exception, this should never happen! java.util.NoSuchElementException: null at java.util.ArrayDeque.removeFirst(ArrayDeque.java:361) ~[?:?] at java.util.ArrayDeque.remove(ArrayDeque.java:522) ~[?:?] at co.elastic.apm.agent.impl.ActiveStack.deactivate(ActiveStack.java:119) ~[elastic-apm-agent-1.51.0.jar:1.51.0] at co.elastic.apm.agent.impl.ElasticApmTracer.deactivate(ElasticApmTracer.java:940) ~[elastic-apm-agent-1.51.0.jar:1.51.0] at co.elastic.apm.agent.impl.transaction.TraceStateImpl.deactivate(TraceStateImpl.java:71) ~[elastic-apm-agent-1.51.0.jar:1.51.0] at co.elastic.apm.agent.impl.transaction.TraceStateImpl.deactivate(TraceStateImpl.java:33) ~[elastic-apm-agent-1.51.0.jar:1.51.0] at co.elastic.apm.agent.concurrent.RunnableCallableForkJoinTaskInstrumentation$AdviceClass.onExit(RunnableCallableForkJoinTaskInstrumentation.java:83) ~[elastic-apm-agent-1.51.0.jar:1.51.0] at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:87) ~[reactor-core-3.5.11.jar:3.5.11] at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) ~[reactor-core-3.5.11.jar:3.5.11] at java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?] at java.lang.Thread.run(Thread.java:1570) [?:?] ``` ---
**Author:** ![Jack\_Shirazi](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jack_shirazi/32/91641_2.png) [@Jack\_Shirazi](https://discuss.elastic.co/u/Jack_Shirazi)\ **Post date:** [October 7, 2024, 1:27pm UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/2 "2024-10-07T13:27:21Z")
Can you try the artifact in [this snapshot](https://github.com/elastic/apm-agent-java/actions/runs/11214384346?pr=3830), eg [this agent jar](https://github.com/elastic/apm-agent-java/actions/runs/11214384346/artifacts/2023441330) and see if the functionality is what you want? ---
**Author:** ![pickypg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pickypg/32/62409_2.png) [@pickypg](https://discuss.elastic.co/u/pickypg)\ **Post date:** [October 7, 2024, 5:32pm UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/3 "2024-10-07T17:32:47Z")
Hey @Jack_Shirazi, this changes the behavior and avoids the stacktrace, but it has introduced a new warning: ```auto 2024-10-07 11:30:30,125 [reactive-kafka-indexer-2] WARN co.elastic.apm.agent.impl.transaction.AbstractSpanImpl - End has already been called: 'Kafka record from metrics' 00-267240554c7e5f88ff830484f04d42b3-37d4763c1ab58522-01 (691e56cb) 2024-10-07 11:30:30,226 [reactive-kafka-indexer-2] WARN co.elastic.apm.agent.impl.ActiveStack - Deactivating a context ('Kafka record from metrics' 00-267240554c7e5f88ff830484f04d42b3-37d4763c1ab58522-01 (691e56cb)) which is not the currently active one (co.elastic.apm.agent.impl.EmptyTraceState@213815fd). This can happen when not properly deactivating a previous span or context. ``` ---
**Author:** ![Jack\_Shirazi](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jack_shirazi/32/91641_2.png) [@Jack\_Shirazi](https://discuss.elastic.co/u/Jack_Shirazi)\ **Post date:** [October 8, 2024, 11:30am UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/4 "2024-10-08T11:30:18Z")
Thanks, I kind of expected that, since the only reason the active stack could be misaligned would be somewhere in the `reactor-kafka` implementation propagation is not happening correctly. Is it functionally working for you? I'll open a low priority issue for this but unless there's a functional problem it'll stay like this for a while ---
**Author:** ![pickypg](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pickypg/32/62409_2.png) [@pickypg](https://discuss.elastic.co/u/pickypg)\ **Post date:** [October 10, 2024, 4:04pm UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/5 "2024-10-10T16:04:37Z")
The work being done is happening correctly, but it's hard to say if APM is reporting correctly because we have to aggressively sample the data, so it has a lot of holes in it on its own. ---
**Author:** ![Jack\_Shirazi](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jack_shirazi/32/91641_2.png) [@Jack\_Shirazi](https://discuss.elastic.co/u/Jack_Shirazi)\ **Post date:** [October 11, 2024, 9:31am UTC](https://discuss.elastic.co/t/reactor-parallel-streams-causes-apm-log-spam-and-possibly-missed-spans/366890/6 "2024-10-11T09:31:20Z")
Well if you identify something more, please update the [issue](https://github.com/elastic/apm-agent-java/issues/3837)