# APM transactions displayed in wrong time order

**URL:** https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406
**Category:** APM
**Created:** [April 25, 2019, 9:10am UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406 "2019-04-25T09:10:50Z")
**Posts on this page:** 8
**Page:** 1

<div class="post-metadata">

### Author: ![vsmelov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/vsmelov/32/79783_2.png) [@vsmelov](https://discuss.elastic.co/u/vsmelov)
#### Post date: [April 25, 2019, 9:10am UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/1 "2019-04-25T09:10:50Z")

</div>

I checked this problem on both versions

**Kibana version** :  
6.7.1 and 6.5.3

**Elasticsearch version** :  
6.7.1 and 6.5.3

**APM Server version** :  
6.7.1 and 6.5.3

**APM Agent language and version** :  
python  
elastic-apm==4.0.2

**Original install method (e.g. download page, yum, deb, from source, etc.) and version**:  
docker-compose

**Description of the problem including expected versus actual behavior. Please include screenshots (if relevant)**:

I have 3 components and 2 types of events.

ComponentA:  
- publish event1  
ComponentB:  
- receive event1, process it (for ~200ms) and publish event2  
ComponentC:  
- receive event1 and process it  
- receive event2 and process it

Expected APM plot:

 ![expected](https://us1.discourse-cdn.com/elastic/original/3X/a/c/ac23c2e4503228a214e82a48a7922168c89674cc.png)

Actual:

 ![Event1](https://us1.discourse-cdn.com/elastic/original/3X/7/f/7fdf519a4caaee6ebd8c677c0e4cba24d06b1f32.png)  
I see two problems here

1. (mian) C:recv\_event2 started before B:recv\_event1 finished and published event2 (what is impossible)
2. B:recv\_event1 and C:recv\_event1 started immediately at the same time point as event1 (what is impossible because event1 first should be published/finished and then processed by others)

If I check Elastic log messages it is fine

 ![Discover%20%20%20Kibana](https://us1.discourse-cdn.com/elastic/original/3X/5/f/5fb1abd475aa5ae8eab1436727f1d7953855d9b5.png)

1. C:recv\_event2 happened after the end of B:recv\_event1
2. B:recv\_event1 and C:recv\_event1 timestamp is bigger than event1 timestamp

Why do I see wrong APM plot?

**Code implementation**  
I create APM transaction when I publish event1 and forward transaction\_id with event.  
So in component B and C I use

```auto
msg = parse(socket.recv())
apm.begin_transaction('B:recv_event2', trace_parent=TraceParent.from_string(msg['apm_id']))

```

---

<div class="post-metadata">

### Author: ![sqren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sqren/32/26110_2.png) [@sqren](https://discuss.elastic.co/u/sqren)
#### Post date: [April 25, 2019, 11:06am UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/2 "2019-04-25T11:06:08Z")

</div>

Hi Vladimir,

Thanks for reaching out. This does indeed look like a bug.  
For me to look further into this, it would be very helpful to see the response from the backend.

If possible, please open your browsers Dev Tools and find the response for the XHR request containing `/traces/` in the url eg:

```auto
<host>/apm/traces/88cf30e3cf1b935d976238b0d92ec81a?start=2019-04-24T11%3A01%3A31.927Z&end=2019-04-25T11%3A01%3A31.927Z

```

You are welcome to send it to me as a private message if you don't want to post it publicly.

---

<div class="post-metadata">

### Author: ![vsmelov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/vsmelov/32/79783_2.png) [@vsmelov](https://discuss.elastic.co/u/vsmelov)
#### Post date: [April 25, 2019, 12:15pm UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/4 "2019-04-25T12:15:46Z")

</div>

here is request-response  
[https://pastebin.com/9EkyuwJP](https://pastebin.com/9EkyuwJP)

it's too big so I cannot post it here

---

<div class="post-metadata">

### Author: ![roncohen](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/roncohen/32/22881_2.png) [@roncohen](https://discuss.elastic.co/u/roncohen)
#### Post date: [April 26, 2019, 10:56am UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/5 "2019-04-26T10:56:14Z")

</div>

@vsmelov thanks for the data!

Could you help us understand a bit more about your use case? What kind of transport mechanism do you use when you say that an event is "published"? Are you using some kind of event bus?

---

<div class="post-metadata">

### Author: ![vsmelov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/vsmelov/32/79783_2.png) [@vsmelov](https://discuss.elastic.co/u/vsmelov)
#### Post date: [April 26, 2019, 12:22pm UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/6 "2019-04-26T12:22:14Z")

</div>

I use ZMQ sockets

componentA publishes message like `{'apm_id': 'xxx', 'data': 'event1'}` to socket and log transaction to APM  
componentB receive event1 from socket, process it for 200ms, log transaction to APM and publishes `{'apm_id': 'xxx', 'data': 'event2'}`to socket  
componentC receive event1 from socket and log transaction to APM  
componentC receive event2 from socket and log transaction to APM

I can write some very simplified python-code for this use-case and post it if necessary.  
Because now these components are parts of our big application.

But it still does not clear for me, why I see correct logs in elasticsearch but wrong visualisation.

---

<div class="post-metadata">

### Author: ![vsmelov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/vsmelov/32/79783_2.png) [@vsmelov](https://discuss.elastic.co/u/vsmelov)
#### Post date: [April 30, 2019, 1:31pm UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/7 "2019-04-30T13:31:36Z")

</div>

So why can it happen? 🙂 Can we use any workaround?

---

<div class="post-metadata">

### Author: ![roncohen](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/roncohen/32/22881_2.png) [@roncohen](https://discuss.elastic.co/u/roncohen)
#### Post date: [April 30, 2019, 1:48pm UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/8 "2019-04-30T13:48:36Z")

</div>

Thanks for hanging in there @vsmelov.  
We've identified the issue and will fix it in one of the upcoming releases.  
You can follow along here: [https://github.com/elastic/kibana/issues/35800](https://github.com/elastic/kibana/issues/35800)

---

<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: [May 21, 2019, 9:57am UTC](https://discuss.elastic.co/t/apm-transactions-displayed-in-wrong-time-order/178406/9 "2019-05-21T09:57:11Z")

</div>

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