Skip to content

Instantly share code, notes, and snippets.

@kingster

kingster/gist:88d9e64368e3a2af4a6f603d81100457 Secret

Created February 1, 2018 10:45
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save kingster/88d9e64368e3a2af4a6f603d81100457 to your computer and use it in GitHub Desktop.
Save kingster/88d9e64368e3a2af4a6f603d81100457 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
2018-02-01 16:03:29.569268 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-02-01 16:03:29.569268 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@10.85.185.65 [95622d76-9a98-48d7-a53b-6f55598d78e1]
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:4819 (sofia/internal/1001@10.85.185.65) State Change CS_NEW -> CS_INIT
2018-02-01 16:03:29.569268 [DEBUG] switch_core_session.c:615 sofia/internal/1001@10.85.185.65 set UUID=95622d76-9a98-48d7-a53b-6f55598d78e1
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.85.185.65) Running State Change CS_INIT (Cur 1 Tot 1)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.85.185.65) State INIT
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:90 sofia/internal/1001@10.85.185.65 SOFIA INIT
2018-02-01 16:03:29.569268 [DEBUG] sofia_glue.c:1295 sofia/internal/1001@10.85.185.65 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1517461011 1517461012 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 20198 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 27610 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@10.85.185.65 Standard INIT
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@10.85.185.65) State Change CS_INIT -> CS_ROUTING
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.85.185.65) State INIT going to sleep
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.85.185.65) Running State Change CS_ROUTING (Cur 1 Tot 1)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.85.185.65) State ROUTING
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:143 sofia/internal/1001@10.85.185.65 SOFIA ROUTING
2018-02-01 16:03:29.569268 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@10.85.185.65) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.85.185.65) State ROUTING going to sleep
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.85.185.65) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 1)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@10.85.185.65) State CONSUME_MEDIA
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@10.85.185.65) State CONSUME_MEDIA going to sleep
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.85.185.65 entering state [calling][0]
2018-02-01 16:03:29.569268 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/0000@10.85.185.65 [f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c]
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_NEW (Cur 2 Tot 2)
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:9873 sofia/internal/0000@10.85.185.65 receiving invite from 10.85.185.65:5060 version: 1.6.19 -36-7a77e0b 64bit
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:9989 IP 10.85.185.65 Approved by acl "domains[]". Access Granted.
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:7084 Channel sofia/internal/0000@10.85.185.65 entering state [received][100]
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=FreeSWITCH 1517461011 1517461012 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 20198 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 27610 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.569268 [DEBUG] sofia.c:7486 (sofia/internal/0000@10.85.185.65) State Change CS_NEW -> CS_INIT
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/0000@10.85.185.65) State NEW
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_INIT (Cur 2 Tot 2)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/0000@10.85.185.65) State INIT
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:90 sofia/internal/0000@10.85.185.65 SOFIA INIT
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:40 sofia/internal/0000@10.85.185.65 Standard INIT
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/0000@10.85.185.65) State Change CS_INIT -> CS_ROUTING
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/0000@10.85.185.65) State INIT going to sleep
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_ROUTING (Cur 2 Tot 2)
2018-02-01 16:03:29.569268 [DEBUG] switch_channel.c:2249 (sofia/internal/0000@10.85.185.65) Callstate Change DOWN -> RINGING
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/0000@10.85.185.65) State ROUTING
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:143 sofia/internal/0000@10.85.185.65 SOFIA ROUTING
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:236 sofia/internal/0000@10.85.185.65 Standard ROUTING
2018-02-01 16:03:29.569268 [INFO] mod_dialplan_xml.c:637 Processing 0000 <0000>->1001 in context public
Dialplan: sofia/internal/0000@10.85.185.65 parsing [public->unloop] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [public->outside_call] continue=true
Dialplan: sofia/internal/0000@10.85.185.65 Absolute Condition [outside_call]
Dialplan: sofia/internal/0000@10.85.185.65 Action set(outside_call=true)
Dialplan: sofia/internal/0000@10.85.185.65 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/0000@10.85.185.65 parsing [public->call_debug] continue=true
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/0000@10.85.185.65 parsing [public->public_extensions] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (PASS) [public_extensions] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Action transfer(1001 XML default)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/0000@10.85.185.65) State Change CS_ROUTING -> CS_EXECUTE
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/0000@10.85.185.65) State ROUTING going to sleep
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_EXECUTE (Cur 2 Tot 2)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/0000@10.85.185.65) State EXECUTE
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:198 sofia/internal/0000@10.85.185.65 SOFIA EXECUTE
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:328 sofia/internal/0000@10.85.185.65 Standard EXECUTE
EXECUTE sofia/internal/0000@10.85.185.65 set(outside_call=true)
2018-02-01 16:03:29.569268 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [outside_call]=[true]
EXECUTE sofia/internal/0000@10.85.185.65 export(RFC2822_DATE=Thu, 01 Feb 2018 16:03:29 +0530)
2018-02-01 16:03:29.569268 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530]
EXECUTE sofia/internal/0000@10.85.185.65 transfer(1001 XML default)
2018-02-01 16:03:29.569268 [DEBUG] switch_ivr.c:2165 (sofia/internal/0000@10.85.185.65) State Change CS_EXECUTE -> CS_ROUTING
2018-02-01 16:03:29.569268 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/0000@10.85.185.65 to XML[1001@default]
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/0000@10.85.185.65) State EXECUTE going to sleep
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_ROUTING (Cur 2 Tot 2)
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/0000@10.85.185.65) State ROUTING
2018-02-01 16:03:29.569268 [DEBUG] mod_sofia.c:143 sofia/internal/0000@10.85.185.65 SOFIA ROUTING
2018-02-01 16:03:29.569268 [DEBUG] switch_core_state_machine.c:236 sofia/internal/0000@10.85.185.65 Standard ROUTING
2018-02-01 16:03:29.569268 [INFO] mod_dialplan_xml.c:637 Processing 0000 <0000>->1001 in context default
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->unloop] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/0000@10.85.185.65 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Action set(open=true)
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/0000@10.85.185.65 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->redial] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->global] continue=true
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [global] ${default_password}(kingster) =~ /^1234$/ break=never
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
Dialplan: sofia/internal/0000@10.85.185.65 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=FreeSWITCH 1517461011 1517461012 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 20198 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 27610 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/0000@10.85.185.65 Absolute Condition [global]
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->call_return] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->del-group] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->add-group] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/0000@10.85.185.65 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/0000@10.85.185.65 Action export(dialed_extension=1001)
Dialplan: sofia/internal/0000@10.85.185.65 Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/0000@10.85.185.65 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/0000@10.85.185.65 Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/0000@10.85.185.65 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
Dialplan: sofia/internal/0000@10.85.185.65 Action set(ringback=${us-ring})
Dialplan: sofia/internal/0000@10.85.185.65 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/0000@10.85.185.65 Action set(call_timeout=30)
Dialplan: sofia/internal/0000@10.85.185.65 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/0000@10.85.185.65 Action set(continue_on_fail=true)
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/0000@10.85.185.65 Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/0000@10.85.185.65 Action answer()
Dialplan: sofia/internal/0000@10.85.185.65 Action sleep(1000)
Dialplan: sofia/internal/0000@10.85.185.65 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/0000@10.85.185.65) State Change CS_ROUTING -> CS_EXECUTE
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/0000@10.85.185.65) State ROUTING going to sleep
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000@10.85.185.65) Running State Change CS_EXECUTE (Cur 2 Tot 2)
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/0000@10.85.185.65) State EXECUTE
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:198 sofia/internal/0000@10.85.185.65 SOFIA EXECUTE
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:328 sofia/internal/0000@10.85.185.65 Standard EXECUTE
EXECUTE sofia/internal/0000@10.85.185.65 set(open=true)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [open]=[true]
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-spymap/0000/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial/0000/1001)
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial/global/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 export(RFC2822_DATE=Thu, 01 Feb 2018 16:03:29 +0530)
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530]
EXECUTE sofia/internal/0000@10.85.185.65 export(dialed_extension=1001)
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1001]
EXECUTE sofia/internal/0000@10.85.185.65 bind_meta_app(1 b s execute_extension::dx XML features)
2018-02-01 16:03:29.589223 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *1 execute_extension::dx XML features
EXECUTE sofia/internal/0000@10.85.185.65 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/0000.2018-02-01-16-03-29.wav)
2018-02-01 16:03:29.589223 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/0000.2018-02-01-16-03-29.wav
EXECUTE sofia/internal/0000@10.85.185.65 bind_meta_app(3 b s execute_extension::cf XML features)
2018-02-01 16:03:29.589223 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *3 execute_extension::cf XML features
EXECUTE sofia/internal/0000@10.85.185.65 bind_meta_app(4 b s execute_extension::att_xfer XML features)
2018-02-01 16:03:29.589223 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/0000@10.85.185.65 set(ringback=%(2000,4000,440,480))
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/0000@10.85.185.65 set(transfer_ringback=local_stream://moh)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/0000@10.85.185.65 set(call_timeout=30)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [call_timeout]=[30]
EXECUTE sofia/internal/0000@10.85.185.65 set(hangup_after_bridge=true)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/0000@10.85.185.65 set(continue_on_fail=true)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [continue_on_fail]=[true]
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-call_return/1001/0000)
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial_ext/1001/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 set(called_party_callgroup=techsupport)
2018-02-01 16:03:29.589223 [DEBUG] mod_dptools.c:1548 SET sofia/internal/0000@10.85.185.65 [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial_ext/techsupport/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial_ext/global/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 hash(insert/10.85.185.65-last_dial/techsupport/f0bbf9cb-bf35-4a93-8cfc-c1ff42cc7f0c)
EXECUTE sofia/internal/0000@10.85.185.65 bridge(user/1001@10.85.185.65)
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 01 Feb 2018 16:03:29 +0530] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_channel.c:1250 sofia/internal/0000@10.85.185.65 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2018-02-01 16:03:29.589223 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-02-01 16:03:29.589223 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@172.20.49.53:64001 [13f68cd8-38e8-4c32-9f04-4a28dca4621e]
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:4819 (sofia/internal/1001@172.20.49.53:64001) State Change CS_NEW -> CS_INIT
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_INIT (Cur 3 Tot 3)
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@172.20.49.53:64001) State INIT
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:90 sofia/internal/1001@172.20.49.53:64001 SOFIA INIT
2018-02-01 16:03:29.589223 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@172.20.49.53:57952 [bcc583bd-97f3-479e-b6f6-4ba95408ac8d]
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:4819 (sofia/internal/1001@172.20.49.53:57952) State Change CS_NEW -> CS_INIT
2018-02-01 16:03:29.589223 [DEBUG] sofia_glue.c:1264 sip:10.85.185.62;lr;received=sip:172.20.49.53:64001 Setting proxy route to sofia/internal/1001@172.20.49.53:64001
2018-02-01 16:03:29.589223 [DEBUG] sofia_glue.c:1295 sofia/internal/1001@172.20.49.53:64001 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1517455579 1517455580 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 25630 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 29786 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@172.20.49.53:64001 Standard INIT
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@172.20.49.53:64001) State Change CS_INIT -> CS_ROUTING
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@172.20.49.53:64001) State INIT going to sleep
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:57952) Running State Change CS_INIT (Cur 4 Tot 4)
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_ROUTING (Cur 4 Tot 4)
2018-02-01 16:03:29.589223 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@172.20.49.53:57952) State INIT
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:90 sofia/internal/1001@172.20.49.53:57952 SOFIA INIT
2018-02-01 16:03:29.589223 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:64001 entering state [calling][0]
2018-02-01 16:03:29.589223 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@172.20.49.53:64001) State ROUTING
2018-02-01 16:03:29.589223 [DEBUG] mod_sofia.c:143 sofia/internal/1001@172.20.49.53:64001 SOFIA ROUTING
2018-02-01 16:03:29.609221 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@172.20.49.53:64001) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@172.20.49.53:64001) State ROUTING going to sleep
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 4)
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@172.20.49.53:64001) State CONSUME_MEDIA
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@172.20.49.53:64001) State CONSUME_MEDIA going to sleep
2018-02-01 16:03:29.609221 [DEBUG] sofia_glue.c:1264 sip:1001@172.20.49.53:57952;rinstance=1eaf1ec483a674a3 Setting proxy route to sofia/internal/1001@172.20.49.53:57952
2018-02-01 16:03:29.609221 [DEBUG] sofia_glue.c:1295 sofia/internal/1001@172.20.49.53:57952 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1517459405 1517459406 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 21804 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 20404 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@172.20.49.53:57952 Standard INIT
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@172.20.49.53:57952) State Change CS_INIT -> CS_ROUTING
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@172.20.49.53:57952) State INIT going to sleep
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:57952) Running State Change CS_ROUTING (Cur 4 Tot 4)
2018-02-01 16:03:29.609221 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:57952 entering state [calling][0]
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@172.20.49.53:57952) State ROUTING
2018-02-01 16:03:29.609221 [DEBUG] mod_sofia.c:143 sofia/internal/1001@172.20.49.53:57952 SOFIA ROUTING
2018-02-01 16:03:29.609221 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@172.20.49.53:57952) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@172.20.49.53:57952) State ROUTING going to sleep
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:57952) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 4)
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@172.20.49.53:57952) State CONSUME_MEDIA
2018-02-01 16:03:29.609221 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@172.20.49.53:57952) State CONSUME_MEDIA going to sleep
2018-02-01 16:03:29.789255 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:57952 entering state [proceeding][180]
2018-02-01 16:03:29.789255 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/1001@172.20.49.53:57952!
2018-02-01 16:03:29.789255 [DEBUG] switch_channel.c:3346 (sofia/internal/1001@172.20.49.53:57952) Callstate Change DOWN -> RINGING
2018-02-01 16:03:29.809259 [INFO] switch_ivr_originate.c:1215 Sending early media
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/0000@10.85.185.65 G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-02-01 16:03:29.809259 [DEBUG] switch_core_codec.c:111 sofia/internal/0000@10.85.185.65 Original read codec set to G722:9
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4767 sofia/internal/0000@10.85.185.65 Set 2833 dtmf send payload to 101 recv payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4950 Video Codec Compare [VP8:102]/[VP8:99]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4982 Video Codec Compare [VP8:102] +++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-02-01 16:03:29.809259 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:2871 Set VIDEO Codec sofia/internal/0000@10.85.185.65 VP8/90000 0 ms
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/0000@10.85.185.65] 10.85.185.65 port 22040 -> 10.85.185.65 port 20198 codec: 9 ms: 20
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7179 sofia/internal/0000@10.85.185.65 Set 2833 dtmf send payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7186 sofia/internal/0000@10.85.185.65 Set 2833 dtmf receive payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7209 sofia/internal/0000@10.85.185.65 Set rtp dtmf delay to 40
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4126 Starting video timer.
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7398 VIDEO RTP [sofia/internal/0000@10.85.185.65] 10.85.185.65:27072->10.85.185.65:27610 codec: 102 ms: 0 [SUCCESS]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:6003 sofia/internal/0000@10.85.185.65 Starting Video thread
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:5869 sofia/internal/0000@10.85.185.65 Video thread started. Echo is off
2018-02-01 16:03:29.809259 [INFO] switch_core_media.c:7478 Activating VIDEO RTCP PORT 27611 interval 1000 mux -1
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 27611
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 10.85.185.65:27611 2
2018-02-01 16:03:29.809259 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/0000@10.85.185.65!
2018-02-01 16:03:29.809259 [DEBUG] switch_channel.c:3474 (sofia/internal/0000@10.85.185.65) Callstate Change RINGING -> EARLY
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/0000@10.85.185.65.
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7256 Video params are unchanged for sofia/internal/0000@10.85.185.65.
2018-02-01 16:03:29.809259 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1517459169 1517459170 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 22040 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 27072 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp:27073 IN IP4 10.85.185.65
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.809259 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@16000hz 1 channel 20ms
2018-02-01 16:03:29.809259 [DEBUG] switch_core_codec.c:223 sofia/internal/0000@10.85.185.65 Push codec L16:100
2018-02-01 16:03:29.809259 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)]
2018-02-01 16:03:29.809259 [INFO] sofia.c:1279 sofia/internal/1001@10.85.185.65 Update Callee ID to "1001" <sip:1001@10.85.185.65>
2018-02-01 16:03:29.809259 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.85.185.65 entering state [proceeding][183]
2018-02-01 16:03:29.809259 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=FreeSWITCH 1517459169 1517459170 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 22040 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 27072 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp:27073 IN IP4 10.85.185.65
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1001@10.85.185.65 G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-02-01 16:03:29.809259 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@10.85.185.65 Original read codec set to G722:9
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4767 sofia/internal/1001@10.85.185.65 Set 2833 dtmf send payload to 101 recv payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4950 Video Codec Compare [VP8:102]/[VP8:99]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:4982 Video Codec Compare [VP8:102] +++ is saved as a match
2018-02-01 16:03:29.809259 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-02-01 16:03:29.809259 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:2871 Set VIDEO Codec sofia/internal/1001@10.85.185.65 VP8/90000 0 ms
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1001@10.85.185.65] 10.85.185.65 port 20198 -> 10.85.185.65 port 22040 codec: 9 ms: 20
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7179 sofia/internal/1001@10.85.185.65 Set 2833 dtmf send payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7186 sofia/internal/1001@10.85.185.65 Set 2833 dtmf receive payload to 101
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7209 sofia/internal/1001@10.85.185.65 Set rtp dtmf delay to 40
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4126 Starting video timer.
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:7398 VIDEO RTP [sofia/internal/1001@10.85.185.65] 10.85.185.65:27610->10.85.185.65:27072 codec: 102 ms: 0 [SUCCESS]
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:6003 sofia/internal/1001@10.85.185.65 Starting Video thread
2018-02-01 16:03:29.809259 [DEBUG] switch_core_media.c:5869 sofia/internal/1001@10.85.185.65 Video thread started. Echo is off
2018-02-01 16:03:29.809259 [INFO] switch_core_media.c:7478 Activating VIDEO RTCP PORT 27073 interval 1000 mux -1
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 27073
2018-02-01 16:03:29.809259 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 10.85.185.65:27073 2
2018-02-01 16:03:29.809259 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@10.85.185.65!
2018-02-01 16:03:29.829271 [DEBUG] switch_channel.c:3474 (sofia/internal/1001@10.85.185.65) Callstate Change DOWN -> EARLY
2018-02-01 16:03:29.839451 [DEBUG] sofia.c:7084 Channel sofia/internal/0000@10.85.185.65 entering state [early][183]
2018-02-01 16:03:29.839451 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/1001@10.85.185.65]
2018-02-01 16:03:29.839451 [INFO] switch_channel.c:3129 sofia/internal/1001@10.85.185.65 Flipping CID from "0000" <0000> to "1001" <1001>
2018-02-01 16:03:29.839451 [DEBUG] mod_commands.c:4862 (sofia/internal/1001@10.85.185.65) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2018-02-01 16:03:29.839451 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.85.185.65) Running State Change CS_EXECUTE (Cur 4 Tot 4)
2018-02-01 16:03:29.839451 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@10.85.185.65) State EXECUTE
2018-02-01 16:03:29.839451 [DEBUG] mod_sofia.c:198 sofia/internal/1001@10.85.185.65 SOFIA EXECUTE
2018-02-01 16:03:29.839451 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@10.85.185.65 Standard EXECUTE
EXECUTE sofia/internal/1001@10.85.185.65 park()
2018-02-01 16:03:29.879448 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2018-02-01 16:03:29.929445 [NOTICE] switch_vpx.c:406 VPX reset encoder picture from 320x240 to 352x288 1024 BW
2018-02-01 16:03:29.939439 [NOTICE] switch_vpx.c:406 VPX reset encoder picture from 320x240 to 352x288 1024 BW
2018-02-01 16:03:29.979436 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: video ssrc[2034098188] base_seq[28491]
2018-02-01 16:03:29.979436 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: video ssrc[4248532124] base_seq[46952]
2018-02-01 16:03:30.099439 [DEBUG] switch_rtp.c:7271 Correct video ip/port confirmed.
2018-02-01 16:03:30.099439 [DEBUG] switch_rtp.c:7271 Correct video ip/port confirmed.
2018-02-01 16:03:31.589451 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:64001 entering state [terminated][408]
2018-02-01 16:03:31.589451 [NOTICE] sofia.c:8273 Hangup sofia/internal/1001@172.20.49.53:64001 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_HANGUP (Cur 4 Tot 4)
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@172.20.49.53:64001) Callstate Change DOWN -> HANGUP
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@172.20.49.53:64001) State HANGUP
2018-02-01 16:03:31.589451 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1001@172.20.49.53:64001 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@172.20.49.53:64001 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@172.20.49.53:64001) State HANGUP going to sleep
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@172.20.49.53:64001) State Change CS_HANGUP -> CS_REPORTING
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_REPORTING (Cur 4 Tot 4)
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@172.20.49.53:64001) State REPORTING
2018-02-01 16:03:31.589451 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("0000","0000","1001","default","2018-02-01 16:03:29","","2018-02-01 16:03:31",2,0,"RECOVERY_ON_TIMER_EXPIRE","13f68cd8-38e8-4c32-9f04-4a28dca4621e","","")
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@172.20.49.53:64001 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@172.20.49.53:64001) State REPORTING going to sleep
2018-02-01 16:03:31.589451 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@172.20.49.53:64001) State Change CS_REPORTING -> CS_DESTROY
2018-02-01 16:03:31.589451 [DEBUG] switch_core_session.c:1665 Session 3 (sofia/internal/1001@172.20.49.53:64001) Locked, Waiting on external entities
2018-02-01 16:03:32.199438 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:57952 entering state [completing][200]
2018-02-01 16:03:32.199438 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 244124720 3 IN IP4 172.20.49.53
s=X-Lite release 5.1.0 stamp 89320
c=IN IP4 172.20.49.53
t=0 0
m=audio 53608 RTP/AVP 9 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 0 RTP/AVP 19
2018-02-01 16:03:32.199438 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@172.20.49.53:57952 entering state [ready][200]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1001@172.20.49.53:57952 G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-02-01 16:03:32.199438 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@172.20.49.53:57952 Original read codec set to G722:9
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:4767 sofia/internal/1001@172.20.49.53:57952 Set 2833 dtmf send payload to 101 recv payload to 101
2018-02-01 16:03:32.199438 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1001@172.20.49.53:57952] 10.85.185.65 port 21804 -> 172.20.49.53 port 53608 codec: 9 ms: 20
2018-02-01 16:03:32.199438 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-02-01 16:03:32.209409 [DEBUG] switch_core_media.c:7179 sofia/internal/1001@172.20.49.53:57952 Set 2833 dtmf send payload to 101
2018-02-01 16:03:32.209409 [DEBUG] switch_core_media.c:7186 sofia/internal/1001@172.20.49.53:57952 Set 2833 dtmf receive payload to 101
2018-02-01 16:03:32.209409 [DEBUG] switch_core_media.c:7209 sofia/internal/1001@172.20.49.53:57952 Set rtp dtmf delay to 40
2018-02-01 16:03:32.209409 [NOTICE] sofia.c:8218 Channel [sofia/internal/1001@172.20.49.53:57952] has been answered
2018-02-01 16:03:32.209409 [DEBUG] switch_channel.c:3773 (sofia/internal/1001@172.20.49.53:57952) Callstate Change RINGING -> ACTIVE
2018-02-01 16:03:32.209409 [DEBUG] switch_core_codec.c:248 sofia/internal/0000@10.85.185.65 Restore previous codec G722:9.
2018-02-01 16:03:32.209409 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/0000@10.85.185.65.
2018-02-01 16:03:32.209409 [DEBUG] switch_core_media.c:7256 Video params are unchanged for sofia/internal/0000@10.85.185.65.
2018-02-01 16:03:32.209409 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/0000@10.85.185.65:
v=0
o=FreeSWITCH 1517459169 1517459171 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 22040 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 27072 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp:27073 IN IP4 10.85.185.65
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:32.209409 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/internal/0000@10.85.185.65] has been answered
2018-02-01 16:03:32.209409 [DEBUG] switch_channel.c:3773 (sofia/internal/0000@10.85.185.65) Callstate Change EARLY -> ACTIVE
2018-02-01 16:03:32.209409 [DEBUG] sofia.c:7084 Channel sofia/internal/0000@10.85.185.65 entering state [completed][200]
2018-02-01 16:03:32.209409 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/1001@172.20.49.53:57952]
2018-02-01 16:03:32.209409 [NOTICE] switch_core_session.c:1683 Session 3 (sofia/internal/1001@172.20.49.53:64001) Ended
2018-02-01 16:03:32.209409 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1001@172.20.49.53:64001 [CS_DESTROY]
2018-02-01 16:03:32.209409 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@172.20.49.53:64001) Running State Change CS_DESTROY (Cur 3 Tot 4)
2018-02-01 16:03:32.209409 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@172.20.49.53:64001) State DESTROY
2018-02-01 16:03:32.209409 [DEBUG] mod_sofia.c:343 sofia/internal/1001@172.20.49.53:64001 SOFIA DESTROY
2018-02-01 16:03:32.209409 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@172.20.49.53:64001 Standard DESTROY
2018-02-01 16:03:32.209409 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@172.20.49.53:64001) State DESTROY going to sleep
2018-02-01 16:03:32.219422 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/1001@172.20.49.53:57952]
2018-02-01 16:03:32.219422 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/1001@172.20.49.53:57952) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-02-01 16:03:32.219422 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@172.20.49.53:57952) Running State Change CS_EXCHANGE_MEDIA (Cur 3 Tot 4)
2018-02-01 16:03:32.219422 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1001@172.20.49.53:57952) State EXCHANGE_MEDIA
2018-02-01 16:03:32.219422 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2018-02-01 16:03:32.229437 [INFO] sofia.c:1268 sofia/internal/1001@10.85.185.65 Update Caller ID to "Outbound Call" <sip:1001@10.85.185.65>
2018-02-01 16:03:32.229437 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.85.185.65 entering state [completing][200]
2018-02-01 16:03:32.229437 [DEBUG] sofia.c:7091 Duplicate SDP
v=0
o=FreeSWITCH 1517459169 1517459170 IN IP4 10.85.185.65
s=FreeSWITCH
c=IN IP4 10.85.185.65
t=0 0
m=audio 22040 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 27072 RTP/AVP 102
b=AS:1024
a=rtpmap:102 VP8/90000
a=rtcp:27073 IN IP4 10.85.185.65
a=rtcp-fb:102 ccm fir
a=rtcp-fb:102 ccm tmmbr
a=rtcp-fb:102 nack
a=rtcp-fb:102 nack pli
2018-02-01 16:03:32.239447 [DEBUG] switch_rtp.c:7271 Correct video ip/port confirmed.
2018-02-01 16:03:32.249428 [DEBUG] sofia.c:7084 Channel sofia/internal/0000@10.85.185.65 entering state [ready][200]
2018-02-01 16:03:32.249428 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.85.185.65 entering state [ready][200]
2018-02-01 16:03:32.249428 [NOTICE] sofia.c:8159 Channel [sofia/internal/1001@10.85.185.65] has been answered
2018-02-01 16:03:32.249428 [DEBUG] switch_channel.c:3773 (sofia/internal/1001@10.85.185.65) Callstate Change EARLY -> ACTIVE
2018-02-01 16:03:32.259433 [DEBUG] switch_rtp.c:7271 Correct video ip/port confirmed.
2018-02-01 16:03:32.299438 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2018-02-01 16:03:32.339439 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2018-02-01 16:03:33.819454 [DEBUG] switch_rtp.c:6721 Correct video RTCP ip/port confirmed.
2018-02-01 16:03:33.829447 [DEBUG] switch_rtp.c:6721 Correct video RTCP ip/port confirmed.
freeswitch@strowger-freeswitch-6058743>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment