I've spent the better part of a day on this and I'm stumped, hopefully someone can provide much needed insight...
call flow:
Mobile phone --> SIP trunk on PBX #1 --> Bridged automatically to PBX #2 and Answered --> Attended Transfer started, inbound mobile phone hears MOH --> Extension being transfered to on PBX #1 rings, is answered and audio is fine during attended part, but when call is finally transferred it has no audio on PBX #1 extension and mobile phone keeps hearing MOH so it is never connected through --> Call times out or is hung up.
PBX #1 is xxx.xxx.0.189, Master on Bridge, and call comes in to it via SIP trunk
PBX #2 is xxx.xxx.9.189, Slave on Bridge, and call gets bridged to it, answered, then attended transferred back to PBX #1
Bridge on both sides set with Reinvite, Replace. Tried with PBX Delivers Audio with no difference.
Both 3CX 18.0 (Build 418) Enterprise license
105 is extension on PBX #1, using Yealink T46S, IP xxx.xxx.9.140 in logs
201 is extension on PBX #2, using newest 3CX Softphone Desktop App
Extensions are set with Reinvite, Replace and PBX Delivers Audio
The below log excerpt is from PBX #2 (xxx.xxx.9.189) - the PBX doing the attended transfer
Call 35 is the call inbound from bridge, 37 is the attended transfer call (36 was canceled by mistake)
the moment of pushing Transfer a second time is at 12:27:16, this should connect the attended transfer but doesn't:
The logs on PBX#1 show nothing interesting related to the transfer, they show the inbound call (56) and the attended transfer (58) as active throughout the time of the call.
The SIP message flow between the PBXs and the INVITE of the actual transfer is below, the moment of attended transfer connecting the inbound call back to PBX #1 is 12:27:16.
Right side of flow is PBX #1 where call comes in and is bridged further to PBX #2 which is attended transfering back and is on left side of the below flow.
SIP trace looks fine to me, I've tried everything I can think of with no luck. Blind transfer works fine and looks like this in logs:
The curious part is the mix of FQDN and IP address, why not use just one or the other instead of mixing both? Not sure if that has any effect though. Other thing I see is the attended transfer shows up in log as [Flow] Refer but the blind is just joined the call without REFER.
I'm confused just spending all day sifting through logs and SIP traces, could it be that PBX1 is confused since its receiving back a call that it already has active and so doesn't know what to do with it? Any thoughts? I've managed to find a very similar but very ancient problem on the forums here but with no solution
call flow:
Mobile phone --> SIP trunk on PBX #1 --> Bridged automatically to PBX #2 and Answered --> Attended Transfer started, inbound mobile phone hears MOH --> Extension being transfered to on PBX #1 rings, is answered and audio is fine during attended part, but when call is finally transferred it has no audio on PBX #1 extension and mobile phone keeps hearing MOH so it is never connected through --> Call times out or is hung up.
PBX #1 is xxx.xxx.0.189, Master on Bridge, and call comes in to it via SIP trunk
PBX #2 is xxx.xxx.9.189, Slave on Bridge, and call gets bridged to it, answered, then attended transferred back to PBX #1
Bridge on both sides set with Reinvite, Replace. Tried with PBX Delivers Audio with no difference.
Both 3CX 18.0 (Build 418) Enterprise license
105 is extension on PBX #1, using Yealink T46S, IP xxx.xxx.9.140 in logs
201 is extension on PBX #2, using newest 3CX Softphone Desktop App
Extensions are set with Reinvite, Replace and PBX Delivers Audio
The below log excerpt is from PBX #2 (xxx.xxx.9.189) - the PBX doing the attended transfer
Call 35 is the call inbound from bridge, 37 is the attended transfer call (36 was canceled by mistake)
the moment of pushing Transfer a second time is at 12:27:16, this should connect the attended transfer but doesn't:
Code:
02/02/2023 12:27:19 - Currently active calls - 1: [35]
02/02/2023 12:27:16 - Leg L:35.2[Extn:201] is terminated: Cause: BYE from xxx.xxx.9.140:5060
02/02/2023 12:27:16 - Leg L:37.1[Extn:201] is terminated: Cause: BYE from local
02/02/2023 12:27:16 - [CM503008]: Call(C:37): Call is terminated
02/02/2023 12:27:16 - Call(C:35): Replaces: L:37.2[Line:10000>>105]
02/02/2023 12:27:16 - [Flow] Refer: RefTo=<sip:[email protected]:5060>; was call from=<sip:[email protected]:0> to="SITENAME:" <sip:[email protected]:5060>
02/02/2023 12:27:02 - [CM503007]: Call(C:37): Extn:201 has joined, contact <sip:[email protected]:5060/UDP>
02/02/2023 12:27:02 - [CM503007]: Call(C:37): Line:10000>>105 has joined, contact <sip:[email protected]:5060/UDP>
02/02/2023 12:27:02 - L:37.2[Line:10000>>105] has joined to L:37.1[Extn:201]The logs on PBX#1 show nothing interesting related to the transfer, they show the inbound call (56) and the attended transfer (58) as active throughout the time of the call.
Code:
02/02/2023 12:28:44 - Leg L:58.2[Extn:105] is terminated: Cause: BYE from local
02/02/2023 12:28:29 - Currently active calls - 2: [56,58]
02/02/2023 12:27:59 - Currently active calls - 2: [56,58]
02/02/2023 12:27:29 - Currently active calls - 2: [56,58]
02/02/2023 12:27:02 - [CM503007]: Call(C:58): Line:10000<<+201 has joined, contact <sip:[email protected]:5060/UDP>
02/02/2023 12:27:02 - [CM503007]: Call(C:58): Extn:105 has joined, contact <sip:[email protected]:5063/UDP>
02/02/2023 12:27:02 - L:58.2[Extn:105] has joined to L:58.1[Line:10000<<+201]
02/02/2023 12:26:59 - Currently active calls - 2: [56,58]The SIP message flow between the PBXs and the INVITE of the actual transfer is below, the moment of attended transfer connecting the inbound call back to PBX #1 is 12:27:16.
Right side of flow is PBX #1 where call comes in and is bridged further to PBX #2 which is attended transfering back and is on left side of the below flow.
Code:
│INVITE sip:[email protected]:5060 SIP/2.0
xxx.xxx.9.189:5060 xxx.xxx.0.189:5060 │Via: SIP/2.0/UDP xxx.xxx.9.189:5060;branch=z9hG4bK-524287-1---4cb3436922712d26;rport
──────────┬───────── ──────────┬─────────│Max-Forwards: 70
12:26:57.340654 │ INVITE (SDP) │ │Contact: <sip:[email protected]:5060>
+0.087008 │ ──────────────────────────> │ │To: <sip:[email protected]:5060>;tag=3f2cf67c
12:26:57.427662 │ 407 Proxy Authentication R │ │From: <sip:[email protected]:5060>;tag=23fc4127
+0.000459 │ <────────────────────────── │ │Call-ID: h5juU1V3NqoTQHu-dYNn2Q..
12:26:57.428121 │ ACK │ │CSeq: 3 INVITE
+0.050466 │ ──────────────────────────> │ │Session-Expires: 1800;refresher=uac
12:26:57.478587 │ INVITE (SDP) │ │Min-SE: 90
+0.118034 │ ──────────────────────────> │ │Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE, UPDATE
12:26:57.596621 │ 100 Trying │ │Content-Type: application/sdp
+0.100053 │ <────────────────────────── │ │Proxy-Authorization: Digest username="10000",realm="3CXPhoneSystem",nonce="414d535963db9e0162:3975847fdaa2d96365e3d046a560f8e2",uri="sip:[email protected]
12:26:57.696674 │ 180 Ringing │ │.xxx.189:5060",response="0b4c7bde732f428d4f8414e3edb0e383",algorithm=MD5
+4.769051 │ <────────────────────────── │ │Supported: replaces, timer
12:27:02.465725 │ 200 OK (SDP) │ │User-Agent: 3CXPhoneSystem 18.0.5.418 (418)
+0.007548 │ <────────────────────────── │ │Remote-Party-ID: "Persons Name"<sip:[email protected]:5060>;party=calling
12:27:02.473273 │ ACK │ │Content-Length: 285
+14.140651 │ ──────────────────────────> │ │
12:27:16.613924 │ INVITE (SDP) │ │v=0
+0.087714 │ ──────────────────────────> │ │o=3cxPS 6638864781279232 374379632394242 IN IP4 xxx.xxx.9.189
12:27:16.701638 │ 407 Proxy Authentication R │ │s=3cxPS Audio call
+0.000427 │ <────────────────────────── │ │c=IN IP4 10.120.9.189
12:27:16.702065 │ ACK │ │t=0 0
+0.050410 │ ──────────────────────────> │ │m=audio 7210 RTP/AVP 0 8 9 3 101
12:27:16.752475 │ INVITE (SDP) │ │a=rtpmap:0 PCMU/8000
+0.118153 │ ──────────────────────────> │ │a=rtpmap:8 PCMA/8000
12:27:16.870628 │ 100 Trying │ │a=rtpmap:9 G722/8000
+0.101062 │ <────────────────────────── │ │a=rtpmap:3 GSM/8000
12:27:16.971690 │ 200 OK (SDP) │ │a=rtpmap:101 telephone-event/8000
+0.026806 │ <────────────────────────── │ │a=sendrecv
12:27:16.998496 │ ACK │ │
+87.473102 │ ──────────────────────────> │ │
12:28:44.471598 │ BYE │ │
+0.050612 │ <────────────────────────── │ │
12:28:44.522210 │ 200 OK │ │
│ ──────────────────────────> │ │SIP trace looks fine to me, I've tried everything I can think of with no luck. Blind transfer works fine and looks like this in logs:
Code:
01/02/2023 13:13:08 - [CM503007]: Call(C:23): Line:10000>>105 has joined, contact <sip:[email protected]:5060/UDP>
01/02/2023 13:13:08 - L:23.5[Line:10000>>105] has joined to L:23.1[Line:10000<<+0xxxxxxxxxx]The curious part is the mix of FQDN and IP address, why not use just one or the other instead of mixing both? Not sure if that has any effect though. Other thing I see is the attended transfer shows up in log as [Flow] Refer but the blind is just joined the call without REFER.
I'm confused just spending all day sifting through logs and SIP traces, could it be that PBX1 is confused since its receiving back a call that it already has active and so doesn't know what to do with it? Any thoughts? I've managed to find a very similar but very ancient problem on the forums here but with no solution
