Freeeswitch 1.5.8 WebRTC JSSIP to linphone client has no audio or video without bypassing
Hi, I have Installed freeswitch 1.5 from apt-get using freeswitch deb package on debian 7. When I set inbound-bypass-media = true in my sip internal profile. two clients in a local network can connect usingtryit.jssip.net and everything is fine. but calling from jssip to linphone client or linphone to jssip cause INCOMPATIBLE_DESTINATION. And when I remove the inbound-bypass-media = true from my sip profile. both jssip to jssip and jssip to linphon clients connects but there is no audio or video flowing. at first I encountered a DTLS client error and have solved that by creating a certificate and private key for dtls client and putting them in /etc/freeswitch/tls/dtls-srtp.cert and /etc/freeswitch/tls/dtls-srtp.key. here is the log of my freeswitch: 2014-03-02 12:08:09.617836 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/1007@pbx.example.org [c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_NEW 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:7989 sofia/internal/ 1007@pbx.example.org receiving invite from192.168.1.33:51467 version: 1.5.8b+git git 35f2bcc 2014-02-12 23:33:16Z 64bit 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:8095 IP 192.168.1.33 Approved by acl "domains[]". Access Granted. 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:9196 Setting NAT mode based on websockets 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007@pbx.example.org entering state [received][100] 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:5941 Remote SDP: v=0 o=- 6335760585494417936 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video a=msid-semantic: WMS pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB m=audio 62117 RTP/SAVPF 111 103 104 0 8 106 105 13 126 c=IN IP4 192.168.1.33 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=rtcp:62117 IN IP4 192.168.1.33 a=candidate:2608808550 1 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:2608808550 2 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:3590110870 1 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=candidate:3590110870 2 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=ice-ufrag:eJnNnt5asGqM3JCe a=ice-pwd:HkuSIEBjJjxWgaZ0i/XrmPD5 a=ice-options:google-ice a=fingerprint:sha-256 EC:04:9A:9F:88:36:08:4E:7B:7E:45:8C:E7:F1:E2:05:4D:D0:42:2E:C9:C9:68:96:E0:34:B4:E3:7B:99:04:A1 a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:wDS2uKYeEIyjVhWu4X1qrw8ozr/lTWJONcQ4tclN a=maxptime:60 a=ssrc:1877104875 cname:SXJLdFQk+JbMD3lo a=ssrc:1877104875 msid:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB 81cc1301-e200-4127-84b3-468d21652f03 a=ssrc:1877104875 mslabel:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB a=ssrc:1877104875 label:81cc1301-e200-4127-84b3-468d21652f03 m=video 62117 RTP/SAVPF 100 116 117 c=IN IP4 192.168.1.33 a=rtpmap:100 VP8/90000 a=rtpmap:116 red/90000 a=rtpmap:117 ulpfec/90000 a=rtcp:62117 IN IP4 192.168.1.33 a=candidate:2608808550 1 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:2608808550 2 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:3590110870 1 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=candidate:3590110870 2 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=ice-ufrag:eJnNnt5asGqM3JCe a=ice-pwd:HkuSIEBjJjxWgaZ0i/XrmPD5 a=ice-options:google-ice a=fingerprint:sha-256 EC:04:9A:9F:88:36:08:4E:7B:7E:45:8C:E7:F1:E2:05:4D:D0:42:2E:C9:C9:68:96:E0:34:B4:E3:7B:99:04:A1 a=setup:actpass a=mid:video a=extmap:2 urn:ietf:params:rtp-hdrext:toffset a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:wDS2uKYeEIyjVhWu4X1qrw8ozr/lTWJONcQ4tclN a=rtcp-fb:100 ccm fir a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli a=rtcp-fb:100 goog-remb a=ssrc:2204797885 cname:SXJLdFQk+JbMD3lo a=ssrc:2204797885 msid:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB 2b1c7300-8d87-450c-8268-675616f8098a a=ssrc:2204797885 mslabel:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB a=ssrc:2204797885 label:2b1c7300-8d87-450c-8268-675616f8098a 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:6186 (sofia/internal/ 1007@pbx.example.org) State Change CS_NEW -> CS_INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:486 (sofia/internal/1007@pbx.example.org) State NEW 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:507 (sofia/internal/1007@pbx.example.org) State INIT 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:87 sofia/internal/ 1007@pbx.example.org SOFIA INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1007@pbx.example.org Standard INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1007@pbx.example.org) State Change CS_INIT -> CS_ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:507 (sofia/internal/1007@pbx.example.org) State INIT going to sleep 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:2179 (sofia/internal/ 1007@pbx.example.org) Callstate Change DOWN -> RINGING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007@pbx.example.org) State ROUTING 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/ 1007@pbx.example.org SOFIA ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164 sofia/internal/1007@pbx.example.org Standard ROUTING 2014-03-02 12:08:09.617836 [INFO] mod_dialplan_xml.c:558 Processing ehsan <1007>->1009 in context public Dialplan: sofia/internal/1007@pbx.example.org parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [nb_conferences] destination_number(1009) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [public->unloop] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [public->outside_call] continue=true Dialplan: sofia/internal/1007@pbx.example.org Absolute Condition [outside_call] Dialplan: sofia/internal/1007@pbx.example.org Action set(outside_call=true) Dialplan: sofia/internal/1007@pbx.example.org Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1007@pbx.example.org parsing [public->call_debug] continue=true Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1007@pbx.example.org parsing [public->public_extensions] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [public_extensions] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org Action transfer(1009 XML default) 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:214 (sofia/internal/1007@pbx.example.org) State Change CS_ROUTING -> CS_EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007@pbx.example.org) State ROUTING going to sleep 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1007@pbx.example.org) State EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/ 1007@pbx.example.org SOFIA EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256 sofia/internal/1007@pbx.example.org Standard EXECUTE EXECUTE sofia/internal/1007@pbx.example.org set(outside_call=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [outside_call]=[true] EXECUTE sofia/internal/1007@pbx.example.org export(RFC2822_DATE=Sun, 02 Mar 2014 12:08:09 +0330) 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] EXECUTE sofia/internal/1007@pbx.example.org transfer(1009 XML default) 2014-03-02 12:08:09.617836 [DEBUG] switch_ivr.c:1832 (sofia/internal/ 1007@pbx.example.org) State Change CS_EXECUTE -> CS_ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [NOTICE] switch_ivr.c:1839 Transfer sofia/internal/1007@pbx.example.org to XML[1009@default] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1007@pbx.example.org) State EXECUTE going to sleep 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007@pbx.example.org) State ROUTING 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/ 1007@pbx.example.org SOFIA ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164 sofia/internal/1007@pbx.example.org Standard ROUTING 2014-03-02 12:08:09.617836 [INFO] mod_dialplan_xml.c:558 Processing ehsan <1007>->1009 in context default Dialplan: sofia/internal/1007@pbx.example.org parsing [default->unloop] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->tod_example] continue=true Dialplan: sofia/internal/1007@pbx.example.org Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1007@pbx.example.org Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [global-intercept] destination_number(1009) =~ /^886$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [group-intercept] destination_number(1009) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [intercept-ext] destination_number(1009) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->redial] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [redial] destination_number(1009) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->global] continue=true Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [global] ${switch_r_sdp}(v=0 o=- 6335760585494417936 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video a=msid-semantic: WMS pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB m=audio 62117 RTP/SAVPF 111 103 104 0 8 106 105 13 126 c=IN IP4 192.168.1.33 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=rtcp:62117 IN IP4 192.168.1.33 a=candidate:2608808550 1 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:2608808550 2 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:3590110870 1 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=candidate:3590110870 2 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=ice-ufrag:eJnNnt5asGqM3JCe a=ice-pwd:HkuSIEBjJjxWgaZ0i/XrmPD5 a=ice-options:google-ice a=fingerprint:sha-256 EC:04:9A:9F:88:36:08:4E:7B:7E:45:8C:E7:F1:E2:05:4D:D0:42:2E:C9:C9:68:96:E0:34:B4:E3:7B:99:04:A1 a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:wDS2uKYeEIyjVhWu4X1qrw8ozr/lTWJONcQ4tclN a=maxptime:60 a=ssrc:1877104875 cname:SXJLdFQk+JbMD3lo a=ssrc:1877104875 msid:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB 81cc1301-e200-4127-84b3-468d21652f03 a=ssrc:1877104875 mslabel:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB a=ssrc:1877104875 label:81cc1301-e200-4127-84b3-468d21652f03 m=video 62117 RTP/SAVPF 100 116 117 c=IN IP4 192.168.1.33 a=rtpmap:100 VP8/90000 a=rtpmap:116 red/90000 a=rtpmap:117 ulpfec/90000 a=rtcp:62117 IN IP4 192.168.1.33 a=candidate:2608808550 1 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:2608808550 2 udp 2122194687 192.168.1.33 62117 typ host generation 0 a=candidate:3590110870 1 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=candidate:3590110870 2 tcp 1518214911 192.168.1.33 0 typ host generation 0 a=ice-ufrag:eJnNnt5asGqM3JCe a=ice-pwd:HkuSIEBjJjxWgaZ0i/XrmPD5 a=ice-options:google-ice a=fingerprint:sha-256 EC:04:9A:9F:88:36:08:4E:7B:7E:45:8C:E7:F1:E2:05:4D:D0:42:2E:C9:C9:68:96:E0:34:B4:E3:7B:99:04:A1 a=setup:actpass a=mid:video a=extmap:2 urn:ietf:params:rtp-hdrext:toffset a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:wDS2uKYeEIyjVhWu4X1qrw8ozr/lTWJONcQ4tclN a=rtcp-fb:100 ccm fir a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli a=rtcp-fb:100 goog-remb a=ssrc:2204797885 cname:SXJLdFQk+JbMD3lo a=ssrc:2204797885 msid:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB 2b1c7300-8d87-450c-8268-675616f8098a a=ssrc:2204797885 mslabel:pEDQQ2vhdsVWBFjMONkvZZUI1YWjbOihMnVB a=ssrc:2204797885 label:2b1c7300-8d87-450c-8268-675616f8098a ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1007@pbx.example.org Action set(rtp_secure_media=true) Dialplan: sofia/internal/1007@pbx.example.org Absolute Condition [global] Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1007@pbx.example.org parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [snom-demo-2] destination_number(1009) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [snom-demo-1] destination_number(1009) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^779$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->call_return] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [call_return] destination_number(1009) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->del-group] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [del-group] destination_number(1009) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->add-group] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [add-group] destination_number(1009) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [call-group-simo] destination_number(1009) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [call-group-order] destination_number(1009) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (FAIL) [extension-intercom] destination_number(1009) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1007@pbx.example.org Regex (PASS) [Local_Extension] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007@pbx.example.org Action export(dialed_extension=1009) Dialplan: sofia/internal/1007@pbx.example.org Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1007@pbx.example.org Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1007@pbx.example.org Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1007@pbx.example.org Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1007@pbx.example.org Action set(ringback=${us-ring}) Dialplan: sofia/internal/1007@pbx.example.org Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1007@pbx.example.org Action set(call_timeout=30) Dialplan: sofia/internal/1007@pbx.example.org Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1007@pbx.example.org Action set(continue_on_fail=true) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1007@pbx.example.org Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1007@pbx.example.org Action answer() Dialplan: sofia/internal/1007@pbx.example.org Action sleep(1000) Dialplan: sofia/internal/1007@pbx.example.org Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:214 (sofia/internal/1007@pbx.example.org) State Change CS_ROUTING -> CS_EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007@pbx.example.org) State ROUTING going to sleep 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1007@pbx.example.org) State EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/ 1007@pbx.example.org SOFIA EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256 sofia/internal/1007@pbx.example.org Standard EXECUTE EXECUTE sofia/internal/1007@pbx.example.org set(rtp_secure_media=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [rtp_secure_media]=[true] EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-spymap/1007/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial/1007/1009) EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org export(RFC2822_DATE=Sun, 02 Mar 2014 12:08:09 +0330) 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] EXECUTE sofia/internal/1007@pbx.example.org export(dialed_extension=1009) 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [dialed_extension]=[1009] EXECUTE sofia/internal/1007@pbx.example.org bind_meta_app(1 b s execute_extension::dx XML features) 2014-03-02 12:08:09.617836 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1007@pbx.example.org bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/1007.2014-03-02-12-08-09.wav) 2014-03-02 12:08:09.617836 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/1007.2014-03-02-12-08-09.wav EXECUTE sofia/internal/1007@pbx.example.org bind_meta_app(3 b s execute_extension::cf XML features) 2014-03-02 12:08:09.617836 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1007@pbx.example.org bind_meta_app(4 b s execute_extension::att_xfer XML features) 2014-03-02 12:08:09.617836 [INFO] switch_ivr_async.c:3631 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1007@pbx.example.org set(ringback=%(2000,4000,440,480)) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1007@pbx.example.org set(transfer_ringback=local_stream://moh) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1007@pbx.example.org set(call_timeout=30) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [call_timeout]=[30] EXECUTE sofia/internal/1007@pbx.example.org set(hangup_after_bridge=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1007@pbx.example.org set(continue_on_fail=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [continue_on_fail]=[true] EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-call_return/1009/1007) EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial_ext/1009/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org set(called_party_callgroup=techsupport) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007@pbx.example.org SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial_ext/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial_ext/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org hash(insert/pbx.example.org-last_dial/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007@pbx.example.org bridge(user/1009@pbx.example.org ) 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [dialed_extension]=[1009] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_ivr_originate.c:2078 Parsing global variables 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [RFC2822_DATE]=[Sun, 02 Mar 2014 12:08:09 +0330] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007@pbx.example.orgEXPORTING[export_vars] [dialed_extension]=[1009] to event 2014-03-02 12:08:09.617836 [DEBUG] switch_ivr_originate.c:2078 Parsing global variables 2014-03-02 12:08:09.617836 [DEBUG] switch_event.c:1687 Parsing variable [sip_invite_domain]=[pbx.example.org] 2014-03-02 12:08:09.617836 [DEBUG] switch_event.c:1687 Parsing variable [presence_id]=[1009@pbx.example.org] 2014-03-02 12:08:09.617836 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid[e1007194-671c-4725-9526-1fd664ae8bd9] 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:4446 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_NEW -> CS_INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:4516 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:4519 [zrtp_passthru] Setting b-leg absolute_codec_string='opus@48000h@20i,PCMU@8000h@20i@64000b ,PCMA@8000h@20i@64000b,VP8@90000h' 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_INIT 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:507 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State INIT 2014-03-02 12:08:09.636777 [DEBUG] mod_sofia.c:87 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid SOFIA INIT 2014-03-02 12:08:09.636777 [DEBUG] switch_core_media.c:865 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:x1tfaRnkPZtBd2mHlWeSgTXvn4b2jV5V2kUTVQmf] 2014-03-02 12:08:09.636777 [DEBUG] switch_core_media.c:865 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:sgZ2cTsJe0+BlbiIZVHZ1+L6f+nHoN6i/nDxRsHf] 2014-03-02 12:08:09.636777 [DEBUG] sofia_glue.c:1196 sip:hraog9ag@192.168.1.37:55712;transport=ws Setting proxy route to sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid 2014-03-02 12:08:09.636777 [DEBUG] sofia_glue.c:1225 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid sending invite version: 1.5.8b+git git 35f2bcc 2014-02-12 23:33:16Z 64bit Local SDP: v=0 o=FreeSWITCH 1393730247 1393730248 IN IP4 192.168.1.13 s=FreeSWITCH c=IN IP4 192.168.1.13 t=0 0 a=msid-semantic: WMS UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2 m=audio 19242 RTP/SAVPF 111 0 8 101 13 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:19242 IN IP4 192.168.1.13 a=ssrc:1439184865 cname:T1jV37xsIboPBNUi a=ssrc:1439184865 msid:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2 a0 a=ssrc:1439184865 mslabel:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2 a=ssrc:1439184865 label:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2a0 a=ice-ufrag:U7B6j6a7gW3nrNfb a=ice-pwd:EoWylkRUl5zMIjUs a=candidate:4375327169 1 udp 659136 192.168.1.13 19242 typ host generation 0 a=candidate:4375327169 2 udp 659136 192.168.1.13 19242 typ host generation 0 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:x1tfaRnkPZtBd2mHlWeSgTXvn4b2jV5V2kUTVQmf a=ptime:20 a=sendrecv m=video 23596 RTP/SAVPF 100 a=rtpmap:100 VP8/90000 a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:23596 IN IP4 192.168.1.13 b=AS:256 a=rtcp-fb:100 ccm fir a=ssrc:742329504 cname:T1jV37xsIboPBNUi a=ssrc:742329504 msid:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2 v0 a=ssrc:742329504 mslabel:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2 a=ssrc:742329504 label:UogrbcXMzLN5gAyfQgntmmEeXjV6hFU2v0 a=ice-ufrag:xO6r6hzPddAy4wJE a=ice-pwd:WWGZzl1DIPEcmYgK a=candidate:6281769243 1 udp 659136 192.168.1.13 23596 typ host generation 0 a=candidate:6281769243 2 udp 659134 192.168.1.13 23596 typ host generation 0 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:sgZ2cTsJe0+BlbiIZVHZ1+L6f+nHoN6i/nDxRsHf 2014-03-02 12:08:09.636777 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:40 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Standard INIT 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_INIT -> CS_ROUTING 2014-03-02 12:08:09.636777 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:507 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State INIT going to sleep 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_ROUTING 2014-03-02 12:08:09.636777 [DEBUG] sofia.c:5931 Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid entering state [calling][0] 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State ROUTING 2014-03-02 12:08:09.636777 [DEBUG] mod_sofia.c:123 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid SOFIA ROUTING 2014-03-02 12:08:09.636777 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-03-02 12:08:09.636777 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State ROUTING going to sleep 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_CONSUME_MEDIA 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State CONSUME_MEDIA 2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State CONSUME_MEDIA going to sleep 2014-03-02 12:08:09.676760 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.676760 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:09.676760 [DEBUG] sofia.c:5931 Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid entering state [proceeding][180] 2014-03-02 12:08:09.676760 [NOTICE] sofia.c:6021 Ring-Ready sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid! 2014-03-02 12:08:09.676760 [DEBUG] switch_channel.c:3267 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Callstate Change DOWN -> RINGING 2014-03-02 12:08:09.696763 [WARNING] switch_channel.c:3339 rtp_secure_media invalid in this context. 2014-03-02 12:08:09.696763 [INFO] switch_ivr_originate.c:1191 Sending early media 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [opus:116:48000:20:0] ++++ is saved as a match 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:103:16000:30:32000]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [ISAC:104:32000:30:32000]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:105:16000:60:0]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[G722:9:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[GSM:3:8000:20:13200] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[opus:116:48000:20:0] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [CN:13:8000:60:0]/[SPEEX:99:8000:20:24600] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3120 Set telephone-event payload to 126 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:2139 Set Codec sofia/internal/1007@pbx.example.orgopus/48000 20 ms 960 samples 0 bits 2014-03-02 12:08:09.696763 [DEBUG] switch_core_codec.c:111 sofia/internal/ 1007@pbx.example.org Original read codec set to opus:116 2014-03-02 12:08:09.696763 [WARNING] switch_core_media.c:2340 NO candidate ACL defined, Defaulting to wan.auto 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2378 Save audio Candidate cid: 1 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 2 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2378 Save audio Candidate cid: 2 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2428 No audio RTP candidate found; defaulting to the first local one. 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2435 No audio RTCP candidate found; defaulting to the first local one. 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2502 setting remote audio ice addr to 192.168.1.33:62117 based on candidate 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2522 setting remote rtcp audio addr to 192.168.1.33:62117based on candidate 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3426 Set 2833 dtmf send/recv payload to 126 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [VP8:100]/[VP8:99] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3558 Video Codec Compare [VP8:99] +++ is saved as a match 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [VP8:100]/[H264:97] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [red:116]/[VP8:99] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [red:116]/[H264:97] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [ulpfec:117]/[VP8:99] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3545 Video Codec Compare [ulpfec:117]/[H264:97] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:1960 Set VIDEO Codec sofia/internal/1007@pbx.example.orgVP8/90000 0 ms 2014-03-02 12:08:09.696763 [WARNING] switch_core_media.c:2340 NO candidate ACL defined, Defaulting to wan.auto 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2378 Save video Candidate cid: 1 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 2 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2378 Save video Candidate cid: 2 proto: udp type: host addr:192.168.1.33:62117 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2428 No video RTP candidate found; defaulting to the first local one. 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2435 No video RTCP candidate found; defaulting to the first local one. 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2502 setting remote video ice addr to 192.168.1.33:62117 based on candidate 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:2522 setting remote rtcp video addr to 192.168.1.33:62117based on candidate 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:4626 AUDIO RTP [sofia/internal/1007@pbx.example.org] 192.168.1.13 port 18628 -> 192.168.1.33 port 62117 codec: 111 ms: 20 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:3284 Starting timer [soft] 960 bytes per 20ms 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:4795 Activating Audio ICE 2014-03-02 12:08:09.696763 [NOTICE] switch_rtp.c:3725 Activating RTP audio ICE: eJnNnt5asGqM3JCe:lVSF6mTQyIzfUkFJ 192.168.1.33:62117 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:4838 Activating RTCP PORT 62117 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:3630 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 62117 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:2140 Setting RTCP remote addr to 192.168.1.33:62117 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:4846 Skipping RTCP ICE (Same as RTP) 2014-03-02 12:08:09.696763 [INFO] switch_rtp.c:2867 Activate RTP/RTCP audio DTLS client 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:4970 Set 2833 dtmf send payload to 126 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:4976 Set 2833 dtmf receive payload to 126 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:5004 Set comfort noise payload to 106 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:3293 Not using a timer 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:5173 VIDEO RTP [sofia/internal/1007@pbx.example.org] 192.168.1.33:19732->192.168.1.33:62117 codec: 100 ms: 0 [SUCCESS] 2014-03-02 12:08:09.696763 [NOTICE] switch_core_media.c:3912 sofia/internal/ 1007@pbx.example.org Starting Video thread 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:5215 Activating Video ICE 2014-03-02 12:08:09.696763 [NOTICE] switch_rtp.c:3725 Activating RTP video ICE: eJnNnt5asGqM3JCe:YLijYqQyACzovsdi192.168.1.33:62117 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:5253 Activating VIDEO RTCP PORT 62117 mux 1 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:3630 RTCP send rate is: 10000 and packet rate is: 90000 Remote Port: 62117 2014-03-02 12:08:09.696763 [DEBUG] switch_rtp.c:2140 Setting RTCP remote addr to 192.168.1.33:62117 2014-03-02 12:08:09.696763 [INFO] switch_core_media.c:5263 Skipping VIDEO RTCP ICE (Same as VIDEO RTP) 2014-03-02 12:08:09.696763 [INFO] switch_rtp.c:2867 Activate RTP/RTCP video DTLS client 2014-03-02 12:08:09.696763 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1007@pbx.example.org! 2014-03-02 12:08:09.696763 [DEBUG] switch_channel.c:3405 (sofia/internal/ 1007@pbx.example.org) Callstate Change RINGING -> EARLY 2014-03-02 12:08:09.696763 [DEBUG] mod_sofia.c:2092 Ring SDP: v=0 o=FreeSWITCH 1393730861 1393730862 IN IP4 192.168.1.13 s=FreeSWITCH c=IN IP4 192.168.1.13 t=0 0 a=msid-semantic: WMS TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA m=audio 18628 RTP/SAVPF 111 126 106 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:126 telephone-event/8000 a=rtpmap:106 CN/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:18628 IN IP4 192.168.1.13 a=ssrc:1435227249 cname:ZXcjBCvqI7GFb0V1 a=ssrc:1435227249 msid:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a0 a=ssrc:1435227249 mslabel:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a=ssrc:1435227249 label:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVAa0 a=ice-ufrag:lVSF6mTQyIzfUkFJ a=ice-pwd:7HTzaePIclddcZ5o a=candidate:0240363285 1 udp 659136 192.168.1.13 18628 typ host generation 0 m=video 19732 RTP/SAVPF 100 116 117 a=rtpmap:100 VP8/90000 a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:19732 IN IP4 192.168.1.13 a=rtcp-fb:* fir pli b=AS:256 a=rtcp-fb:100 ccm fir a=ssrc:738371888 cname:ZXcjBCvqI7GFb0V1 a=ssrc:738371888 msid:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA v0 a=ssrc:738371888 mslabel:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a=ssrc:738371888 label:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVAv0 a=ice-ufrag:YLijYqQyACzovsdi a=ice-pwd:jo4kl82X250KV67J a=candidate:9676010799 1 udp 659136 192.168.1.13 19732 typ host generation 0 2014-03-02 12:08:09.696763 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.696763 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007@pbx.example.org entering state [early][183] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:09.696763 [DEBUG] switch_ivr_originate.c:1248 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2014-03-02 12:08:09.696763 [DEBUG] switch_core_codec.c:221 sofia/internal/ 1007@pbx.example.org Push codec L16:70 2014-03-02 12:08:09.696763 [DEBUG] switch_ivr_originate.c:1316 Play Ringback Tone [%(2000,4000,440,480)] 2014-03-02 12:08:09.696763 [DEBUG] switch_core_media.c:3836 sofia/internal/ 1007@pbx.example.org Video thread started. Echo is on 2014-03-02 12:08:19.736758 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.736758 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.736758 [DEBUG] sofia.c:5931 Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid entering state [completing][200] 2014-03-02 12:08:19.736758 [DEBUG] sofia.c:5941 Remote SDP: v=0 o=- 8664835346844021379 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS 38dRvJph58eUkCpfXKDMEJUSKakmMti0wfvZ m=audio 54160 RTP/SAVPF 111 0 8 13 101 c=IN IP4 192.168.1.37 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=rtcp:1 IN IP4 0.0.0.0 a=candidate:337499441 1 udp 2113937151 192.168.1.37 54160 typ host generation 0 a=candidate:2999745851 1 udp 2113937151 192.168.56.1 54161 typ host generation 0 a=candidate:1520314817 1 tcp 1509957375 192.168.1.37 0 typ host generation 0 a=candidate:4233069003 1 tcp 1509957375 192.168.56.1 0 typ host generation 0 a=ice-ufrag:vCxhoDyXqqvj+mr+ a=ice-pwd:BQg2kRONGtoepIJ8Bk+xiNES a=fingerprint:sha-256 E3:57:52:06:AB:D3:F3:50:AE:AF:35:07:36:C1:34:79:E3:D0:79:78:44:40:94:8D:14:8B:20:18:C2:75:89:B7 a=setup:active a=mid:audio a=rtcp-mux a=maxptime:60 a=ssrc:1415016457 cname:MWRrkQgJ5hwMkeGq a=ssrc:1415016457 msid:38dRvJph58eUkCpfXKDMEJUSKakmMti0wfvZ 2ed2b540-f009-443e-8727-d8e805b8f5ce a=ssrc:1415016457 mslabel:38dRvJph58eUkCpfXKDMEJUSKakmMti0wfvZ a=ssrc:1415016457 label:2ed2b540-f009-443e-8727-d8e805b8f5ce m=video 54162 RTP/SAVPF 100 c=IN IP4 192.168.1.37 a=rtpmap:100 VP8/90000 a=rtcp:1 IN IP4 0.0.0.0 a=candidate:337499441 1 udp 2113937151 192.168.1.37 54162 typ host generation 0 a=candidate:2999745851 1 udp 2113937151 192.168.56.1 54163 typ host generation 0 a=candidate:1520314817 1 tcp 1509957375 192.168.1.37 0 typ host generation 0 a=candidate:4233069003 1 tcp 1509957375 192.168.56.1 0 typ host generation 0 a=ice-ufrag:A8338TChMZLM6Bep a=ice-pwd:YW/YrV0gej8hSQSlu+rgavqM a=fingerprint:sha-256 E3:57:52:06:AB:D3:F3:50:AE:AF:35:07:36:C1:34:79:E3:D0:79:78:44:40:94:8D:14:8B:20:18:C2:75:89:B7 a=setup:active a=mid:video a=rtcp-mux a=rtcp-fb:100 ccm fir a=ssrc:1990083148 cname:MWRrkQgJ5hwMkeGq a=ssrc:1990083148 msid:38dRvJph58eUkCpfXKDMEJUSKakmMti0wfvZ e0e094e4-654f-4fc6-9061-c355cae3e2ad a=ssrc:1990083148 mslabel:38dRvJph58eUkCpfXKDMEJUSKakmMti0wfvZ a=ssrc:1990083148 label:e0e094e4-654f-4fc6-9061-c355cae3e2ad 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.756784 [DEBUG] sofia.c:5931 Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid entering state [ready][200] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[opus:116:48000:20:0] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [opus:116:48000:20:0] ++++ is saved as a match 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [opus:111:48000:60:0]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[opus:116:48000:20:0] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[opus:116:48000:20:0] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMU:0:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3194 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMA:8:8000:20:64000] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3248 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3120 Set telephone-event payload to 101 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:2139 Set Codec sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid opus/48000 20 ms 960 samples 0 bits 2014-03-02 12:08:19.756784 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Original read codec set to opus:116 2014-03-02 12:08:19.756784 [WARNING] switch_core_media.c:2340 NO candidate ACL defined, Defaulting to wan.auto 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.1.37:54160 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2378 Save audio Candidate cid: 1 proto: udp type: host addr:192.168.1.37:54160 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.56.1:54161 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2378 Save audio Candidate cid: 1 proto: udp type: host addr:192.168.56.1:54161 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2428 No audio RTP candidate found; defaulting to the first local one. 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2467 No audio RTCP candidate found; defaulting to the same as RTP [192.168.1.37:54160] 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2502 setting remote audio ice addr to 192.168.1.37:54160 based on candidate 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2522 setting remote rtcp audio addr to 192.168.1.37:54160based on candidate 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3417 Set 2833 dtmf send payload to 101 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3545 Video Codec Compare [VP8:100]/[VP8:99] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3558 Video Codec Compare [VP8:99] +++ is saved as a match 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:1960 Set VIDEO Codec sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid VP8/90000 0 ms 2014-03-02 12:08:19.756784 [WARNING] switch_core_media.c:2340 NO candidate ACL defined, Defaulting to wan.auto 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.1.37:54162 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2378 Save video Candidate cid: 1 proto: udp type: host addr:192.168.1.37:54162 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:2364 Checking Candidate cid: 1 proto: udp type: host addr:192.168.56.1:54163 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2378 Save video Candidate cid: 1 proto: udp type: host addr:192.168.56.1:54163 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2428 No video RTP candidate found; defaulting to the first local one. 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2467 No video RTCP candidate found; defaulting to the same as RTP [192.168.1.37:54162] 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2502 setting remote video ice addr to 192.168.1.37:54162 based on candidate 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:2522 setting remote rtcp video addr to 192.168.1.37:54162based on candidate 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:4626 AUDIO RTP [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] 192.168.1.13 port 19242 -> 192.168.1.37 port 54160 codec: 111 ms: 20 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:3284 Starting timer [soft] 960 bytes per 20ms 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:4795 Activating Audio ICE 2014-03-02 12:08:19.756784 [NOTICE] switch_rtp.c:3725 Activating RTP audio ICE: vCxhoDyXqqvj+mr+:U7B6j6a7gW3nrNfb192.168.1.37:54160 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:4838 Activating RTCP PORT 54160 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:3630 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 54160 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:2140 Setting RTCP remote addr to 192.168.1.37:54160 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:4846 Skipping RTCP ICE (Same as RTP) 2014-03-02 12:08:19.756784 [INFO] switch_rtp.c:2867 Activate RTP/RTCP audio DTLS server 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:4970 Set 2833 dtmf send payload to 101 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:4976 Set 2833 dtmf receive payload to 101 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:5004 Set comfort noise payload to 13 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:3293 Not using a timer 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:5173 VIDEO RTP [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] 192.168.1.37:23596-> 192.168.1.37:54162 codec: 100 ms: 0 [SUCCESS] 2014-03-02 12:08:19.756784 [NOTICE] switch_core_media.c:3912 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Starting Video thread 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:5215 Activating Video ICE 2014-03-02 12:08:19.756784 [NOTICE] switch_rtp.c:3725 Activating RTP video ICE: A8338TChMZLM6Bep:xO6r6hzPddAy4wJE 192.168.1.37:54162 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:5253 Activating VIDEO RTCP PORT 54162 mux 1 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:3630 RTCP send rate is: 10000 and packet rate is: 90000 Remote Port: 54162 2014-03-02 12:08:19.756784 [DEBUG] switch_rtp.c:2140 Setting RTCP remote addr to 192.168.1.37:54162 2014-03-02 12:08:19.756784 [INFO] switch_core_media.c:5263 Skipping VIDEO RTCP ICE (Same as VIDEO RTP) 2014-03-02 12:08:19.756784 [INFO] switch_rtp.c:2867 Activate RTP/RTCP video DTLS server 2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3640 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:19.756784 [NOTICE] sofia.c:6717 Channel [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] has been answered 2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3686 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Callstate Change RINGING -> ACTIVE 2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3836 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Video thread started. Echo is off 2014-03-02 12:08:19.756784 [DEBUG] switch_core_codec.c:246 sofia/internal/ 1007@pbx.example.org Restore previous codec opus:116. 2014-03-02 12:08:19.756784 [DEBUG] mod_sofia.c:775 Local SDP sofia/internal/ 1007@pbx.example.org: v=0 o=FreeSWITCH 1393730861 1393730863 IN IP4 192.168.1.13 s=FreeSWITCH c=IN IP4 192.168.1.13 t=0 0 a=msid-semantic: WMS TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA m=audio 18628 RTP/SAVPF 111 126 106 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:126 telephone-event/8000 a=rtpmap:106 CN/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:18628 IN IP4 192.168.1.13 a=ssrc:1435227249 cname:ZXcjBCvqI7GFb0V1 a=ssrc:1435227249 msid:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a0 a=ssrc:1435227249 mslabel:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a=ssrc:1435227249 label:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVAa0 a=ice-ufrag:lVSF6mTQyIzfUkFJ a=ice-pwd:7HTzaePIclddcZ5o a=candidate:3649406103 1 udp 659136 192.168.1.13 18628 typ host generation 0 m=video 19732 RTP/SAVPF 100 116 117 a=rtpmap:100 VP8/90000 a=fingerprint:sha-256 4B:BE:F6:C4:78:16:F1:9A:82:F5:A5:A1:4D:F1:82:BB:C8:21:AF:55:A6:1E:20:08:07:50:8A:B7:3D:D6:0B:2B a=rtcp-mux a=rtcp:19732 IN IP4 192.168.1.13 a=rtcp-fb:* fir pli b=AS:256 a=rtcp-fb:100 ccm fir a=ssrc:738371888 cname:ZXcjBCvqI7GFb0V1 a=ssrc:738371888 msid:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA v0 a=ssrc:738371888 mslabel:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVA a=ssrc:738371888 label:TNbMuOAlYfMp7euqZv91tlDnTmZSQmVAv0 a=ice-ufrag:YLijYqQyACzovsdi a=ice-pwd:jo4kl82X250KV67J a=candidate:4729655507 1 udp 659136 192.168.1.13 19732 typ host generation 0 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:19.756784 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007@pbx.example.org entering state [completed][200] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:19.756784 [NOTICE] switch_ivr_originate.c:3493 Channel [sofia/internal/1007@pbx.example.org] has been answered 2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3686 (sofia/internal/ 1007@pbx.example.org) Callstate Change EARLY -> ACTIVE 2014-03-02 12:08:19.756784 [DEBUG] switch_ivr_originate.c:3551 Originate Resulted in Success: [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] 2014-03-02 12:08:19.756784 [DEBUG] switch_ivr_originate.c:3551 Originate Resulted in Success: [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:19.756784 [DEBUG] switch_ivr_bridge.c:1440 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:19.756784 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_EXCHANGE_MEDIA 2014-03-02 12:08:19.756784 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State EXCHANGE_MEDIA 2014-03-02 12:08:19.756784 [DEBUG] mod_sofia.c:592 SOFIA EXCHANGE_MEDIA 2014-03-02 12:08:19.776762 [DEBUG] switch_core_media.c:3843 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Video thread paused. Echo is off 2014-03-02 12:08:19.776762 [DEBUG] switch_core_media.c:3843 sofia/internal/ 1007@pbx.example.org Video thread paused. Echo is on 2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:20.216756 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007@pbx.example.org entering state [ready][200] 2014-03-02 12:08:20.216756 [DEBUG] switch_core_session.c:966 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:20.216756 [DEBUG] switch_core_session.c:966 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:31.296757 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:31.316769 [NOTICE] sofia.c:737 Hangup sofia/internal/ 1007@pbx.example.org [CS_EXECUTE] [NORMAL_CLEARING] 2014-03-02 12:08:31.316769 [DEBUG] switch_channel.c:3212 Send signal sofia/internal/1007@pbx.example.org [KILL] 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:585 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:586 Ending video thread. 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:633 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:634 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:636 Ending video thread. 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:99 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:100 sofia/internal/ 1007@pbx.example.org video thread ended. 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992 sofia/internal/1007@pbx.example.org skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.316769 [DEBUG] switch_core_media.c:3846 sofia/internal/ 1007@pbx.example.org Video thread resumed Echo is on 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992 sofia/internal/1007@pbx.example.org skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD DONE [sofia/internal/1007@pbx.example.org] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:672 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_core_media.c:3885 sofia/internal/ 1007@pbx.example.org Video thread ended 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:99 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:100 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid video thread ended. 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992 sofia/internal/1007@pbx.example.org skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.316769 [DEBUG] switch_core_media.c:3846 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Video thread resumed Echo is off 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:585 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:586 Ending video thread. 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:633 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:634 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:636 Ending video thread. 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD DONE [sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid] 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:672 Send signal sofia/internal/1007@pbx.example.org [BREAK] 2014-03-02 12:08:31.336755 [NOTICE] switch_ivr_bridge.c:735 Hangup sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2014-03-02 12:08:31.336755 [DEBUG] switch_channel.c:3212 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [KILL] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State EXCHANGE_MEDIA going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:731 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:407 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Overriding SIP cause 480 with 200 from the other leg 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:413 Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid hanging up, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:58 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Standard HANGUP, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:731 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State HANGUP going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:744 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Callstate Change ACTIVE -> HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_HANGUP -> CS_REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:816 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:102 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Standard REPORTING, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:816 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State REPORTING going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:493 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State Change CS_REPORTING -> CS_DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1592 Session 14 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Locked, Waiting on external entities 2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:1541 sofia/internal/ 1007@pbx.example.org skip receive message [UNBRIDGE] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2853 sofia/internal/1007@pbx.example.org skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1007@pbx.example.org) State EXECUTE going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:731 (sofia/internal/1007@pbx.example.org) State HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/1007@pbx.example.org skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:413 Channel sofia/internal/ 1007@pbx.example.org hanging up, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:58 sofia/internal/1007@pbx.example.org Standard HANGUP, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:731 (sofia/internal/1007@pbx.example.org) State HANGUP going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:744 (sofia/internal/1007@pbx.example.org) Callstate Change ACTIVE -> HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1007@pbx.example.org) State Change CS_HANGUP -> CS_REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007@pbx.example.org) Running State Change CS_REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:816 (sofia/internal/1007@pbx.example.org) State REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/1007@pbx.example.org skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:102 sofia/internal/1007@pbx.example.org Standard REPORTING, cause: NORMAL_CLEARING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:816 (sofia/internal/1007@pbx.example.org) State REPORTING going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:493 (sofia/internal/1007@pbx.example.org) State Change CS_REPORTING -> CS_DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007@pbx.example.org[BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1592 Session 13 (sofia/internal/1007@pbx.example.org) Locked, Waiting on external entities 2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1610 Session 13 (sofia/internal/1007@pbx.example.org) Ended 2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1614 Close Channel sofia/internal/1007@pbx.example.org[CS_DESTROY] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:618 (sofia/internal/1007@pbx.example.org) Callstate Change HANGUP -> DOWN 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/1007@pbx.example.org) Running State Change CS_DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631 (sofia/internal/1007@pbx.example.org) State DESTROY 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:323 sofia/internal/ 1007@pbx.example.org SOFIA DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:109 sofia/internal/1007@pbx.example.org Standard DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631 (sofia/internal/1007@pbx.example.org) State DESTROY going to sleep 2014-03-02 12:08:31.336755 [DEBUG] switch_core_media.c:3885 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Video thread ended 2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1610 Session 14 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Ended 2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1614 Close Channel sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid [CS_DESTROY] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:618 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Callstate Change HANGUP -> DOWN 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) Running State Change CS_DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State DESTROY 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:323 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid SOFIA DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:109 sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid Standard DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631 (sofia/internal/sip:hraog9ag@goo45dluhn0t.invalid) State DESTROY going to sleep freeswitch@internal> freeswitch@internal> version FreeSWITCH Version 1.5.8b+git-20140212T233316Z~35f2bcccf7~64bit (git 35f2bcc 2014-02-12 23:33:16Z 64bit) -- Best Wishes, Ehsan Afzali
participants (1)
-
Ehsan Afzali