March 2014 - FreeSWITCH-users - FreeSWITCH Mailing Lists

Unknown source moh, trying 'default'
by Miha 03 Mar '14

03 Mar '14

hi, I noticed that when transfer is made music on hold is not played. In fs logs I can see this: 2014-03-03 14:29:16.872049 [WARNING] mod_local_stream.c:470 Unknown source moh, trying 'default' 2014-03-03 14:29:16.872049 [ERR] mod_local_stream.c:479 Unknown source default I can see that mod_local_stream is loaded and it has default source. What could be reason for this? tnx miha

1 1

How to check the "fax_result_code" in the script? such as php script?
by sparklezou 03 Mar '14

03 Mar '14

Hi Buddies, Reviewed the wiki, https://wiki.freeswitch.org/wiki/Mod_spandsp How to check the "fax_result_code" in the php script? Also other result info, such as fax_result_text, then could provide more detail response info to the client. Thanks! 2014-03-03 sparklezou

1 0

ft_mod_misdn: Failed to bind mISDN socket [0:1]: Device or resource busy
by Doug Warren 02 Mar '14

02 Mar '14

Hi! I got on my machine a 4 port ISDN board, which I'd love to use with my FS machine. I followed this guide, one of your developers Stefan Knoblich, had written once. I followed this guide: http://lists.freeswitch.org/pipermail/freeswitch-users/2012-June/084633.html but I am not getting really smart. Somewhere in the output I see the error message: http://pastebin.com/YucJ7rPf Failed to bind mISDN socket [0:1]: Device or resource busy Is somebody of you guys familiar with mISDN with freeswitch ?! Or do you advise that I should keep the fingers away, and switch to different pbx to make use of the ISDN board ?! if you guys have any ideas, would be cool! Doug

1 0

Freeeswitch 1.5.8 WebRTC JSSIP to linphone client has no audio or video without bypassing
by Ehsan Afzali 02 Mar '14

