[Home]

Summary:ASTERISK-21323: Asterisk 11 svn branch and srtp - white noise only
Reporter:andrea (sickpig)Labels:
Date Opened:2013-03-27 05:57:11Date Closed:2013-03-27 12:33:18
Priority:CriticalRegression?Yes
Status:Closed/CompleteComponents:Channels/chan_sip/SRTP
Versions:SVN 11.3.0 Frequency of
Occurrence		Constant
Related
Issues:
must be completed before resolvingASTERISK-21004 Open Blockers for 1.8.21.0
must be completed before resolvingASTERISK-21005 Open Blockers for 11.3.0
Environment:ubuntu 12.10 / 12.04 64bitAttachments:( 0) myDebugLog
( 1) sip.conf
( 2) whitenoise_fix.diff
Description:Hi all,



we have just updated our Asterisk 11 testbed from 11.2.1 to 11.3.0-rc1. Now we notice that all sRTP calls fail with “white noise” in the media channel phone > asterisk.



Example 1:



Snom w/ srtp > asterisk > Yealink w/ srtp

Both ends hear “white noise”



Snom w/ srtp > asterisk > Gigaset w/o srtp

Snom hears Gigaset, Gigaset hears white noise.



There have been no other changes to the setup, SIP.conf  specifies



transport=tls

encryption=yes



for the sRTP phones.



Asterisk is linked to libsrtp 1.4.2.



Here is the log (that imho looks good):

\[inline log removed\]
Comments:By: Matt Jordan (mjordan) 2013-03-27 06:18:16.185-0500

We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

Please ensure that you have 'sip set debug on' enabled. Please also include your sip.conf file.
By: andrea (sickpig) 2013-03-27 06:33:38.534-0500

per request of Matt Jordan I've added
a file containing the complete debug log
and my sip.conf
By: andrea (sickpig) 2013-03-27 06:41:27.332-0500

anyway the original report to the dev mailing list
was posted by Martin Koening. It seems he already found
the possible cause of the problem, look at:

http://article.gmane.org/gmane.comp.telephony.pbx.asterisk.devel/56248

he said that:

"Look at the crypto logging. When Asterisk is processing the remote SDP answer,
it is logging his own key and not the one from SDP – I assume that it is then
trying to decode the remote srtp stream with the wrong key, and not with the
proper remote from the SDP. This would explain the white noise."


By: Matt Jordan (mjordan) 2013-03-27 08:47:38.921-0500

My reply :-)

{quote}
> Quick follow-up, I believe that recent changes related to sdp_crypto are
> causing the issue.
>
> Here is another log, Call Flow
>
> Gigaset w/o srtp > Asterisk > snom.
>
> Look at the crypto logging. When Asterisk is processing the remote SDP
> answer, it is logging his own key and not the one from SDP – I assume
> that it is then trying to decode the remote srtp stream with the wrong
> key, and not with the proper remote from the SDP. This would explain the
> white noise.
>
{quote}

Based on the logging statements, I can see how you'd come to that
conclusion. However, I'm not sure that's the case. When a response is
received, it parses out the remote key and uses the already calculated
local key to set the policy in sdp_crypto_activate. As a final activity,
the local key attribute is re-computed.

The first logging statement happens immediately after the SRTP policy
being activated. Oddly, there should be a DEBUG 1 level log statement
indicating that the SRTP policy was activated (from
sdp_crypto_activate), and we shouldn't see "Accepting crypto tag 1" if
sdp_crypto_activate failed. It's possible that the different way in
which the DEBUG log statements are created is causing the difference
here (ast_debug(1, ...) versus ast_log(LOG_DEBUG, ...)).

{quote}
>
> [Mar 20 16:31:27] DEBUG[13795][C-00000002] sip/sdp_crypto.c: Accepting
> crypto tag 1
{quote}

This particular statement is the re-computing of the local key. It isn't
the key computed for the remote policy.

{quote}
> [Mar 20 16:31:27] DEBUG[13795][C-00000002] sip/sdp_crypto.c: Crypto
> line: a=crypto:1 AES_CM_128_HMAC_SHA1_80
> inline:cEglQBq1wgUwFUV6Wg++6QzqZ0tUlSmA1hZSkmhE
>
{quote}

All of that aside, getting 'white noise' is odd. In general, when we
have a mismatch in keys, you will get a lot of 'unprotect' failures in
Asterisk as it attempts to unprotect the inbound SRTP and fails. Did you
see any such failures?

Or is it the other way around, where Asterisk is successfully decoding
the inbound SRTP but failing to successfully transmit SRTP to the device?

-------------------

If we had the crypto keys reversed or used the wrong crypto key in an SRTP policy, you'd see a *lot* of unprotect warnings. The remote end would attempt to send us with what it thought was the agreed upon key, but we'd use the wrong key to unprotect it.

While there is certainly something wrong going on here, it feels like it's caused by something else.
By: Kinsey Moore (kmoore) 2013-03-27 10:24:16.494-0500

Attached diff that fixes the bug for my reproduction.  The change still needs to be verified to be correct (it looks OK according to the SRTP, RTP, STUN, and TURN RFCs I've looked at so far).
By: Matt Jordan (mjordan) 2013-03-27 10:34:51.684-0500

FYI, the problem is r378555, which attempted to prevent unprotecting non-RTP packets (STUN, etc.) It looks like it's just throwing away all packets instead.