# Spans outside request scope (distributed tracing / forkJoinpool)

**URL:** <https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533>\
**Category:** APM\
**Tags:** java\
**Created:** [November 24, 2020, 3:45pm UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533 "2020-11-24T15:45:29Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![nicoo](https://avatars.discourse-cdn.com/v4/letter/n/0ea827/32.png) [@nicoo](https://discuss.elastic.co/u/nicoo)\
**Post date:** [November 24, 2020, 3:45pm UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533/1 "2020-11-24T15:45:30Z")

</div>

**logstash version:** 7.9.2  
**APM server version:** 7.9.2  
**APM java agent version:** 1.18.1 / 1.19.0

Hi! I'm facing a strange case related to distributed tracing:  
There are two apps deployed on a k8s cluster, both using elasticAPM java agent. The first app executes N parallel calls to the another via HTTP, using Fork/Join (ForkJoinPool) Java classes.  
The second application also manages the service request in an asynchronous way executing its implementation method (service#callService) with Fork/Join too.

Sometimes, on the first request to the app after deployment, I can see that some spans of the second application (service#callService) are not recorded properly. They're tracked with a different traceId and get dettached outside from the original request scope.  
Currently, that's the only situation where this issue arises. I've made some tests with more than one thread using Jmeter, and it worked OK the rest of the time, showing in APM monitor all the request spans.

This ¿bug? was also reproduced using the opentracing bridge.

Have you ever experienced an issue like this? maybe could it be related to Fork/Join components?

Regards!

 ![trace](https://us1.discourse-cdn.com/elastic/original/3X/2/b/2be3b515a942f2a09dc6e9e84ba8f76fc3cbd181.png)

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [November 25, 2020, 11:53am UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533/2 "2020-11-25T11:53:19Z")

</div>

Hi @nicoo and welcome to our forum 👋

Making sure I understand correctly: the `TicketGroup2Controller#singleSelectTicket` transaction is traced properly as child of the `POST` span from the root transaction, however, the `SingleSelectTicketService#callService` span is sometimes traced with improper parent and wrong trace ID? Is it still captured and sent to the APM server, but with wrong trace ID? If you search in Kibana for this trace ID, do you find additional events?

Also, what is producing the `SingleSelectTicketService#callService` span? Is it the agent's auto-instrumentation? If so- for which [technology](https://www.elastic.co/guide/en/apm/agent/java/current/supported-technologies-details.html)? If not (meaning - if you creating it manually), please add your code that creates this span.

> [@nicoo](#):
>
> Sometimes, on the first request to the app after deployment, I can see that some spans of the second application (service#callService) are not recorded properly.

So, this can be observed only within the first request, but not in any subsequent requests?

> [@nicoo](#):
>
> I've made some tests with more than one thread using Jmeter, and it worked OK the rest of the time, showing in APM monitor all the request spans.

I didn't get this one.

---

<div class="post-metadata">

**Author:** ![nicoo](https://avatars.discourse-cdn.com/v4/letter/n/0ea827/32.png) [@nicoo](https://discuss.elastic.co/u/nicoo)\
**Post date:** [November 25, 2020, 2:15pm UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533/3 "2020-11-25T14:15:15Z")

</div>

Hi @Eyal_Koren!

> [@Eyal\_Koren](#):
>
> Making sure I understand correctly: the `TicketGroup2Controller#singleSelectTicket` transaction is traced properly as child of the `POST` span from the root transaction, however, the `SingleSelectTicketService#callService` span is sometimes traced with improper parent and wrong trace ID? Is it still captured and sent to the APM server, but with wrong trace ID? If you search in Kibana for this trace ID, do you find additional events?

Yes, it's ok. `#singleSelectTicket` transaction is traced properly. But sometimes `callService` span (child of the previous one) is tracked with another trace ID and isn't shown in the chart (in the picture sent you can see that the 2nd and 3rd transactions don't contain that span).  
I can see the "lost" spans in Kibana but as unrelated transactions (not associated with the original main request transaction).

> [@Eyal\_Koren](#):
>
> Also, what is producing the `SingleSelectTicketService#callService` span? Is it the agent's auto-instrumentation? If so- for which [technology](https://www.elastic.co/guide/en/apm/agent/java/current/supported-technologies-details.html)? If not (meaning - if you creating it manually), please add your code that creates this span.

I tested it producing these spans with two different strategies:

- Using Elastic APM java agent via [trace\_methods](https://www.elastic.co/guide/en/apm/agent/java/current/config-core.html#config-trace-methods) property configuration.

- Using an implementation of opentracing bridge.

The issue was observed in both alternatives ☹  
The apps are based on spring-boot 2.x (supported by elastic java agent)

> [@Eyal\_Koren](#):
>
> So, this can be observed only within the first request, but not in any subsequent requests?

Yes, just in the first transaction request after application deployment. So far that's the only case where I've seen this issue.

> [@Eyal\_Koren](#):
>
> > [@nicoo](#):
> >
> > I've made some tests with more than one thread using Jmeter, and it worked OK the rest of the time, showing in APM monitor all the request spans.
> 
> I didn't get this one.

In order to see if the issue occurs in another situation, I've made some additional tests, but they worked OK.

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [December 3, 2020, 9:20am UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533/4 "2020-12-03T09:20:36Z")

</div>

I think this miss in the first request happens due to the fact that we are applying our inter-thread context propagation instrumentation dynamically when we first encounter a task/runnable/callable type. We do that in order to reduce the impact on startup time.

The reason you get the forked task as a separate transaction is because you trace it with `trace_methods`, which creates a transaction if there is no active one on the executing thread, which is the case in the first invocation due to the context-propagation miss explained above. It is the same with OT bridge.

Bottom line, this may be the cost of reducing startup time overhead of the agent. Would you say this is problematic enough for you to trade it with startup time increase? (Not suggesting we will do that, but interested in your opinion 🙂 )

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [December 24, 2020, 5:20am UTC](https://discuss.elastic.co/t/spans-outside-request-scope-distributed-tracing-forkjoinpool/256533/5 "2020-12-24T05:20:48Z")

</div>

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.
