One way speech, native_rtc bridge, music on hold during atx

Asterisk Asterisk Support
1

Hello all, first time poster here…

I have gone some way towards diagnosing an issue but need a further pointers please.

We recently upgraded from 1.4 up to 13. It didn’t take us too long to get segments of our previous configs over and into 13; within a working day we had our new version up and running, another day or so testing and ironing out other small (our config) issues, then we went live with it.

A big jump I know, but generally if it ain’t broke…

I have a particular and specific issue with attended transfers, notably after the inbound caller has heard MoH when the calling party is connected through to the intended call recipient (the third party) speech flows only to that third party from the calling party.

Some specifics of our setup:

  • Ubuntu latest release, asterisk installed using apt-get.
  • External IAX provider accessed via NAT’d connection, registrations initiated on our side only, so pin holing through our firewall is dynamic as a result of the outbound traffic.
  • All extensions internally are Linksys SPA942 clients, accessing as SIP peers.
  • No external SIP services are offered or consumed, SIP is only used internally within the local LAN.

Some notable things which are working absolutely fine:

  • Inbound calls via voice menus to extensions.
  • Inbound calls to confbridge (which use MoH without any issues).
  • Inbound calls which are transferred using a blind Xfer, or inbound calls which are transferred very quickly using an attended transfer where there is nothing said between the second and third parties, when it’s done quickly and no MoH channel is setup.
  • Call from internal extension to the same secondary party, with attended transfer to the same third party, with the same flow, hearing MoH, and with the 2nd and 3rd parties talking briefly before connecting caller and 3rd party.

Here’s the interesting part:

  • When I disable bridge type native_rtp using: bridge technology suspend native_rtp - we are then able to do an attended transfer where the caller does hear MoH while party 2 speaks to party 3, then transfers, after which caller and party 3 are able to hear each other in both directions.

It appears to me that: switching from native_rtp technology to simple_bridge - which is a step shown in the CLI when the 2nd party connects the third party to the inbound IAX; the caller channel is failing to continue to pass the RTP packets to the 3rd party.

I turned on RTP debug to view the packet flow, here’s what I noticed:

  • when party 2 and party 3 are talking and the caller is listening to MoH, I can see bi-directional RTP flow between party 2 and party 3. As soon as the caller is connected and party 2 is removed, I continue to see traffic towards party 3, but nothing being returned to the caller. - This is in-line with the direction of speech which is being experienced by the caller and the intended call recipient.

So… I can leave things running as they are for now, with the native_rtp bridge type suspended, we will manage to avoid this issue while this is in place. However, it’s not the fix I want and I’m also worried about a reboot of this system and this option not being suspended.

I have yet to find a way to issue this command to suspend this bridge type on startup, or to disable it through the config files…

I would appreciate any pointers (and perhaps some instructions to help me sort this).

