External attended transfer into freePBX - one way audio

FreePBX Endpoints
1

Dear Community Members, Good morning,

Has anyone ever encountered the following issue with external attended transfers?
The trunk and extensions are using the pjsip stack.

Situation:

Outgoing call from freePBX14 to external SIP server.
Attended transfer done between two phones on the external sip server.
After attended transfer complete call between phone on freePBX14 and new callee is with one way audio.

In the call flow details below, you can see the system putting the caller on “music on hold”, you can see the replaces INVITE together with sendrecv SDP, however only one way audio is established.
The from and to tags seem to be correct in the (re)INVITE.

Call flow:

call from 6202 to 6205/686205

INVITE
From: <sip 6202 at 10.254.250.236>;tag=984408ab-bd93-46ee-a7ec-25cc16923d34
To: <sip 686205 at 10.253.0.1>
Call-ID: 3d712369-4768-49c4-9261-264508214003

To: <sip 686205 at 10.253.0.1>;tag=c6e049b72995aefcd228d070891ee07c
From: <sip 6202 at 10.254.250.236>;tag=984408ab-bd93-46ee-a7ec-25cc16923d34
Call-ID: 3d712369-4768-49c4-9261-264508214003

bridge_channel.c: Channel PJSIP/asteriskpabx-00000143 joined ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
bridge_channel.c: Channel Local/686205@from-internal-000000da;2 joined ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
bridge_channel.c: Channel Local/686205@from-internal-000000da;1 joined ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>
bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;2 joined ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>
bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;1 joined ‘simple_bridge’ basic-bridge
bridge_channel.c: Channel PJSIP/6202-00000142 joined ‘simple_bridge’ basic-bridge
bridge_channel.c: Channel Local/686205@from-internal-000000da;1 left ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>
bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;1 left ‘simple_bridge’ basic-bridge
bridge_channel.c: Channel Local/686205@from-internal-000000da;1 swapped with Local/FMGL-686205#@from-internal-000000d9;1 into ‘simple_bridge’ basic-bridge
bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;2 left ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>

music on hold while external attended transfer

TRANSFER INVITE (music on hold)
To: sip 6202 at 10.254.250.236;tag=984408ab-bd93-46ee-a7ec-25cc16923d34
From: sip 686205 at 10.253.0.1;tag=c6e049b72995aefcd228d070891ee07c
Call-ID: 3d712369-4768-49c4-9261-264508214003
…
…
a=sendonly
…
…

TRANSFER OK
From: <sip 686205 at 10.253.0.1>; tag=c6e049b72995aefcd228d070891ee07c
To: <sip 6202 at 10.254.250.236>;
tag=984408ab-bd93-46ee-a7ec-25cc16923d34
Contact: <sip asterisk at 10.254.250.236:5060>
…
…
a=recvonly
…
…

external attended transfer complete

REPLACES INVITE
From: <sip 1211 at 10.253.0.1>;tag=728fae7321881cf9a34b2b93f3a29afc
Replaces: 3d712369-4768-49c4-9261-264508214003;from-tag=c6e049b72995aefcd228d070891ee07c;to-tag=984408ab-bd93-46ee-a7ec-25cc16923d34
To: sip:6202 at 10.254.250.236
Call-ID: 8b9d2830fc8819d204400abfb78dac31 at 10.253.0.1
…
…
a=sendrecv
…
…

REPLACES OK
From: <sip:1211 at 10.253.0.1>;tag=728fae7321881cf9a34b2b93f3a29afc
To: <sip:6202 at 10.254.250.236>;tag=b4042a9c-701f-416d-aa43-916374bb283f
…
…
a=sendrecv
…
…

bridge_channel.c: Channel PJSIP/asteriskpabx-00000143 left ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
Channel PJSIP/incomingcall-00000144 swapped with PJSIP/asteriskpabx-00000143 into ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>

2

What you have labelled as TRANSFER INVITE is actually a hold.

You haven’t included the whole of the SDP, and as the a=sendrecv, etc. are good, the problem probably lies in the c or m lines.

3

Hi David, thank you for providing this pointer.

I have looked into this and the rtp port number is changed in the ‘m’ field when the call from 1211 comes in (the number where the call has been transferred to). This seems to be accepted by both freePBX and external PBX (all audio and control passes through the PABX’s - there is no direct media between phones).

What I am concerned about it the following logs in freePBX.

