Negotiation of the codec incorrect

kwemheuer · June 8, 2023, 10:01am

Hi *,

I have a problem with the codec negotiation in pjsip (Asterisk 18.17.1).

The following trace shows the communication between Asterisk and the provider. A call is made to the provider. From the provider comes in “180 Ringing” G.722 as codec request from the provider.
Early-Media flows as G.722 in both directions.

Then in “200 OK” G.711a comes as codec request from the provider.

Then the data flows:

Provider->Asterisk G.711a
Asterisk->Provider G.722

Audio is not audible (in both directions.

Where is the error?

Trace with remarks, marked with “===”:

U 192.168.10.70:25060 -> 46.182.249.41:5060
INVITE sip:some-dest-number@some-provider-net SIP/2.0.
Via: SIP/2.0/UDP 217.229.82.74:25060;rport;branch=z9hG4bKPj0655e86e-a402-4e31-831f-d67dad6b0672.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>.
Contact: <sip:29763dc0e02cc15d@217.229.82.74:25060>.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4492 INVITE.
Route: <sip:proxy-provider.net;lr>.
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER.
Supported: timer, replaces, norefersub, histinfo.
Session-Expires: 1800.
Min-SE: 90.
Max-Forwards: 70.
User-Agent: IPTAM PBX (Version 20230523/3020).
Content-Type: application/sdp.
Content-Length:   257.
.
v=0.
o=- 4110149 4110149 IN IP4 217.229.82.74.
s=Asterisk.
c=IN IP4 217.229.82.74.
t=0 0.
m=audio 10092 RTP/AVP 9 8 101.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.
a=maxptime:150.
a=sendrecv.

#
U 46.182.249.41:5060 -> 192.168.10.70:25060 #39
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 217.229.82.74:25060;received=217.229.82.74;rport=25060;branch=z9hG4bKPj0655e86e-a402-4e31-831f-d67dad6b0672.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4492 INVITE.
Content-Length: 0.
.

#
U 46.182.249.41:5060 -> 192.168.10.70:25060 #40
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP 217.229.82.74:25060;received=217.229.82.74;rport=25060;branch=z9hG4bKPj0655e86e-a402-4e31-831f-d67dad6b0672.
Max-Forwards: 69.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>;tag=1c1818890434.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4492 INVITE.
Supported: timer.
Allow: INVITE,ACK,CANCEL,BYE,INFO,REGISTER,NOTIFY.
Proxy-Authenticate: Digest realm="some-provider-net",nonce="c2582678877a6690492a896cf39411de",opaque="cdc429a9be50991d72b4b9e1dd037143",algorithm=MD5,qop="auth".
Session-Expires: 1800.
User-Agent: Communi5.PROXY/7.3.6.2 (Version 20230523/3020).
Allow-Events: talk.
Content-Length: 0.
.

#
U 192.168.10.70:25060 -> 46.182.249.41:5060 #41
ACK sip:some-dest-number@some-provider-net SIP/2.0.
Via: SIP/2.0/UDP 217.229.82.74:25060;rport;branch=z9hG4bKPj0655e86e-a402-4e31-831f-d67dad6b0672.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>;tag=1c1818890434.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4492 ACK.
Route: <sip:proxy-provider.net;lr>.
Max-Forwards: 70.
User-Agent: IPTAM PBX (Version 20230523/3020).
Content-Length:  0.
.

#
U 192.168.10.70:25060 -> 46.182.249.41:5060 #42
INVITE sip:some-dest-number@some-provider-net SIP/2.0.
Via: SIP/2.0/UDP 217.229.82.74:25060;rport;branch=z9hG4bKPj6f975982-3917-4d95-aeb4-b83059f9a770.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>.
Contact: <sip:29763dc0e02cc15d@217.229.82.74:25060>.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4493 INVITE.
Route: <sip:proxy-provider.net;lr>.
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER.
Supported: timer, replaces, norefersub, histinfo.
Session-Expires: 1800.
Min-SE: 90.
Max-Forwards: 70.
User-Agent: IPTAM PBX (Version 20230523/3020).
Proxy-Authorization: Digest username="29763dc0e02cc15d", realm="some-provider-net", nonce="c2582678877a6690492a896cf39411de", uri="sip:some-dest-number@some-provider-net", response="10a2c62a1e6b4f475459b71674b5ee57", algorithm=MD5, cnonce="899742248e9d4483ad5e125e2f401632", opaque="cdc429a9be50991d72b4b9e1dd037143", qop=auth, nc=00000001.
Content-Type: application/sdp.
Content-Length:   257.
.
v=0.
o=- 4110149 4110149 IN IP4 217.229.82.74.
s=Asterisk.
c=IN IP4 217.229.82.74.
t=0 0.
m=audio 10092 RTP/AVP 9 8 101.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.
a=maxptime:150.
a=sendrecv.

#
U 46.182.249.41:5060 -> 192.168.10.70:25060 #43
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 217.229.82.74:25060;received=217.229.82.74;rport=25060;branch=z9hG4bKPj6f975982-3917-4d95-aeb4-b83059f9a770.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4493 INVITE.
Content-Length: 0.
.

#
U 46.182.249.41:5060 -> 192.168.10.70:25060 #44
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 217.229.82.74:25060;received=217.229.82.74;rport=25060;branch=z9hG4bKPj6f975982-3917-4d95-aeb4-b83059f9a770.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>;tag=HrTYG-Pino.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4493 INVITE.
Contact: <sip:46.182.249.41:5060>.
Supported: timer,sdp-anat.
Allow: INVITE,ACK,CANCEL,BYE,INFO,REGISTER,NOTIFY.
User-Agent: Communi5.PROXY/7.3.6.2.
Allow-Events: talk.
Content-Type: application/sdp.
Content-Length: 270.
.
v=0.
o=xmserver 396466239 1412421382 IN IP4 46.182.249.41.
s=xmserver.
c=IN IP4 46.182.249.41.
b=AS:80.
t=0 0.
m=audio 11395 RTP/AVP 9 101.
b=AS:80.
a=rtpmap:9 G722/8000.
a=sendrecv.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=rtcp:11396 IN IP4 46.182.249.41.

=== RTP data is G.722 in both directions ===

=== Second SDP forces G.711a ===
#
U 46.182.249.41:5060 -> 192.168.10.70:25060 #47
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 217.229.82.74:25060;received=217.229.82.74;rport=25060;branch=z9hG4bKPj6f975982-3917-4d95-aeb4-b83059f9a770.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>;tag=HrTYG-Pino.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4493 INVITE.
Contact: <sip:46.182.249.41:5060>.
Supported: x-diversion,timer,sdp-anat.
Allow: INVITE,ACK,CANCEL,BYE,INFO,REGISTER,NOTIFY.
User-Agent: Communi5.PROXY/7.3.6.2.
Allow-Events: talk.
Content-Type: application/sdp.
Content-Length: 285.
X-Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9-UASession-7L6KIK_dOn.
.
v=0.
o=- 396466239 1412421383 IN IP4 46.182.249.41.
s=TELES-SBC.
c=IN IP4 46.182.249.41.
t=0 0.
m=audio 11395 RTP/AVP 8 101.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.
a=silenceSupp:off - - - -.
a=rtcp:11396 IN IP4 46.182.249.41.

#
U 192.168.10.70:25060 -> 46.182.249.41:5060 #48
ACK sip:46.182.249.41:5060 SIP/2.0.
Via: SIP/2.0/UDP 217.229.82.74:25060;rport;branch=z9hG4bKPj89c800db-a490-4999-85ab-dab027fff5a1.
From: "some-source-number" <sip:29763dc0e02cc15d@some-provider-net>;tag=70a1d3c3-6aa9-4307-ace5-6fa1545d6316.
To: <sip:some-dest-number@some-provider-net>;tag=HrTYG-Pino.
Call-ID: c3f6495f-81fd-4312-9eb8-3b3c14227fc9.
CSeq: 4493 ACK.
Max-Forwards: 70.
User-Agent: IPTAM PBX (Version 20230523/3020).
Content-Length:  0.
.

=== Provider->Asterisk G.711a, Asterisk->Provider G.722 ===
=== no communication ===

jcolp · June 8, 2023, 10:04am

You will need to provide an actual Asterisk console log[1] as well as an RTP trace (rtp set debug on) to show how media is actually flowing. How did you come to the conclusion that it is codec negotiation related?

[1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

david551 · June 8, 2023, 12:00pm

I’d also want to see what codecs were configured in Asterisk.

kwemheuer · June 8, 2023, 12:05pm

Hi Joshua,

I have created and attached the debug info.
debug.txt (406.5 KB)

I think it is related to the codec negotiation, because the provider’s codec changes between “180 Ringing” and “200 OK”. If this does not happen (other side supports G.722) the error does not occur.

jcolp · June 8, 2023, 12:28pm

There are log messages in here which do not exist in mainline Asterisk. What modifications or changes have been done to this?

jcolp · June 8, 2023, 12:32pm

And I think you need to enable the accept_multiple_sdp_answers[1] option. Note the comment, it needs to be on the endpoint AND in the system section.

[1] asterisk/pjsip.conf.sample at 18 · asterisk/asterisk · GitHub

kwemheuer · June 8, 2023, 12:51pm

I am not aware of modifications. Which log messages do You mean?

kwemheuer · June 8, 2023, 12:53pm

This seems to solve the issue. Does this setting have any side effects? Why is it not enabled by default? Or is the behavior of the provider incorrect according to RFCs?

jcolp · June 8, 2023, 12:56pm

If I recall correctly it is not technically valid according to the standards thus why it isn’t the default, plus this was added many many many years after and so changing default behavior could have had other consequences. It’s probably fine.

I was mistaken on the log messages not appearing, I was in an older version due to looking at someone elses older version.

kwemheuer · June 8, 2023, 1:02pm

Hi Joshua,

thank You for the information. I’ll change the setting and test for side effects.
Have a nice day

Karsten

system · July 8, 2023, 1:03pm

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