| Summary: | ASTERISK-27223: chan_pjsip: unable to agree on audio codec with AVM Fritz!Box trunk (async rtp issue) | ||||
| Reporter: | M. Ustermann (Ustermann) | Labels: | |||
| Date Opened: | 2017-08-27 08:02:16 | Date Closed: | 2017-12-20 11:28:21.000-0600 | ||
| Priority: | Major | Regression? | No | ||
| Status: | Closed/Complete | Components: | Channels/chan_pjsip | ||
| Versions: | 14.6.0 | Frequency of Occurrence | Constant | ||
| Related Issues: |
| ||||
| Environment: | FreePBX Distro 7 | Attachments: | ( 0) debug_log_123456_asymmetric_rtp_codec_is_no_default.txt ( 1) debug_log_123456_asymmetric_rtp_codec_is_yes.txt ( 2) logs-new-2017-08-31.zip ( 3) pruned-pcap.pcapng | ||
| Description: | I'm trying to use the SIP server integrated in the AVM Fritz!Box router (a popular and well supported model in Germany) as an Asterisk Trunk. Everything works fine with chan_sip, but with chan_pjsip there are problems negotiating the audio codec.
I can call some external destinations just fine, but other destinations, presumably those which request PCMA (instead of the prioritized G722) audio will lead to no audio I can hear and garbled audio for the other side. rtp_symmetric=yes/no => has no effect asymmetric_rtp_codec=yes => this makes it possible for me to hear the other side just fine, but the other side still receives garbled audio from me. I've looked a packet capture and can see the following: 1) Asterisk sends an INVITE to the Fritz!Box SIP Server, offering both G722 and G711 PCMA 2) Fritz!Box responds in the Status: 183 Session Progress" packet, also offering G722 and G711 PCMA Both devices now send G722 packets back and forth during the call setup phase (ringing). 3) the call is now accepted by the remote party and Fritz!Box sends a "Status: 200 OK" packet to Asterisk, now only offering G.711 PCMA From now on, all voice data coming from the Fritz!Box is using G.711 (which I can properly hear, provided I've set asymmetric_rtp_codec=yes) but all voice data sent to the remote party is still G.722 (which arrives garbled at the remote party). My guess is the SIP packet #3 after which the Fritz!Box starts sending PCMA data is also is supposed to make asterisk switch to PCMA. But I of course have no clue if this SIP package is not using the correct syntax for this of if asterisk is not interpreting it correctly. SIP Packet #3 contains the following: (192.168.7.1 = Fritz!Box, 192.168.7.5 = Asterisk 14.6.0) {noformat} Session Initiation Protocol (200) Status-Line: SIP/2.0 200 OK Message Header Via: SIP/2.0/UDP 192.168.7.5:5060;rport=5060;branch=z9hG4bKPj35b15360-cba5-42d8-9ba5-c9b3bc89b8f4 From: <sip:0000042002014@192.168.7.5>;tag=2fe7fc32-3275-41a9-9474-58c884b1e53b To: <sip:46201501@192.168.7.1>;tag=D1E915482207B644 Call-ID: c80a694c-1953-4a0f-9931-0e832cb6bbab CSeq: 9330 INVITE Contact: <sip:5EFC81EFC5C6FB7AEB414899110F7@192.168.7.1> Session-Expires: 1800;refresher=uac Min-SE: 90 User-Agent: AVM FRITZ!Box 7490 113.06.88 (Aug 22 2017) Supported: 100rel,replaces,timer Allow-Events: telephone-event,refer Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,PUBLISH Content-Type: application/sdp Accept: application/sdp, multipart/mixed Accept-Encoding: identity Content-Length: 216 Message Body Session Description Protocol Session Description Protocol Version (v): 0 Owner/Creator, Session Id (o): user 6757382 6757383 IN IP4 192.168.7.1 Session Name (s): Asterisk Connection Information (c): IN IP4 192.168.7.1 Time Description, active time (t): 0 0 Media Description, name and address (m): audio 7082 RTP/AVP 8 101 Media Type: audio Media Port: 7082 Media Protocol: RTP/AVP Media Format: ITU-T G.711 PCMA Media Format: DynamicRTP-Type-101 Media Attribute (a): rtpmap:8 PCMA/8000 Media Attribute Fieldname: rtpmap Media Format: 8 MIME Type: PCMA Sample Rate: 8000 Media Attribute (a): rtpmap:101 telephone-event/8000 Media Attribute Fieldname: rtpmap Media Format: 101 MIME Type: telephone-event Sample Rate: 8000 Media Attribute (a): fmtp:101 0-15 Media Attribute Fieldname: fmtp Media Format: 101 [telephone-event] Media format specific parameters: 0-15 Media Attribute (a): sendrecv Media Attribute (a): rtcp:7083 Media Attribute Fieldname: rtcp Media Attribute Value: 7083 {noformat} Is this something that needs to be fixed in Asterisk or is it clearly a violation from AVM, the manufacturer of the Fritz!Box? The specific Fritz!Box Model is a 7490, I've tried both the latest final firmware 6.83 as well as the current beta firmware 06.88-46101. I will try to attach the .pcap file to this bug. | ||||
| Comments: | By: Asterisk Team (asteriskteam) 2017-08-27 08:02:18.624-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. By: M. Ustermann (Ustermann) 2017-08-27 08:03:40.405-0500 Packet capture - communication between Asterisk 14.6.0 and AVM Fritz!Box 7490 with asymmetric_rtp_codec=yes option set. By: Joshua C. Colp (jcolp) 2017-08-28 05:33:48.130-0500 Thank you for taking the time to report this bug and helping to make Asterisk better. Unfortunately, we cannot work on this bug because your description did not include enough information. Please read over the Asterisk Issue Guidelines [1] which discusses the information necessary for your issue to be resolved and the format that information needs to be in. We would be grateful if you would then provide a more complete description of the problem. At a minimum, we need: 1. The specific steps or actions you took that caused you to encounter the problem. 2. The behavior you expected and the location of documentation that led you to that expectation. 3. The behavior you actually encountered. To demonstrate the issue in detail, please include Asterisk log files generated per the instructions on the wiki [2]. If applicable, please ensure that protocol-level trace debugging is enabled, e.g., 'sip set debug on' if the issue involves chan_sip, and configuration information such as dialplan and channel configuration. Thanks! [1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines [2] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information By: M. Ustermann (Ustermann) 2017-08-29 04:12:43.515-0500 Debug Log with asymmetric_rtp_codec=yes By: M. Ustermann (Ustermann) 2017-08-29 04:13:14.697-0500 Debug Log with asymmetric_rtp_codec=no By: M. Ustermann (Ustermann) 2017-08-29 04:23:14.302-0500 I've attached the required debug log, two of them - one with asymmetric_rtp_codec=no (which is default) ==> chan_pjsip.c: Oooh, got a frame with format of alaw on channel 'PJSIP/pj_42002013-00000069' when it has not been negotiated And one which was made with asymmetric_rtp_codec=yes (which this bug is more about) in which I can see the following suspicious lines: ==> translate.c: Sample size different 160 vs 320 In the second case (asymmetric_rtp_codec=yes) which this bug is more about, I can hear the other side (call to 08003301000) just fine, but audio I send is being garbled. PJSIP endpoint configuration: [15] type=endpoint aors=15 auth=15-auth allow=g722,alaw context=from-internal callerid=15 <15> dtmf_mode=rfc4733 aggregate_mwi=yes use_avpf=no rtcp_mux=no ice_support=no media_use_received_transport=no trust_id_inbound=yes media_encryption=no timers=yes media_encryption_optimistic=no send_pai=yes rtp_symmetric=yes rewrite_contact=yes force_rport=yes language=en [pj_42002013] type=endpoint transport=0.0.0.0-udp context=from-pstn disallow=all allow=g722,alaw,ulaw,gsm,g726 aors=pj_42002013 language=en outbound_auth=pj_42002013 from_user=0000042002013 t38_udptl=no t38_udptl_ec=none fax_detect=no t38_udptl_nat=no dtmf_mode=auto ====> THIS LINE IS SET TO YES OR NO DEPENDING ON THE TEST ########## asymmetric_rtp_codec=yes ====> THIS LINE IS SET TO YES OR NO DEPENDING ON THE TEST ########## [15-identify] type=identify endpoint=15 [pj_42002013] type=identify endpoint=pj_42002013 match=192.168.7.1 [pj_42002013] type=registration transport=0.0.0.0-udp outbound_auth=pj_42002013 retry_interval=60 max_retries=10 expiration=600 line=yes endpoint=pj_42002013 auth_rejection_permanent=yes contact_user=0000042002013 server_uri=sip:192.168.7.1:5060 client_uri=sip:0000042002013@192.168.7.1:5060 PJSIP transport configuration: [0.0.0.0-udp] type=transport protocol=udp bind=0.0.0.0:5060 allow_reload=yes local_net=192.168.7.0/255.255.255.0 By: Joshua C. Colp (jcolp) 2017-08-29 04:51:03.658-0500 I don't understand, do things work with the asymmetric option set to "no" but not with "yes"? If so then it is likely the endpoint not supporting asymmetric. By: M. Ustermann (Ustermann) 2017-08-29 04:58:12.815-0500 It does not work with EITHER option, just the symptom varies. With asymmetric_rtp_codec=no (default) I cannot hear the other side at all (silence) and the other side hears garbled audio from me. With asymmetric_rtp_codec=yes I can hear the other side perfectly fine but the other side also receives garbled audio from me. Asterisk and the AVM Fritz!Box have problems negotiating the audio codec (Fritz!Box@192.168.7.1 wants to switch back from G722 to PCM as soon as the call is established). I don't know who is at fault, but I do know that it works perfectly with chan_sip. By: Rusty Newton (rnewton) 2017-08-31 15:44:40.775-0500 I see where AVM requests PCMA in the 200 OK when they answer. I don't know why Asterisk keeps the RTP on G722. Can you provide another pcap just like the one you provided, but also provide the exact Asterisk debug that correlates to it. Make sure that Asterisk debug has the pjsip logger output inline (so we can correlate the packets in the capture to the timing in the log) and the following log levels: notice,warning,error,verbose,debug with verbose and debug both turned up to 5 or higher. https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information Please also attach the complete PJSIP configuration if possible, feel free to sanitize it of confidential info. By: M. Ustermann (Ustermann) 2017-08-31 16:35:49.935-0500 I've uploaded a new file "logs-new-2017-08-31.zip" which contains a packet capture, the asterisk debug log and all non-zero-byte files named pf*conf from /etc/asterisk/. I'm pretty confident I've created it the way you requested. asymmetric_rtp_codec was not set to yes this run, so the symptoms of the test that can be seen in the logs were: No audio can be heard on my side and my audio arrives garbled at the party I've called. By: Rusty Newton (rnewton) 2017-09-01 14:39:11.206-0500 The capture looks pretty much the same in terms of flow. The correlating Asterisk debug shows me that Asterisk seems to be simply ignoring the codec change in the 200 OK SDP from the far end. When that is received I'd expect Asterisk/PJSIP to do something about the fact that we are transmitting in an unsupported codec. Looks like a bug to me. I'm going to open this up. By: Rusty Newton (rnewton) 2017-09-05 18:30:11.446-0500 Can you revert to any commit previous to the commit bc51d4324a69a0b8ee4a3be208b91bb2081124ff and report back if the issue no longer occurs? I'm thinking the root problem here is the same as on ASTERISK-27250 and they are reporting that that commit caused the regression. By: M. Ustermann (Ustermann) 2017-09-05 19:04:24.175-0500 I'm absolutely not able to revert commits... but I was able to downgrade from Asterisk 14.6.0/14.6.1 to 14.5.0 and audio works in both directions with Asterisk 14.5.0 I've also tried Asterisk 13.17.x (doesn't work) and Asterisk 13.16 (works fine). So it was indeed a very recent patch! Most likely the one you suspect? By: Joshua C. Colp (jcolp) 2017-10-20 11:40:59.720-0500 This issue should be resolved in the current release candidates. A fix was put in to resolve an issue where we would not switch our sending codec as expected. Please try and see. By: Joshua C. Colp (jcolp) 2017-12-20 06:11:41.635-0600 Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1]. [1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines By: M. Ustermann (Ustermann) 2017-12-20 11:26:32.175-0600 Sorry for not following up on this bug in a timely manner. Bug seems fixed now when I just tried it with Asterisk 14.7.4... By: Asterisk Team (asteriskteam) 2017-12-20 11:26:32.401-0600 This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable. | ||||