02 Mar '14

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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007(a)pbx.example.org) Running State Change CS_NEW 2014-03-02 12:08:09.617836 [DEBUG] sofia.c:7989 sofia/internal/ 1007(a)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(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:486 (sofia/internal/1007(a)pbx.example.org) State NEW 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007(a)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(a)pbx.example.org) State INIT 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:87 sofia/internal/ 1007(a)pbx.example.org SOFIA INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1007(a)pbx.example.org Standard INIT 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:507 (sofia/internal/1007(a)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(a)pbx.example.org) Running State Change CS_ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:2179 (sofia/internal/ 1007(a)pbx.example.org) Callstate Change DOWN -> RINGING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007(a)pbx.example.org) State ROUTING 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/ 1007(a)pbx.example.org SOFIA ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164 sofia/internal/1007(a)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(a)pbx.example.org parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [nb_conferences] destination_number(1009) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [public->unloop] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [public->outside_call] continue=true Dialplan: sofia/internal/1007(a)pbx.example.org Absolute Condition [outside_call] Dialplan: sofia/internal/1007(a)pbx.example.org Action set(outside_call=true) Dialplan: sofia/internal/1007(a)pbx.example.org Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1007(a)pbx.example.org parsing [public->call_debug] continue=true Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1007(a)pbx.example.org parsing [public->public_extensions] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (PASS) [public_extensions] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007(a)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(a)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(a)pbx.example.org) State EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/ 1007(a)pbx.example.org SOFIA EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256 sofia/internal/1007(a)pbx.example.org Standard EXECUTE EXECUTE sofia/internal/1007(a)pbx.example.org set(outside_call=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [outside_call]=[true] EXECUTE sofia/internal/1007(a)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(a)pbx.example.org transfer(1009 XML default) 2014-03-02 12:08:09.617836 [DEBUG] switch_ivr.c:1832 (sofia/internal/ 1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:904 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [NOTICE] switch_ivr.c:1839 Transfer sofia/internal/1007(a)pbx.example.org to XML[1009@default] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1007(a)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(a)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(a)pbx.example.org) State ROUTING 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/ 1007(a)pbx.example.org SOFIA ROUTING 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164 sofia/internal/1007(a)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(a)pbx.example.org parsing [default->unloop] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->tod_example] continue=true Dialplan: sofia/internal/1007(a)pbx.example.org Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1007(a)pbx.example.org Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [global-intercept] destination_number(1009) =~ /^886$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [group-intercept] destination_number(1009) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [intercept-ext] destination_number(1009) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->redial] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [redial] destination_number(1009) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->global] continue=true Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1007(a)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(a)pbx.example.org Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1007(a)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(a)pbx.example.org Action set(rtp_secure_media=true) Dialplan: sofia/internal/1007(a)pbx.example.org Absolute Condition [global] Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [snom-demo-2] destination_number(1009) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [snom-demo-1] destination_number(1009) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^779$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->call_return] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [call_return] destination_number(1009) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->del-group] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [del-group] destination_number(1009) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->add-group] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [add-group] destination_number(1009) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [call-group-simo] destination_number(1009) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [call-group-order] destination_number(1009) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (FAIL) [extension-intercom] destination_number(1009) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1007(a)pbx.example.org Regex (PASS) [Local_Extension] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1007(a)pbx.example.org Action export(dialed_extension=1009) Dialplan: sofia/internal/1007(a)pbx.example.org Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1007(a)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(a)pbx.example.org Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1007(a)pbx.example.org Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(ringback=${us-ring}) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(call_timeout=30) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(continue_on_fail=true) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1007(a)pbx.example.org Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1007(a)pbx.example.org Action answer() Dialplan: sofia/internal/1007(a)pbx.example.org Action sleep(1000) Dialplan: sofia/internal/1007(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523 (sofia/internal/1007(a)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(a)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(a)pbx.example.org) State EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/ 1007(a)pbx.example.org SOFIA EXECUTE 2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256 sofia/internal/1007(a)pbx.example.org Standard EXECUTE EXECUTE sofia/internal/1007(a)pbx.example.org set(rtp_secure_media=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [rtp_secure_media]=[true] EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-spymap/1007/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial/1007/1009) EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)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(a)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(a)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(a)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(a)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(a)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(a)pbx.example.org set(ringback=%(2000,4000,440,480)) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1007(a)pbx.example.org set(transfer_ringback=local_stream://moh) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1007(a)pbx.example.org set(call_timeout=30) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [call_timeout]=[30] EXECUTE sofia/internal/1007(a)pbx.example.org set(hangup_after_bridge=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1007(a)pbx.example.org set(continue_on_fail=true) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [continue_on_fail]=[true] EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-call_return/1009/1007) EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial_ext/1009/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)pbx.example.org set(called_party_callgroup=techsupport) 2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/ 1007(a)pbx.example.org SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial_ext/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial_ext/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)pbx.example.org hash(insert/pbx.example.org-last_dial/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8) EXECUTE sofia/internal/1007(a)pbx.example.org bridge(user/1009(a)pbx.example.org ) 2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/ 1007(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)pbx.example.org! 2014-03-02 12:08:09.696763 [DEBUG] switch_channel.c:3405 (sofia/internal/ 1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:09.696763 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:19.756784 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:19.756784 [NOTICE] switch_ivr_originate.c:3493 Channel [sofia/internal/1007(a)pbx.example.org] has been answered 2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3686 (sofia/internal/ 1007(a)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(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:20.216756 [DEBUG] sofia.c:5931 Channel sofia/internal/ 1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:31.296757 [DEBUG] switch_core_session.c:1049 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:31.316769 [NOTICE] sofia.c:737 Hangup sofia/internal/ 1007(a)pbx.example.org [CS_EXECUTE] [NORMAL_CLEARING] 2014-03-02 12:08:31.316769 [DEBUG] switch_channel.c:3212 Send signal sofia/internal/1007(a)pbx.example.org [KILL] 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:1384 Send signal sofia/internal/1007(a)pbx.example.org[BREAK] 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/1007(a)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(a)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(a)pbx.example.org video thread ended. 2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992 sofia/internal/1007(a)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(a)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(a)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(a)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(a)pbx.example.org Video thread ended 2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:99 Send signal sofia/internal/1007(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)pbx.example.org) State HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/1007(a)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(a)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(a)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(a)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(a)pbx.example.org) Callstate Change ACTIVE -> HANGUP 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1007(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1007(a)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(a)pbx.example.org) State REPORTING 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992 sofia/internal/1007(a)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(a)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(a)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(a)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(a)pbx.example.org[BREAK] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1592 Session 13 (sofia/internal/1007(a)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(a)pbx.example.org) Ended 2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1614 Close Channel sofia/internal/1007(a)pbx.example.org[CS_DESTROY] 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:618 (sofia/internal/1007(a)pbx.example.org) Callstate Change HANGUP -> DOWN 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/1007(a)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(a)pbx.example.org) State DESTROY 2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:323 sofia/internal/ 1007(a)pbx.example.org SOFIA DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:109 sofia/internal/1007(a)pbx.example.org Standard DESTROY 2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631 (sofia/internal/1007(a)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

1 0

Call Without Authorization
by Shahzad Bhatti 02 Mar '14

02 Mar '14

Hi everybody, i create my xml_curl script as that don't allow unregistered calls with the following condition *<condition field=\"\${sofia_contact */{$sipuser}@$domain}\" expression=\"^[^@]+@(.+)\">* and its working but yesterday a call is originated from having *fs_cli log as * http://pastebin.freeswitch.org/22050 *xml_cdr is* http://pastebin.freeswitch.org/22052 *dialplan xml is * http://pastebin.freeswitch.org/22054 this is only example that how the hacker breached i want to know that *1. how it is possible that this call is originated as i check condition that allow to call only registered sip accounts.* *2. how to prevent that this would not happened in future. * *3. if there any better way to do that do inform me;* i check about 500 calls placed under the given scenario and many of them also answered Regards Shahzad Bhatti

2 1

Dialplan Issues with Nortel CS1000
by Joel White 01 Mar '14

01 Mar '14

> I have modded the default dialplan to allow 5 digit local extensions. I have the Nortel NRS sending the calls to the public context. I have created the xml to route the incoming call to a local extension. > > Question is, why do the calls go straight to voicemail without ringing the extension. The extension is registered and can make and recieve calls locally on the FS. > > The incoming call from the Nortel CS 1000 reaches the XML parsing for "public" and executes the XML in the public folder relating to the Nortel. The call also makes its way to the "default" context and executes the LOCAL 5 Digit Extension XML config. What I am not understanding is why, if it makes it through the variables and expressions and ends up at the 5 digit local dialing, that it would go straight to voicemail without ringing the phone. > > > > If anyone has any insight into why this behavior would occur.... please point me in the right direction. > > > Thank you in advance > > Joel

3 2

Re: [Freeswitch-users] Dialplan help needed - inbound PBX dialing (to BUSY extension)
by Adelia C. 01 Mar '14

01 Mar '14

In reply to : Answer 1: Check your 2nd destination_number - you lacked 1 digit, I think. On Sat, Mar 1, 2014 at 5:23 AM, Adelia C. <hexade at hotmail.com> wrote: > Setting up a FreeSwitch PBX and running into some issues. Please help. > > Question1of2. - Collapse dialplan with regex. > > How do I collapse this simple condition using regex and params/vars?: > <include> > <extension name="Dialplan1"> > <condition field="destination_number" expression="^15102481000$"> > <action application="transfer" data="1001 XML default"/> > </condition> > </extension> > <extension name="Dialplan2"> > <condition field="destination_number" expression="^1510481003$"> > <action application="transfer" data="1003 XML default"/> > </condition> > </extension>" Tried to be smart and replace the real number, but - in doing so - I mistyped it. The number in Dialplan2 is 15102481003 and that one works. I am calling from 1000 to 1003 and that works fine. When I call from 1000 to 1000 - I am calling over an external Sip Trunk, the call fails when I am calling 1000 inbound (knowing that the extension is busy on the outbound leg). I found the config that controls playing music to the caller (remember, no VM set up) and I commeted it out: in FreeSWITCH\conf\dialplan\default.xml, in LocalExtension, I commented out this: <action application="bridge" data="user/${dialed_extension}@${domain_name}"/> <action application="answer"/>  Music is gone, call is not connected but it's a silent failure. Still not sure how to force calls to busy extensions. Maybe 'transfer' to extension will not do in this case ... Hope someone will chime in. Thank you. PS: Thanks for the regex.

2 1

Re: [Freeswitch-users] Performance
by Keith 01 Mar '14

01 Mar '14

Hi Yossi, Yeah I appreciate that and I don't expect any performance tuning tips above what is in thw wiki. I suppose what I really need to understand is why in 1.2.12 I can load 1000 concurrent calls but in 1.2.22 I can only load 100 without audio delay etc. I appreciate all comments and help with this. Thanks Keith

5 4