Solved Yealinks not receiving INVITES while 3cx clients do

[George Ts]

Hello,

We are under the following environment, using all the latest supported releases for each node:
- 3cx SP6 (15.5.15502.6)
- Yealinks T26P 6.73.0.60
- Yealinks T28P 2.3.0.60

A strange issue occurred on the following simple scenario:
Incoming call from SIP trunk to E1 gateway - - > Ring Group of 5 users

Result = Only 3 out of 5 Ring Group users received the call normally to their Yealinks
Two of them only received the call on their 3cx soft clients, not on their Yealinks.

Wireshark traces show that the Yealinks were normally registered during the time of the incoming call (in fact they had registered just a few seconds before the call).
Interestingly, during the call the two Yealinks with the issue never receive an INVITE request: They only receive "TCP SYN" from the 3cx server towards their TCP port 5062, which they reject with "TCP RST,ACK".

Since 3cx initiates those TCP SYNs instead of sending INVITEs over UDP to the Yealinks, I was wondering if this is a known issue.
The attached screenshot could give a better overview of the issue:
Users RG1, RG2 and RG3 receive the call normally on their Yealinks (INVITE over UDP), while users RG4 and RG5 just receive TCP SYNs to their Yealinks.

The respective extensions are all set to accept Multiple calls and Accept Calls from Ring Groups.
Any ideas?

Thank you,
George

 

[eddv123]

Agreed, it would be good to get some insight from a 3CX employee to see if there is anything we have missed.

In the meantime I am happy to look at a Wireshark capture for anything obvious if you would like to post or PM one across.

 

[YiannisH_3CX]

From the provided data (which are not a lot) the PBX does not try to use TCP to send the Invite to the phones. It tries to communicate with the phone via TCP but does not send an Invite. That makes me think that the phones were not registered properly during the initiation of the call or were not reachable and the PBX tries to reach the phones via TCP. Of course this is just a guess as you will need both a wireshark capture and the PBX logs in verbose in order to determine what is going on when the issue occurs.
The PBX Bin log viewer will show the internal working of the PBX and why there is no Invite towards the 2 phones. And to answer your question CTI should not cause the phones the communication to switch to TCP.

 

[George Ts]

Thank you @YiannisH_3CX for your response.
It's good to find out about the Bin Log Viewer, did not know about that.

I also tried to consider network or registration issues, but it still does not make much sense to me.
The trace was captured on the 3cx server. Given that, I would expect the following:

1. If 3cx server did not consider the IP phones registered at the moment (registration removed from its registrar database) it would not even know their Contact IP address. So how would it try to establish a TCP session using the correct IP address of the phones?

2. If 3cx had indeed those 2 phones in its registrar database but we were having a network issue at that very moment, I would see in the Wireshark trace 3cx retransmitting the INVITES over UDP using exponential back-off. This did not happen either.

Which leaves the whole TCP thing unexplained to me.
Unfortunately I only have the Wireshark traces at the moment, nothing more from 3cx Activity log as more than 10 days have passed.

Please let me know if the two arguments mentioned above make sense to you.

Thank you,
George

 

[eddv123]

Apologies for the delay on this one George.

I have made a test today on 3CX with a Yealink and softphone. To confirm:

* The Yealink by default (account settings) when provisioned by 3CX defaults to transport type UDP.

* I have toggled between TCP/UDP on the provisioned phone manually and the change to TCP works (I have Wireshark traced both).

* Calls made were local calls using both a 3rd party soft client and 3CX Phone and both worked exactly the same.

What is interesting however is that in one of the tests I set the 3CX Phone to TCP for transport and the Yealink to UDP. Despite which end I started the call from the transport type used was UDP.

I know this is not conclusive to what you are seeing, but hope it helps confirm a few things for you.

 

[YiannisH_3CX]

1. If 3cx server did not consider the IP phones registered at the moment (registration removed from its registrar database) it would not even know their Contact IP address. So how would it try to establish a TCP session using the correct IP address of the phones?

2. If 3cx had indeed those 2 phones in its registrar database but we were having a network issue at that very moment, I would see in the Wireshark trace 3cx retransmitting the INVITES over UDP using exponential back-off. This did not happen either.

Which leaves the whole TCP thing unexplained to me.
Unfortunately I only have the Wireshark traces at the moment, nothing more from 3cx Activity log as more than 10 days have passed.

Please let me know if the two arguments mentioned above make sense to you.

You reasoning is not wrong and i would normally i would expect something along those lines to occur however as i mentioned without data we can only make guesses as to what happened and caused this behaviour. I would recommend seeing if you can replicate the issue and then going through the logs to find the cause.

 

[George Ts]

@YiannisH_3CX
As the issue has not recurred for almost a month now, while those two specific extensions (Yealinks and softphones) receive many calls every day, we can conclude that for some reason the registration was not working by the very moment of the call.
Please feel free to close this case.

Regards,
George

 

[YiannisH_3CX]

Glad to see that the issue has not returned and thank you for updating the thread.

 

[George Ts]

Hello everyone,

Unfortunately the issue recurred, with some differences this time:

Again, users of a Ring Group could receive the call on their 3cx softphones on Windows but could not receive the call on their Yealinks.
3cx server actually tried to reach the Yealinks with SIP INVITE over UDP, however it never received a provisional response (1xx) by the Yealinks, so it retransmitted the INVITE (normally this time, over UDP).
In simple words, the server knew that the Yealinks were registered by that time, it just could not reach those.
This makes me suspect network issues by that time. Something in the LAN prevented the INVITE to reach from switch0 (3cx server) to switch1 (Yealink clients). For now, I have no idea what this is and why this happens sporadically. Any ideas?

@complex1 there is one thing I have not yet clarified: Do you still believe that changing the Yealinks' T1 timer will somehow affect this behavior? If yes, how exactly?

Thank you,
George

 

[George Ts]

@YiannisH_3CX I am trying to follow your recommendation about checking 3cx logs.
Going under Dashboard - - > Activity Log - - > Filter by date does not work, it does not display any logs.
So, I picked the 3cx Bin Log Viewer approach.
I selected Support - - > Generate Support Info and downloaded the generated zip file.
Under the "Logs/" folder it includes indeed a "3cxPhoneSystem.bldef" file which can be imported in the Bin Log Viewer.
However, it does not include information about January 21st, when the issue happened.

For this scope, I have downloaded the ".3CXPhoneSystem-20190121-052106.blrec" file which seems to include logs produced during the time of the issue.

Two questions please:
1. Why does the filter under Dashboard - - > Activity Log - - > Filter by date not seem to work?
2. How can I import the Logs of the 21st of January into the Bin Log Viewer? I assume I need to correlate the blrec file of that date with the bldef file produced after the "generate support info", correct?

Thank you in advance,
George

 

[YiannisH_3CX]

1. Why does the filter under Dashboard - - > Activity Log - - > Filter by date not seem to work?

That would depend with your settings for retaining the logs and if you restarted the services of the system.

2. How can I import the Logs of the 21st of January into the Bin Log Viewer? I assume I need to correlate the blrec file of that date with the bldef file produced after the "generate support info", correct?

The following link can provide more info regarding the Bin log viewer. https://www.3cx.com/docs/3cx-log-viewer/

 

[George Ts]

Thank you for your response @YiannisH_3CX
Please find my answers below:
1. We have not restarted any service, including the Conf service. Our Settings under Activity Log are "verbose" and "keep backups for 10 days"
2. I have been through the document but still, generating the support logs only creates a bldef file which includes only today's logs (23rd of January). However, I searched in the server and under C:\ProgramData\3CX\Instance1\Data\Logs\Backup\20190121 I found the blrec file with the day before yesterday's logs. Importing the blrec file after importing the bldef file does not display the logs of January, 21st. Am I missing something? The document does not explain this, or maybe I got lost in the information.

Thank you,
George

 

[YiannisH_3CX]

The bldef file contains info on what blrec files it can open so if the blrec file is not included in the bldef file for whatever reason then you won't be able to open them. If services were not restarted then you should be able to open blrec files that are in your backup folder. I think the only time i have seen support info without blrec files was because the blrec file was just transferred to backup and a new file was not yet created.
If the required blrec file cannot be opened via the Bin Log Viewer you can still get the information included by editing it with a text editor like notepad++ for example.

 

[George Ts]

Hi @YiannisH_3CX
As seen in my screenshot below, not the whole blrec file is human-readable.
Same for the bldef file, so I am not sure in which of its lines I should add the exact filename of the blrec file, so that it is imported in the 3cx Bin Log Viewer.

Please let me make my question more simple, in case this helps:
I know that the issue of the thread recurred on January 21st, 15:00EST.
I have Wireshark logs of that recurrence, and I need to check 3cx's Logs, exactly as they would be displayed during that time under Dashboard - - > Activity Log.

Is there any way to achieve this?

Thank you,
George

 

[YiannisH_3CX]

I cannot answer your question without having access to your logs. If the bldef file does not contain the reference for the blrec file you want then probably you cannot use the bin log viewer to view them.

 

[George Ts]

So, I have found a workaround which might be good for future reference:

1. Generated the support logs under 3cx management console - - > Support - - > Generate support info
2. A .zip file was created which included the bldef file under the /Logs directory. That bldef file included some 3cxPhoneSystem-YYYYMMDD.blrec files, none of which included previous days's logs.
3. I searched into the 3cx Windows server, and found under C:\ProgramData\3CX\Instance1\Data\Logs\Backup\20190121 the .blrec file for January 21st
4. Then, I edited the bldef file with a text editor. The lines that included references to today's blrec files, were edited so that they include the filename of the blrec file of two days ago (January 21st)
5. Placed into the same folder on my PC the bldef file and the blrec files of January 21st.
6. Finally, imported the bldef file into 3cx Bin Log Viewer

This is how I managed to work on two days' ago 3cx Log data. Working on those already, hopefully will get some indication about what happened with the Yealinks. Will keep the thread posted.

 

[George Ts]

Update: As per Yealink forum's recommendation I downgraded some of the Ring Group's Yealinks from 6.73.0.60 to 6.72.0.51. During the next occurrence, if the ones with the previous Firmware succeed in responding to incoming INVITES, while the ones with the latest supported 3cx version (6.73.0.60) fail to do so, we will know that the issue resides on the Yealinks' Firmware.