thr3ads.net - asterisk users - [asterisk-users] Negotiates g729 but RTP contains g711 [Sep 2020]

If this information is useful, please help other people find it:
Share via:

David Herselman

2020-Sep-24 07:48 UTC

[asterisk-users] Negotiates g729 but RTP contains g711

Hi,

I was able to use Unsniff to validate that the incoming 20 byte payloads of
audio from the downstream IAX2 trunk was definitely G.729a whilst Asterisk
16.13.0 transcodes to G.711a unnecessarily. Media is confirmed as having been
negotiated as g729 on all four streams. Nuance with this call is that it's
from a WebRTC client which doesn't transmit any audio, could this be
influencing Asterisk?

Is this a known scenario, something obvious or should I be logging something in
JIRA?

In the below +27888888888 (chan_sip) calls 0100000000 (chan_iax), negotiates
g729 on both legs of the bridged call, exclusively receives g729 media from
0100000000 (chan_iax) but then transmits g711a media to +27888888888 (chan_sip).

Herewith the scrubbed logging with SIP debug:
[2020-09-19 23:42:19] VERBOSE[2637] chan_sip.c:
<--- SIP read from UDP:41.11.11.12:5060 --->
INVITE sip:0100000000 at 52.22.22.22:5160 SIP/2.0
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
Via: SIP/2.0/UDP 41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>
Contact: <sip:+27888888888 at 41.11.11.11:5070>
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 102 INVITE
User-Agent: PortaOne
Max-Forwards: 69
Date: Sat, 19 Sep 2020 21:42:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
X-LOCATION:
X-StartID: SDvb9r601-d482cc2b5e0b32417957ea02aaade464-a04aba0
Content-Type: application/sdp
Content-Length: 283

v=0
o=root 6009 6009 IN IP4 41.11.11.11
s=session
c=IN IP4 41.11.11.11
t=0 0
m=audio 13918 RTP/AVP 18 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
[2020-09-19 23:42:19] VERBOSE[2637] chan_sip.c: --- (18 headers 14 lines) ---
[2020-09-19 23:42:19] VERBOSE[2637] chan_sip.c: Sending to 41.11.11.12:5060
(NAT)
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Sending to
41.11.11.12:5060 (NAT)
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Using INVITE request
as basis request - 7030be5a09d89a9543234da051897a49 at 41.11.11.11
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found peer
'Upstream' for '+27888888888' from 41.11.11.12:5060
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] netsock2.c: Using SIP RTP TOS
bits 184
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] netsock2.c: Using SIP RTP CoS
mark 5
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Got SDP version 6009
and unique parts [root 6009 IN IP4 41.11.11.11]
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found RTP audio
format 18
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found RTP audio
format 8
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found RTP audio
format 101
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found audio
description format G729 for ID 18
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found audio
description format PCMA for ID 8
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Found audio
description format telephone-event for ID 101
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Capabilities: us -
(g722|alaw|g729), peer - audio=(alaw|g729)/video=(nothing)/text=(nothing),
combined - (alaw|g729)
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Non-codec
capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|),
combined - 0x1 (telephone-event|)
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] res_rtp_asterisk.c:
0x7f02241bdaf0 -- Strict RTP learning after remote address set to:
41.11.11.11:13918
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Peer audio RTP is at
port 41.11.11.11:13918
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Looking for
0100000000 in from-pstn (domain 52.22.22.22)
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] sip/route.c: sip_route_dump:
route/path hop: <sip:41.11.11.12;lr;ftag=as40fe2614>
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c:
<--- Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 102 INVITE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:0100000000 at 52.22.22.22:5160>
Content-Length: 0


<------------>
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:1] Set("SIP/Upstream-00021a0d", "1?SIP_CODEC=g729")
in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:2] NoOp("SIP/Upstream-00021a0d", "SIP Call ID:
7030be5a09d89a9543234da051897a49 at 41.11.11.11") in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:3] Dial("SIP/Upstream-00021a0d",
"iax2/Downstream/0100000000") in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] app_dial.c: Called
iax2/Downstream/0100000000
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Call accepted by
196.43.209.105:4569 (format g729)
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Format for call is
(g729)
[2020-09-19 23:42:20] VERBOSE[15153][C-00021a1f] app_dial.c:
IAX2/Downstream-26055 is ringing
[2020-09-19 23:42:20] VERBOSE[15153][C-00021a1f] chan_sip.c:
<--- Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 102 INVITE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:0100000000 at 52.22.22.22:5160>
Content-Length: 0


