[Freeswitch-users] WSS SSL errors "decryption failed or bad record mac" under load

Fri May 12 17:51:23 UTC 2017

Thanks Michael,

I am more then happy to setup something with libks if needed.

I have figured out some more however.  It appears that this only happens
when a wss connections session has not fully established and is cleaning up
because of timing out.  The problem is that it causes another wss
connection it to get this ssl error, even if that other wss connection has
a fully established and running audio session.  It is important to note it
does not seem to interrupt audio just the wss sip channel, which I am
fairly sure can be reestablished for that audio session w/o an issue.

The sessions that is being cleaned up sends the logs messages as its doing
it:
2017-05-12 17:32:46.607768 [NOTICE] sofia.c:8438 Hangup
sofia/websocket/nobody at 1LF3F6I924P9WH6U [CS_EXECUTE] [NORMAL_UNSPECIFIED]
2017-05-12 17:32:46.627768 [INFO] conference_loop.c:1621 Channel leaving
conference, cause: NORMAL_UNSPECIFIED
2017-05-12 17:32:46.627768 [NOTICE] switch_core_session.c:1730 Session 46
(sofia/websocket/nobody at 1LF3F6I924P9WH6U) Ended
2017-05-12 17:32:46.627768 [NOTICE] switch_core_session.c:1734 Close
Channel sofia/websocket/nobody at 1LF3F6I924P9WH6U [CS_DESTROY]

I have attached the updated python script, it can duplicate this every time
now with only 2 connections.  I verified with a webRTC client that if I
initiate this first connection in the script, let it close, then connect
the webRTC client and get full audio, once the first session from the
script times out it causes the webRTC wss connection to get an error and
close.

The webRTC connection is in chrome with sip.js.

Sorry the python script is so nasty, was working through any possible
duplicated sip session stuff in it to make sure that was not why it was
hitting the second connection.

On Fri, May 12, 2017 at 10:20 AM, Michael Jerris <mike at jerris.com> wrote:

> test on master.. work a similar test for verto maybe, this might have to
> do with sip specifically trying to keep state.  Might make sense to build
> something out of libks as it has basically the same web socket code, and
> has both client and server web socket support in it, to do a “real” test”,
> instead of this fake sip without any state over web sockets.
>
>
> On May 12, 2017, at 11:42 AM, Luke Wahlmeier <lwahlmeier at gmail.com> wrote:
>
> Just got done testing this on v1.6 head and master, both seem to still
> have this issue.  This box is using libssl version 1.0.1t-1+deb8u6.  I am
> gonna start digging more into the ws/wss/sofia code to see if I can figure
> it out.  Any suggestions on debugging this would be appreciated.
>
> Thanks
> Luke
>
> On Thu, May 11, 2017 at 5:12 PM, Luke Wahlmeier <lwahlmeier at gmail.com>
> wrote:
>
>> Its just in our isolated lab, pretty normal dell xeon server running
>> Jessie 8.6.  I just want to get it building on the same box I am testing
>> with so setting that all up.
>>
>> I was able to reproduce it w/o DTLS/Srtp.  here is a much simpler and
>> cleaned up version of the python script.
>>
>>
>>
>> On Thu, May 11, 2017 at 4:34 PM, Michael Jerris <mike at jerris.com> wrote:
>>
>>> what is “this environment” ?
>>>
>>> On May 11, 2017, at 6:31 PM, Luke Wahlmeier <lwahlmeier at gmail.com>
>>> wrote:
>>>
>>> Yeah I can usually get it to happen within about 5 minutes or so of
>>> testing.  Still getting all setup to build freeswitch in this environment,
>>> but I should have it working by tomorrow.  I will try more w/o dtls/srtp as
>>> well and make sure it does not need to be on.
>>>
>>> Thanks
>>> Luke
>>>
>>> On Thu, May 11, 2017 at 4:20 PM, Michael Jerris <mike at jerris.com> wrote:
>>>
>>>> if you can reproduce this reliably, i’d try master as well.  Unless
>>>> this is a bug in openssl, i can’t imagine how dtls would come into play in
>>>> something like this.
>>>>
>>>> > On May 11, 2017, at 5:48 PM, Luke Wahlmeier <lwahlmeier at gmail.com>
>>>> wrote:
>>>> >
>>>> > I keep semi-regularly running into issues using the wss transport
>>>> when using dtls/strp/ice.  This is on the latest 1.6.17~34~0fc0946 on
>>>> Debian jessie, but I am pretty sure it was happening on the last couple
>>>> releases as well.
>>>> >
>>>> > It seems like something bad/wrong happens to the encrypted data going
>>>> over the websocket coming from freeswitch when more then 1 websocket
>>>> connection are going and so far ice/srtp/dtls also seem to be needed in the
>>>> invite to duplicate it.
>>>> >
>>>> > I have tried many different languages and network/ssl stacks and keep
>>>> running into this.  It is always on data coming in from freeswitch on the
>>>> websocket connection, and its very very random.  Sometimes I will get it 20
>>>> times in a row, other times it takes thousands of connections/sessions
>>>> before it happen.  It also, obviously, completely goes away if I use plain
>>>> ws instead wss.
>>>> >
>>>> > Here are the errors:
>>>> > python:
>>>> > SSLError: [SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption
>>>> failed or bad record mac (_ssl.c:1750)
>>>> > c/c++ (stunnel4):
>>>> > SSL_read: 1408F119: error:1408F119:SSL routines:SSL3_GET_RECORD:decryption
>>>> failed or bad record mac
>>>> > Java:
>>>> > java.lang.IllegalArgumentException: Bad arguments
>>>> >     at javax.crypto.Mac.update(Mac.java:509)
>>>> >     at sun.security.ssl.MAC.compute(MAC.java:135)
>>>> >     at sun.security.ssl.InputRecord.checkMacTags(InputRecord.java:2
>>>> 65)
>>>> >     at sun.security.ssl.InputRecord.decrypt(InputRecord.java:216)
>>>> >     at sun.security.ssl.EngineInputRecord.decrypt(EngineInputRecord
>>>> .java:177)
>>>> >     at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java
>>>> :974)
>>>> >     at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.j
>>>> ava:907)
>>>> >     at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
>>>> >     at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
>>>> >
>>>> > Attached are a simple python script to do the load, my dialplan and
>>>> sip_profile.  The python script can take a few runs before it see the
>>>> error, and I know its not completing the sip or rtp, but even if it does
>>>> this still happens.
>>>> >
>>>> > I have also looked at libsofia-sip-ua/tport/ws.c and I dont see
>>>> anything obvious.  I am getting setup to build v1.6 head and test this any
>>>> guidance on ways I can trouble shoot this better or requests for more info
>>>> are very welcome.
>>>> >
>>>>
>>>
>>>
>>> ____________________________________________________________
>>> _____________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://confluence.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>
>>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20170512/fe6786fd/attachment-0001.html 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: load.py
Type: text/x-python
Size: 2976 bytes
Desc: not available
Url : http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20170512/fe6786fd/attachment-0001.py 