The initial call is made at 09:44:27
The call is put on hold (whilst being transferred) at 09:44:30/1
The re-invite(updates) comes in at 09:44:34
The whole call circuit ends at 09:44:38

Referring to the logs below I can see that the music is put “off hold” at the time when the whole call circuit is being torn down.
Because of this at the moment I suspect something amiss on the freePBX machine (config or code or signalling).

[2021-06-08 09:44:31] VERBOSE[6040][C-00000059] res_musiconhold.c: Started music on hold, class ‘default’, on channel ‘Local/686205@from-internal-000000da;2’

[2021-06-08 09:44:38] VERBOSE[6040][C-00000059] bridge_channel.c: Channel Local/686205@from-internal-000000da;2 left ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>

[2021-06-08 09:44:38] VERBOSE[6040][C-00000059] res_musiconhold.c: Stopped music on hold on Local/686205@from-internal-000000da;2

4

I’m having trouble matching this up with the SIP extract in your first posting. Also there are no ReINVITEs. You have a new INVITE with Replaces.

The music on hold should stop when the INVITE/Replaces is processed.

I guess it is uncommon to have a transfer pushed back by another PBX, especially if it is not taking itself out of the loop, so it is possible that the unhold is overlooked when taking over the channel/bridge. Normally transfers arrive as REFER/Replaces, from an extension, and Asterisk itself doesn’t push the transfer back if both old and new legs are already in it.

What version of Asterisk do you have?

5

I haven’t read this carefully enough to be sure it is exactly the same problem, but https://issues.asterisk.org/jira/browse/ASTERISK-29253 looks similar. This has not yet been fixed.

There is a workaround, but I don’t know if that is available when using FreePBX generated dialplan.

6

Hi David, looking at the issue it seems that they are related, thank you!

We have Asterisk 13.38.2

Please excuse me for the broken logs as im not sure if I should paste the whole log.

I have tried to summarise the full flow below:

[2021-06-08 09:44:27] VERBOSE[150254] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘10.254.250.236’
[2021-06-08 09:44:27] VERBOSE[150254] netsock2.c: Using SIP RTP Audio TOS bits 184
[2021-06-08 09:44:27] VERBOSE[150254] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2021-06-08 09:44:27] VERBOSE[150254] netsock2.c: Using SIP RTP Audio CoS mark 5
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] pbx.c: Executing [6205@from-internal:1] GotoIf(“PJSIP/6202-00000142”, “0?ext-local,6205,1:followme-check,6205,1”) in new stack
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Caller ID name is ‘’ number is ‘6202’
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: CW Ignore is:
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: CF Ignore is:
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Methodology of ring is ‘ringallv2-prim’
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Added extension 686205# to extension map
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Extension 6205 cf is disabled
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Extension 686205# cf is disabled
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Extension 6205 do not disturb is disabled
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Extension 6205 has ExtensionState: 4
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Discovered PJSIP Endpoint PJSIP/6205
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Ended up with no PJSIP contacts
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: dbset CALLTRACE/6205 to 6202
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: Filtered ARG3: 6205-686205
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: RING ALL V2 : 686205#
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: RVOL_MODE ‘’
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: RVOL is:
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] res_agi.c: dialparties.agi: RVOLPARENT is:

[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] pbx.c: Executing [s@macro-dial:22] Dial(“PJSIP/6202-00000142”, “Local/FMPR-6205@from-internal&Local/FMGL-686205#@from-internal,62,HhTtrM(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] app_stack.c: Local/FMPR-6205@from-internal-000000d8;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2021-06-08 09:44:27] VERBOSE[6030][C-00000059] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp(“Local/FMPR-6205@from-internal-000000d8;1”, “Applying SIP Headers to channel Local/FMPR-6205@from-internal-000000d8;1”) in new stack

[2021-06-08 09:44:29] VERBOSE[6037][C-00000059] pbx.c: Executing [s@macro-dial:22] Dial(“Local/FMGL-686205#@from-internal-000000d9;2”, “Local/686205@from-internal/n,60,HhTtrM(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
[2021-06-08 09:44:29] VERBOSE[6037][C-00000059] app_stack.c: Local/686205@from-internal-000000da;1 Internal Gosub(func-apply-sipheaders,s,1) start

[2021-06-08 09:44:29] VERBOSE[6030][C-00000059] app_dial.c: Local/FMGL-686205#@from-internal-000000d9;1 is ringing

[2021-06-08 09:44:29] VERBOSE[6040][C-00000059] app_dial.c: PJSIP/asteriskpabx-00000143 is ringing
[2021-06-08 09:44:29] VERBOSE[6040][C-00000059] app_dial.c: PJSIP/asteriskpabx-00000143 is ringing
[2021-06-08 09:44:29] VERBOSE[6037][C-00000059] app_dial.c: Local/686205@from-internal-000000da;1 is ringing
[2021-06-08 09:44:29] VERBOSE[6030][C-00000059] app_dial.c: Local/FMGL-686205#@from-internal-000000d9;1 is ringing
[2021-06-08 09:44:30] VERBOSE[6040][C-00000059] app_dial.c: PJSIP/asteriskpabx-00000143 answered Local/686205@from-internal-000000da;2

[2021-06-08 09:44:30] VERBOSE[6041][C-00000059] bridge_channel.c: Channel PJSIP/asteriskpabx-00000143 joined ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>

[2021-06-08 09:44:30] VERBOSE[6042][C-00000059] bridge_channel.c: Channel Local/686205@from-internal-000000da;1 joined ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>

[2021-06-08 09:44:30] VERBOSE[6037][C-00000059] bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;2 joined ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>

[2021-06-08 09:44:30] VERBOSE[6043][C-00000059] bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;1 joined ‘simple_bridge’ basic-bridge
[2021-06-08 09:44:30] VERBOSE[6030][C-00000059] bridge_channel.c: Channel PJSIP/6202-00000142 joined ‘simple_bridge’ basic-bridge
[2021-06-08 09:44:30] VERBOSE[6037][C-00000059] bridge_channel.c: Channel Local/686205@from-internal-000000da;1 left ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>
[2021-06-08 09:44:30] VERBOSE[6037][C-00000059] bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;1 left ‘simple_bridge’ basic-bridge
[2021-06-08 09:44:30] VERBOSE[6037][C-00000059] bridge_channel.c: Channel Local/686205@from-internal-000000da;1 swapped with Local/FMGL-686205#@from-internal-000000d9;1 into ‘simple_bridge’ basic-bridge
[2021-06-08 09:44:30] VERBOSE[6037][C-00000059] bridge_channel.c: Channel Local/FMGL-686205#@from-internal-000000d9;2 left ‘simple_bridge’ basic-bridge <9fb2980b-10e9-423a-bbd0-e1f248e6ef72>

[2021-06-08 09:44:31] VERBOSE[6040][C-00000059] res_musiconhold.c: Started music on hold, class ‘default’, on channel ‘Local/686205@from-internal-000000da;2’
[2021-06-08 09:44:34] VERBOSE[60786] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘10.254.250.236’
[2021-06-08 09:44:34] VERBOSE[6049] bridge_channel.c: Channel PJSIP/asteriskpabx-00000143 left ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
[2021-06-08 09:44:34] VERBOSE[6049] bridge_channel.c: Channel PJSIP/incomingcall-00000144 swapped with PJSIP/asteriskpabx-00000143 into ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>

[2021-06-08 09:44:38] VERBOSE[6049] bridge_channel.c: Channel PJSIP/incomingcall-00000144 left ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
[2021-06-08 09:44:38] VERBOSE[6040][C-00000059] bridge_channel.c: Channel Local/686205@from-internal-000000da;2 left ‘simple_bridge’ basic-bridge <6cb24bfa-351b-49b4-a6ff-689b5fe77566>
[2021-06-08 09:44:38] VERBOSE[6040][C-00000059] res_musiconhold.c: Stopped music on hold on Local/686205@from-internal-000000da;2

7

share logs via pastebin

8

Yes I do notice that many newer phones have a ‘transfer’ button on the physical set, however we encourage our users to use the pabx transfer functionality (with functions similar to ‘*2’ or ‘##’) as in this way we are not reliant on phones that may have different firmware’s/model’s (and thus bugs/functionality).

9

Not sure if this will help with future t.shooting:

We have done some testing in such a way that ‘replaces’ is not used but rather REFER is used and we still have similar problems with transfers using the REFER method

10

I’m not sure if it was clear, but there isn’t a Replaces method; Replace is a parameter on a REFER. A REFER without replace is always a blind transfer, but the current subject is attended transfers.

11

Hi David, thanks for pointing this out and please excuse me for my non precise use of terms which I can understand make a difference.

Before the replaces was appearing in the INVITE and this way of transferring the call was successfully disabled.

The call transfer is now being achieved using the REFER (with a replaces inside the REFER packet) rather than the replaces appearing in the INVITE packet.

12

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