Solved Delayed notification to iOS/iPadOS clients 3CX app (from V183CX)

Status
Not open for further replies.

giox069c

Customer
Joined
Mar 31, 2022
Messages
26
Reaction score
3
When a call is made to a 3CX app on iOS/iPad, the caller hears 3 to 5 rings before the called device starts ringing.
This does not happen with Android Phones, there is no delay.

Here are some logs from both 3CX V18 and the app. Call is started by the user at 11:17:18

On the 3CX PBX server side:
Code:
2024/05/27 11:17:16.945|25108|0039|Verb|Dequeue Updated.REGISTRATION.10032
2024/05/27 11:17:19.027|25108|0005|Verb|Enqueue Inserted.CONNECTION.951
2024/05/27 11:17:19.028|25108|0039|Verb|Dequeue Inserted.CONNECTION.951
2024/05/27 11:17:19.108|25108|0005|Verb|Enqueue Updated.REGISTRAR.10072
2024/05/27 11:17:19.108|25108|0062|Verb|Dequeue Updated.REGISTRAR.10072
2024/05/27 11:17:19.108|25108|0005|Verb|Enqueue Updated.REGISTRATION.10072
2024/05/27 11:17:19.108|25108|0062|Verb|Dequeue Updated.REGISTRATION.10072
2024/05/27 11:17:19.132|25108|0005|Verb|Enqueue Inserted.CONNECTION.952
2024/05/27 11:17:19.132|25108|0062|Verb|Dequeue Inserted.CONNECTION.952
2024/05/27 11:17:19.133|25108|0005|Verb|Enqueue Inserted.CONNECTION.953
2024/05/27 11:17:19.133|25108|0039|Verb|Dequeue Inserted.CONNECTION.953
2024/05/27 11:17:19.167|25108|0005|Verb|Enqueue Updated.CONNECTION.952
2024/05/27 11:17:19.167|25108|0039|Verb|Dequeue Updated.CONNECTION.952
2024/05/27 11:17:19.167|25108|0039|Info|Sending PUSH call-started for dn=647, replaces=szF6aoPxJQf48epT7Yn1Eg..;from-tag=7303b465;to-tag=f1448574, callerid=607, calle
rname=Luca Surname, callid=471, image=
2024/05/27 11:17:19.168|25108|0039|Info|IV: Sending PUSH to extension 647 device iPhone12,1iPhone
2024/05/27 11:17:19.694|25108|0005|Verb|Enqueue Updated.REGISTRAR.10031
2024/05/27 11:17:19.694|25108|0005|Verb|Enqueue Updated.REGISTRATION.10031
2024/05/27 11:17:19.694|25108|0062|Verb|Dequeue Updated.REGISTRAR.10031
2024/05/27 11:17:19.694|25108|0062|Verb|Dequeue Updated.REGISTRATION.10031
2024/05/27 11:17:19.695|25108|0005|Verb|Enqueue Updated.REGISTRAR.10015
2024/05/27 11:17:19.695|25108|0005|Verb|Enqueue Updated.REGISTRATION.10015
2024/05/27 11:17:19.695|25108|0062|Verb|Dequeue Updated.REGISTRAR.10015
2024/05/27 11:17:19.695|25108|0062|Verb|Dequeue Updated.REGISTRATION.1001


On the iPhone side:

Code:
11:15:25.663 VCE|bootstrap *** Destroying tunnel...
11:15:25.663 TNL|tunnel
---------- DESTROY TNL LIB ----------
11:15:25.663 TNL|tunnel  destroyed
11:15:25.663 VCE|EMGR destroyed
11:17:31.122 [5343] [APP] =============== Application started ===================
11:17:31.171 [5343] VERBOSE MODE CHANGED:true
11:17:31.253 [5343] [SavedChats] save 0 on profile will change []
11:17:31.257 [5343] [SavedChats] read 0 from profile did change [1c561b7f-0ada-41f0-b43c-08399ad57110]
11:17:31.280 [5345] [Lifecycle] - Ringing calls: false
11:17:31.280 [5345] [Lifecycle] - calls updated, noCalls: true, backgroundTaskActive: false
11:17:31.281 [5345] [Lifecycle] - sceneActive: false && noCalls, stop the VCE?
11:17:31.293 [5345] [quickchat] new session created: NullConnection, active: false
11:17:31.349 [5345] [APP] daily push refresh background task scheduled at martedì 28 maggio 2024 alle ore 11:17:31 Ora legale dell’Europa centrale
11:17:31.467 [5345] Received push - callerId: 607, callerName: Luca Surname, replaces: szF6aoPxJQf48epT7Yn1Eg..;from-tag=7303b465;to-tag=f1448574, callId: 471, reason: 0

as you can see, the server sends notification on 11:17:19, but the iPhone receives it at 11:17:31

How can we remove that delay ?

Thank you
 
@giox069c
For this kind of troubleshooting, I would recommend you to contact our tech support.
However, I don't want to lie, but I think in the past this problem was related to some DNS (mis)configuration issue on the PBX.
 
  • Like
Reactions: Evolute IT
Thanks Vali_3CX for pointing me to a DNS problem. It's a DNS issue between Debian 10 glibc and some firewalls.

Short workaround for 3CX V18: add
Code:
options single-request-reopen
to /etc/resolv.conf file

Long explanation:
Debian10 has a glibc version suffering this problem: when resolving a host name via getaddrinfo(), two queries are sent to DNS server, one for the A record and one for the AAAA record. Queries are sent from the same UDP source port. If getaddrifo() for this version of glibc does not receive both answers, it will sleep and retry to send the queries after 5 seconds.
In our case, between 3CX and the DNS server there is a Watchguard Firebox M270 Firewall, which for unknown reason is blocking the AAAA query, without leaving a trace on its logs. The DNS server only receives the A query and produces only an A answer, making glibc() sleeping and retrying after 5 seconds.
Adding options single-request-reopen to /etc/resolv.conf makes the two queries originating from different UDP ports, and the watchguard firebox will not block them so getaddrinfo() will not go to sleep for 5 seconds.
The problem does not seems to occur in Debian 12 (3CX V20): getaddrinfo() will never sleep waiting for the missing AAAA answer.
 
  • Like
Reactions: Vali_3CX
Status
Not open for further replies.

Latest Posts

Forum statistics

Threads
112,279
Messages
591,666
Members
165,399
Latest member
NetworkActive