Here’s some CLI trace of a failing call - with speech path from the caller to party 3 only (SIP/706):

    -- Accepting AUTHENTICATED call from 27.111.14.68:4569:
    --        > requested format = alaw,
    --        > requested prefs = (alaw|g722|ulaw|g729|gsm),
    --        > actual format = ulaw,
    --        > host prefs = (ulaw|alaw|siren14|siren7|g722|slin16|slin|g726|g726aal2|adpcm|gsm|ilbc|speex|g729|speex16|testlaw|g719|opus|jpeg|png|h261...),
    --        > priority = mine
    -- Executing [099129107@from-099129107:1] Set("IAX2/099129107-6552", "CALLERID(number)=021624717") in new stack
    -- Executing [099129107@from-099129107:2] Goto("IAX2/099129107-6552", "default,707,1") in new stack
    -- Goto (default,707,1)
    -- Executing [707@default:1] Gosub("IAX2/099129107-6552", "707,stdexten(SIP/707)") in new stack
    -- Executing [707@default:50000] NoOp("IAX2/099129107-6552", "Start stdexten") in new stack
    -- Executing [707@default:50001] Answer("IAX2/099129107-6552", "") in new stack
    -- Executing [707@default:50002] Set("IAX2/099129107-6552", "LOCAL(ext)=707") in new stack
    -- Executing [707@default:50003] Set("IAX2/099129107-6552", "LOCAL(dev)=SIP/707") in new stack
    -- Executing [707@default:50004] Set("IAX2/099129107-6552", "LOCAL(cntx)=") in new stack
    -- Executing [707@default:50005] Set("IAX2/099129107-6552", "LOCAL(mbx)=707") in new stack
    -- Executing [707@default:50006] Dial("IAX2/099129107-6552", "SIP/707,20") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/707
    -- SIP/707-00000064 is ringing
    -- SIP/707-00000064 answered IAX2/099129107-6552
    -- Channel IAX2/099129107-6552 joined 'simple_bridge' basic-bridge <e0e0c448-a709-46c7-af10-084fd6d0f7e2>
    -- Channel SIP/707-00000064 joined 'simple_bridge' basic-bridge <e0e0c448-a709-46c7-af10-084fd6d0f7e2>
       > 0x7f12c48096d0 -- Probation passed - setting RTP source address to 192.168.5.107:16474
    -- Started music on hold, class 'default', on channel 'IAX2/099129107-6552'
  == Using SIP RTP CoS mark 5
    -- Executing [706@numberplan-IAX2-SetDDI:1] NoOp("SIP/707-00000065", "callerid num is 707") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:2] GotoIf("SIP/707-00000065", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:3] GotoIf("SIP/707-00000065", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:4] GotoIf("SIP/707-00000065", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:5] GotoIf("SIP/707-00000065", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:6] GotoIf("SIP/707-00000065", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:7] GotoIf("SIP/707-00000065", "1?yesDDI") in new stack
    -- Goto (numberplan-IAX2-SetDDI,706,17)
    -- Executing [706@numberplan-IAX2-SetDDI:17] Set("SIP/707-00000065", "IAXCHAN=099129107") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:18] Goto("SIP/707-00000065", "numberplan-cost-efficient,706,1") in new stack
    -- Goto (numberplan-cost-efficient,706,1)
    -- Executing [706@numberplan-cost-efficient:1] Gosub("SIP/707-00000065", "706,stdexten(SIP/706)") in new stack
    -- Executing [706@numberplan-cost-efficient:50000] NoOp("SIP/707-00000065", "Start stdexten") in new stack
    -- Executing [706@numberplan-cost-efficient:50001] Answer("SIP/707-00000065", "") in new stack
       > 0x40e7750 -- Probation passed - setting RTP source address to 192.168.5.107:16476
    -- Executing [706@numberplan-cost-efficient:50002] Set("SIP/707-00000065", "LOCAL(ext)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50003] Set("SIP/707-00000065", "LOCAL(dev)=SIP/706") in new stack
    -- Executing [706@numberplan-cost-efficient:50004] Set("SIP/707-00000065", "LOCAL(cntx)=") in new stack
    -- Executing [706@numberplan-cost-efficient:50005] Set("SIP/707-00000065", "LOCAL(mbx)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50006] Dial("SIP/707-00000065", "SIP/706,20") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/706
    -- SIP/706-00000066 is ringing
    -- SIP/706-00000066 answered SIP/707-00000065
    -- Channel SIP/707-00000065 joined 'simple_bridge' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>
    -- Channel SIP/706-00000066 joined 'simple_bridge' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>
       > Bridge e5d3fd4c-25a8-4910-bfe0-2b90a253b047: switching from simple_bridge technology to native_rtp
    -- Channel IAX2/099129107-6552 left 'simple_bridge' basic-bridge <e0e0c448-a709-46c7-af10-084fd6d0f7e2>
    -- Channel IAX2/099129107-6552 swapped with SIP/707-00000065 into 'native_rtp' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>
    -- Channel SIP/707-00000065 left 'native_rtp' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>
       > Bridge e5d3fd4c-25a8-4910-bfe0-2b90a253b047: switching from native_rtp technology to simple_bridge
    -- Channel SIP/707-00000064 left 'simple_bridge' basic-bridge <e0e0c448-a709-46c7-af10-084fd6d0f7e2>
  == Spawn extension (numberplan-cost-efficient, 706, 50006) exited non-zero on 'SIP/707-00000065'
    -- Stopped music on hold on IAX2/099129107-6552
    -- Channel IAX2/099129107-6552 left 'simple_bridge' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>
  == Spawn extension (default, 707, 50006) exited non-zero on 'IAX2/099129107-6552'
    -- Hungup 'IAX2/099129107-6552'
    -- Channel SIP/706-00000066 left 'simple_bridge' basic-bridge <e5d3fd4c-25a8-4910-bfe0-2b90a253b047>

Here’s one which does work, with the native_rtp bridge suspended…:

asterisk-2015*CLI> bridge technology suspend native_rtp 
Suspended bridge technology 'native_rtp'
    -- Accepting AUTHENTICATED call from 27.111.14.68:4569:
    --        > requested format = alaw,
    --        > requested prefs = (alaw|g722|ulaw|g729|gsm),
    --        > actual format = ulaw,
    --        > host prefs = (ulaw|alaw|siren14|siren7|g722|slin16|slin|g726|g726aal2|adpcm|gsm|ilbc|speex|g729|speex16|testlaw|g719|opus|jpeg|png|h261...),
    --        > priority = mine
    -- Executing [099129107@from-099129107:1] Set("IAX2/099129107-14595", "CALLERID(number)=021624717") in new stack
    -- Executing [099129107@from-099129107:2] Goto("IAX2/099129107-14595", "default,707,1") in new stack
    -- Goto (default,707,1)
    -- Executing [707@default:1] Gosub("IAX2/099129107-14595", "707,stdexten(SIP/707)") in new stack
    -- Executing [707@default:50000] NoOp("IAX2/099129107-14595", "Start stdexten") in new stack
    -- Executing [707@default:50001] Answer("IAX2/099129107-14595", "") in new stack
    -- Executing [707@default:50002] Set("IAX2/099129107-14595", "LOCAL(ext)=707") in new stack
    -- Executing [707@default:50003] Set("IAX2/099129107-14595", "LOCAL(dev)=SIP/707") in new stack
    -- Executing [707@default:50004] Set("IAX2/099129107-14595", "LOCAL(cntx)=") in new stack
    -- Executing [707@default:50005] Set("IAX2/099129107-14595", "LOCAL(mbx)=707") in new stack
    -- Executing [707@default:50006] Dial("IAX2/099129107-14595", "SIP/707,20") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/707
    -- SIP/707-00000067 is ringing
    -- SIP/707-00000067 answered IAX2/099129107-14595
    -- Channel IAX2/099129107-14595 joined 'simple_bridge' basic-bridge <e86b058b-1ce1-42a9-9399-b2b3698672b6>
    -- Channel SIP/707-00000067 joined 'simple_bridge' basic-bridge <e86b058b-1ce1-42a9-9399-b2b3698672b6>
       > 0x7f12c48096d0 -- Probation passed - setting RTP source address to 192.168.5.107:16478
    -- Started music on hold, class 'default', on channel 'IAX2/099129107-14595'
  == Using SIP RTP CoS mark 5
    -- Executing [706@numberplan-IAX2-SetDDI:1] NoOp("SIP/707-00000068", "callerid num is 707") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:2] GotoIf("SIP/707-00000068", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:3] GotoIf("SIP/707-00000068", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:4] GotoIf("SIP/707-00000068", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:5] GotoIf("SIP/707-00000068", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:6] GotoIf("SIP/707-00000068", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:7] GotoIf("SIP/707-00000068", "1?yesDDI") in new stack
    -- Goto (numberplan-IAX2-SetDDI,706,17)
    -- Executing [706@numberplan-IAX2-SetDDI:17] Set("SIP/707-00000068", "IAXCHAN=099129107") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:18] Goto("SIP/707-00000068", "numberplan-cost-efficient,706,1") in new stack
    -- Goto (numberplan-cost-efficient,706,1)
    -- Executing [706@numberplan-cost-efficient:1] Gosub("SIP/707-00000068", "706,stdexten(SIP/706)") in new stack
    -- Executing [706@numberplan-cost-efficient:50000] NoOp("SIP/707-00000068", "Start stdexten") in new stack
    -- Executing [706@numberplan-cost-efficient:50001] Answer("SIP/707-00000068", "") in new stack
       > 0x40e7750 -- Probation passed - setting RTP source address to 192.168.5.107:16480
    -- Executing [706@numberplan-cost-efficient:50002] Set("SIP/707-00000068", "LOCAL(ext)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50003] Set("SIP/707-00000068", "LOCAL(dev)=SIP/706") in new stack
    -- Executing [706@numberplan-cost-efficient:50004] Set("SIP/707-00000068", "LOCAL(cntx)=") in new stack
    -- Executing [706@numberplan-cost-efficient:50005] Set("SIP/707-00000068", "LOCAL(mbx)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50006] Dial("SIP/707-00000068", "SIP/706,20") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/706
    -- SIP/706-00000069 is ringing
    -- SIP/706-00000069 answered SIP/707-00000068
    -- Channel SIP/707-00000068 joined 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
    -- Channel SIP/706-00000069 joined 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
       > 0x7f12c47f9510 -- Probation passed - setting RTP source address to 192.168.5.106:16460
    -- Channel IAX2/099129107-14595 left 'simple_bridge' basic-bridge <e86b058b-1ce1-42a9-9399-b2b3698672b6>
    -- Channel IAX2/099129107-14595 swapped with SIP/707-00000068 into 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
    -- Channel SIP/707-00000068 left 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
    -- Channel SIP/707-00000067 left 'simple_bridge' basic-bridge <e86b058b-1ce1-42a9-9399-b2b3698672b6>
    -- Stopped music on hold on IAX2/099129107-14595
  == Spawn extension (numberplan-cost-efficient, 706, 50006) exited non-zero on 'SIP/707-00000068'
    -- Channel SIP/706-00000069 left 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
    -- Channel IAX2/099129107-14595 left 'simple_bridge' basic-bridge <9eb9a516-095e-4662-a2b2-eaff6debcc16>
  == Spawn extension (default, 707, 50006) exited non-zero on 'IAX2/099129107-14595'
    -- Hungup 'IAX2/099129107-14595'

I expect this won’t be an issue with the RTP bridge itself, I think this will more likely be an issue with the switching of channels / types and the SIP messaging required to do this, along with my SIP / user configs… It’s just a little over my head at this point… HELP? Thank you.

PS; some other things I know:

  • My dial plan for extension dialling internally is completely excessive and could be trimmed…
  • It is not 2015 yet.
2

IAX doesn’t use RTP.

It sounds like the problem is with the re-invite back of the SIP device, so you need to use sip set debug on on the final destination device.

3

Hi David, thanks for your post.

Asterisk SVN-branch-13-r428169, Copyright (C) 1999 - 2014, Digium, Inc. and others.
Created by Mark Spencer <markster@digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'core show license' for details.
=========================================================================
Connected to Asterisk SVN-branch-13-r428169 currently running on asterisk-2015 (pid = 1295)
asterisk-2015*CLI> bridge technology unsuspend native_rtp 
Unsuspended bridge technology 'native_rtp'
asterisk-2015*CLI> sip set debug peer 706 
SIP Debugging Enabled for IP: 192.168.5.106
    -- Accepting AUTHENTICATED call from 27.111.14.68:4569:
    --        > requested format = alaw,
    --        > requested prefs = (alaw|g722|ulaw|g729|gsm),
    --        > actual format = ulaw,
    --        > host prefs = (ulaw|alaw|siren14|siren7|g722|slin16|slin|g726|g726aal2|adpcm|gsm|ilbc|speex|g729|speex16|testlaw|g719|opus|jpeg|png|h261...),
    --        > priority = mine
    -- Executing [099129107@from-099129107:1] Set("IAX2/099129107-14913", "CALLERID(number)=021624717") in new stack
    -- Executing [099129107@from-099129107:2] Goto("IAX2/099129107-14913", "default,707,1") in new stack
    -- Goto (default,707,1)
    -- Executing [707@default:1] Gosub("IAX2/099129107-14913", "707,stdexten(SIP/707)") in new stack
    -- Executing [707@default:50000] NoOp("IAX2/099129107-14913", "Start stdexten") in new stack
    -- Executing [707@default:50001] Answer("IAX2/099129107-14913", "") in new stack
    -- Executing [707@default:50002] Set("IAX2/099129107-14913", "LOCAL(ext)=707") in new stack
    -- Executing [707@default:50003] Set("IAX2/099129107-14913", "LOCAL(dev)=SIP/707") in new stack
    -- Executing [707@default:50004] Set("IAX2/099129107-14913", "LOCAL(cntx)=") in new stack
    -- Executing [707@default:50005] Set("IAX2/099129107-14913", "LOCAL(mbx)=707") in new stack
    -- Executing [707@default:50006] Dial("IAX2/099129107-14913", "SIP/707,20") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/707
    -- SIP/707-0000007a is ringing
    -- SIP/707-0000007a answered IAX2/099129107-14913
    -- Channel IAX2/099129107-14913 joined 'simple_bridge' basic-bridge <10776594-e661-4e5f-8d22-a4960552fe64>
    -- Channel SIP/707-0000007a joined 'simple_bridge' basic-bridge <10776594-e661-4e5f-8d22-a4960552fe64>
       > 0x7f12c4813b70 -- Probation passed - setting RTP source address to 192.168.5.107:16392
    -- Started music on hold, class 'default', on channel 'IAX2/099129107-14913'
  == Using SIP RTP CoS mark 5
    -- Executing [706@numberplan-IAX2-SetDDI:1] NoOp("SIP/707-0000007b", "callerid num is 707") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:2] GotoIf("SIP/707-0000007b", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:3] GotoIf("SIP/707-0000007b", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:4] GotoIf("SIP/707-0000007b", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:5] GotoIf("SIP/707-0000007b", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:6] GotoIf("SIP/707-0000007b", "0?yesDDI") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:7] GotoIf("SIP/707-0000007b", "1?yesDDI") in new stack
    -- Goto (numberplan-IAX2-SetDDI,706,17)
    -- Executing [706@numberplan-IAX2-SetDDI:17] Set("SIP/707-0000007b", "IAXCHAN=099129107") in new stack
    -- Executing [706@numberplan-IAX2-SetDDI:18] Goto("SIP/707-0000007b", "numberplan-cost-efficient,706,1") in new stack
    -- Goto (numberplan-cost-efficient,706,1)
    -- Executing [706@numberplan-cost-efficient:1] Gosub("SIP/707-0000007b", "706,stdexten(SIP/706)") in new stack
    -- Executing [706@numberplan-cost-efficient:50000] NoOp("SIP/707-0000007b", "Start stdexten") in new stack
    -- Executing [706@numberplan-cost-efficient:50001] Answer("SIP/707-0000007b", "") in new stack
       > 0x40e7750 -- Probation passed - setting RTP source address to 192.168.5.107:16394
    -- Executing [706@numberplan-cost-efficient:50002] Set("SIP/707-0000007b", "LOCAL(ext)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50003] Set("SIP/707-0000007b", "LOCAL(dev)=SIP/706") in new stack
    -- Executing [706@numberplan-cost-efficient:50004] Set("SIP/707-0000007b", "LOCAL(cntx)=") in new stack
    -- Executing [706@numberplan-cost-efficient:50005] Set("SIP/707-0000007b", "LOCAL(mbx)=706") in new stack
    -- Executing [706@numberplan-cost-efficient:50006] Dial("SIP/707-0000007b", "SIP/706,20") in new stack
  == Using SIP RTP CoS mark 5
Audio is at 16254
Adding codec ulaw to SDP
Adding codec gsm to SDP
Adding codec alaw to SDP
Adding codec g723 to SDP
Adding codec g726 to SDP
Adding codec g726aal2 to SDP
Adding codec adpcm to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec lpc10 to SDP
Adding codec g729 to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec ilbc to SDP
Adding codec g722 to SDP
Adding codec siren7 to SDP
Adding codec siren14 to SDP
Adding codec testlaw to SDP
Adding codec g719 to SDP
Adding codec opus to SDP
Adding codec none to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.5.106:5060:
INVITE sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK3fd52444
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX SVN-branch-13-r428169
Date: Sun, 30 Nov 2014 21:25:17 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 913

v=0
o=root 1534752810 1534752810 IN IP4 192.168.5.47
s=Asterisk PBX SVN-branch-13-r428169
c=IN IP4 192.168.5.47
t=0 0
m=audio 16254 RTP/AVP 0 3 8 4 111 112 5 10 118 7 18 110 117 119 97 9 102 115 116 107 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=no
a=rtpmap:111 G726-32/8000
a=rtpmap:112 AAL2-G726-32/8000
a=rtpmap:5 DVI4/8000
a=rtpmap:10 L16/8000
a=rtpmap:118 L16/16000
a=rtpmap:7 LPC/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:110 speex/8000
a=rtpmap:117 speex/16000
a=rtpmap:119 speex/32000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=0
a=rtpmap:9 G722/8000
a=rtpmap:102 G7221/16000
a=fmtp:102 bitrate=32000
a=rtpmap:115 G7221/32000
a=fmtp:115 bitrate=48000
a=rtpmap:116 G719/48000
a=fmtp:116 bitrate=64000
a=rtpmap:107 opus/48000/2
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:20
a=sendrecv

---
    -- Called SIP/706

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 100 Trying
To: <sip:706@192.168.5.106:5060>
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK3fd52444
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 180 Ringing
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK3fd52444
Contact: "Avi" <sip:706@192.168.5.106:5060>
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
sip_route_dump: route/path hop: <sip:706@192.168.5.106:5060>
    -- SIP/706-0000007c is ringing

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 200 OK
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK3fd52444
Contact: "Avi" <sip:706@192.168.5.106:5060>
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 212
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp

v=0
o=- 60880805 60880805 IN IP4 192.168.5.106
s=-
c=IN IP4 192.168.5.106
t=0 0
m=audio 16466 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv
<------------->
--- (12 headers 11 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format telephone-event for ID 101
failed to extend from 64 to 98
Capabilities: us - (gsm|ulaw|alaw|h263|g723|g726|g726aal2|adpcm|slin|slin|slin|), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.5.106:16466
sip_route_dump: route/path hop: <sip:706@192.168.5.106:5060>
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Transmitting (no NAT) to 192.168.5.106:5060:
ACK sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK141503e0
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX SVN-branch-13-r428169
Content-Length: 0


---
    -- SIP/706-0000007c answered SIP/707-0000007b
    -- Channel SIP/707-0000007b joined 'simple_bridge' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
    -- Channel SIP/706-0000007c joined 'simple_bridge' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
       > Bridge 0f3ce377-ce4b-4e24-a77e-0a4af7db9b81: switching from simple_bridge technology to native_rtp
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Audio is at 16254
Adding codec ulaw to SDP
Adding codec gsm to SDP
Adding codec alaw to SDP
Adding codec g723 to SDP
Adding codec g726 to SDP
Adding codec g726aal2 to SDP
Adding codec adpcm to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec lpc10 to SDP
Adding codec g729 to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec ilbc to SDP
Adding codec g722 to SDP
Adding codec siren7 to SDP
Adding codec siren14 to SDP
Adding codec testlaw to SDP
Adding codec g719 to SDP
Adding codec opus to SDP
Adding codec none to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.5.106:5060:
INVITE sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK741a7463
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 103 INVITE
User-Agent: Asterisk PBX SVN-branch-13-r428169
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 915

v=0
o=root 1534752810 1534752811 IN IP4 192.168.5.107
s=Asterisk PBX SVN-branch-13-r428169
c=IN IP4 192.168.5.107
t=0 0
m=audio 16394 RTP/AVP 0 3 8 4 111 112 5 10 118 7 18 110 117 119 97 9 102 115 116 107 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=no
a=rtpmap:111 G726-32/8000
a=rtpmap:112 AAL2-G726-32/8000
a=rtpmap:5 DVI4/8000
a=rtpmap:10 L16/8000
a=rtpmap:118 L16/16000
a=rtpmap:7 LPC/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:110 speex/8000
a=rtpmap:117 speex/16000
a=rtpmap:119 speex/32000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=0
a=rtpmap:9 G722/8000
a=rtpmap:102 G7221/16000
a=fmtp:102 bitrate=32000
a=rtpmap:115 G7221/32000
a=fmtp:115 bitrate=48000
a=rtpmap:116 G719/48000
a=fmtp:116 bitrate=64000
a=rtpmap:107 opus/48000/2
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:20
a=sendrecv

---

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 200 OK
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 103 INVITE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK741a7463
Contact: "Avi" <sip:706@192.168.5.106:5060>
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 212
Content-Type: application/sdp

v=0
o=- 60880805 60880806 IN IP4 192.168.5.106
s=-
c=IN IP4 192.168.5.106
t=0 0
m=audio 16466 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv
<------------->
--- (10 headers 11 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format telephone-event for ID 101
failed to extend from 64 to 98
Capabilities: us - (gsm|ulaw|alaw|h263|g723|g726|g726aal2|adpcm|slin|slin|slin|), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.5.106:16466
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Transmitting (no NAT) to 192.168.5.106:5060:
ACK sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK5c5d9fcc
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 103 ACK
User-Agent: Asterisk PBX SVN-branch-13-r428169
Content-Length: 0


---
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Audio is at 16254
Adding codec ulaw to SDP
Adding codec gsm to SDP
Adding codec alaw to SDP
Adding codec g723 to SDP
Adding codec g726 to SDP
Adding codec g726aal2 to SDP
Adding codec adpcm to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec slin to SDP
Adding codec lpc10 to SDP
Adding codec g729 to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec speex to SDP
Adding codec ilbc to SDP
Adding codec g722 to SDP
Adding codec siren7 to SDP
Adding codec siren14 to SDP
Adding codec testlaw to SDP
Adding codec g719 to SDP
Adding codec opus to SDP
Adding codec none to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.5.106:5060:
INVITE sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK7278ded2
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 104 INVITE
User-Agent: Asterisk PBX SVN-branch-13-r428169
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 915

v=0
o=root 1534752810 1534752812 IN IP4 192.168.5.107
s=Asterisk PBX SVN-branch-13-r428169
c=IN IP4 192.168.5.107
t=0 0
m=audio 16394 RTP/AVP 0 3 8 4 111 112 5 10 118 7 18 110 117 119 97 9 102 115 116 107 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=no
a=rtpmap:111 G726-32/8000
a=rtpmap:112 AAL2-G726-32/8000
a=rtpmap:5 DVI4/8000
a=rtpmap:10 L16/8000
a=rtpmap:118 L16/16000
a=rtpmap:7 LPC/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:110 speex/8000
a=rtpmap:117 speex/16000
a=rtpmap:119 speex/32000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=0
a=rtpmap:9 G722/8000
a=rtpmap:102 G7221/16000
a=fmtp:102 bitrate=32000
a=rtpmap:115 G7221/32000
a=fmtp:115 bitrate=48000
a=rtpmap:116 G719/48000
a=fmtp:116 bitrate=64000
a=rtpmap:107 opus/48000/2
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:20
a=sendrecv

---

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 200 OK
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 104 INVITE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK7278ded2
Contact: "Avi" <sip:706@192.168.5.106:5060>
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 212
Content-Type: application/sdp

v=0
o=- 60880805 60880807 IN IP4 192.168.5.106
s=-
c=IN IP4 192.168.5.106
t=0 0
m=audio 16466 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv
<------------->
--- (10 headers 11 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format telephone-event for ID 101
failed to extend from 64 to 98
Capabilities: us - (gsm|ulaw|alaw|h263|g723|g726|g726aal2|adpcm|slin|slin|slin|), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.5.106:16466
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Transmitting (no NAT) to 192.168.5.106:5060:
ACK sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK72e5362a
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Contact: <sip:707@192.168.5.47:5060>
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 104 ACK
User-Agent: Asterisk PBX SVN-branch-13-r428169
Content-Length: 0


---
    -- Channel IAX2/099129107-14913 left 'simple_bridge' basic-bridge <10776594-e661-4e5f-8d22-a4960552fe64>
    -- Channel IAX2/099129107-14913 swapped with SIP/707-0000007b into 'native_rtp' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
    -- Channel SIP/707-0000007b left 'native_rtp' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
       > Bridge 0f3ce377-ce4b-4e24-a77e-0a4af7db9b81: switching from native_rtp technology to simple_bridge
    -- Channel SIP/707-0000007a left 'simple_bridge' basic-bridge <10776594-e661-4e5f-8d22-a4960552fe64>
    -- Stopped music on hold on IAX2/099129107-14913
  == Spawn extension (numberplan-cost-efficient, 706, 50006) exited non-zero on 'SIP/707-0000007b'
    -- Channel IAX2/099129107-14913 left 'simple_bridge' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
  == Spawn extension (default, 707, 50006) exited non-zero on 'IAX2/099129107-14913'
    -- Hungup 'IAX2/099129107-14913'
    -- Channel SIP/706-0000007c left 'simple_bridge' basic-bridge <0f3ce377-ce4b-4e24-a77e-0a4af7db9b81>
Scheduling destruction of SIP dialog '22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060' in 32000 ms (Method: INVITE)
set_destination: Parsing <sip:706@192.168.5.106:5060> for address/port to send to
set_destination: set destination to 192.168.5.106:5060
Reliably Transmitting (no NAT) to 192.168.5.106:5060:
BYE sip:706@192.168.5.106:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK0bddb701
Max-Forwards: 70
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 105 BYE
User-Agent: Asterisk PBX SVN-branch-13-r428169
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---

<--- SIP read from UDP:192.168.5.106:5060 --->
SIP/2.0 200 OK
To: <sip:706@192.168.5.106:5060>;tag=b156cae5542cd483i0
From: "Chris" <sip:707@192.168.5.47>;tag=as5b16daa2
Call-ID: 22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060
CSeq: 105 BYE
Via: SIP/2.0/UDP 192.168.5.47:5060;branch=z9hG4bK0bddb701
Server: Linksys/SPA942-6.1.5(a)
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
Really destroying SIP dialog '22cab2456d7da2c75122d3f20d5d9e1c@192.168.5.47:5060' Method: INVITE
asterisk-2015*CLI>

I noticed an issue here (failed to extend from 64 to 98) which appears to be covered in a very recent bug track report (and fix) in the current asterisk build: https://reviewboard.asterisk.org/r/4204/ - this may not be the cause of the failure on our system though? I’d very much appreciate a review of the above and some further pointers if anyone has any please?

Thank you.

4

For the information of others who might follow / find this thread in future, I could not find an elegant way to suspend native_rtp bridge types via config, only via the CLI. - I may have missed something.

While I do not think that this is the final, appropriate long term solution, I need to apply this as a ‘sticky’ work-around in the mean time. I couldn’t find explicit enough docco on the #exec command to know when it might execute that type of command from within the config files, and wondered where I should put something like that to run within them, it would have needed to run once, after successful asterisk service start-up.

Through nothing more than ignorance then, I have decided that the simplest method of applying the ‘bridge technology suspend native_rtp’ CLI command is to get a cron job to do this via the OS’ shell every 30 mins (this is needed just in case of a reboot of the server for what-ever reason). At least having done this, the effect of this not being applied post-reboot will not be long-lasting: I’ve added two lines to my scheduled jobs, making use of the -x param for asterisk:

[code]
Inside the editor using: crontab -e

0 * * * * /usr/sbin/asterisk -x "bridge technology suspend native_rtp"
30 * * * * /usr/sbin/asterisk -x “bridge technology suspend native_rtp”[/code]

5

Assuming the trace is complete, that looks like a bug to me. It is logging that it is exiting the native bridge, but not sending the SDP updates needed to actually do that.

If this is the most recent minor version of 13, I would raise a bug on issues.asterisk.org.

6

Thanks David for your help. That was a complete trace, there was nothing removed from it at all.

Being new to the forums etc I’m a little hesitant to think that I would be able to successfully log an issue in sufficient detail but I’ll give it a go tomorrow.

Thanks again for your help. It’s nice to think I wasn’t being a complete womble.

7

Please cross link the bug report, and this thread, in both directions.

8

The historic way was directmedia=no (the "pre-"historic way was canreinvite=no). I assume it is still valid in version 13.

9

We are running the first build of 13: 13.0.0 - r428169 - From my SVN codebase searches of the releases, it appears that there was a release 13.0.1: r428504 some 10 days ago.

Before I’m happy to report this as a bug, I’d want to re-test it with the latest minor version. I’ve asked for help snapshotting our production image, duplicating then running up a test version which we can patch before I’ll report this… The release notes do not appear to have addressed this, but I don’t want to waste anyone’s time.

Thanks for your help.

10

We’ve duplicated our running image, then upgraded it to v13.0.1 I can confirm in our environment it has continued to behave exactly as we had observed before. We have taken fresh traces of the CLI with the SIP debug, with both the native_rtp suspended and active and have comparative CLI and debug traces for both the working and failing useless respectively.

I will try to log this with the issue tracker later on today.

Thanks again for the guidance.

11

Issue logged: https://issues.asterisk.org/jira/browse/ASTERISK-24585