[asterisk-bugs] [JIRA] (ASTERISK-29030) res_rtp_asterisk: Additional RTP-frame (with wrong SSRC) gets inserted when switching from progress to established

Wed Aug 19 04:23:43 CDT 2020

    [ https://issues.asterisk.org/jira/browse/ASTERISK-29030?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=251698#comment-251698 ] 

Matthias Hensler edited comment on ASTERISK-29030 at 8/19/20 4:21 AM:
----------------------------------------------------------------------

Well, reversing the patch for ASTERISK-28773 did something unexpected. The "additional" RTP-frame is still there, and its sequence number is still matching the previous stream of the inband-ringing. However, the SSRC does not longer match the new RTP-stream of the established call (so the patch for ASTERISK-28773 is at least related), but is now a complete different SSRC which does not match any other SSRC of the call.

Could it be, that Asterisk tries to mux one RTP-frame from the established call into the stream with the inband-ringing (therefore using the sequence numbers from that stream), but in parallel creating the new stream? If you carefully check how the sequencenumbers on the traces above a created, you see that all frames starting with sequence 6754 and timestamp of 160 in 60350068.pcap are copied 1:1 in 60350082.pcap (only that 6754 gets the mark in that trace), while the frame with 6743 and timestamp of 0 in 60350068.pcap is copied without mark and the SSRC from the inband-ringing in 60350082.pcap.

In our new traces (which I will upload now) that first frame is copied with a completely different SSRC and is completely unrelated to any of the other frames. I am thinking that I saw this issue earlier, but did not investigate, as it did not cause any trouble. But my suspicion is, that this strange behaviour of Swyx is causing some strange timing issues on the asterisk, which just surfaced with patch ASTERISK-28773, as now a previous unrelated RTP-frame suddenly gets a SSRC from an related RTP-stream and causing hickups because of the timejump this frame creates.

was (Author: cubbi):
Well, reversing the patch for ASTERISK-28773 did something unexpected. The "additional" RTP-frame is still there, and its sequence number is still matching the previous stream of the inband-ringing. However, the SSRC does not longer match the new RTP-stream of the established call (so the patch for ASTERISK-28773 is at least related), but is now a complete different SSRC which does not match any other SSRC of the call.

Could it be, that Asterisk tries to mux one RTP-frame from the established call into the stream with the inband-ringing (therefore using the sequence numbers from that stream), but in parallel creating the new stream? If you carefully check how the sequencenumbers on the traces above a created, you see that all frames starting with sequence 6754 and timestamp of 160 in 60350068.pcap are copied 1:1 in 60350082.pcap (only that 6754 gets the mark in that trace), while the frame with 6743 and timestamp of 0 in 60350068.pcap is copied without mark and the SSRC from the inband-ringing in 60350082.pcap.

In our new traces (which I will upload now) that first frame is copied with a completley different SSRC and is completley unrelated to any of the other frames. I am thinking that I saw this issue earlier, but did not investigate, as it did not cause any trouble. But my suspicion is, that this strange behaviour of Swyx is causing some strange timing issues on the asterisk, which just surfaced with patch ASTERISK-28773, as now a previous unrelated RTP-frame suddenly gets a SSRC from an related RTP-stream and causing hickups because of the timejump this frame creates.

> res_rtp_asterisk: Additional RTP-frame (with wrong SSRC) gets inserted when switching from progress to established
> ------------------------------------------------------------------------------------------------------------------
>
>                 Key: ASTERISK-29030
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29030
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Channels/chan_sip/General, Resources/res_rtp_asterisk
>    Affects Versions: 16.10.0, 16.11.0, 16.12.0
>         Environment: CentOS 7
>            Reporter: Matthias Hensler
>            Assignee: Unassigned
>            Severity: Minor
>         Attachments: 60350068.pcap, 60350082.pcap, 60408587.pcap, 64008592.pcap, debug_all2.txt
>
>
> Hi there,
> we have a strange problem in which a broken RTP-frame (old sequence-number but
> new ssrc) is sent in the moment a call gets established after its progress
> phase.
> In that scenario we are receiving calls from our upstream provider (via
> TELES-SBC) and forwarding them to a customer. Both calllegs are provided via
> chan_sip and use G711a as voicecodec. A ringtone is provided via
> progressinband currently (I want to switch that off, as this is at least
> part of the problem).
> Before I add the details I have to emphasize, that only calls to one specific
> customer show the problem, and no other calls which are distributed in exact the
> same way. So far, after checking numerous traces, I have no clue what so ever
> about which difference in the setup for this one customer is, that leads to
> this issue.
> Via upstream this bug is causing the Teles to drop all audioframes after
> receiving that broken RTP frame.
> It might (and I cannot really confirm this at this moment) that the bug was
> introduced with Asterisk 16.10.0, as the first problem report was shortly after we
> updated from 16.9.0. So far we already updated to 16.11.0 and 16.12.0 which
> all show the same issue (however the problem is so obscure that it took us
> really long to figure the rootcause for the customers problem).
> As such I can say with confidence that the problem is present in versions
> 16.10.0, 16.11.0 and 16.12.0, while 16.9.0 could be ok. To make matters
> complicated in pointing to a specific version is, that the customer also did
> several updates of his software in the meantime, so it might be difficult to
> rollback to the specific version in which everything was ok.
> I am not sure on how to proceed here, to find the point in where Asterisk gets
> mixed up in the RTP flow, so I am hoping you have either a clue where the
> issue might come from or on how to debug (and of course fix it).
> This Asterisk installation processes several 10000 calls a day, with >200 calls
> in parallel, but as said only one client triggers that issue, while all other
> clients are fine.
> OK, up to the setup and configuration (I "XXX"ed some values):
> Our "sip.conf" looks like this:
> {noformat}
> [general]
> context=inbound_mapping
> allowoverlap=no
> realm=XXX
> bindport=5060
> language=de
> canreinvite=no
> alwaysauthreject=yes
> allowguest=no
> bindaddr=::
> tcpenable=yes
> tcpbindaddr=::
> tlsenable=yes
> tlsbindaddr=::
> tlscertfile=/etc/asterisk/certificate.pem
> tlscipher=HIGH:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!MD5:!PSK
> tlsclientmethod=tlsv1
> transport=udp,tls
> srvlookup=no
> allowsubscribe=no
> disallow=all
> allow=g722
> allow=alaw
> t38pt_udptl=yes,redundancy,maxdatagram=400
> progressinband=yes
> prematuremedia=no
> sendrpid=yes
> trustrpid=no
> send_diversion=no
> allowtransfer=no
> tos_sip=cs3
> tos_audio=ef
> [our_inbound]
> type=peer
> host=XXX.XXX.XXX.XXX
> qualify=yes
> context=inbound_provider
> disallow=all
> allow=g722
> allow=alaw
> [iads](!)
> type=friend
> context=iads_unregistered
> dtmfmode=auto
> host=dynamic
> amaflags=documentation
> canreinvite=no
> ignoresdpversion=yes
> [the_customer](iads)
> type=friend
> accountcode=0049XXXX
> setvar=NOTRUF_UUI=002DXXXXXXX
> secret=XXXXX
> context=iads_registered
> acl=public
> {noformat}
> The interesting part of our "extensions.conf" looks like this:
> {noformat}
> [inbound_provider]
> exten => _+X.,1,Goto(00${EXTEN:1},1)
> exten => _X.,1,Noop(Inboundcall XXX)
> exten => _X.,n,GotoIf($[${DIALPLAN_EXISTS(routing_intern,${EXTEN},1)} = 1]?DoRouting:)
> exten => _X.,n,Noop(Zielnummer ${EXTEN} existiert nicht)
> exten => _X.,n,Hangup(1)
> exten => _X.,n(DoRouting),Goto(routing_intern,${EXTEN},1)
> [routing_intern]
> include => inbound_mapping
> [inbound_mapping]
> exten => _0049XXX!,1,Set(Peerstring="SIP/the_customer")
> exten => _0049XXX!,n(DoMapping),Gosub(gosub-do_mapping,${EXTEN},1(${Peerstring},3,0049,,0049XXX,XXX,XXX,XXX,XX))
> [gosub-do_mapping]
> exten => _00Z.,1,Noop(Mapping)
> exten => _00Z.,n,Set(DIAL_ARGS=)
> exten => _00Z.,n,Set(CallTimeout=180)
> exten => _00Z.,n,Dial(${ARG1},${CallTimeout},${DIAL_ARGS})
> {noformat}
> So in short: an inbound call from "our_inbound" is signaled to
> "Dial(SIP/our_customer,180,)". All stuff inbetween is just for checking
> channellimits, billing, redirections, etc. and should not be important for
> this issue.
> In the following I will present the SIP-traces and RTP-packets of a broken
> call. In that I switched the ip-address of "our_inbound" to 1.1.1.1, the
> ip-address of the Asteriskserver to 2.2.2.2 and the ip-address of the client
> "the_customer" to 3.3.3.3. (For our reference the pcap-trace for LAG 1 which
> is 1.1.1.1 <-> 2.2.2.2 has the id 60155926 and the trace for LAG 2 which is
> 2.2.2.2 <-> 3.3.3.3 has the id 60155922). In case of "our_inbound" the
> RTP-media is terminated at a different ip for which I will use 1.1.1.2.
> {noformat}
> -----------------------------------------------------------------------------
> At 0.000000 the call is initiated by "our_inbound":
> -----------------------------------------------------------------------------
> INVITE sip:+49XXX at customer.XXX.net;transport=udp;user=phone SIP/2.0
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCE106BF410B7
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 INVITE
> Contact: <sip:sgc_c at 1.1.1.1:5060;transport=udp>
> Allow-Events: refer
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE
> Content-Type: application/sdp
> Max-Forwards: 70
> P-Asserted-Identity: <sip:+49XXX at mgc-cluster.XXX.net;user=phone>
> P-Preferred-Identity: <sip:+49XXX at mgc-cluster.XXX.net>
> Privacy: none
> Supported: timer, replaces, histinfo, 100rel
> User-Agent: TELES-SBC
> Content-Length:   229
> v=0
> o=- 2285767812167987084 1 IN IP4 1.1.1.1
> s=TELES-SBC
> c=IN IP4 1.1.1.2
> t=0 0
> m=audio 11940 RTP/AVP 8 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=silenceSupp:off - - - -
> -----------------------------------------------------------------------------
> At 0.001351 Asterisk is replying with Trying:
> -----------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCE106BF410B7;received=1.1.1.1
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 INVITE
> Server: Asterisk PBX 16.12.0
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Session-Expires: 1800;refresher=uas
> Contact: <sip:+49XXX at 2.2.2.2:5060>
> Content-Length: 0
> -----------------------------------------------------------------------------
> In parallel Asterisk now signales "our_customer":
> -----------------------------------------------------------------------------
> INVITE sip:+49XXX at 3.3.3.3 SIP/2.0
> Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK7d70de6a
> Max-Forwards: 70
> From: <sip:+49XXX at 2.2.2.2>;tag=as437a6f2f
> To: <sip:+49XXX at 3.3.3.3>
> Contact: <sip:+49XXX at 2.2.2.2:5060>
> Call-ID: 46f3325b1867f4985b09200e05ff2519 at 2.2.2.2:5060
> CSeq: 102 INVITE
> User-Agent: Asterisk PBX 16.12.0
> Date: Fri, 14 Aug 2020 07:41:31 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Remote-Party-ID: "+49XXX" <sip:+49XXX at 2.2.2.2>;party=calling;privacy=off;screen=no
> Content-Type: application/sdp
> Content-Length: 278
> v=0
> o=root 1849926336 1849926336 IN IP4 2.2.2.2
> s=Asterisk PBX 16.12.0
> c=IN IP4 2.2.2.2
> t=0 0
> m=audio 22504 RTP/AVP 8 9 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:9 G722/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=maxptime:150
> a=sendrecv
> -----------------------------------------------------------------------------
> First the customer replies with Trying:
> -----------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK7d70de6a
> To: <sip:+49XXX at 3.3.3.3>
> From: <sip:+49XXX at 2.2.2.2>;tag=as437a6f2f
> Call-ID: 46f3325b1867f4985b09200e05ff2519 at 2.2.2.2:5060
> CSeq: 102 INVITE
> Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE
> User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1)
> Content-Length: 0
> -----------------------------------------------------------------------------
> And then (after around 0.4s) with Ringing:
> -----------------------------------------------------------------------------
> SIP/2.0 180 Ringing
> Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK7d70de6a
> Contact: <sip:+49XXX at 3.3.3.3:65002;transport=udp>
> To: "XXX, XXX"<sip:+49XXX at 3.3.3.3>;tag=a236c740
> From: <sip:+49XXX at 2.2.2.2>;tag=as437a6f2f
> Call-ID: 46f3325b1867f4985b09200e05ff2519 at 2.2.2.2:5060
> CSeq: 102 INVITE
> Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE
> User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1)
> Content-Length: 0
> -----------------------------------------------------------------------------
> With that Asterisk starts (at 0.426196) ringing to "our_inbound":
> -----------------------------------------------------------------------------
> SIP/2.0 180 Ringing
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCE106BF410B7;received=1.1.1.1
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>;tag=as32a03bca
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 INVITE
> Server: Asterisk PBX 16.12.0
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Session-Expires: 1800;refresher=uas
> Contact: <sip:+49XXX at 2.2.2.2:5060>
> Content-Length: 0
> -----------------------------------------------------------------------------
> And then (because of "inbandprogress=yes") Asterisk sends progress and starts
> sending RTP:
> -----------------------------------------------------------------------------
> SIP/2.0 183 Session Progress
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCE106BF410B7;received=1.1.1.1
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>;tag=as32a03bca
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 INVITE
> Server: Asterisk PBX 16.12.0
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Session-Expires: 1800;refresher=uas
> Contact: <sip:+49XXX at 1.1.1.1:5060>
> Content-Type: application/sdp
> Require: timer
> Content-Length: 252
> v=0
> o=root 829526440 829526440 IN IP4 1.1.1.1
> s=Asterisk PBX 16.12.0
> c=IN IP4 1.1.1.1
> t=0 0
> m=audio 46586 RTP/AVP 8 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=maxptime:150
> a=sendrecv
> -----------------------------------------------------------------------------
> For the next 3.2s Asterisk is sending RTP frames to 1.1.1.2 containing a
> ringtone. In total 161 packets are sent with the SSRC 783be076.
> The flow is 2.2.2.2:46586 -> 1.1.1.2:11940
> -----------------------------------------------------------------------------
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27297, Time=160, Mark
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27298, Time=320
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27299, Time=480
> [...]
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27455, Time=25440
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27456, Time=25600
> PT=ITU-T G.711 PCMA, SSRC=0x783BE076, Seq=27457, Time=25760
> -----------------------------------------------------------------------------
> Now "our_customer" answers the call:
> -----------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK7d70de6a
> Contact: <sip:+49XXX at 2.2.2.2:65002;transport=udp>
> To: "XXX, XXX"<sip:+49XXX at 3.3.3.3>;tag=a236c740
> From: <sip:+49XXX at 2.2.2.2>;tag=as437a6f2f
> Call-ID: 46f3325b1867f4985b09200e05ff2519 at 2.2.2.2:5060
> CSeq: 102 INVITE
> Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE
> Content-Type: application/sdp
> User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1)
> Content-Length: 208
> v=0
> o=- 3330958455 1 IN IP4 3.3.3.3
> s=Swyx LinkMgr
> c=IN IP4 3.3.3.3
> t=0 0
> m=audio 55542 RTP/AVP 8 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=ptime:20
> -----------------------------------------------------------------------------
> Asterisk acks:
> -----------------------------------------------------------------------------
> ACK sip:+49XXX at 3.3.3.3:65002;transport=udp SIP/2.0
> Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK0ea35c4b
> Max-Forwards: 70
> From: <sip:+49XXX at 2.2.2.2>;tag=as437a6f2f
> To: <sip:+49XXX at 3.3.3.3>;tag=a236c740
> Contact: <sip:+49XXX at 2.2.2.2:5060>
> Call-ID: 46f3325b1867f4985b09200e05ff2519 at 2.2.2.2:5060
> CSeq: 102 ACK
> User-Agent: Asterisk PBX 16.12.0
> Content-Length: 0
> {noformat}
> -----------------------------------------------------------------------------
> RTP between Asterisk and "our_customer" is exchanged.
> Asterisk sends 311 packets with SSRC 7f5a528c from 2.2.2.2:22504 to
> 3.3.3.3:55542, while "our_customer" sends 317 packets with SSRC 6b48138f from
> 3.3.3.3:55542 to 2.2.2.2:22504:
> -----------------------------------------------------------------------------
> {noformat}
> 3.687479 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14272, Time=0, Mark
> 3.687489 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14273, Time=160
> 3.707447 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14274, Time=320
> 3.726456 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14275, Time=480
> 3.746436 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14276, Time=640
> 3.764300 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=140, Time=3320682905, Mark
> 3.766431 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14277, Time=800
> 3.774281 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=141, Time=3320683065
> 3.786686 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14278, Time=960
> 3.794455 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=142, Time=3320683225
> [...]
> 9.920692 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14587, Time=50400
> 9.934279 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=449, Time=3320732345
> 9.41389 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14588, Time=50560
> 9.964234 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=450, Time=3320732505
> {noformat}
> -----------------------------------------------------------------------------
> Meanwhile Asterisk establishes (at 3.660704) the call with "our_inbound"
> -----------------------------------------------------------------------------
> {noformat}
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCE106BF410B7;received=1.1.1.1
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>;tag=as32a03bca
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 INVITE
> Server: Asterisk PBX 16.12.0
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Session-Expires: 1800;refresher=uas
> Contact: <sip:+49XXX at 2.2.2.2:5060>
> Content-Type: application/sdp
> Require: timer
> Content-Length: 252
> v=0
> o=root 829526440 829526440 IN IP4 2.2.2.2
> s=Asterisk PBX 16.12.0
> c=IN IP4 2.2.2.2
> t=0 0
> m=audio 46586 RTP/AVP 8 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=maxptime:150
> a=sendrecv
> -----------------------------------------------------------------------------
> "our_inbound" acks
> -----------------------------------------------------------------------------
> ACK sip:+49XXX at 2.2.2.2:5060 SIP/2.0
> Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK00E0F515158AAD9FCF7F6278F296
> From: "+49XXX" <sip:+49XXX at mgc-cluster.XXX.net;user=phone>;tag=0UUHS0000030000E1D0101Cu045FV8G07E1469
> To: "+49XXX" <sip:+49XXX at customer.XXX.net;user=phone>;tag=as32a03bca
> Call-ID: 8415e00015f5-5f36402b-2d18768f-23c282b0-3916f46-01
> CSeq: 163 ACK
> Contact: <sip:+49XXX at 1.1.1.1:5060;transport=udp>
> Max-Forwards: 70
> Content-Length:     0
> {noformat}
> -----------------------------------------------------------------------------
> And now the fun part with the real issues begins.
> "our_inbound" sends 313 RTP-packets with SSRC 7f5a528c from 1.1.1.2:11940 to
> 2.2.2.2:46586. Asterisk switches its SSRC to 6b48138f sending 316 packets from
> 2.2.2.2:46586 to 1.1.1.2:11940.
> However, just after starting Asterisk includes another RTP-frame with the new
> SSRC 6b48138f but with the old(!) sequence number. At this moment RTP breaks
> on the Teles at "our_inbound".
> -----------------------------------------------------------------------------
> {noformat}
> 3.695997 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14273, Time=160, Mark
> 3.696054 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=27458, Time=0             (<---- !)
> 3.715943 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14274, Time=320
> 3.734968 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14275, Time=480
> 3.754930 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14276, Time=640
> 3.762733 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=140, Time=3320682905
> 3.774945 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14277, Time=800
> 3.782714 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=141, Time=3320683065
> 3.795174 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14278, Time=960
> 3.802902 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=142, Time=3320683225
> [...]
> 9.942691 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=449, Time=3320732345
> 9.949898 PT=ITU-T G.711 PCMA, SSRC=0x6B48138F, Seq=14588, Time=50560
> 9.962661 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=450, Time=3320732505
> 9.983132 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=451, Time=3320732655
> 10.007195 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=452, Time=3320732825
> 10.022785 PT=ITU-T G.711 PCMA, SSRC=0x7F5A528C, Seq=453, Time=3320732985
> {noformat}
> -----------------------------------------------------------------------------
> I am speculating, but something causes Asterisk to send a spurious RTP-frame
> which seems to belong to the inband-progress signal (as it uses the old
> sequencenumbers), but the RTP-stack does not longer know the old stream and
> thus sending it with the new SSRC-identifier and a timestamp of 0.
> Still, that issue seems to only affect calls which a routed to "our_customer".
> As to why I am at total loss, as I checked a lot of calls to other clients,
> which all look the same (Asterisk creating an inband ringtone and switching to
> a new SSRC when the call established). All calls to the other customers make a
> perfect switch on the leg to "our_inbound", only on calls to "our_customer"
> show that spurious RTP-frame.
> As always I am happy to provide any additional infos or details needed.

--
This message was sent by Atlassian JIRA
(v6.2#6252)