[Freeswitch-users] Freeeswitch 1.5.8 WebRTC JSSIP to linphone client has no audio or video without bypassing

Sun Mar 2 12:43:57 MSK 2014

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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/1007 at pbx.example.org) Running State Change CS_NEW
2014-03-02 12:08:09.617836 [DEBUG] sofia.c:7989 sofia/internal/
1007 at 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 at 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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:486
(sofia/internal/1007 at pbx.example.org) State NEW
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/1007 at 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 at pbx.example.org) State INIT
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:87 sofia/internal/
1007 at pbx.example.org SOFIA INIT
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:40
sofia/internal/1007 at pbx.example.org Standard INIT
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:507
(sofia/internal/1007 at 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 at pbx.example.org) Running State Change CS_ROUTING
2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:2179 (sofia/internal/
1007 at pbx.example.org) Callstate Change DOWN -> RINGING
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523
(sofia/internal/1007 at pbx.example.org) State ROUTING
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/
1007 at pbx.example.org SOFIA ROUTING
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164
sofia/internal/1007 at 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 at pbx.example.org parsing
[public->nb_conferences] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [nb_conferences]
destination_number(1009) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [public->unloop]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[public->outside_call] continue=true
Dialplan: sofia/internal/1007 at pbx.example.org Absolute Condition
[outside_call]
Dialplan: sofia/internal/1007 at pbx.example.org Action set(outside_call=true)
Dialplan: sofia/internal/1007 at pbx.example.org Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1007 at pbx.example.org parsing [public->call_debug]
continue=true
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [call_debug]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[public->public_extensions] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (PASS)
[public_extensions] destination_number(1009) =~ /^(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1007 at 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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523
(sofia/internal/1007 at 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 at 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 at pbx.example.org) State EXECUTE
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/
1007 at pbx.example.org SOFIA EXECUTE
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256
sofia/internal/1007 at pbx.example.org Standard EXECUTE
EXECUTE sofia/internal/1007 at pbx.example.org set(outside_call=true)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [outside_call]=[true]
EXECUTE sofia/internal/1007 at 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 at pbx.example.org transfer(1009 XML default)
2014-03-02 12:08:09.617836 [DEBUG] switch_ivr.c:1832 (sofia/internal/
1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_session.c:904 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [NOTICE] switch_ivr.c:1839 Transfer
sofia/internal/1007 at pbx.example.org to XML[1009 at default]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:530
(sofia/internal/1007 at 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 at 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 at pbx.example.org) State ROUTING
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:123 sofia/internal/
1007 at pbx.example.org SOFIA ROUTING
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:164
sofia/internal/1007 at 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 at pbx.example.org parsing [default->unloop]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->tod_example] continue=true
Dialplan: sofia/internal/1007 at pbx.example.org Date/TimeMatch (FAIL)
[tod_example] break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/1007 at pbx.example.org Date/TimeMatch (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL)
[global-intercept] destination_number(1009) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL)
[group-intercept] destination_number(1009) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [intercept-ext]
destination_number(1009) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->redial]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [redial]
destination_number(1009) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->global]
continue=true
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1007 at 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 at pbx.example.org Regex (PASS) [global]
${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/
break=on-false
Dialplan: sofia/internal/1007 at 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 at pbx.example.org Action
set(rtp_secure_media=true)
Dialplan: sofia/internal/1007 at pbx.example.org Absolute Condition [global]
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->snom-demo-2] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [snom-demo-2]
destination_number(1009) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [snom-demo-1]
destination_number(1009) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [eavesdrop]
destination_number(1009) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [eavesdrop]
destination_number(1009) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->call_return] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [call_return]
destination_number(1009) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->del-group]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [del-group]
destination_number(1009) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing [default->add-group]
continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL) [add-group]
destination_number(1009) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL)
[call-group-simo] destination_number(1009) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL)
[call-group-order] destination_number(1009) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (FAIL)
[extension-intercom] destination_number(1009) =~ /^8(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1007 at pbx.example.org Regex (PASS)
[Local_Extension] destination_number(1009) =~ /^(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1007 at pbx.example.org Action
export(dialed_extension=1009)
Dialplan: sofia/internal/1007 at pbx.example.org Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/1007 at 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 at pbx.example.org Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/1007 at pbx.example.org Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1007 at pbx.example.org Action
set(ringback=${us-ring})
Dialplan: sofia/internal/1007 at pbx.example.org Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1007 at pbx.example.org Action set(call_timeout=30)
Dialplan: sofia/internal/1007 at pbx.example.org Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/1007 at pbx.example.org Action
set(continue_on_fail=true)
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1007 at pbx.example.org Action
bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1007 at pbx.example.org Action answer()
Dialplan: sofia/internal/1007 at pbx.example.org Action sleep(1000)
Dialplan: sofia/internal/1007 at 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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:523
(sofia/internal/1007 at 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 at 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 at pbx.example.org) State EXECUTE
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:178 sofia/internal/
1007 at pbx.example.org SOFIA EXECUTE
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:256
sofia/internal/1007 at pbx.example.org Standard EXECUTE
EXECUTE sofia/internal/1007 at pbx.example.org set(rtp_secure_media=true)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [rtp_secure_media]=[true]
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-spymap/1007/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial/1007/1009)
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at 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 at 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 at 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 at 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 at 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 at 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 at pbx.example.org
 set(ringback=%(2000,4000,440,480))
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1007 at pbx.example.org
 set(transfer_ringback=local_stream://moh)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1007 at pbx.example.org set(call_timeout=30)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [call_timeout]=[30]
EXECUTE sofia/internal/1007 at pbx.example.org set(hangup_after_bridge=true)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1007 at pbx.example.org set(continue_on_fail=true)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [continue_on_fail]=[true]
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-call_return/1009/1007)
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial_ext/1009/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at pbx.example.org
 set(called_party_callgroup=techsupport)
2014-03-02 12:08:09.617836 [DEBUG] mod_dptools.c:1409 sofia/internal/
1007 at pbx.example.org SET [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial_ext/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial_ext/global/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at pbx.example.org
 hash(insert/pbx.example.org-last_dial/techsupport/c5d3896c-f8cb-4d5a-abad-ce5a3d821ef8)
EXECUTE sofia/internal/1007 at pbx.example.org bridge(user/1009 at pbx.example.org
)
2014-03-02 12:08:09.617836 [DEBUG] switch_channel.c:1201 sofia/internal/
1007 at 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 at 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 at 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 at 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 at 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 at 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 at pbx.example.org]
2014-03-02 12:08:09.617836 [NOTICE] switch_channel.c:1055 New Channel
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid[e1007194-671c-4725-9526-1fd664ae8bd9]
2014-03-02 12:08:09.617836 [DEBUG] mod_sofia.c:4446
(sofia/internal/sip:hraog9ag at 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 at 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 at 48000h@20i,PCMU at 8000h@20i at 64000b
,PCMA at 8000h@20i at 64000b,VP8 at 90000h'
2014-03-02 12:08:09.617836 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid) State INIT
2014-03-02 12:08:09.636777 [DEBUG] mod_sofia.c:87
sofia/internal/sip:hraog9ag at 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 at 192.168.1.37:55712;transport=ws Setting proxy route to
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid
2014-03-02 12:08:09.636777 [DEBUG] sofia_glue.c:1225
sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:40
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid Standard INIT
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:507
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid) Running State Change
CS_ROUTING
2014-03-02 12:08:09.636777 [DEBUG] sofia.c:5931 Channel
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid entering state [calling][0]
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:523
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) State ROUTING
2014-03-02 12:08:09.636777 [DEBUG] mod_sofia.c:123
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid SOFIA ROUTING
2014-03-02 12:08:09.636777 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:523
(sofia/internal/sip:hraog9ag at 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 at 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 at goo45dluhn0t.invalid) State CONSUME_MEDIA
2014-03-02 12:08:09.636777 [DEBUG] switch_core_state_machine.c:542
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:09.676760 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:09.676760 [DEBUG] sofia.c:5931 Channel
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid entering state
[proceeding][180]
2014-03-02 12:08:09.676760 [NOTICE] sofia.c:6021 Ring-Ready
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid!
2014-03-02 12:08:09.676760 [DEBUG] switch_channel.c:3267
(sofia/internal/sip:hraog9ag at 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 at 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 at 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 at 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 at 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 at 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 at 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 at pbx.example.org!
2014-03-02 12:08:09.696763 [DEBUG] switch_channel.c:3405 (sofia/internal/
1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.696763 [DEBUG] sofia.c:5931 Channel sofia/internal/
1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:09.696763 [DEBUG] switch_ivr_originate.c:1248 Raw Codec
Activation Success L16 at 48000hz 1 channel 20ms
2014-03-02 12:08:09.696763 [DEBUG] switch_core_codec.c:221 sofia/internal/
1007 at 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 at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.736758 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.736758 [DEBUG] sofia.c:5931 Channel
sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.756784 [DEBUG] sofia.c:5931 Channel
sofia/internal/sip:hraog9ag at 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 at 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 at 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 at 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 at 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 at 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 at 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 at pbx.example.org [BREAK]
2014-03-02 12:08:19.756784 [NOTICE] sofia.c:6717 Channel
[sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid] has been answered
2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3686
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) Callstate Change RINGING
-> ACTIVE
2014-03-02 12:08:19.756784 [DEBUG] switch_core_media.c:3836
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid Video thread started. Echo
is off
2014-03-02 12:08:19.756784 [DEBUG] switch_core_codec.c:246 sofia/internal/
1007 at 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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:19.756784 [DEBUG] sofia.c:5931 Channel sofia/internal/
1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:19.756784 [NOTICE] switch_ivr_originate.c:3493 Channel
[sofia/internal/1007 at pbx.example.org] has been answered
2014-03-02 12:08:19.756784 [DEBUG] switch_channel.c:3686 (sofia/internal/
1007 at 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 at goo45dluhn0t.invalid]
2014-03-02 12:08:19.756784 [DEBUG] switch_ivr_originate.c:3551 Originate
Resulted in Success: [sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid]
2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:904 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.756784 [DEBUG] switch_core_session.c:904 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:19.756784 [DEBUG] switch_ivr_bridge.c:1440
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:19.756784 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/sip:hraog9ag at 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 at 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 at goo45dluhn0t.invalid Video thread paused. Echo
is off
2014-03-02 12:08:19.776762 [DEBUG] switch_core_media.c:3843 sofia/internal/
1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:20.196755 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:20.216756 [DEBUG] sofia.c:5931 Channel sofia/internal/
1007 at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:20.216756 [DEBUG] switch_core_session.c:966 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:31.296757 [DEBUG] switch_core_session.c:1049 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:31.316769 [NOTICE] sofia.c:737 Hangup sofia/internal/
1007 at pbx.example.org [CS_EXECUTE] [NORMAL_CLEARING]
2014-03-02 12:08:31.316769 [DEBUG] switch_channel.c:3212 Send signal
sofia/internal/1007 at pbx.example.org [KILL]
2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:1384 Send signal
sofia/internal/1007 at pbx.example.org[BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:584 Send signal
sofia/internal/1007 at pbx.example.org [BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:585 Send signal
sofia/internal/sip:hraog9ag at 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 at pbx.example.org [BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:634 Send signal
sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:100 sofia/internal/
1007 at pbx.example.org video thread ended.
2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992
sofia/internal/1007 at 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 at 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 at 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 at pbx.example.org]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:672 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_core_media.c:3885 sofia/internal/
1007 at pbx.example.org Video thread ended
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:99 Send signal
sofia/internal/1007 at pbx.example.org [BREAK]
2014-03-02 12:08:31.316769 [DEBUG] switch_ivr_bridge.c:100
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid video thread ended.
2014-03-02 12:08:31.316769 [DEBUG] switch_core_session.c:2992
sofia/internal/1007 at 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 at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:585 Send signal
sofia/internal/1007 at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:634 Send signal
sofia/internal/1007 at 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 at goo45dluhn0t.invalid]
2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:672 Send signal
sofia/internal/1007 at pbx.example.org [BREAK]
2014-03-02 12:08:31.336755 [NOTICE] switch_ivr_bridge.c:735 Hangup
sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [KILL]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1384 Send signal
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:533
(sofia/internal/sip:hraog9ag at 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 at 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 at goo45dluhn0t.invalid) State HANGUP
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992
sofia/internal/sip:hraog9ag at 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 at 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 at 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 at goo45dluhn0t.invalid
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:58
sofia/internal/sip:hraog9ag at 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 at 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 at goo45dluhn0t.invalid) Callstate Change ACTIVE
-> HANGUP
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:499
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid) State REPORTING
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992
sofia/internal/sip:hraog9ag at 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 at 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 at 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 at 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 at goo45dluhn0t.invalid [BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1592 Session 14
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) Locked, Waiting on
external entities
2014-03-02 12:08:31.336755 [DEBUG] switch_ivr_bridge.c:1541 sofia/internal/
1007 at 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 at 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 at 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 at 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 at pbx.example.org) State HANGUP
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992
sofia/internal/1007 at 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 at 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 at 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 at 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 at pbx.example.org) Callstate Change ACTIVE -> HANGUP
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:499
(sofia/internal/1007 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:467
(sofia/internal/1007 at 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 at pbx.example.org) State REPORTING
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:2992
sofia/internal/1007 at 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 at 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 at 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 at 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 at pbx.example.org[BREAK]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_session.c:1592 Session 13
(sofia/internal/1007 at 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 at pbx.example.org) Ended
2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1614 Close
Channel sofia/internal/1007 at pbx.example.org[CS_DESTROY]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:618
(sofia/internal/1007 at pbx.example.org) Callstate Change HANGUP -> DOWN
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:621
(sofia/internal/1007 at 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 at pbx.example.org) State DESTROY
2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:323 sofia/internal/
1007 at pbx.example.org SOFIA DESTROY
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:109
sofia/internal/1007 at pbx.example.org Standard DESTROY
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631
(sofia/internal/1007 at 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 at goo45dluhn0t.invalid Video thread ended
2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1610 Session 14
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) Ended
2014-03-02 12:08:31.336755 [NOTICE] switch_core_session.c:1614 Close
Channel sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid [CS_DESTROY]
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:618
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) Callstate Change HANGUP
-> DOWN
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:621
(sofia/internal/sip:hraog9ag at 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 at goo45dluhn0t.invalid) State DESTROY
2014-03-02 12:08:31.336755 [DEBUG] mod_sofia.c:323
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid SOFIA DESTROY
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:109
sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid Standard DESTROY
2014-03-02 12:08:31.336755 [DEBUG] switch_core_state_machine.c:631
(sofia/internal/sip:hraog9ag at goo45dluhn0t.invalid) State DESTROY going to
sleep
freeswitch at internal>
freeswitch at internal> version
FreeSWITCH Version 1.5.8b+git-20140212T233316Z~35f2bcccf7~64bit (git
35f2bcc 2014-02-12 23:33:16Z 64bit)

-- 
Best Wishes,
Ehsan Afzali
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140302/59152b0e/attachment-0001.html 