<------------>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] app_dial.c:
IAX2/Downstream-26055 answered SIP/Upstream-00021a0d
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Audio is at 17678
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding codec g729
to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding non-codec
0x1 (telephone-event) to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c:
<--- Reliably Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 102 INVITE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:0100000000 at 52.22.22.22:5160>
Content-Type: application/sdp
Content-Length: 259

v=0
o=root 430525994 430525994 IN IP4 52.22.22.22
s=Asterisk PBX 16.13.0
c=IN IP4 52.22.22.22
t=0 0
m=audio 17678 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:230
a=sendrecv

<------------>
[2020-09-19 23:42:22] VERBOSE[15154][C-00021a1f] bridge_channel.c: Channel
IAX2/Downstream-26055 joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] bridge_channel.c: Channel
SIP/Upstream-00021a0d joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[2637] chan_sip.c:
<--- SIP read from UDP:41.11.11.12:5060 --->
ACK sip:0100000000 at 52.22.22.22:5160 SIP/2.0
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
Via: SIP/2.0/UDP 41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.2
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK7caba5c1;rport=5070
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Contact: <sip:+27888888888 at 41.11.11.11:5070>
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 102 ACK
User-Agent: PortaOne
Max-Forwards: 69
Content-Length: 0

<------------->
[2020-09-19 23:42:22] VERBOSE[2637] chan_sip.c: --- (12 headers 0 lines) ---
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020640, ts 000160, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020641, ts 000320, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020642, ts 000480, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020643, ts 000640, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020644, ts 000800, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020645, ts 000960, len 000160)
<snip>
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020999, ts 250248, len 000160)
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 021000, ts 250408, len 000160)
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 021001, ts 250568, len 000160)
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 021002, ts 250728, len 000160)
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 021003, ts 250888, len 000160)
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 021004, ts 251048, len 000160)
[2020-09-19 23:42:29] VERBOSE[2637] chan_sip.c:
<--- SIP read from UDP:41.11.11.12:5060 --->
BYE sip:0100000000 at 52.22.22.22:5160 SIP/2.0
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
Via: SIP/2.0/UDP 41.11.11.12:5060;branch=z9hG4bK5df7.1435d67.0
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK577fb6bb;rport=5070
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 103 BYE
User-Agent: PortaOne
Max-Forwards: 69
Reason: Q.850 ;cause=16; text="Normal Clearing"
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

<------------->
[2020-09-19 23:42:29] VERBOSE[2637] chan_sip.c: --- (13 headers 0 lines) ---
[2020-09-19 23:42:29] VERBOSE[2637][C-00021a1f] chan_sip.c: Sending to
41.11.11.12:5060 (NAT)
[2020-09-19 23:42:29] VERBOSE[2637][C-00021a1f] chan_sip.c: Scheduling
destruction of SIP dialog '7030be5a09d89a9543234da051897a49 at
41.11.11.11' in 32000 ms (Method: BYE)
[2020-09-19 23:42:29] VERBOSE[2637][C-00021a1f] chan_sip.c:
<--- Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK5df7.1435d67.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK577fb6bb;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at 41.11.11.11
CSeq: 103 BYE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] bridge_channel.c: Channel
SIP/Upstream-00021a0d left 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:29] VERBOSE[15154][C-00021a1f] bridge_channel.c: Channel
IAX2/Downstream-26055 left 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:29] VERBOSE[15153][C-00021a1f] pbx.c: Spawn extension
(incoming, Downstream_0100000000, 1) exited non-zero on
'SIP/Upstream-00021a0d'
[2020-09-19 23:42:29] VERBOSE[15154][C-00021a1f] chan_iax2.c: Hungup
'IAX2/Downstream-26055'


Regards
David Herselman


From: asterisk-users <asterisk-users-bounces at lists.digium.com> On
Behalf Of David Herselman
Sent: Wednesday, 23 September 2020 4:17 PM
To: asterisk-users at lists.digium.com
Subject: [asterisk-users] Negotiates g729 but RTP contains g711

Hi,

We have a scenario where inbound calls from an upstream provider (chan_sip) sent
downstream (chan_iax2) negotiates only g729 yet RTP media contains g711. Both
the upstream and downstream trunks are limited to only offering g729 whilst the
initial invite from our upstream provider offers both g711 and g729. Asterisk
presumably simply forwards the media from iax2 trunk encapsulation to sip
encapsulation. Most calls surprisingly work, presumably by the caller's
system identifying the incoming media as g711, whilst very few callers don't
hear the IVR prompt. The downstream is unfortunately not within our control but
can't be anything other than Asterisk, considering it's using iax2 in
trunk mode.

We are running Asterisk 16.13.0, not sure what version the downstream is using.

caller -> upstream -> us -> downstream (IVR)

Herewith the SIP portion of the call, between upstream and us:
Available here: https://ibb.co/jRGvvVc


Wireshark unfortunately still cannot dissect iax2 trunk captures though, so I
didn't know how to conclusively identify where this problem originates. I do
however have a concern that the media we are receiving's packet size (74
bytes) indicates that it is most likely G729.

Herewith the IAX2 trunk portion of the call, between us and downstream:
Available here: https://ibb.co/r07PkkK


ie: We appear to have a reproducible environment where an inbound SIP trunk call
sent to a downstream IAX2 trunk negotiates g729 in all 4 streams, receives g729
media from downstream iax2 trunk but then transmits g711a upstream.

I'm however struggling with the downstream pcap, to establish what's
different about these calls. Trunk config and forwarding structure works the
identical way for 50+ other flows on the same host.


Regards
David Herselman
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20200924/3aa1330e/attachment.html>

David Herselman

2020-Sep-25 07:32 UTC

head link

[asterisk-users] Negotiates g729 but RTP contains g711

Hi,

I was able to use Unsniff to validate that the incoming 20 byte payloads of
audio from the downstream IAX2 trunk was definitely G.729a whilst Asterisk
16.13.0 transcodes to G.711a unnecessarily. Media is confirmed as having been
negotiated as g729 on all four streams. Nuance with this call is that it's
from a WebRTC client which doesn't transmit any audio, could this be
influencing Asterisk?

I couldn't post the asterisk debug in the mailing list, perhaps we could
consider increasing maximum messages sizes from 40 KiB in 2020? I subsequently
opened a case in JIRA instead
(https://issues.asterisk.org/jira/browse/ASTERISK-29096).


In the below +27888888888 (chan_sip) calls 0100000000 (chan_iax), negotiates
g729 on both legs of the bridged call, exclusively receives g729 media from
0100000000 (chan_iax) but then transmits g711a media to +27888888888 (chan_sip).

Herewith the scrubbed and reduced dialogues, full details are available in the
JIRA case:
[2020-09-19 23:42:19] VERBOSE[2637] chan_sip.c:
<--- SIP read from UDP:41.11.11.12:5060 --->
INVITE sip:0100000000 at 52.22.22.22:5160 SIP/2.0
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
Via: SIP/2.0/UDP 41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>
Contact: <sip:+27888888888 at 41.11.11.11:5070>
Call-ID: 7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>
CSeq: 102 INVITE
User-Agent: PortaOne
Max-Forwards: 69
Date: Sat, 19 Sep 2020 21:42:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
X-LOCATION:
X-StartID: SDvb9r601-d482cc2b5e0b32417957ea02aaade464-a04aba0
Content-Type: application/sdp
Content-Length: 283

v=0
o=root 6009 6009 IN IP4 41.11.11.11
s=session
c=IN IP4 41.11.11.11
t=0 0
m=audio 13918 RTP/AVP 18 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
<snip>
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Capabilities: us -
(g722|alaw|g729), peer - audio=(alaw|g729)/video=(nothing)/text=(nothing),
combined - (alaw|g729)
<snip>
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:1] Set("SIP/Upstream-00021a0d", "1?SIP_CODEC=g729")
in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:2] NoOp("SIP/Upstream-00021a0d", "SIP Call ID:
7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>")
in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:3] Dial("SIP/Upstream-00021a0d",
"iax2/Downstream/0100000000") in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] app_dial.c: Called
iax2/Downstream/0100000000
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Call accepted by
196.43.209.105:4569 (format g729)
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Format for call is
(g729)
<snip>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] app_dial.c:
IAX2/Downstream-26055 answered SIP/Upstream-00021a0d
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Audio is at 17678
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding codec g729
to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding non-codec
0x1 (telephone-event) to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c:
<--- Reliably Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>
CSeq: 102 INVITE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:0100000000 at 52.22.22.22:5160>
Content-Type: application/sdp
Content-Length: 259

