12 May
2017
12 May
'17
6:03 p.m.
Here is the debug logs from this happening: f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [NOTICE] switch_channel.c:1104 New Channel sofia/websocket/nobody@52LX8LP8BBWG6990 [f9a97c98-373b-11e7-9136-499bb33ea37e] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_NEW (Cur 1 Tot 1) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] sofia.c:10028 sofia/websocket/nobody@52LX8LP8BBWG6990 receiving invite from 192.168.56.151:53442 version: 1.9.0 git db24869 2017-05-11 18:22:45Z 64bit f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] sofia.c:11325 Setting NAT mode based on websockets f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@52LX8LP8BBWG6990 entering state [received][100] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] sofia.c:7257 Remote SDP: f9a97c98-373b-11e7-9136-499bb33ea37e v=0 f9a97c98-373b-11e7-9136-499bb33ea37e o=- 196478633 2 IN IP4 192.168.56.151 f9a97c98-373b-11e7-9136-499bb33ea37e s=- f9a97c98-373b-11e7-9136-499bb33ea37e c=IN IP4 192.168.56.151 f9a97c98-373b-11e7-9136-499bb33ea37e t=0 0 f9a97c98-373b-11e7-9136-499bb33ea37e m=audio 42504 RTP/AVP 0 100 f9a97c98-373b-11e7-9136-499bb33ea37e a=rtpmap:0 PCMU/8000 f9a97c98-373b-11e7-9136-499bb33ea37e a=maxptime:20 f9a97c98-373b-11e7-9136-499bb33ea37e f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:5165 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [:100:0:20:0:1]/[PCMU:0:8000:20:64000:1] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:3425 Set Codec sofia/websocket/nobody@52LX8LP8BBWG6990 PCMU/8000 20 ms 160 samples 64000 bits 1 channels f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_codec.c:111 sofia/websocket/nobody@52LX8LP8BBWG6990 Original read codec set to PCMU:0 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:5398 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event. f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_media.c:5427 sofia/websocket/nobody@52LX8LP8BBWG6990 Set 2833 dtmf send payload to 101 recv payload to 101 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] sofia.c:7670 (sofia/websocket/nobody@52LX8LP8BBWG6990) State Change CS_NEW -> CS_INIT f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_state_machine.c:603 (sofia/websocket/nobody@52LX8LP8BBWG6990) State NEW f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_INIT (Cur 1 Tot 1) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_state_machine.c:627 (sofia/websocket/nobody@52LX8LP8BBWG6990) State INIT f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] mod_sofia.c:93 sofia/websocket/nobody@52LX8LP8BBWG6990 SOFIA INIT f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.912851 [DEBUG] switch_core_state_machine.c:40 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard INIT f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:48 (sofia/websocket/nobody@52LX8LP8BBWG6990) State Change CS_INIT -> CS_ROUTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:627 (sofia/websocket/nobody@52LX8LP8BBWG6990) State INIT going to sleep f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_ROUTING (Cur 1 Tot 1) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_channel.c:2249 (sofia/websocket/nobody@52LX8LP8BBWG6990) Callstate Change DOWN -> RINGING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:643 (sofia/websocket/nobody@52LX8LP8BBWG6990) State ROUTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] mod_sofia.c:154 sofia/websocket/nobody@52LX8LP8BBWG6990 SOFIA ROUTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:236 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard ROUTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [INFO] mod_dialplan_xml.c:637 Processing unknown <>->52LX8LP8BBWG6990 in context wss-dialplan f9a97c98-373b-11e7-9136-499bb33ea37e Dialplan: sofia/websocket/nobody@52LX8LP8BBWG6990 parsing [wss-dialplan->wss-dialplan] continue=false f9a97c98-373b-11e7-9136-499bb33ea37e Dialplan: sofia/websocket/nobody@52LX8LP8BBWG6990 Regex (PASS) [wss-dialplan] destination_number(52LX8LP8BBWG6990) =~ /.+/ break=on-false f9a97c98-373b-11e7-9136-499bb33ea37e Dialplan: sofia/websocket/nobody@52LX8LP8BBWG6990 Action conference(test123) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:286 (sofia/websocket/nobody@52LX8LP8BBWG6990) State Change CS_ROUTING -> CS_EXECUTE f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:643 (sofia/websocket/nobody@52LX8LP8BBWG6990) State ROUTING going to sleep f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_EXECUTE (Cur 1 Tot 1) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:650 (sofia/websocket/nobody@52LX8LP8BBWG6990) State EXECUTE f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] mod_sofia.c:209 sofia/websocket/nobody@52LX8LP8BBWG6990 SOFIA EXECUTE f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_state_machine.c:328 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard EXECUTE f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_session.c:2707 Application conference Requires media! pre_answering channel sofia/websocket/nobody@52LX8LP8BBWG6990 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [INFO] switch_core_session.c:2709 Sending early media f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_media.c:8144 AUDIO RTP [sofia/websocket/nobody@52LX8LP8BBWG6990] 172.16.19.215 port 27662 -> 192.168.56.151 port 42504 codec: 0 ms: 20 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_media.c:8447 sofia/websocket/nobody@52LX8LP8BBWG6990 Set 2833 dtmf send payload to 101 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_media.c:8454 sofia/websocket/nobody@52LX8LP8BBWG6990 Set 2833 dtmf receive payload to 101 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_media.c:8477 sofia/websocket/nobody@52LX8LP8BBWG6990 Set rtp dtmf delay to 40 f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] mod_sofia.c:2512 Ring SDP: f9a97c98-373b-11e7-9136-499bb33ea37e v=0 f9a97c98-373b-11e7-9136-499bb33ea37e o=FreeSWITCH 1494583976 1494583977 IN IP4 172.16.19.215 f9a97c98-373b-11e7-9136-499bb33ea37e s=FreeSWITCH f9a97c98-373b-11e7-9136-499bb33ea37e c=IN IP4 172.16.19.215 f9a97c98-373b-11e7-9136-499bb33ea37e t=0 0 f9a97c98-373b-11e7-9136-499bb33ea37e m=audio 27662 RTP/AVP 0 101 f9a97c98-373b-11e7-9136-499bb33ea37e a=rtpmap:0 PCMU/8000 f9a97c98-373b-11e7-9136-499bb33ea37e a=rtpmap:101 telephone-event/8000 f9a97c98-373b-11e7-9136-499bb33ea37e a=fmtp:101 0-16 f9a97c98-373b-11e7-9136-499bb33ea37e a=ptime:20 f9a97c98-373b-11e7-9136-499bb33ea37e a=sendrecv f9a97c98-373b-11e7-9136-499bb33ea37e f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [NOTICE] mod_sofia.c:2515 Pre-Answer sofia/websocket/nobody@52LX8LP8BBWG6990! f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_channel.c:3481 (sofia/websocket/nobody@52LX8LP8BBWG6990) Callstate Change RINGING -> EARLY f9a97c98-373b-11e7-9136-499bb33ea37e EXECUTE sofia/websocket/nobody@52LX8LP8BBWG6990 conference(test123) f9a97c98-373b-11e7-9136-499bb33ea37e v=0 f9a97c98-373b-11e7-9136-499bb33ea37e o=FreeSWITCH 1494583976 1494583978 IN IP4 172.16.19.215 f9a97c98-373b-11e7-9136-499bb33ea37e s=FreeSWITCH f9a97c98-373b-11e7-9136-499bb33ea37e c=IN IP4 172.16.19.215 f9a97c98-373b-11e7-9136-499bb33ea37e t=0 0 f9a97c98-373b-11e7-9136-499bb33ea37e m=audio 27662 RTP/AVP 0 101 f9a97c98-373b-11e7-9136-499bb33ea37e a=rtpmap:0 PCMU/8000 f9a97c98-373b-11e7-9136-499bb33ea37e a=rtpmap:101 telephone-event/8000 f9a97c98-373b-11e7-9136-499bb33ea37e a=fmtp:101 0-16 f9a97c98-373b-11e7-9136-499bb33ea37e a=ptime:20 f9a97c98-373b-11e7-9136-499bb33ea37e a=sendrecv f9a97c98-373b-11e7-9136-499bb33ea37e f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@52LX8LP8BBWG6990 entering state [early][183] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [NOTICE] mod_conference.c:1829 Channel [sofia/websocket/nobody@52LX8LP8BBWG6990] has been answered f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_channel.c:3780 (sofia/websocket/nobody@52LX8LP8BBWG6990) Callstate Change EARLY -> ACTIVE f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@52LX8LP8BBWG6990 entering state [completed][200] 2017-05-12 17:53:58.932851 [DEBUG] mod_conference.c:3289 using channel sound prefix: /tmp/fs1.8/share/freeswitch/sounds/en/us/callie f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] conference_member.c:1715 Raw Codec Activation Success L16@8000hz 1 channel 20ms f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] conference_member.c:1762 Raw Codec Activation Success L16@8000hz 1 channel 20ms f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] switch_core_codec.c:223 sofia/websocket/nobody@52LX8LP8BBWG6990 Push codec L16:100 2017-05-12 17:53:58.932851 [DEBUG] mod_conference.c:227 Setup timer success interval: 20 samples: 160 2017-05-12 17:53:58.932851 [ERR] switch_core_video.c:2868 This function is not available, libpng not installed f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:53:58.932851 [DEBUG] conference_loop.c:1306 Setup timer soft success interval: 20 samples: 160 from codec PCMU 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [NOTICE] switch_channel.c:1104 New Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W [02b30be2-373c-11e7-913a-499bb33ea37e] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_NEW (Cur 2 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:10028 sofia/websocket/nobody@3PXT9NIJPMV6KC8W receiving invite from 192.168.56.151:53568 version: 1.9.0 git db24869 2017-05-11 18:22:45Z 64bit 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:11325 Setting NAT mode based on websockets 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W entering state [received][100] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:7257 Remote SDP: 02b30be2-373c-11e7-913a-499bb33ea37e v=0 02b30be2-373c-11e7-913a-499bb33ea37e o=- 716582477 2 IN IP4 192.168.56.151 02b30be2-373c-11e7-913a-499bb33ea37e s=- 02b30be2-373c-11e7-913a-499bb33ea37e c=IN IP4 192.168.56.151 02b30be2-373c-11e7-913a-499bb33ea37e t=0 0 02b30be2-373c-11e7-913a-499bb33ea37e m=audio 11866 RTP/AVP 0 100 02b30be2-373c-11e7-913a-499bb33ea37e a=rtpmap:0 PCMU/8000 02b30be2-373c-11e7-913a-499bb33ea37e a=maxptime:20 02b30be2-373c-11e7-913a-499bb33ea37e 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:5165 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:5110 Audio Codec Compare [:100:0:20:0:1]/[PCMU:0:8000:20:64000:1] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:3425 Set Codec sofia/websocket/nobody@3PXT9NIJPMV6KC8W PCMU/8000 20 ms 160 samples 64000 bits 1 channels 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_codec.c:111 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Original read codec set to PCMU:0 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:5398 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event. 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:5427 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Set 2833 dtmf send payload to 101 recv payload to 101 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:7670 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State Change CS_NEW -> CS_INIT 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:603 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State NEW 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_INIT (Cur 2 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:627 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State INIT 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] mod_sofia.c:93 sofia/websocket/nobody@3PXT9NIJPMV6KC8W SOFIA INIT 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:40 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Standard INIT 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:48 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State Change CS_INIT -> CS_ROUTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:627 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State INIT going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_ROUTING (Cur 2 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_channel.c:2249 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Callstate Change DOWN -> RINGING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:643 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State ROUTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] mod_sofia.c:154 sofia/websocket/nobody@3PXT9NIJPMV6KC8W SOFIA ROUTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:236 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Standard ROUTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [INFO] mod_dialplan_xml.c:637 Processing unknown <>->3PXT9NIJPMV6KC8W in context wss-dialplan 02b30be2-373c-11e7-913a-499bb33ea37e Dialplan: sofia/websocket/nobody@3PXT9NIJPMV6KC8W parsing [wss-dialplan->wss-dialplan] continue=false 02b30be2-373c-11e7-913a-499bb33ea37e Dialplan: sofia/websocket/nobody@3PXT9NIJPMV6KC8W Regex (PASS) [wss-dialplan] destination_number(3PXT9NIJPMV6KC8W) =~ /.+/ break=on-false 02b30be2-373c-11e7-913a-499bb33ea37e Dialplan: sofia/websocket/nobody@3PXT9NIJPMV6KC8W Action conference(test123) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:286 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State Change CS_ROUTING -> CS_EXECUTE 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:643 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State ROUTING going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_EXECUTE (Cur 2 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:650 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State EXECUTE 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] mod_sofia.c:209 sofia/websocket/nobody@3PXT9NIJPMV6KC8W SOFIA EXECUTE 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_state_machine.c:328 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Standard EXECUTE 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_session.c:2707 Application conference Requires media! pre_answering channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [INFO] switch_core_session.c:2709 Sending early media 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:8144 AUDIO RTP [sofia/websocket/nobody@3PXT9NIJPMV6KC8W] 172.16.19.215 port 28858 -> 192.168.56.151 port 11866 codec: 0 ms: 20 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:8447 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Set 2833 dtmf send payload to 101 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:8454 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Set 2833 dtmf receive payload to 101 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_media.c:8477 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Set rtp dtmf delay to 40 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] mod_sofia.c:2512 Ring SDP: 02b30be2-373c-11e7-913a-499bb33ea37e v=0 02b30be2-373c-11e7-913a-499bb33ea37e o=FreeSWITCH 1494582796 1494582797 IN IP4 172.16.19.215 02b30be2-373c-11e7-913a-499bb33ea37e s=FreeSWITCH 02b30be2-373c-11e7-913a-499bb33ea37e c=IN IP4 172.16.19.215 02b30be2-373c-11e7-913a-499bb33ea37e t=0 0 02b30be2-373c-11e7-913a-499bb33ea37e m=audio 28858 RTP/AVP 0 101 02b30be2-373c-11e7-913a-499bb33ea37e a=rtpmap:0 PCMU/8000 02b30be2-373c-11e7-913a-499bb33ea37e a=rtpmap:101 telephone-event/8000 02b30be2-373c-11e7-913a-499bb33ea37e a=fmtp:101 0-16 02b30be2-373c-11e7-913a-499bb33ea37e a=ptime:20 02b30be2-373c-11e7-913a-499bb33ea37e a=sendrecv 02b30be2-373c-11e7-913a-499bb33ea37e 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [NOTICE] mod_sofia.c:2515 Pre-Answer sofia/websocket/nobody@3PXT9NIJPMV6KC8W! 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_channel.c:3481 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Callstate Change RINGING -> EARLY 02b30be2-373c-11e7-913a-499bb33ea37e EXECUTE sofia/websocket/nobody@3PXT9NIJPMV6KC8W conference(test123) 02b30be2-373c-11e7-913a-499bb33ea37e v=0 02b30be2-373c-11e7-913a-499bb33ea37e o=FreeSWITCH 1494582796 1494582798 IN IP4 172.16.19.215 02b30be2-373c-11e7-913a-499bb33ea37e s=FreeSWITCH 02b30be2-373c-11e7-913a-499bb33ea37e c=IN IP4 172.16.19.215 02b30be2-373c-11e7-913a-499bb33ea37e t=0 0 02b30be2-373c-11e7-913a-499bb33ea37e m=audio 28858 RTP/AVP 0 101 02b30be2-373c-11e7-913a-499bb33ea37e a=rtpmap:0 PCMU/8000 02b30be2-373c-11e7-913a-499bb33ea37e a=rtpmap:101 telephone-event/8000 02b30be2-373c-11e7-913a-499bb33ea37e a=fmtp:101 0-16 02b30be2-373c-11e7-913a-499bb33ea37e a=ptime:20 02b30be2-373c-11e7-913a-499bb33ea37e a=sendrecv 02b30be2-373c-11e7-913a-499bb33ea37e 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W entering state [early][183] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [NOTICE] mod_conference.c:1829 Channel [sofia/websocket/nobody@3PXT9NIJPMV6KC8W] has been answered 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_channel.c:3780 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Callstate Change EARLY -> ACTIVE 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W entering state [completed][200] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] conference_member.c:1715 Raw Codec Activation Success L16@8000hz 1 channel 20ms 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] conference_member.c:1762 Raw Codec Activation Success L16@8000hz 1 channel 20ms 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] switch_core_codec.c:223 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Push codec L16:100 2017-05-12 17:54:14.092839 [ERR] switch_core_video.c:2868 This function is not available, libpng not installed 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:14.092839 [DEBUG] conference_loop.c:1306 Setup timer soft success interval: 20 samples: 160 from codec PCMU This is where session 02b30be2-373c-11e7-913a-499bb33ea37e wss socket gets an ssl errror: f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.952843 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@52LX8LP8BBWG6990 entering state [terminating][0] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.952843 [NOTICE] sofia.c:8438 Hangup sofia/websocket/nobody@52LX8LP8BBWG6990 [CS_EXECUTE] [NORMAL_UNSPECIFIED] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [INFO] conference_loop.c:1621 Channel leaving conference, cause: NORMAL_UNSPECIFIED f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] mod_conference.c:2404 sofia/websocket/nobody@52LX8LP8BBWG6990 skip receive message [TRANSFER] (channel is hungup already) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_media.c:11838 sofia/websocket/nobody@52LX8LP8BBWG6990 skip receive message [BITRATE_REQ] (channel is hungup already) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_codec.c:248 sofia/websocket/nobody@52LX8LP8BBWG6990 Restore previous codec PCMU:0. f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_session.c:2884 sofia/websocket/nobody@52LX8LP8BBWG6990 skip receive message [PHONE_EVENT] (channel is hungup already) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:650 (sofia/websocket/nobody@52LX8LP8BBWG6990) State EXECUTE going to sleep f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_HANGUP (Cur 2 Tot 2) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:850 (sofia/websocket/nobody@52LX8LP8BBWG6990) Callstate Change ACTIVE -> HANGUP f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:852 (sofia/websocket/nobody@52LX8LP8BBWG6990) State HANGUP f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] mod_sofia.c:449 Channel sofia/websocket/nobody@52LX8LP8BBWG6990 hanging up, cause: NORMAL_UNSPECIFIED f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:60 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard HANGUP, cause: NORMAL_UNSPECIFIED f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:852 (sofia/websocket/nobody@52LX8LP8BBWG6990) State HANGUP going to sleep f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:619 (sofia/websocket/nobody@52LX8LP8BBWG6990) State Change CS_HANGUP -> CS_REPORTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_REPORTING (Cur 2 Tot 2) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:938 (sofia/websocket/nobody@52LX8LP8BBWG6990) State REPORTING f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:174 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard REPORTING, cause: NORMAL_UNSPECIFIED f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:938 (sofia/websocket/nobody@52LX8LP8BBWG6990) State REPORTING going to sleep f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:610 (sofia/websocket/nobody@52LX8LP8BBWG6990) State Change CS_REPORTING -> CS_DESTROY f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_session.c:1712 Session 1 (sofia/websocket/nobody@52LX8LP8BBWG6990) Locked, Waiting on external entities f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [NOTICE] switch_core_session.c:1730 Session 1 (sofia/websocket/nobody@52LX8LP8BBWG6990) Ended f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [NOTICE] switch_core_session.c:1734 Close Channel sofia/websocket/nobody@52LX8LP8BBWG6990 [CS_DESTROY] f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:741 (sofia/websocket/nobody@52LX8LP8BBWG6990) Running State Change CS_DESTROY (Cur 1 Tot 2) f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:751 (sofia/websocket/nobody@52LX8LP8BBWG6990) State DESTROY f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] mod_sofia.c:354 sofia/websocket/nobody@52LX8LP8BBWG6990 SOFIA DESTROY f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:181 sofia/websocket/nobody@52LX8LP8BBWG6990 Standard DESTROY f9a97c98-373b-11e7-9136-499bb33ea37e 2017-05-12 17:54:30.972859 [DEBUG] switch_core_state_machine.c:751 (sofia/websocket/nobody@52LX8LP8BBWG6990) State DESTROY going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.112842 [DEBUG] sofia.c:7247 Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W entering state [terminating][0] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.112842 [NOTICE] sofia.c:8438 Hangup sofia/websocket/nobody@3PXT9NIJPMV6KC8W [CS_EXECUTE] [NORMAL_UNSPECIFIED] 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [INFO] conference_loop.c:1621 Channel leaving conference, cause: NORMAL_UNSPECIFIED 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] mod_conference.c:2404 sofia/websocket/nobody@3PXT9NIJPMV6KC8W skip receive message [TRANSFER] (channel is hungup already) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_media.c:11838 sofia/websocket/nobody@3PXT9NIJPMV6KC8W skip receive message [BITRATE_REQ] (channel is hungup already) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_codec.c:248 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Restore previous codec PCMU:0. 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_session.c:2884 sofia/websocket/nobody@3PXT9NIJPMV6KC8W skip receive message [PHONE_EVENT] (channel is hungup already) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:650 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State EXECUTE going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_HANGUP (Cur 1 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:850 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Callstate Change ACTIVE -> HANGUP 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:852 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State HANGUP 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] mod_sofia.c:449 Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W hanging up, cause: NORMAL_UNSPECIFIED 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:60 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Standard HANGUP, cause: NORMAL_UNSPECIFIED 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:852 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State HANGUP going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:619 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State Change CS_HANGUP -> CS_REPORTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:584 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Running State Change CS_REPORTING (Cur 1 Tot 2) 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:938 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State REPORTING 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:174 sofia/websocket/nobody@3PXT9NIJPMV6KC8W Standard REPORTING, cause: NORMAL_UNSPECIFIED 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:938 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State REPORTING going to sleep 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_state_machine.c:610 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) State Change CS_REPORTING -> CS_DESTROY 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [DEBUG] switch_core_session.c:1712 Session 2 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Locked, Waiting on external entities 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [NOTICE] switch_core_session.c:1730 Session 2 (sofia/websocket/nobody@3PXT9NIJPMV6KC8W) Ended 02b30be2-373c-11e7-913a-499bb33ea37e 2017-05-12 17:54:46.132852 [NOTICE] switch_core_session.c:1734 Close Channel sofia/websocket/nobody@3PXT9NIJPMV6KC8W [CS_DESTROY] On Fri, May 12, 2017 at 11:51 AM, Luke Wahlmeier <lwahlmeier@gmail.com> wrote: > 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@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@1LF3F6I924P9WH6U) Ended > 2017-05-12 17:32:46.627768 [NOTICE] switch_core_session.c:1734 Close > Channel sofia/websocket/nobody@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@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@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@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@jerris.com> wrote: >>> >>>> what is “this environment” ? >>>> >>>> On May 11, 2017, at 6:31 PM, Luke Wahlmeier <lwahlmeier@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@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@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@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@lists.freeswitch.org >>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users >>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/free >>>> switch-users >>>> http://www.freeswitch.org >>>> >>> >>> >> _________________________________________________________________________ >> Professional FreeSWITCH Consulting Services: >> consulting@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@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@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@lists.freeswitch.org >> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users >> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users >> http://www.freeswitch.org >> > >