[asterisk-bugs] [JIRA] (ASTERISK-27239) PJSIP losing RTP connection (no more audio)
Frederic Steinfels (JIRA)
noreply at issues.asterisk.org
Sat Sep 2 02:30:09 CDT 2017
[ https://issues.asterisk.org/jira/browse/ASTERISK-27239?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Frederic Steinfels updated ASTERISK-27239:
------------------------------------------
Comment: was deleted
(was: please provide me with wireshark etc options.
here is the complete debug:
Executing [xxx at internal:1] Set("SCCP/Frederic-0000018B", "CALLEDNUM=xxx") in new stack
-- Executing [xxx at internal:2] Goto("SCCP/Frederic-0000018B", "outbound,s,1") in new stack
-- Goto (outbound,s,1)
-- Executing [s at outbound:1] Gosub("SCCP/Frederic-0000018B", "macro-lookup-local,s,1(xxx,SEP001F9EAC4817,)") in new stack
-- Executing [s at macro-lookup-local:1] GotoIf("SCCP/Frederic-0000018B", "0?5:2") in new stack
-- Goto (macro-lookup-local,s,2)
-- Executing [s at macro-lookup-local:2] AGI("SCCP/Frederic-0000018B", "lookupnumberlocal.agi,SEP001F9EAC4817,xxx") in new stack
-- Launched AGI Script /usr/share/asterisk/agi-bin/lookupnumberlocal.agi
-- <SCCP/Frederic-0000018B>AGI Script lookupnumberlocal.agi completed, returning 0
-- Executing [s at macro-lookup-local:3] NoOp("SCCP/Frederic-0000018B", "Name found ") in new stack
-- Executing [s at macro-lookup-local:4] GotoIf("SCCP/Frederic-0000018B", "1?5:8") in new stack
-- Goto (macro-lookup-local,s,5)
-- Executing [s at macro-lookup-local:5] GotoIf("SCCP/Frederic-0000018B", "1?8:6") in new stack
-- Goto (macro-lookup-local,s,8)
-- Executing [s at macro-lookup-local:8] Return("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outbound:2] GotoIf("SCCP/Frederic-0000018B", "1?3:10") in new stack
-- Goto (outbound,s,3)
-- Executing [s at outbound:3] GotoIf("SCCP/Frederic-0000018B", "1?outboundfst,s,1:4") in new stack
-- Goto (outboundfst,s,1)
-- Executing [s at outboundfst:1] NoOp("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outboundfst:2] NoOp("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outboundfst:3] GotoIf("SCCP/Frederic-0000018B", "1?4:6") in new stack
-- Goto (outboundfst,s,4)
-- Executing [s at outboundfst:4] Gosub("SCCP/Frederic-0000018B", "macro-lookup-global,s,1(xxx)") in new stack
-- Executing [s at macro-lookup-global:2] MYSQL("SCCP/Frederic-0000018B", "Query resultid 1 SET NAMES 'utf8'") in new stack
-- Executing [s at macro-lookup-global:3] MYSQL("SCCP/Frederic-0000018B", "Clear ") in new stack
[Sep 1 16:45:16] WARNING[29528][C-00000019]: app_mysql.c:203 find_identifier: Identifier 0, identifier_type 2 not found in identifier list
[Sep 1 16:45:16] WARNING[29528][C-00000019]: app_mysql.c:534 aMYSQL_clear: Invalid result identifier 0 passed in aMYSQL_clear
-- Executing [s at macro-lookup-global:4] MYSQL("SCCP/Frederic-0000018B", "Query resultid 1 SELECT INTPHONENUM('xxx')") in new stack
-- Executing [s at macro-lookup-global:5] MYSQL("SCCP/Frederic-0000018B", "Fetch fetchid 2 CIDNUM") in new stack
-- Executing [s at macro-lookup-global:6] MYSQL("SCCP/Frederic-0000018B", "Clear 2") in new stack
-- Executing [s at macro-lookup-global:7] MYSQL("SCCP/Frederic-0000018B", "Query resultid 1 SELECT IF(`company`<>'',`company`,CONCAT(`fname`,' ',`lname`)) AS n FROM `userdb` WHERE (`phone_day`<>'' AND `phone_day`='+xxx') OR (`phone_night`<>'' AND `phone_night`='+xxx') LIMIT 1") in new stack
-- Executing [s at macro-lookup-global:8] MYSQL("SCCP/Frederic-0000018B", "Fetch fetchid 2 CIDNAME") in new stack
-- Executing [s at macro-lookup-global:9] MYSQL("SCCP/Frederic-0000018B", "Clear 2") in new stack
-- Executing [s at macro-lookup-global:10] MYSQL("SCCP/Frederic-0000018B", "Disconnect 1") in new stack
-- Executing [s at macro-lookup-global:11] GotoIf("SCCP/Frederic-0000018B", "0?12:13") in new stack
-- Goto (macro-lookup-global,s,13)
-- Executing [s at macro-lookup-global:13] NoOp("SCCP/Frederic-0000018B", "SITRAC") in new stack
-- Executing [s at macro-lookup-global:14] Return("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outboundfst:5] Macro("SCCP/Frederic-0000018B", "jabber-outbound") in new stack
-- Executing [s at macro-jabber-outbound:1] GotoIf("SCCP/Frederic-0000018B", "0?2:4") in new stack
-- Goto (macro-jabber-outbound,s,4)
-- Executing [s at macro-jabber-outbound:4] NoOp("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at macro-jabber-outbound:5] JabberSend("SCCP/Frederic-0000018B", "asterisk,www at highdefinition.ch,Outgoing call from 22 to ") in new stack
-- Executing [s at macro-jabber-outbound:6] NoOp("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outboundfst:6] Set("SCCP/Frederic-0000018B", "CHANNEL(musicclass)=default") in new stack
-- Executing [s at outboundfst:7] Macro("SCCP/Frederic-0000018B", "record-enable") in new stack
-- Executing [s at macro-record-enable:1] NoOp("SCCP/Frederic-0000018B", "Called xxxcallerid 22") in new stack
-- Executing [s at macro-record-enable:2] Set("SCCP/Frederic-0000018B", "MONITORFILE=20170901-164516-22-xxx.wav") in new stack
-- Executing [s at macro-record-enable:3] MixMonitor("SCCP/Frederic-0000018B", "20170901-164516-22-xxx.wav") in new stack
== Begin MixMonitor Recording SCCP/Frederic-0000018B
-- Executing [s at macro-record-enable:4] NoOp("SCCP/Frederic-0000018B", "") in new stack
-- Executing [s at outboundfst:8] Set("SCCP/Frederic-0000018B", "TRANSFER_CONTEXT=transfering") in new stack
-- Executing [s at outboundfst:9] Set("SCCP/Frederic-0000018B", "CALLERID(name)=highdefinition.ch") in new stack
-- Executing [s at outboundfst:10] Set("SCCP/Frederic-0000018B", "CONNECTEDLINE(name,i)=xxx") in new stack
-- Executing [s at outboundfst:11] Set("SCCP/Frederic-0000018B", "CONNECTEDLINE(number)=xxx") in new stack
-- Executing [s at outboundfst:12] Set("SCCP/Frederic-0000018B", "CONNECTEDLINE(name-pres,i)=allowed") in new stack
-- Executing [s at outboundfst:13] Set("SCCP/Frederic-0000018B", "CALLERID(num)=+41435440808") in new stack
-- Executing [s at outboundfst:14] Dial("SCCP/Frederic-0000018B", "PJSIP/xxx at swisscomTestTrunk,180,gIT") in new stack
-- Called PJSIP/xxx at swisscomTestTrunk
-- Connected line update to SCCP/Frederic-0000018B prevented.
<--- Transmitting SIP request (925 bytes) to UDP:192.168.99.19:5060 --->
INVITE sip:xxx at 192.168.99.19 SIP/2.0
Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPj0498641c-1b92-4ab1-96a2-8b36b6ec48b2
From: "highdefinition.ch" <sip:+41435440808 at 192.168.99.10>;tag=3dd25027-f7f7-44f4-adda-1abdf350ac17
To: <sip:xxx at 192.168.99.19>
Contact: <sip:asterisk at 192.168.99.10:5060>
Call-ID: 13a094af-dd24-4417-8a95-4b9a9eac8e37
CSeq: 2819 INVITE
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE
Supported: 100rel, replaces, norefersub
Max-Forwards: 70
User-Agent: Asterisk PBX
Content-Type: application/sdp
Content-Length: 285
v=0
o=- 121103717 121103717 IN IP4 192.168.99.10
s=Asterisk
c=IN IP4 192.168.99.10
t=0 0
m=audio 12662 RTP/AVP 9 8 0 101
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv
<--- Received SIP response (450 bytes) from UDP:192.168.99.19:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPj0498641c-1b92-4ab1-96a2-8b36b6ec48b2
From: "highdefinition.ch" <sip:+41435440808 at 192.168.99.10>;tag=3dd25027-f7f7-44f4-adda-1abdf350ac17
To: <sip:xxx at 192.168.99.19>
Date: Fri, 01 Sep 2017 14:45:16 GMT
Call-ID: 13a094af-dd24-4417-8a95-4b9a9eac8e37
CSeq: 2819 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-15.5.2.16.T
Content-Length: 0
<--- Received SIP response (1025 bytes) from UDP:192.168.99.19:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPj0498641c-1b92-4ab1-96a2-8b36b6ec48b2
From: "highdefinition.ch" <sip:+41435440808 at 192.168.99.10>;tag=3dd25027-f7f7-44f4-adda-1abdf350ac17
To: <sip:xxx at 192.168.99.19>;tag=52254C34-18CD
Date: Fri, 01 Sep 2017 14:45:16 GMT
Call-ID: 13a094af-dd24-4417-8a95-4b9a9eac8e37
CSeq: 2819 INVITE
Require: 100rel
RSeq: 1975
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Contact: <sip:xxx at 192.168.99.19:5060>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-15.5.2.16.T
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 271
v=0
o=CiscoSystemsSIP-GW-UserAgent 2899 4114 IN IP4 192.168.99.19
s=SIP Call
c=IN IP4 192.168.99.19
t=0 0
m=audio 25596 RTP/AVP 9 101
c=IN IP4 192.168.99.19
a=rtpmap:9 G722/8000
a=fmtp:9 bitrate=64
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
<--- Transmitting SIP request (455 bytes) to UDP:192.168.99.19:5060 --->
PRACK sip:xxx at 192.168.99.19:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPjba3dd3dd-6080-4cc7-80f1-d264ab5c0516
From: "highdefinition.ch" <sip:+41435440808 at 192.168.99.10>;tag=3dd25027-f7f7-44f4-adda-1abdf350ac17
To: <sip:xxx at 192.168.99.19>;tag=52254C34-18CD
Call-ID: 13a094af-dd24-4417-8a95-4b9a9eac8e37
CSeq: 2820 PRACK
RAck: 1975 2819 INVITE
Max-Forwards: 70
User-Agent: Asterisk PBX
Content-Length: 0
-- PJSIP/swisscomTestTrunk-00000120 is making progress passing it to SCCP/Frederic-0000018B
== Using SCCP RTP TOS bits 184
== Using SCCP RTP CoS mark 6
<--- Received SIP response (432 bytes) from UDP:192.168.99.19:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPjba3dd3dd-6080-4cc7-80f1-d264ab5c0516
From: "highdefinition.ch" <sip:+41435440808 at 192.168.99.10>;tag=3dd25027-f7f7-44f4-adda-1abdf350ac17
To: <sip:xxx at 192.168.99.19>;tag=52254C34-18CD
Date: Fri, 01 Sep 2017 14:45:18 GMT
Call-ID: 13a094af-dd24-4417-8a95-4b9a9eac8e37
Server: Cisco-SIPGateway/IOS-15.5.2.16.T
CSeq: 2820 PRACK
Content-Length: 0
> 0x7febd0013300 -- Probation passed - setting RTP source address to 192.168.99.166:22750
> 0x7febc40008c0 -- Probation passed - setting RTP source address to 192.168.99.19:25596
-- Remote UNIX connection
-- Remote UNIX connection disconnected
-- Remote UNIX connection
-- Remote UNIX connection disconnected
)
> PJSIP losing RTP connection (no more audio)
> -------------------------------------------
>
> Key: ASTERISK-27239
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-27239
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Channels/chan_pjsip
> Affects Versions: 13.17.1, 14.6.1, 15.0.0-beta1
> Environment: independent
> Reporter: Frederic Steinfels
> Assignee: Frederic Steinfels
> Severity: Minor
> Attachments: log.txt
>
>
> Using PJSIP together with the biggest telecom provider in Switzerland, Swisscom, in conjunction with there "Smart Business Connect Trunk" solution, there is a scenario resulting in losing the audio connection.
> First, the call is initiated and RTP packets are exchanged (code alaw). After a few seconds, the call is diverted for some reason and Swisscom is changing to g722. At this point, PJSIP or asterisk will not reinitiate the RTP connection as it is supposed to.
> If a call is picked up normally, swisscom knows the correct codec from the beginning so there is no codec change after ringing. That works perfectly. However if the call is diverted to an answering machine or another party that requires a different codec, the problem occurs. When I am talking about diversion, I mean diversion + call pickup using a different codec.
> I have complained at Swisscom, they are telling me its my (asterisks) fault. Their response was (translated to english):
> In the worst case, BTN is starting 17:13: RTP. As soon as the ringing is sent, the MS is turned on and is playing the ringing. As soon as the BTN is taking the call, the P4_eMRS_NNI2 is starting the RTP towards the ATN and is reinitiating it. However, the ATN is only starting the RTP but not reinitiating it.
> ATN propably means Party A or calling party, ie me.
> BTN probably means Party B or called party.
> If there is a diversion without a change of codec, the audio is not lost.
> If the call is initiated with g722 from the beginning, the audio is available.
> I can not force Swisscom to only use g722 to avoid the problem. If I do so, the call can not be initiated.
> If you want to try this, please PM me to so I can give you a phone number that behaves this way.
> Here are some logs:
> -- Executing [s at outboundfst:14] Dial("SCCP/Frederic-000006DE", "PJSIP/xxxx at swisscomTestTrunk,180,gIT") in new stack
> -- Called PJSIP/xxxx at swisscomTestTrunk
> -- Connected line update to SCCP/Frederic-000006DE prevented.
> -- PJSIP/swisscomTestTrunk-000003ea is making progress passing it to SCCP/Frederic-000006DE
> == Using SCCP RTP TOS bits 184
> == Using SCCP RTP CoS mark 6
> > 0x7f2150013300 -- Probation passed - setting RTP source address to 192.168.99.166:27936
> RTP Packets are flowing (192.168.99.19 is swisscom):
> Sent RTP packet to 192.168.99.19:24496 (type 09, seq 006312, ts 1155988568, len 000160)
> Got RTP packet from 192.168.99.19:24496 (type 09, seq 028521, ts 3235640619, len 000160)
> at the time of the diversion, this happens:
> -- PJSIP/swisscomTestTrunk-000003ea requested media update control 26, passing it to SCCP/Frederic-000006DE
> -- PJSIP/swisscomTestTrunk-000003ea answered SCCP/Frederic-000006DE
> -- SEP001F9EAC4817: (sccp_pbx_answer) Outgoing call SCCP/Frederic-000006DE has been answered by remote party
> -- Channel PJSIP/swisscomTestTrunk-000003ea joined 'simple_bridge' basic-bridge <64e1db67-f435-4393-a360-05e59ef59887>
> -- Channel SCCP/Frederic-000006DE joined 'simple_bridge' basic-bridge <64e1db67-f435-4393-a360-05e59ef59887>
> From this point, there are no further "Got RTP packet from" messages from the corresponding IP.
> It does not matter, if the call is made from a PJSIP or SCCP device (tried both).
> The corresponding SIP headers in case of the diversion and codec change:
> -- PJSIP/swisscomTestTrunk-0000000d requested media update control 26, passing it to SCCP/Frederic-0000001E
> <--- Received SIP response (1022 bytes) from UDP:192.168.99.19:5060 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPjf91cf3c1-f62b-44bb-b336-c7556481f67f
> From: "xxx.ch" <sip:+41435440808 at 192.168.99.10>;tag=db836e4b-0a44-4a95-ad4e-93a8d885393c
> To: <sip:xxxx at 192.168.99.19>;tag=D590A070-1660
> Date: Tue, 08 Aug 2017 10:04:31 GMT
> Call-ID: 329cc7ac-938a-40a5-87d4-17733d86220a
> CSeq: 12944 INVITE
> Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
> Allow-Events: telephone-event
> Contact: <sip:xxxx at 192.168.99.19:5060>
> Supported: replaces
> Supported: sdp-anat
> Server: Cisco-SIPGateway/IOS-15.5.2.16.T
> Supported: timer
> Content-Type: application/sdp
> Content-Disposition: session;handling=required
> Content-Length: 271
> v=0
> o=CiscoSystemsSIP-GW-UserAgent 1121 8511 IN IP4 192.168.99.19
> s=SIP Call
> c=IN IP4 192.168.99.19
> t=0 0
> m=audio 21872 RTP/AVP 9 101
> c=IN IP4 192.168.99.19
> a=rtpmap:9 G722/8000
> a=fmtp:9 bitrate=64
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> <--- Transmitting SIP request (428 bytes) to UDP:192.168.99.19:5060 --->
> ACK sip:xxxx at 192.168.99.19:5060 SIP/2.0
> Via: SIP/2.0/UDP 192.168.99.10:5060;rport;branch=z9hG4bKPj3335f178-728b-47a0-b3ae-a187da37fb92
> From: "xxx.ch" <sip:+41435440808 at 192.168.99.10>;tag=db836e4b-0a44-4a95-ad4e-93a8d885393c
> To: <sip:xxxx at 192.168.99.19>;tag=D590A070-1660
> Call-ID: 329cc7ac-938a-40a5-87d4-17733d86220a
> CSeq: 12944 ACK
> Max-Forwards: 70
> User-Agent: Asterisk PBX
> Content-Length: 0
> The difference is:
> g722:
> a=rtpmap:9 G722/8000
> a=fmtp:9 bitrate=64
> not g722:
> a=rtpmap:8 PCMA/8000
> As I said before, if the codec remains g711, no problem. If changed to g722, the call will fail.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list