v=0
o=root 430525994 430525994 IN IP4 52.22.22.22
s=Asterisk PBX 16.13.0
c=IN IP4 52.22.22.22
t=0 0
m=audio 17678 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:230
a=sendrecv

<------------>
[2020-09-19 23:42:22] VERBOSE[15154][C-00021a1f] bridge_channel.c: Channel
IAX2/Downstream-26055 joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] bridge_channel.c: Channel
SIP/Upstream-00021a0d joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[2637] chan_sip.c:
<snip>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020640, ts 000160, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020641, ts 000320, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020642, ts 000480, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020643, ts 000640, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020644, ts 000800, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020645, ts 000960, len 000160)


Regards
David Herselman


From: asterisk-users <asterisk-users-bounces at
lists.digium.com<mailto:asterisk-users-bounces at lists.digium.com>> On
Behalf Of David Herselman
Sent: Wednesday, 23 September 2020 4:17 PM
To: asterisk-users at lists.digium.com<mailto:asterisk-users at
lists.digium.com>
Subject: [asterisk-users] Negotiates g729 but RTP contains g711

Hi,

We have a scenario where inbound calls from an upstream provider (chan_sip) sent
downstream (chan_iax2) negotiates only g729 yet RTP media contains g711. Both
the upstream and downstream trunks are limited to only offering g729 whilst the
initial invite from our upstream provider offers both g711 and g729. Asterisk
presumably simply forwards the media from iax2 trunk encapsulation to sip
encapsulation. Most calls surprisingly work, presumably by the caller's
system identifying the incoming media as g711, whilst very few callers don't
hear the IVR prompt. The downstream is unfortunately not within our control but
can't be anything other than Asterisk, considering it's using iax2 in
trunk mode.

We are running Asterisk 16.13.0, not sure what version the downstream is using.

caller -> upstream -> us -> downstream (IVR)

Herewith the SIP portion of the call, between upstream and us:
Available here: https://ibb.co/jRGvvVc


Wireshark unfortunately still cannot dissect iax2 trunk captures though, so I
didn't know how to conclusively identify where this problem originates. I do
however have a concern that the media we are receiving's packet size (74
bytes) indicates that it is most likely G729.

Herewith the IAX2 trunk portion of the call, between us and downstream:
Available here: https://ibb.co/r07PkkK


ie: We appear to have a reproducible environment where an inbound SIP trunk call
sent to a downstream IAX2 trunk negotiates g729 in all 4 streams, receives g729
media from downstream iax2 trunk but then transmits g711a upstream.

I'm however struggling with the downstream pcap, to establish what's
different about these calls. Trunk config and forwarding structure works the
identical way for 50+ other flows on the same host.


Regards
David Herselman
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20200925/8cfa90c2/attachment-0001.html>

David Herselman

2020-Sep-25 07:33 UTC

head link

[asterisk-users] Negotiates g729 but RTP contains g711

Hi,

I was able to use Unsniff to validate that the incoming 20 byte payloads of
audio from the downstream IAX2 trunk was definitely G.729a whilst Asterisk
16.13.0 transcodes to G.711a unnecessarily. Media is confirmed as having been
negotiated as g729 on all four streams. Nuance with this call is that it's
from a WebRTC client which doesn't transmit any audio, could this be
influencing Asterisk?

