Homer 10 - Call Flow - Sorting Issues/Wrong Order

[tony1661]

I am noticing an issue in Homer 10's Call Flow dashboard. It seems that the Call Flow is not in the correct order which is making troubleshooting difficult.

I have a Freeswitch server (FusionPBX) with the portable helpify agent running heplify -hs homer-stack-ip:9060

If I search by the Call-ID in the SIP headers, I see all SIP messages associated with the call. See below:

Obviously the INVITE would have occurred before the 407 however that is not what Grafana shows.

Based on the HEP Flow panel, the messages should be sorted oldest to newest.

If I look into each message I see that the INVITE has a later date than the 407.

INVITE Date

407 Date

The issue is similar to what is being experienced in Homer 7's web-ui which leads me to think the issue may be related to Heplify. In Homer 7, when searching for a call, the results are also in the wrong order, however when I click on the Session ID to view the ladder, it is in the correct order.

Is it possible that the ladder in Homer 7 is referencing a different timestamp that is also being referenced in Homer 10?

[github-actions]

Please star this repository to motivate the developers and to get higher priority! ⭐

[tony1661]

I've tested using captagent instead of heplify and the issue persists in Homer 10.

[tony1661]

To add to this issue, I took a packet capture of a call that has the SIP messages displayed in the wrong order in Homer 10.

It seems that in the HEP packets, the Unix Timestamp doesn't change. See below:

The last two messages (BYE and 200 OK) have a different timestamp and in Homer they do indeed appear at the bottom of the ladder but they appear in a different order in the ladder than they do in the packet capture.

It may be worth adding the Timestamp μs to the equation.

[lmangani]

Thanks for the report @tony1661 we're investigating and will make sure this is part of the next grafana-flow release
@AlexeyOplachko could you check this after the holidays?

[tony1661]

@AlexeyOplachko let me know if I can help in any way. I can provide logs, pcaps etc.

I have this on a production freeswitch server with heplify and captagent both running.

Hundreds of calls a day that we can look at.

[lmangani]

Hi @tony1661 we're back next week and we' ll most definitely address this

[RFbkak37y3kIY]

pushed fix for grafana-plugin, metrico/grafana-flow#47

used field [tsNs] for increased sorting accuracy SIP messages

[tony1661]

Hi all,

I saw there were some code merged. If I pull the latest docker images, will I be able to test this?

[lmangani]

As long as its using plugin version 10.0.10 you can also update an existing setup

[lmangani]

@tony1661 here's how

[tony1661]

@lmangani Thanks for your quick response. I tested and the issue seems to still be there. Is there anything I can provide to help? Logs etc

[AlexeyOplachko]

For starters can you please verify that your grafana indeed got new plugin version please?
your_grafana_url/plugins/qxip-flow-panel

On our side we'll try to replicate this issue today and see if we need anything else from you

[tony1661]

Hi @AlexeyOplachko ,

I have verified that I have 10.0.10 installed. See below:

[tony1661]

Anything I can help with?

[lmangani]

@AlexeyOplachko please provide an update

[AlexeyOplachko]

Anything I can help with?

@tony1661
Can you please provide screenshots of Message details with all the info in them, on two messages that are in incorrect order.


And also can you please check if Sort Items is set.

[tony1661]

Hi @AlexeyOplachko sorry for the delay on this.

The Sort items is set to "Sort by Time: Oldest first".

Here is what the call flow looks like:

Here is the first message (INVITE):

Here is the second message (200 OK):

Here is the fourth message (that is supposed to be second - 100 Trying):

[AlexeyOplachko]

Hi @tony1661, thanks for reply, seems like this is not a sorting issue, but an issue with data.

If you look closely, message with 100 Trying has timestamp almost 4 minutes later than 200 OK.
And all three timestamps(one in labels, one in Time field, and nanosecond one) show matching data that supports this.

[tony1661]

@AlexeyOplachko Yea something seems off with the data. The issue happens on multiple HEP clients (heplify and captagent)

I have some screenshots from pcaps above that may assist.

I am running freeswitch (via FusionPBX)