| Summary: | ASTERISK-27826: res_rtp_asterisk: DTLS negotiation fails when it should succeed, causing SRTP failure | ||||
| Reporter: | Mikhail Ivanov (mivanov@lanta-net.ru) | Labels: | fax pjsip webrtc | ||
| Date Opened: | 2018-04-24 22:24:16 | Date Closed: | 2019-07-11 07:29:12 | ||
| Priority: | Major | Regression? | |||
| Status: | Closed/Complete | Components: | Resources/res_rtp_asterisk | ||
| Versions: | 15.3.0 | Frequency of Occurrence | Constant | ||
| Related Issues: |
| ||||
| Environment: | Attachments: | ( 0) 1205-5191-01.pcap ( 1) 1205-5191-02.pcap ( 2) app_install_list.txt ( 3) asterisk_config_log.txt ( 4) asterisk-console-latest-call.log ( 5) b6-19-09-2018-asterisk-debug.log ( 6) b6-19-09-2018-asterisk-side.pcap ( 7) b6-19-09-2018-chrome-logs.log ( 8) b6-19-09-2018-chrome-side.pcap ( 9) bad_call.mp3 (10) chrome_bad_call_log.txt (11) chrome-debug-latest-call.log (12) chrome-logs.txt (13) config.log (14) dump (15) dump.pcap (16) fragment (17) good_call.mp3 (18) installed.txt (19) res_srtp.txt (20) res_srtp.txt (21) webrtc-at-asterisk-latest.pcap (22) webrtc-at-asterisk-latest-udp-only.pcap (23) webrtc-at-chrome-latest.pcap | |||
| Description: | I have a problem with incoming (may be with outgoing too, not sure) calls to WebRTC clients (based on jssip.net library)
Sometimes (2-5% of all incoming calls) I have no sound (on both sides) on incoming calls. RTP is going fine in both sides (local network) If I turn on mixMonitor on Asterisk, I can see only noise in call (looks like a problem with srtp keys, but not sure) https://www.dropbox.com/s/41nmwqhg0chcwl7/cf626000ac4601445d6cee3cd909188d.mp3?dl=1 Asterisk 15.3.0, JsSIP 3.2.8, tested in Chrome, Chromium and Firefox If I turn off rtp encryption webrtc = no rtcp_mux = yes use_avpf = yes ice_support = yes media_encryption = no and --disable-webrtc-encryption in Chrome (Chromium) everything is fine, yes, it's workaround but not a solution | ||||
| Comments: | By: Asterisk Team (asteriskteam) 2018-04-24 22:24:17.212-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: George Joseph (gjoseph) 2018-04-25 09:12:27.228-0500 We haven't seen any WebRTC issues related to encryption lately. What OS/Distribution are you running and what version of libsrtp do you have? By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-04-25 09:17:11.812-0500 Debian 8 with stock libsrtp By: George Joseph (gjoseph) 2018-04-25 13:48:06 Sorry, I don't know what "stock" is for Debian 8. If it's less than 1.5.4, you should build libsrtp from source. https://wiki.asterisk.org/wiki/display/AST/libsrtp By: Malcolm Davenport (mdavenport) 2018-04-25 13:51:42.247-0500 https://packages.debian.org/jessie/libsrtp0-dev says it's 1.4.5. Too old, by the version number. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-04-25 21:47:15.344-0500 Rebuilding with latest (from git) libsrtp doesn't help. Same issue: 1 per 25-30 calls with silence on both ends and ugly noise in record (mixmonitor) By: George Joseph (gjoseph) 2018-04-26 11:41:16.783-0500 Are there WebRTC clients on both legs of the call? Can you reproduce the issue with calls from a WebRTC client to a simple "Playback" in the dialplan or a normal SIP phone? I'm going to try and reproduce. Also, can you rep[roduce using any of the sample clients that use jssip.net? If so, which one? By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-04-26 11:52:51.841-0500 No, in my case it reproduced in calls from "normal" phones like cisco 7906 and "one leg" (moh) calls like this: app.startmusiconhold() while true do app.wait(1) end By: George Joseph (gjoseph) 2018-04-26 12:56:23.956-0500 OK, so a simple webrtc -> MOH has the issue? What codecs are enabled for the webrtc client and what format are the MOH files? Actually, if you can give me the full output of "pjsip show endpoint <webrtc_client>" that would help greatly. Also if possible, can you get a witeshark capture of both the SIP and RTP flow? I know it's encrypted but I want to look at the TLS/DTLS exchange. At the same time, if you can get the output from "pjsip set logger <host>", where <host> is the webrtc client, that'd help as well. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-04-26 13:11:03.989-0500 yes alaw only asterisk*CLI> pjsip show endpoint 5191 Endpoint: <Endpoint/CID.....................................> <State.....> <Channels.> I/OAuth: <AuthId/UserName...........................................................> Aor: <Aor............................................> <MaxContact> Contact: <Aor/ContactUri..........................> <Hash....> <Status> <RTT(ms)..> Transport: <TransportId........> <Type> <cos> <tos> <BindAddress..................> Identify: <Identify/Endpoint.........................................................> Match: <criteria.........................> Channel: <ChannelId......................................> <State.....> <Time.....> Exten: <DialedExten...........> CLCID: <ConnectedLineCID.......> ========================================================================================== Endpoint: 5191/5191 Not in use 0 of inf OutAuth: 5191/5191 InAuth: 5191/5191 Aor: 5191 1 Contact: 5191/sip:qv1njbdk@127.0.0.1:57521;transpor e27cb64e55 Unknown nan ParameterName : ParameterValue ==================================================================== 100rel : yes accountcode : acl : aggregate_mwi : true allow : (alaw) allow_overlap : true allow_subscribe : true allow_transfer : true aors : 5191 asymmetric_rtp_codec : false auth : 5191 bind_rtp_to_media_address : false bundle : true call_group : callerid : "М. Иванов" <5191> callerid_privacy : allowed_not_screened callerid_tag : connected_line_method : invite contact_acl : context : default cos_audio : 0 cos_video : 0 device_state_busy_at : 0 direct_media : false direct_media_glare_mitigation : none direct_media_method : invite disable_direct_media_on_nat : false dtls_auto_generate_cert : No dtls_ca_file : dtls_ca_path : dtls_cert_file : /etc/asterisk/keys/asterisk.pem dtls_cipher : dtls_fingerprint : SHA-256 dtls_private_key : /etc/asterisk/keys/asterisk.key dtls_rekey : 0 dtls_setup : actpass dtls_verify : Yes dtmf_mode : rfc4733 fax_detect : false fax_detect_timeout : 0 force_avp : false force_rport : true from_domain : from_user : g726_non_standard : false ice_support : true identify_by : username,ip inband_progress : false incoming_mwi_mailbox : language : mailboxes : max_audio_streams : 1 max_video_streams : 1 media_address : media_encryption : dtls media_encryption_optimistic : false media_use_received_transport : true message_context : moh_passthrough : false moh_suggest : default mwi_from_user : mwi_subscribe_replaces_unsolicited : false named_call_group : named_pickup_group : notify_early_inuse_ringing : false one_touch_recording : false outbound_auth : 5191 outbound_proxy : pickup_group : preferred_codec_only : false record_off_feature : automixmon record_on_feature : automixmon refer_blind_progress : true rewrite_contact : false rpid_immediate : false rtcp_mux : true rtp_engine : asterisk rtp_ipv6 : false rtp_keepalive : 0 rtp_symmetric : true rtp_timeout : 0 rtp_timeout_hold : 0 sdp_owner : - sdp_session : Asterisk send_diversion : true send_pai : false send_rpid : false set_var : srtp_tag_32 : false sub_min_expiry : 0 subscribe_context : t38_udptl : false t38_udptl_ec : none t38_udptl_ipv6 : false t38_udptl_maxdatagram : 0 t38_udptl_nat : false timers : yes timers_min_se : 90 timers_sess_expires : 1800 tone_zone : tos_audio : 0 tos_video : 0 transport : trust_id_inbound : false trust_id_outbound : false use_avpf : true use_ptime : false user_eq_phone : false voicemail_extension : webrtc : yes asterisk*CLI> SIP and RTP I'll try to capture tomorrow.... By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-04-27 03:45:54.971-0500 broken call is 1524818419.6358 By: Joshua C. Colp (jcolp) 2018-05-15 02:59:43.063-0500 Can you please also provide the Asterisk console output with debug enabled (debug to console in logger.conf and core set debug 9 done on CLI) for a failing call? As well what are each IP address? What is client and which is Asterisk? It does appear as though the DTLS negotiation is failing, but the trace itself does not indicate a reason why. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-05-15 18:50:03.777-0500 192.168.0.94 is Asterisk By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-05-15 19:14:28.409-0500 1526428919.2046 is broken call By: Richard Mudgett (rmudgett) 2018-05-21 17:31:09.510-0500 This may be a duplicate of ASTERISK-27795 and ASTERISK-27800. By: Joshua C. Colp (jcolp) 2018-06-05 04:51:53.811-0500 I think we're also going to need the browser side as the trace and Asterisk side doesn't provide the full picture and the needed information to understand precisely what is going on. Passing the following arguments to Chrome will spit out all the WebRTC debugging and may provide the information, please attach it as a text file: {{--enable-logging --v=1 --vmodule=\*/webrtc/\*=2,\*=-2 --enable-logging=stderr}} By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-06-05 04:59:22.494-0500 bad call logs from console By: Joshua C. Colp (jcolp) 2018-06-05 05:04:39.685-0500 I've accepted this issue but I have no timeframe on when it will get looked into. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-06-05 05:07:11.339-0500 How can I help? More logs? By: Joshua C. Colp (jcolp) 2018-06-05 05:08:27.937-0500 I've asked for everything that is necessary. It now needs someone to look deeply into it and figure out what is going on. By: Abhay Gupta (agupta) 2018-07-19 04:23:54.432-0500 We also have the same issue and in asterisk 15.5.0 as well . By: Abhay Gupta (agupta) 2018-09-11 22:22:29.341-0500 Have we got a chance to see this and any pointers that can be given to solve the issue ? By: Joshua C. Colp (jcolp) 2018-09-12 04:12:21.851-0500 There is no update on this issue and noone is working on it. By: Sean Bright (seanbright) 2018-09-16 05:57:40.495-0500 [~mivanov@lanta-net.ru], please attach the following (As {{.txt}} files): - {{config.log}} from your Asterisk build directory - The output of {{apt list --installed}} - The output of {{ldd /usr/lib/asterisk/modules/res_srtp.so}} [~agupta], if you are on Debian/Ubuntu, please do the same. By: Abhay Gupta (agupta) 2018-09-16 11:24:35.724-0500 All the files attached as asked for . By: Sean Bright (seanbright) 2018-09-16 14:39:30.019-0500 [~agupta], a pcap of the UDP traffic of a failing call and a working call would go a long way so that we can see why the DTLS is failing. The pcap's that are attached only include the SIP/TCP side. FWIW, I've been trying to reproduce this locally for the last day or so but have been unable to. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-17 01:32:39.719-0500 Latest call is "bad", all others are "good" :) By: Mohd Yusuf Siddiqui (yusufdel) 2018-09-17 03:26:08.716-0500 @Mikhail Only 'bad' is required,quite rare in civilized world :-) By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-17 10:42:30.023-0500 You can try jssip code at https://tryit.jssip.net just make extension at your asterisk and make 30-100 calls to it... By: Sean Bright (seanbright) 2018-09-17 11:40:05.268-0500 [~mivanov@lanta-net.ru], got it. Thanks. By: Sean Bright (seanbright) 2018-09-17 14:49:19.152-0500 I have tried _at least_ 100 calls and have been unable to reproduce, so this is what we need to move this forward: # Packet capture with all traffic # Asterisk console output with debug at level 9 and {{pjsip set logger on}} _- We need to be able to see all of the signalling and a pcap is not going to show us that_ # chrome_debug.txt All 3 of these need to include the same failing call in order to be able to correlate the information between them. Additionally - this should be done against either the Asterisk 15 branch from Git, or the latest Asterisk 15 release which is 15.6.0. If you cannot upgrade to that, please indicate the exact output of {{core show version}}. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-18 00:35:46.721-0500 asterisk-console-latest-call.log - output from asterisk with "pjsip set logger on" and "core set debug 9" (asterisk 15.6.0) chrome-debug-latest-call.log - output from konsole with chrome running webrtc-at-asterisk-latest.pcap - dump from asterisk webrtc-at-chrome-latest.pcap - same time dump from my PC By: Abhay Gupta (agupta) 2018-09-18 01:10:20.245-0500 @Mikhail I think you have not enabled debug message in logger.conf on console as no debug messages are present in asterisk-console-latest-call.log which has only pjsip messages . By: Abhay Gupta (agupta) 2018-09-18 01:55:17.185-0500 The error on chrome shows srtp_err_status_auth_fail = 7, /**< authentication failure*/ Does this mean there is a issue with asterisk corrupting the RTP packets in certain case By: Sean Bright (seanbright) 2018-09-18 09:29:07.196-0500 [~mivanov@lanta-net.ru], out of curiosity - are you able to reproduce using ulaw instead of alaw? By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-18 09:37:06.479-0500 yes, I can :) but as I remember I was try alaw, ulaw and opus with same result. tomorrow (at morning) I'll try to do it with ulaw and full logs from asterisk By: Sean Bright (seanbright) 2018-09-18 09:40:52.228-0500 Attached [^webrtc-at-asterisk-latest-udp-only.pcap] which is just the UDP traffic from [^webrtc-at-asterisk-latest.pcap]. By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-19 00:06:49.694-0500 Hope this helps.... By: Abhay Gupta (agupta) 2018-09-25 06:47:20.044-0500 Looks like this problem will not have a solution soon , do we have a alternate as i am unable to start chrome with -disable-webrtc-encryption in released versions . Mikhail can you help pls By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-25 08:28:36.599-0500 How can I help? By: Abhay Gupta (agupta) 2018-09-25 09:06:18.090-0500 Are you using Canary or Dev build of chrome or have found a way to turn off rtp encryption in stable release . Since i am not able to disable rtp encryption and i am using stable release of chrome . By: Mikhail Ivanov (mivanov@lanta-net.ru) 2018-09-25 09:20:51.852-0500 https://i.imgur.com/rYpWKE6.png By: Abhay Gupta (agupta) 2018-12-12 02:01:32.031-0600 Mikhail i have observed then on a test server when i make any number of calls and no other concurrent calls are going on i am not able to generate the problem , moreover i observed that in the attached pcap's it seems problem comes when we have have two calls at the same time . Can you confirm if it is indeed the case as i am observing this more frequently on production servers . By: Abhay Gupta (agupta) 2019-03-18 05:46:05.967-0500 6 months down the line , did anyone got a chance to look at the issue and provide resolution . By: Joshua C. Colp (jcolp) 2019-03-18 05:59:20.716-0500 [~agupta] If there were any updates or things, they would be on this issue. By: Abhay Gupta (agupta) 2019-05-03 04:29:37.674-0500 I was checking one of the PCAP of 19th sep and on analysing on wireshark i saw that while chrome is saying Failed to unprotect RTP packet: size=172, seqnum=13388, SSRC=135391816 The data on wireshark is indeed a invalid data and is not even detected as a RTP and in fact the data is 80:00:34:a2:18:81:88:40:08:11:ea:48:7e:65:74:ed:5d:5f:70:70:ed:ef:6c:6b:61:6b:ec:f2:f0:de:d7:eb:60:59:5e:6f:63:5a:78:e9:78:e1:f0:69:f6:f6:db:dc:ef:d6:fa:4d:54:58:fc:d0:d2:ce:de:6b:64:4f:59:72:50:45:48:58:6a:e5:f2:f6:cf:cd:cc:ce:cf:db:6a:66:58:5c:56:4f:5f:63:f2:eb:76:e1:dd:fa:78:6f:5e:7a:fc:6c:7c:6d:69:57:55:5c:5b:ed:db:d7:d4:dd:e2:ed:72:5b:5e:eb:e8:ed:e6:f0:7a:72:5e:74:e8:fe:7a:7c:78:5c:50:59:64:70:e2:de:fc:67:61:6a:70:fe:74:72:e5:e8:f6:72:5f:68:6f:f8:f6:7e:ec:f8:f6:f4:fa:7c:76:ef:ef:eb:fa:70:fe:69:5f:67:6f:f4 Now chrome is sending the right data but the recording shows that instead of decrypting , the encrypted data itself is recorded leading to noise in recording . By: Abhay Gupta (agupta) 2019-06-10 08:00:04.602-0500 Have found out that we do not get the following Debug line in case of call with a issue res_srtp.c: Adding new policy for SSRC In successful call we have the following sequence 1. On DailBegin we get DEBUG[24451] res_srtp.c: local_key64 rp9hxgtp0q3LwWW5XlNnnRgYNbuEHn0dA81+cs6e len 40 2. On DialEnd and answer we get DEBUG[32672] res_srtp.c: Adding new policy for SSRC 400086938 On problem call we do not get the line Adding new policy as in point 2 but we do get local_key64 line . By: Abhay Gupta (agupta) 2019-06-17 03:29:12.675-0500 Hi Mikhail , Finally the issue of this garbage voice was solved when we tested Asterisk 16.04 with patch given in the below bug ASTERISK-28018 You can also test and see if that solves the issue for you . By: Abhay Gupta (agupta) 2019-07-11 07:21:29.511-0500 I have tested and this bug is closed via patch of ASTERISK-28018 | ||||