I couldn't post the asterisk debug in the mailing list, perhaps we could
consider increasing maximum messages sizes from 40 KiB in 2020? I subsequently
opened a case in JIRA instead
(https://issues.asterisk.org/jira/browse/ASTERISK-29096).


In the below +27888888888 (chan_sip) calls 0100000000 (chan_iax), negotiates
g729 on both legs of the bridged call, exclusively receives g729 media from
0100000000 (chan_iax) but then transmits g711a media to +27888888888 (chan_sip).

Herewith the scrubbed and reduced dialogues, full details are available in the
JIRA case:
[2020-09-19 23:42:19] VERBOSE[2637] chan_sip.c:
<--- SIP read from UDP:41.11.11.12:5060 --->
INVITE sip:0100000000 at 52.22.22.22:5160 SIP/2.0
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
Via: SIP/2.0/UDP 41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>
Contact: <sip:+27888888888 at 41.11.11.11:5070>
Call-ID: 7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>
CSeq: 102 INVITE
User-Agent: PortaOne
Max-Forwards: 69
Date: Sat, 19 Sep 2020 21:42:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
X-LOCATION:
X-StartID: SDvb9r601-d482cc2b5e0b32417957ea02aaade464-a04aba0
Content-Type: application/sdp
Content-Length: 283

v=0
o=root 6009 6009 IN IP4 41.11.11.11
s=session
c=IN IP4 41.11.11.11
t=0 0
m=audio 13918 RTP/AVP 18 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
<snip>
[2020-09-19 23:42:19] VERBOSE[2637][C-00021a1f] chan_sip.c: Capabilities: us -
(g722|alaw|g729), peer - audio=(alaw|g729)/video=(nothing)/text=(nothing),
combined - (alaw|g729)
<snip>
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:1] Set("SIP/Upstream-00021a0d", "1?SIP_CODEC=g729")
in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:2] NoOp("SIP/Upstream-00021a0d", "SIP Call ID:
7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>")
in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] pbx.c: Executing [0100000000 at
incoming:3] Dial("SIP/Upstream-00021a0d",
"iax2/Downstream/0100000000") in new stack
[2020-09-19 23:42:19] VERBOSE[15153][C-00021a1f] app_dial.c: Called
iax2/Downstream/0100000000
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Call accepted by
196.43.209.105:4569 (format g729)
[2020-09-19 23:42:20] VERBOSE[2602][C-00021a1f] chan_iax2.c: Format for call is
(g729)
<snip>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] app_dial.c:
IAX2/Downstream-26055 answered SIP/Upstream-00021a0d
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Set codec to
'g729' for this call because of ${SIP_CODEC*} variable
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Audio is at 17678
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding codec g729
to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c: Adding non-codec
0x1 (telephone-event) to SDP
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] chan_sip.c:
<--- Reliably Transmitting (NAT) to 41.11.11.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
41.11.11.12:5060;branch=z9hG4bK4df7.5bc77035.0;received=41.11.11.12;rport=5060
Via: SIP/2.0/UDP
41.11.11.11:5070;received=41.11.11.11;branch=z9hG4bK0cb77ea3;rport=5070
Record-Route: <sip:41.11.11.12;lr;ftag=as40fe2614>
From: "+27888888888" <sip:+27888888888 at
41.11.11.11:5070>;tag=as40fe2614
To: <sip:0100000000 at 52.22.22.22:5160>;tag=as11a1cd82
Call-ID: 7030be5a09d89a9543234da051897a49 at
41.11.11.11<mailto:7030be5a09d89a9543234da051897a49 at 41.11.11.11>
CSeq: 102 INVITE
Server: Asterisk PBX 16.13.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO,
PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:0100000000 at 52.22.22.22:5160>
Content-Type: application/sdp
Content-Length: 259

v=0
o=root 430525994 430525994 IN IP4 52.22.22.22
s=Asterisk PBX 16.13.0
c=IN IP4 52.22.22.22
t=0 0
m=audio 17678 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:230
a=sendrecv

<------------>
[2020-09-19 23:42:22] VERBOSE[15154][C-00021a1f] bridge_channel.c: Channel
IAX2/Downstream-26055 joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] bridge_channel.c: Channel
SIP/Upstream-00021a0d joined 'simple_bridge' basic-bridge
<0d377050-bca3-4db8-81e0-f677e37c24e9>
[2020-09-19 23:42:22] VERBOSE[2637] chan_sip.c:
<snip>
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020640, ts 000160, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020641, ts 000320, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020642, ts 000480, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020643, ts 000640, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020644, ts 000800, len 000160)
[2020-09-19 23:42:22] VERBOSE[15153][C-00021a1f] res_rtp_asterisk.c: Sent RTP
packet to      41.11.11.11:13918 (type 8, seq 020645, ts 000960, len 000160)


Regards
David Herselman
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20200925/e30dc007/attachment.html>

Apparently Analagous Threads

Search for more apparently analagous threads

asterisk users - Sep 2020 - Negotiates g729 but RTP contains g711

[asterisk-users] Negotiates g729 but RTP contains g711

[asterisk-users] Negotiates g729 but RTP contains g711

[asterisk-users] Negotiates g729 but RTP contains g711

Apparently Analagous Threads