2016-04-01 13:13:58.137199 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@10.0.0.2:5062 [89c4a596-f7c8-11e5-aaf5-59c0b377cba3]
2016-04-01 13:13:58.137199 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_NEW
2016-04-01 13:13:58.137199 [DEBUG] sofia.c:9374 sofia/internal/1000@10.0.0.2:5062 receiving invite from 10.0.0.16:2051 version: 1.6.7 git d38d065 2016-04-01 01:36:13Z 64bit
2016-04-01 13:13:58.137199 [DEBUG] sofia.c:9541 IP 10.0.0.16 Rejected by acl "domains". Falling back to Digest auth.
2016-04-01 13:13:58.137199 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/1000@10.0.0.2:5062) State NEW
2016-04-01 13:13:58.137199 [DEBUG] sofia.c:2214 detaching session 89c4a596-f7c8-11e5-aaf5-59c0b377cba3
2016-04-01 13:13:58.237179 [DEBUG] sofia.c:2322 Re-attaching to session 89c4a596-f7c8-11e5-aaf5-59c0b377cba3
2016-04-01 13:13:58.237179 [DEBUG] sofia.c:9374 sofia/internal/1000@10.0.0.2:5062 receiving invite from 10.0.0.16:2051 version: 1.6.7 git d38d065 2016-04-01 01:36:13Z 64bit
2016-04-01 13:13:58.237179 [DEBUG] sofia.c:9541 IP 10.0.0.16 Rejected by acl "domains". Falling back to Digest auth.
2016-04-01 13:13:58.257177 [DEBUG] sofia.c:6858 Channel sofia/internal/1000@10.0.0.2:5062 entering state [received][100]
2016-04-01 13:13:58.257177 [DEBUG] sofia.c:6868 Remote SDP:
v=0
o=root 652455919 652455919 IN IP4 10.0.0.16
s=call
c=IN IP4 10.0.0.16
t=0 0
m=audio 55756 RTP/AVP 0 8 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2016-04-01 13:13:58.257177 [DEBUG] sofia.c:7227 (sofia/internal/1000@10.0.0.2:5062) State Change CS_NEW -> CS_INIT
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_INIT
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/1000@10.0.0.2:5062) State INIT
2016-04-01 13:13:58.257177 [DEBUG] mod_sofia.c:89 sofia/internal/1000@10.0.0.2:5062 SOFIA INIT
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@10.0.0.2:5062 Standard INIT
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@10.0.0.2:5062) State Change CS_INIT -> CS_ROUTING
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/1000@10.0.0.2:5062) State INIT going to sleep
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_ROUTING
2016-04-01 13:13:58.257177 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@10.0.0.2:5062) Callstate Change DOWN -> RINGING
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1000@10.0.0.2:5062) State ROUTING
2016-04-01 13:13:58.257177 [DEBUG] mod_sofia.c:142 sofia/internal/1000@10.0.0.2:5062 SOFIA ROUTING
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@10.0.0.2:5062 Standard ROUTING
2016-04-01 13:13:58.257177 [INFO] mod_dialplan_xml.c:637 Processing Ext 1000 <1000>->16502530000 in context default
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1000@10.0.0.2:5062 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action set(open=true)
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1000@10.0.0.2:5062 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [global-intercept] destination_number(16502530000) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [group-intercept] destination_number(16502530000) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [intercept-ext] destination_number(16502530000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->redial] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [redial] destination_number(16502530000) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->global] continue=true
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000@10.0.0.2:5062 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_19
2_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=root 652455919 652455919 IN IP4 10.0.0.16
s=call
c=IN IP4 10.0.0.16
t=0 0
m=audio 55756 RTP/AVP 0 8 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1000@10.0.0.2:5062 Absolute Condition [global]
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [snom-demo-2] destination_number(16502530000) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [snom-demo-1] destination_number(16502530000) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [eavesdrop] destination_number(16502530000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [eavesdrop] destination_number(16502530000) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->call_return] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [call_return] destination_number(16502530000) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->del-group] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [del-group] destination_number(16502530000) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->add-group] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [add-group] destination_number(16502530000) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [call-group-simo] destination_number(16502530000) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [call-group-order] destination_number(16502530000) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [extension-intercom] destination_number(16502530000) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->local_outbound] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (FAIL) [local_outbound] destination_number(16502530000) =~ /^([3689]\d{7})$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 parsing [default->gvoice_out] continue=false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Regex (PASS) [gvoice_out] destination_number(16502530000) =~ /^16502530000$/ break=on-false
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1000@10.0.0.2:5062 Action bridge(dingaling/gtalk/+16502530000@voice.google.com)
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@10.0.0.2:5062) State Change CS_ROUTING -> CS_EXECUTE
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1000@10.0.0.2:5062) State ROUTING going to sleep
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_EXECUTE
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/1000@10.0.0.2:5062) State EXECUTE
2016-04-01 13:13:58.257177 [DEBUG] mod_sofia.c:197 sofia/internal/1000@10.0.0.2:5062 SOFIA EXECUTE
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@10.0.0.2:5062 Standard EXECUTE
EXECUTE sofia/internal/1000@10.0.0.2:5062 set(open=true)
2016-04-01 13:13:58.257177 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1000@10.0.0.2:5062 [open]=[true]
EXECUTE sofia/internal/1000@10.0.0.2:5062 hash(insert/10.0.0.2-spymap/1000/89c4a596-f7c8-11e5-aaf5-59c0b377cba3)
EXECUTE sofia/internal/1000@10.0.0.2:5062 hash(insert/10.0.0.2-last_dial/1000/16502530000)
EXECUTE sofia/internal/1000@10.0.0.2:5062 hash(insert/10.0.0.2-last_dial/global/89c4a596-f7c8-11e5-aaf5-59c0b377cba3)
EXECUTE sofia/internal/1000@10.0.0.2:5062 export(RFC2822_DATE=Fri, 01 Apr 2016 13:13:58 +0800)
2016-04-01 13:13:58.257177 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 01 Apr 2016 13:13:58 +0800]
EXECUTE sofia/internal/1000@10.0.0.2:5062 set(hangup_after_bridge=true)
2016-04-01 13:13:58.257177 [DEBUG] mod_dptools.c:1519 SET sofia/internal/1000@10.0.0.2:5062 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1000@10.0.0.2:5062 bridge(dingaling/gtalk/+16502530000@voice.google.com)
2016-04-01 13:13:58.257177 [DEBUG] switch_channel.c:1250 sofia/internal/1000@10.0.0.2:5062 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 01 Apr 2016 13:13:58 +0800] to event
2016-04-01 13:13:58.257177 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:1037 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:SQ/dvM48OLMHV4U9aaWUWswEpZF/IsACAeKu4sXy]
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:1037 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:xwKu8vl+ukf2Le878fYjOd4Y3nREuu/p1qS/FSRY]
2016-04-01 13:13:58.257177 [NOTICE] switch_channel.c:1104 New Channel dingaling/gtalk/+16502530000@voice.google.com [89d50b66-f7c8-11e5-ab02-59c0b377cba3]
2016-04-01 13:13:58.257177 [CRIT] libdingaling.c:364 Created Session 2706462395
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:2673 (dingaling/gtalk/+16502530000@voice.google.com) State Change CS_NEW -> CS_INIT
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:2110 dingaling/gtalk/+16502530000@voice.google.com CHANNEL KILL
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:543 (dingaling/gtalk/+16502530000@voice.google.com) Running State Change CS_INIT
2016-04-01 13:13:58.257177 [DEBUG] switch_core_state_machine.c:586 (dingaling/gtalk/+16502530000@voice.google.com) State INIT
2016-04-01 13:13:58.257177 [NOTICE] mod_dingaling.c:1829 Ring-Ready dingaling/gtalk/+16502530000@voice.google.com!
2016-04-01 13:13:58.257177 [DEBUG] switch_channel.c:3343 (dingaling/gtalk/+16502530000@voice.google.com) Callstate Change DOWN -> RINGING
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:1705 Don't have my audio codec yet here's one
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:1751 Don't have video codec.
2016-04-01 13:13:58.257177 [DEBUG] mod_dingaling.c:1762 Send Describe [PCMU@8000]
2016-04-01 13:13:58.837168 [DEBUG] mod_dingaling.c:1640 Accepted 0 of 0 rtp candidates.
2016-04-01 13:13:58.837168 [DEBUG] mod_dingaling.c:1642 Accepted 0 of 0 rtcp candidates.
2016-04-01 13:13:58.837168 [DEBUG] mod_dingaling.c:1645 Accepted 0 of 0 video_rtp candidates
2016-04-01 13:13:58.837168 [DEBUG] mod_dingaling.c:1648 Accepted 0 of 0 video_rctp candidates
2016-04-01 13:13:59.097181 [CRIT] libdingaling.c:1843 Processing 1 packets in retry queue
2016-04-01 13:13:59.097181 [CRIT] libdingaling.c:1860 Sending packet 307 (2 left)
2016-04-01 13:13:59.097181 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:13:59.377221 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
xmpp:+16502530000@voice.google.com/srvenc-2JjoFXWduiS81PuS8bP+X2UAYyDVWst4
xmpp:+16502530000@voice.google.com/srvenc-2JjoFXWduiS81PuS8bP+X2UAYyDVWst4
2016-04-01 13:13:59.377221 [CRIT] libdingaling.c:1309 Cancel packet 307
2016-04-01 13:13:59.377221 [CRIT] libdingaling.c:392 Message for Session 2706462395
2016-04-01 13:13:59.377221 [DEBUG] mod_dingaling.c:4124 using Existing session for 2706462395
2016-04-01 13:13:59.377221 [DEBUG] mod_dingaling.c:1751 Don't have video codec.
2016-04-01 13:13:59.377221 [DEBUG] mod_dingaling.c:1762 Send Describe [PCMU@8000]
2016-04-01 13:13:59.377221 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:13:59.377221 [CRIT] libdingaling.c:1843 Processing 2 packets in retry queue
2016-04-01 13:13:59.377221 [CRIT] libdingaling.c:1871 Discarding packet 307
2016-04-01 13:13:59.377221 [CRIT] libdingaling.c:1860 Sending packet 308 (2 left)
2016-04-01 13:13:59.377221 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:13:59.417185 [DEBUG] mod_dingaling.c:1573 Stun Lookup Local 10.0.0.2:27354
2016-04-01 13:13:59.657183 [INFO] mod_dingaling.c:1583 Stun Success :27354
2016-04-01 13:13:59.657183 [DEBUG] mod_dingaling.c:1597 Send rtp Candidate :27354 [9nLDkES8Byi4fS4v]
2016-04-01 13:13:59.657183 [DEBUG] mod_dingaling.c:1573 Stun Lookup Local 10.0.0.2:27355
2016-04-01 13:13:59.677259 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
2016-04-01 13:13:59.677259 [CRIT] libdingaling.c:1309 Cancel packet 308
2016-04-01 13:13:59.677259 [CRIT] libdingaling.c:1843 Processing 1 packets in retry queue
2016-04-01 13:13:59.677259 [CRIT] libdingaling.c:1871 Discarding packet 308
2016-04-01 13:13:59.837224 [INFO] mod_dingaling.c:1583 Stun Success :27355
2016-04-01 13:13:59.837224 [DEBUG] mod_dingaling.c:1597 Send rtcp Candidate :27355 [noKNOQIhKbsTRyDJ]
2016-04-01 13:13:59.837224 [DEBUG] mod_dingaling.c:1640 Accepted 0 of 0 rtp candidates.
2016-04-01 13:13:59.837224 [DEBUG] mod_dingaling.c:1642 Accepted 0 of 0 rtcp candidates.
2016-04-01 13:13:59.837224 [DEBUG] mod_dingaling.c:1645 Accepted 0 of 0 video_rtp candidates
2016-04-01 13:13:59.837224 [DEBUG] mod_dingaling.c:1648 Accepted 0 of 0 video_rctp candidates
2016-04-01 13:14:00.677274 [CRIT] libdingaling.c:1843 Processing 2 packets in retry queue
2016-04-01 13:14:00.677274 [CRIT] libdingaling.c:1860 Sending packet 309 (2 left)
2016-04-01 13:14:00.677274 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:14:00.677274 [CRIT] libdingaling.c:1860 Sending packet 310 (2 left)
2016-04-01 13:14:00.677274 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:14:00.937188 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1309 Cancel packet 309
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1843 Processing 2 packets in retry queue
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1871 Discarding packet 309
2016-04-01 13:14:00.937188 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1309 Cancel packet 310
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1843 Processing 1 packets in retry queue
2016-04-01 13:14:00.937188 [CRIT] libdingaling.c:1871 Discarding packet 310
2016-04-01 13:14:01.137164 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
2016-04-01 13:14:01.137164 [CRIT] libdingaling.c:392 Message for Session 2706462395
2016-04-01 13:14:01.137164 [CRIT] libdingaling.c:570 New Candidate 1
name=rtp
type=relay
protocol=udp
username=34D6A1FD6261B847
password=
address=74.125.39.22
port=19305
pref=3.00
2016-04-01 13:14:01.137164 [CRIT] libdingaling.c:570 New Candidate 2
name=rtp
type=relay
protocol=tcp
username=34D6A1FD6261B847
password=
address=74.125.39.22
port=19305
pref=2.00
2016-04-01 13:14:01.137164 [CRIT] libdingaling.c:570 New Candidate 3
name=rtp
type=relay
protocol=ssltcp
username=34D6A1FD6261B847
password=
address=74.125.39.22
port=443
pref=1.00
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:4124 using Existing session for 2706462395
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3588 3 rtp candidates
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3608 candidate 74.125.39.22:19305 PASS ACL wan.auto
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3662 Acceptable rtp Candidate 74.125.39.22:19305
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3578 Candidate Error!
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3578 Candidate Error!
2016-04-01 13:14:01.137164 [DEBUG] mod_dingaling.c:3578 Candidate Error!
2016-04-01 13:14:01.137164 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:847 Terminate called from line 1917 state=CS_INIT
2016-04-01 13:14:01.157165 [NOTICE] mod_dingaling.c:872 Hangup dingaling/gtalk/+16502530000@voice.google.com [CS_INIT] [DESTINATION_OUT_OF_ORDER]
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:2110 dingaling/gtalk/+16502530000@voice.google.com CHANNEL KILL
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:2110 dingaling/gtalk/+16502530000@voice.google.com CHANNEL KILL
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:586 (dingaling/gtalk/+16502530000@voice.google.com) State INIT going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:543 (dingaling/gtalk/+16502530000@voice.google.com) Running State Change CS_HANGUP
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:809 (dingaling/gtalk/+16502530000@voice.google.com) Callstate Change RINGING -> HANGUP
2016-04-01 13:14:01.157165 [DEBUG] switch_ivr_originate.c:3750 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER]
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:811 (dingaling/gtalk/+16502530000@voice.google.com) State HANGUP
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:2079 dingaling/gtalk/+16502530000@voice.google.com CHANNEL HANGUP
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:60 dingaling/gtalk/+16502530000@voice.google.com Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:811 (dingaling/gtalk/+16502530000@voice.google.com) State HANGUP going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:578 (dingaling/gtalk/+16502530000@voice.google.com) State Change CS_HANGUP -> CS_REPORTING
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:2110 dingaling/gtalk/+16502530000@voice.google.com CHANNEL KILL
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:543 (dingaling/gtalk/+16502530000@voice.google.com) Running State Change CS_REPORTING
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:897 (dingaling/gtalk/+16502530000@voice.google.com) State REPORTING
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:174 dingaling/gtalk/+16502530000@voice.google.com Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:897 (dingaling/gtalk/+16502530000@voice.google.com) State REPORTING going to sleep
2016-04-01 13:14:01.157165 [INFO] mod_dptools.c:3401 Originate Failed. Cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [NOTICE] switch_channel.c:4807 Hangup sofia/internal/1000@10.0.0.2:5062 [CS_EXECUTE] [DESTINATION_OUT_OF_ORDER]
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:569 (dingaling/gtalk/+16502530000@voice.google.com) State Change CS_REPORTING -> CS_DESTROY
2016-04-01 13:14:01.157165 [DEBUG] mod_dingaling.c:2110 dingaling/gtalk/+16502530000@voice.google.com CHANNEL KILL
2016-04-01 13:14:01.157165 [DEBUG] switch_core_session.c:1646 Session 11 (dingaling/gtalk/+16502530000@voice.google.com) Locked, Waiting on external entities
2016-04-01 13:14:01.157165 [NOTICE] switch_core_session.c:1664 Session 11 (dingaling/gtalk/+16502530000@voice.google.com) Ended
2016-04-01 13:14:01.157165 [NOTICE] switch_core_session.c:1668 Close Channel dingaling/gtalk/+16502530000@voice.google.com [CS_DESTROY]
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:700 (dingaling/gtalk/+16502530000@voice.google.com) Running State Change CS_DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_session.c:2796 sofia/internal/1000@10.0.0.2:5062 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/1000@10.0.0.2:5062) State EXECUTE going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_HANGUP
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:710 (dingaling/gtalk/+16502530000@voice.google.com) State DESTROY
2016-04-01 13:14:01.157165 [CRIT] libdingaling.c:308 Destroyed Session 2706462395
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:181 dingaling/gtalk/+16502530000@voice.google.com Standard DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:710 (dingaling/gtalk/+16502530000@voice.google.com) State DESTROY going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/1000@10.0.0.2:5062) Callstate Change RINGING -> HANGUP
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/1000@10.0.0.2:5062) State HANGUP
2016-04-01 13:14:01.157165 [DEBUG] mod_sofia.c:437 Channel sofia/internal/1000@10.0.0.2:5062 hanging up, cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [DEBUG] mod_sofia.c:574 Responding to INVITE with: 502
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@10.0.0.2:5062 Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/1000@10.0.0.2:5062) State HANGUP going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/1000@10.0.0.2:5062) State Change CS_HANGUP -> CS_REPORTING
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_REPORTING
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/1000@10.0.0.2:5062) State REPORTING
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@10.0.0.2:5062 Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/1000@10.0.0.2:5062) State REPORTING going to sleep
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1000@10.0.0.2:5062) State Change CS_REPORTING -> CS_DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_session.c:1646 Session 10 (sofia/internal/1000@10.0.0.2:5062) Locked, Waiting on external entities
2016-04-01 13:14:01.157165 [NOTICE] switch_core_session.c:1664 Session 10 (sofia/internal/1000@10.0.0.2:5062) Ended
2016-04-01 13:14:01.157165 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/1000@10.0.0.2:5062 [CS_DESTROY]
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/1000@10.0.0.2:5062) Running State Change CS_DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/1000@10.0.0.2:5062) State DESTROY
2016-04-01 13:14:01.157165 [DEBUG] mod_sofia.c:342 sofia/internal/1000@10.0.0.2:5062 SOFIA DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@10.0.0.2:5062 Standard DESTROY
2016-04-01 13:14:01.157165 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/1000@10.0.0.2:5062) State DESTROY going to sleep
2016-04-01 13:14:02.137166 [CRIT] libdingaling.c:1843 Processing 1 packets in retry queue
2016-04-01 13:14:02.137166 [CRIT] libdingaling.c:1860 Sending packet 311 (2 left)
2016-04-01 13:14:02.137166 [NOTICE] libdingaling.c:1755 SecSEND:
-------------------------------------------------------------------------------
2016-04-01 13:14:02.417233 [INFO] libdingaling.c:1753 SecRECV:
-------------------------------------------------------------------------------
2016-04-01 13:14:02.417233 [CRIT] libdingaling.c:1309 Cancel packet 311
2016-04-01 13:14:02.417233 [CRIT] libdingaling.c:1843 Processing 1 packets in retry queue
2016-04-01 13:14:02.417233 [CRIT] libdingaling.c:1871 Discarding packet 311
2016-04-01 13:14:08.837181 [DEBUG] mod_dingaling.c:1640 Accepted 0 of 0 rtp candidates.
2016-04-01 13:14:08.837181 [DEBUG] mod_dingaling.c:1642 Accepted 0 of 0 rtcp candidates.
2016-04-01 13:14:08.837181 [DEBUG] mod_dingaling.c:1645 Accepted 0 of 0 video_rtp candidates
2016-04-01 13:14:08.837181 [DEBUG] mod_dingaling.c:1648 Accepted 0 of 0 video_rctp candidates