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