freeswitch@voyage> 
2017-03-01 15:38:35.581718 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [terminated][487]
2017-03-01 15:38:35.581718 [NOTICE] sofia.c:8420 Hangup sofia/internal/1000@rayteldes.co.uk [CS_EXECUTE] [ORIGINATOR_CANCEL]
2017-03-01 15:38:35.601727 [NOTICE] switch_ivr_originate.c:3606 Hangup sofia/internal/1009@df7jal23ls0d.invalid [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_HANGUP (Cur 2 Tot 20)
2017-03-01 15:38:35.601727 [DEBUG] switch_ivr_originate.c:3823 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1009@df7jal23ls0d.invalid) Callstate Change DOWN -> HANGUP
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP
2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:443 sofia/internal/1009@df7jal23ls0d.invalid Overriding SIP cause 487 with 487 from the other leg
2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1009@df7jal23ls0d.invalid hanging up, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.601727 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
2017-03-01 15:38:35.601727 [DEBUG] switch_ivr_originate.c:3834 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1009@df7jal23ls0d.invalid
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1009@df7jal23ls0d.invalid Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP going to sleep
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_HANGUP -> CS_REPORTING
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_REPORTING (Cur 2 Tot 20)
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1009@df7jal23ls0d.invalid Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING going to sleep
2017-03-01 15:38:35.601727 [INFO] mod_dptools.c:3481 Originate Failed.  Cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_REPORTING -> CS_DESTROY
2017-03-01 15:38:35.601727 [DEBUG] switch_core_session.c:1712 Session 20 (sofia/internal/1009@df7jal23ls0d.invalid) Locked, Waiting on external entities
2017-03-01 15:38:35.601727 [NOTICE] switch_core_session.c:1730 Session 20 (sofia/internal/1009@df7jal23ls0d.invalid) Ended
2017-03-01 15:38:35.601727 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1009@df7jal23ls0d.invalid [CS_DESTROY]
2017-03-01 15:38:35.601727 [DEBUG] switch_core_session.c:2884 sofia/internal/1000@rayteldes.co.uk skip receive message [PHONE_EVENT] (channel is hungup already)
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@rayteldes.co.uk) State EXECUTE going to sleep
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_HANGUP (Cur 1 Tot 20)
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_DESTROY (Cur 1 Tot 20)
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@rayteldes.co.uk) Callstate Change RINGING -> HANGUP
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP
2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@rayteldes.co.uk hanging up, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY
2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:354 sofia/internal/1009@df7jal23ls0d.invalid SOFIA DESTROY
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1009@df7jal23ls0d.invalid Standard DESTROY
2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY going to sleep
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@rayteldes.co.uk Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP going to sleep
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@rayteldes.co.uk) State Change CS_HANGUP -> CS_REPORTING
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_REPORTING (Cur 1 Tot 20)
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@rayteldes.co.uk Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING going to sleep
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@rayteldes.co.uk) State Change CS_REPORTING -> CS_DESTROY
2017-03-01 15:38:35.611746 [DEBUG] switch_core_session.c:1712 Session 19 (sofia/internal/1000@rayteldes.co.uk) Locked, Waiting on external entities
2017-03-01 15:38:35.611746 [NOTICE] switch_core_session.c:1730 Session 19 (sofia/internal/1000@rayteldes.co.uk) Ended
2017-03-01 15:38:35.611746 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1000@rayteldes.co.uk [CS_DESTROY]
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_DESTROY (Cur 0 Tot 20)
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY
2017-03-01 15:38:35.611746 [DEBUG] mod_sofia.c:354 sofia/internal/1000@rayteldes.co.uk SOFIA DESTROY
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@rayteldes.co.uk Standard DESTROY
2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY going to sleep
2017-03-01 15:38:40.341737 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@rayteldes.co.uk [40cc7932-3cca-4129-bce4-a0bbe70b7d89]
2017-03-01 15:38:40.341737 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_NEW (Cur 1 Tot 21)
2017-03-01 15:38:40.341737 [DEBUG] sofia.c:10016 sofia/internal/1000@rayteldes.co.uk receiving invite from 192.168.0.102:55008 version: 1.9.0 git 91d62b7 2017-02-24 22:49:43Z 64bit
2017-03-01 15:38:40.341737 [DEBUG] sofia.c:10187 IP 192.168.0.102 Rejected by acl "domains". Falling back to Digest auth.
2017-03-01 15:38:40.341737 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@rayteldes.co.uk) State NEW
2017-03-01 15:38:40.341737 [DEBUG] sofia.c:2405 detaching session 40cc7932-3cca-4129-bce4-a0bbe70b7d89
2017-03-01 15:38:40.391733 [DEBUG] sofia.c:2514 Re-attaching to session 40cc7932-3cca-4129-bce4-a0bbe70b7d89
2017-03-01 15:38:40.401728 [DEBUG] sofia.c:10016 sofia/internal/1000@rayteldes.co.uk receiving invite from 192.168.0.102:55008 version: 1.9.0 git 91d62b7 2017-02-24 22:49:43Z 64bit
2017-03-01 15:38:40.401728 [DEBUG] sofia.c:10187 IP 192.168.0.102 Rejected by acl "domains". Falling back to Digest auth.
2017-03-01 15:38:40.411727 [DEBUG] sofia.c:11331 Setting NAT mode based on websockets
2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [received][100]
2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7251 Remote SDP:
v=0
o=mozilla...THIS_IS_SDPARTA-47.0 2664357058889094700 0 IN IP4 127.0.0.1
s=Doubango Telecom - firefox
t=0 0
a=sendrecv
a=fingerprint:sha-256 0F:88:3E:93:EB:97:AA:44:CD:3C:B4:F0:49:AA:94:77:78:72:23:62:0D:DF:74:C4:5F:D8:12:DE:6E:99:B4:B4
a=group:BUNDLE sdparta_0 sdparta_1
a=ice-options:trickle
a=msid-semantic:WMS *
m=audio 15507 UDP/TLS/RTP/SAVPF 109 9 0 8
c=IN IP4 89.197.91.230
a=rtpmap:109 opus/48000/2
a=fmtp:109 maxplaybackrate=48000;stereo=1
a=rtpmap:9 G722/8000/1
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=candidate:0 1 UDP 2122252543 192.168.0.102 54524 typ host
a=candidate:2 1 UDP 2122187007 192.168.122.1 44666 typ host
a=candidate:0 2 UDP 2122252542 192.168.0.102 41853 typ host
a=candidate:2 2 UDP 2122187006 192.168.122.1 39628 typ host
a=candidate:1 1 UDP 1686052863 89.197.91.230 15507 typ srflx raddr 192.168.0.102 rport 54524
a=candidate:3 1 UDP 1685987327 89.197.91.230 35005 typ srflx raddr 192.168.122.1 rport 44666
a=candidate:1 2 UDP 1686052862 89.197.91.230 46543 typ srflx raddr 192.168.0.102 rport 41853
a=candidate:3 2 UDP 1685987326 89.197.91.230 23183 typ srflx raddr 192.168.122.1 rport 39628
a=end-of-candidates
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
a=ice-ufrag:14e5dc97
a=mid:sdparta_0
a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {082d70f9-788b-4b41-b93f-83618c22d435}
a=rtcp:46543 IN IP4 89.197.91.230
a=rtcp-mux
a=setup:actpass
a=ssrc:2074604834 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
m=video 53618 UDP/TLS/RTP/SAVPF 120 126 97
c=IN IP4 89.197.91.230
a=rtpmap:120 VP8/90000
a=fmtp:120 max-fs=12288;max-fr=60
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=42e01f;level-asymmetry-allowed=1;packetization-mode=1
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=42e01f;level-asymmetry-allowed=1
a=candidate:0 1 UDP 2122252543 192.168.0.102 48991 typ host
a=candidate:2 1 UDP 2122187007 192.168.122.1 32851 typ host
a=candidate:0 2 UDP 2122252542 192.168.0.102 35312 typ host
a=candidate:2 2 UDP 2122187006 192.168.122.1 57587 typ host
a=candidate:1 1 UDP 1686052863 89.197.91.230 53618 typ srflx raddr 192.168.0.102 rport 48991
a=candidate:3 1 UDP 1685987327 89.197.91.230 56064 typ srflx raddr 192.168.122.1 rport 32851
a=candidate:1 2 UDP 1686052862 89.197.91.230 28368 typ srflx raddr 192.168.0.102 rport 35312
a=candidate:3 2 UDP 1685987326 89.197.91.230 21405 typ srflx raddr 192.168.122.1 rport 57587
a=end-of-candidates
a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
a=ice-ufrag:14e5dc97
a=mid:sdparta_1
a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {e13a6c33-b68d-4896-9129-6730102bc3ae}
a=rtcp:28368 IN IP4 89.197.91.230
a=rtcp-fb:120 nack
a=rtcp-fb:120 nack pli
a=rtcp-fb:120 ccm fir
a=rtcp-fb:126 nack
a=rtcp-fb:126 nack pli
a=rtcp-fb:126 ccm fir
a=rtcp-fb:97 nack
a=rtcp-fb:97 nack pli
a=rtcp-fb:97 ccm fir
a=rtcp-mux
a=setup:actpass
a=ssrc:3036601547 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}

2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7643 (sofia/internal/1000@rayteldes.co.uk) State Change CS_NEW -> CS_INIT
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_INIT (Cur 1 Tot 21)
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@rayteldes.co.uk) State INIT
2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:93 sofia/internal/1000@rayteldes.co.uk SOFIA INIT
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@rayteldes.co.uk Standard INIT
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@rayteldes.co.uk) State Change CS_INIT -> CS_ROUTING
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@rayteldes.co.uk) State INIT going to sleep
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_ROUTING (Cur 1 Tot 21)
2017-03-01 15:38:40.411727 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@rayteldes.co.uk) Callstate Change DOWN -> RINGING
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@rayteldes.co.uk) State ROUTING
2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:154 sofia/internal/1000@rayteldes.co.uk SOFIA ROUTING
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@rayteldes.co.uk Standard ROUTING
2017-03-01 15:38:40.411727 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1009 in context default
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->unloop] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1000@rayteldes.co.uk Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(open=true) 
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1000@rayteldes.co.uk Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global-intercept] destination_number(1009) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [group-intercept] destination_number(1009) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [intercept-ext] destination_number(1009) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->redial] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [redial] destination_number(1009) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->global] continue=true
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
Dialplan: sofia/internal/1000@rayteldes.co.uk 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/1000@rayteldes.co.uk Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=mozilla...THIS_IS_SDPARTA-47.0 2664357058889094700 0 IN IP4 127.0.0.1
s=Doubango Telecom - firefox
t=0 0
a=sendrecv
a=fingerprint:sha-256 0F:88:3E:93:EB:97:AA:44:CD:3C:B4:F0:49:AA:94:77:78:72:23:62:0D:DF:74:C4:5F:D8:12:DE:6E:99:B4:B4
a=group:BUNDLE sdparta_0 sdparta_1
a=ice-options:trickle
a=msid-semantic:WMS *
m=audio 15507 UDP/TLS/RTP/SAVPF 109 9 0 8
c=IN IP4 89.197.91.230
a=rtpmap:109 opus/48000/2
a=fmtp:109 maxplaybackrate=48000;stereo=1
a=rtpmap:9 G722/8000/1
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=candidate:0 1 UDP 2122252543 192.168.0.102 54524 typ host
a=candidate:2 1 UDP 2122187007 192.168.122.1 44666 typ host
a=candidate:0 2 UDP 2122252542 192.168.0.102 41853 typ host
a=candidate:2 2 UDP 2122187006 192.168.122.1 39628 typ host
a=candidate:1 1 UDP 1686052863 89.197.91.230 15507 typ srflx raddr 192.168.0.102 rport 54524
a=candidate:3 1 UDP 1685987327 89.197.91.230 35005 typ srflx raddr 192.168.122.1 rport 44666
a=candidate:1 2 UDP 1686052862 89.197.91.230 46543 typ srflx raddr 192.168.0.102 rport 41853
a=candidate:3 2 UDP 1685987326 89.197.91.230 23183 typ srflx raddr 192.168.122.1 rport 39628
a=end-of-candidates
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
a=ice-ufrag:14e5dc97
a=mid:sdparta_0
a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {082d70f9-788b-4b41-b93f-83618c22d435}
a=rtcp:46543 IN IP4 89.197.91.230
a=rtcp-mux
a=setup:actpass
a=ssrc:2074604834 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
m=video 53618 UDP/TLS/RTP/SAVPF 120 126 97
c=IN IP4 89.197.91.230
a=rtpmap:120 VP8/90000
a=fmtp:120 max-fs=12288;max-fr=60
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=42e01f;level-asymmetry-allowed=1;packetization-mode=1
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=42e01f;level-asymmetry-allowed=1
a=candidate:0 1 UDP 2122252543 192.168.0.102 48991 typ host
a=candidate:2 1 UDP 2122187007 192.168.122.1 32851 typ host
a=candidate:0 2 UDP 2122252542 192.168.0.102 35312 typ host
a=candidate:2 2 UDP 2122187006 192.168.122.1 57587 typ host
a=candidate:1 1 UDP 1686052863 89.197.91.230 53618 typ srflx raddr 192.168.0.102 rport 48991
a=candidate:3 1 UDP 1685987327 89.197.91.230 56064 typ srflx raddr 192.168.122.1 rport 32851
a=candidate:1 2 UDP 1686052862 89.197.91.230 28368 typ srflx raddr 192.168.0.102 rport 35312
a=candidate:3 2 UDP 1685987326 89.197.91.230 21405 typ srflx raddr 192.168.122.1 rport 57587
a=end-of-candidates
a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
a=ice-ufrag:14e5dc97
a=mid:sdparta_1
a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {e13a6c33-b68d-4896-9129-6730102bc3ae}
a=rtcp:28368 IN IP4 89.197.91.230
a=rtcp-fb:120 nack
a=rtcp-fb:120 nack pli
a=rtcp-fb:120 ccm fir
a=rtcp-fb:126 nack
a=rtcp-fb:126 nack pli
a=rtcp-fb:126 ccm fir
a=rtcp-fb:97 nack
a=rtcp-fb:97 nack pli
a=rtcp-fb:97 ccm fir
a=rtcp-mux
a=setup:actpass
a=ssrc:3036601547 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1000@rayteldes.co.uk Absolute Condition [global]
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/global/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [snom-demo-2] destination_number(1009) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [snom-demo-1] destination_number(1009) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call_return] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call_return] destination_number(1009) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->del-group] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [del-group] destination_number(1009) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->add-group] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [add-group] destination_number(1009) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call-group-simo] destination_number(1009) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call-group-order] destination_number(1009) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [extension-intercom] destination_number(1009) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (PASS) [Local_Extension] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000@rayteldes.co.uk Action export(dialed_extension=1009) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(1 b s execute_extension::dx XML features) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(3 b s execute_extension::cf XML features) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(4 b s execute_extension::att_xfer XML features) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(ringback=${us-ring}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(transfer_ringback=local_stream://moh) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(call_timeout=30) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(hangup_after_bridge=true) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(continue_on_fail=true) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bridge(user/${dialed_extension}@${domain_name}) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action answer() 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action sleep(1000) 
Dialplan: sofia/internal/1000@rayteldes.co.uk Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@rayteldes.co.uk) State Change CS_ROUTING -> CS_EXECUTE
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@rayteldes.co.uk) State ROUTING going to sleep
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_EXECUTE (Cur 1 Tot 21)
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@rayteldes.co.uk) State EXECUTE
2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:209 sofia/internal/1000@rayteldes.co.uk SOFIA EXECUTE
2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@rayteldes.co.uk Standard EXECUTE
EXECUTE sofia/internal/1000@rayteldes.co.uk set(open=true)
2017-03-01 15:38:40.411727 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [open]=[true]
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-spymap/1000/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/1000/1009)
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/global/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk export(RFC2822_DATE=Wed, 01 Mar 2017 15:38:40 +0000)
2017-03-01 15:38:40.421714 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 01 Mar 2017 15:38:40 +0000]
EXECUTE sofia/internal/1000@rayteldes.co.uk export(dialed_extension=1009)
2017-03-01 15:38:40.421714 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1009]
EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(1 b s execute_extension::dx XML features)
2017-03-01 15:38:40.421714 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *1 execute_extension::dx XML features
EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2017-03-01-15-38-40.wav)
2017-03-01 15:38:40.421714 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1000.2017-03-01-15-38-40.wav
EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(3 b s execute_extension::cf XML features)
2017-03-01 15:38:40.421714 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *3 execute_extension::cf XML features
EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(4 b s execute_extension::att_xfer XML features)
2017-03-01 15:38:40.431736 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/1000@rayteldes.co.uk set(ringback=%(2000,4000,440,480))
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1000@rayteldes.co.uk set(transfer_ringback=local_stream://moh)
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1000@rayteldes.co.uk set(call_timeout=30)
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [call_timeout]=[30]
EXECUTE sofia/internal/1000@rayteldes.co.uk set(hangup_after_bridge=true)
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1000@rayteldes.co.uk set(continue_on_fail=true)
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [continue_on_fail]=[true]
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-call_return/1009/1000)
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/1009/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk set(called_party_callgroup=techsupport)
2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/techsupport/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/global/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/techsupport/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
EXECUTE sofia/internal/1000@rayteldes.co.uk bridge(user/1009@192.168.0.104)
2017-03-01 15:38:40.441712 [DEBUG] switch_channel.c:1250 sofia/internal/1000@rayteldes.co.uk EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 01 Mar 2017 15:38:40 +0000] to event
2017-03-01 15:38:40.441712 [DEBUG] switch_channel.c:1250 sofia/internal/1000@rayteldes.co.uk EXPORTING[export_vars] [dialed_extension]=[1009] to event
2017-03-01 15:38:40.441712 [DEBUG] switch_ivr_originate.c:2143 Parsing global variables
2017-03-01 15:38:40.451709 [DEBUG] switch_channel.c:1250 sofia/internal/1000@rayteldes.co.uk EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 01 Mar 2017 15:38:40 +0000] to event
2017-03-01 15:38:40.451709 [DEBUG] switch_channel.c:1250 sofia/internal/1000@rayteldes.co.uk EXPORTING[export_vars] [dialed_extension]=[1009] to event
2017-03-01 15:38:40.451709 [DEBUG] switch_ivr_originate.c:2143 Parsing global variables
2017-03-01 15:38:40.451709 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1009@df7jal23ls0d.invalid [be33b115-8099-4125-b006-389cdab79078]
2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:5002 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_NEW -> CS_INIT
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_INIT (Cur 2 Tot 22)
2017-03-01 15:38:40.451709 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1009@df7jal23ls0d.invalid) State INIT
2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:93 sofia/internal/1009@df7jal23ls0d.invalid SOFIA INIT
2017-03-01 15:38:40.451709 [DEBUG] sofia_glue.c:1267 sips:1009@192.168.0.128:49588;rtcweb-breaker=yes;transport=wss Setting proxy route to sofia/internal/1009@df7jal23ls0d.invalid
2017-03-01 15:38:40.451709 [DEBUG] sofia_glue.c:1296 sofia/internal/1009@df7jal23ls0d.invalid sending invite version: 1.9.0 git 91d62b7 2017-02-24 22:49:43Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1488350132 1488350133 IN IP4 192.168.0.104
s=FreeSWITCH
c=IN IP4 192.168.0.104
t=0 0
a=msid-semantic: WMS 0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
m=audio 32588 RTP/SAVPF 102 9 0 8 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=rtpmap:101 telephone-event/8000
a=fingerprint:sha-256 18:87:44:40:A4:B1:1B:D2:30:EC:DD:94:D7:73:09:EA:90:12:88:69:9F:15:0A:1B:A9:1A:C7:FD:07:48:82:72
a=setup:actpass
a=rtcp-mux
a=rtcp:32588 IN IP4 192.168.0.104
a=ssrc:2630432881 cname:r35MOsLRUMDxbkbm
a=ssrc:2630432881 msid:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4 a0
a=ssrc:2630432881 mslabel:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
a=ssrc:2630432881 label:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4a0
a=ice-ufrag:jnl1U7iHv2OABQuS
a=ice-pwd:JquoI55tIzQJJSVT57KQ5Tor
a=candidate:3802157812 1 udp 659136 192.168.0.104 32588 typ host generation 0
a=candidate:3802157812 2 udp 659136 192.168.0.104 32588 typ host generation 0
a=ptime:20
a=sendrecv
m=video 32638 RTP/SAVPF 120
b=AS:1024
a=rtpmap:120 VP8/90000
a=fmtp:120 max-fs=12288;max-fr=60
a=sendrecv
a=fingerprint:sha-256 18:87:44:40:A4:B1:1B:D2:30:EC:DD:94:D7:73:09:EA:90:12:88:69:9F:15:0A:1B:A9:1A:C7:FD:07:48:82:72
a=setup:actpass
a=rtcp-mux
a=rtcp:32638 IN IP4 192.168.0.104
a=rtcp-fb:120 ccm fir
a=rtcp-fb:120 ccm tmmbr
a=rtcp-fb:120 nack
a=rtcp-fb:120 nack pli
a=ssrc:1886262480 cname:r35MOsLRUMDxbkbm
a=ssrc:1886262480 msid:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4 v0
a=ssrc:1886262480 mslabel:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
a=ssrc:1886262480 label:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4v0
a=ice-ufrag:yaRX2BwfgFkBpsqQ
a=ice-pwd:kbxO3b3ynt9OpYpNZ6BRxXXE
a=candidate:0169582455 1 udp 659136 192.168.0.104 32638 typ host generation 0
a=candidate:0169582455 2 udp 659135 192.168.0.104 32638 typ host generation 0
a=end-of-candidates

2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1009@df7jal23ls0d.invalid Standard INIT
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_INIT -> CS_ROUTING
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1009@df7jal23ls0d.invalid) State INIT going to sleep
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_ROUTING (Cur 2 Tot 22)
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1009@df7jal23ls0d.invalid) State ROUTING
2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:154 sofia/internal/1009@df7jal23ls0d.invalid SOFIA ROUTING
2017-03-01 15:38:40.451709 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1009@df7jal23ls0d.invalid) State ROUTING going to sleep
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 22)
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1009@df7jal23ls0d.invalid) State CONSUME_MEDIA
2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1009@df7jal23ls0d.invalid) State CONSUME_MEDIA going to sleep
2017-03-01 15:38:40.451709 [DEBUG] sofia.c:7241 Channel sofia/internal/1009@df7jal23ls0d.invalid entering state [calling][0]
2017-03-01 15:38:56.461732 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [terminated][487]
2017-03-01 15:38:56.461732 [NOTICE] sofia.c:8420 Hangup sofia/internal/1000@rayteldes.co.uk [CS_EXECUTE] [ORIGINATOR_CANCEL]
2017-03-01 15:38:56.481726 [NOTICE] switch_ivr_originate.c:3606 Hangup sofia/internal/1009@df7jal23ls0d.invalid [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_HANGUP (Cur 2 Tot 22)
2017-03-01 15:38:56.481726 [DEBUG] switch_ivr_originate.c:3823 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1009@df7jal23ls0d.invalid) Callstate Change DOWN -> HANGUP
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP
2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:443 sofia/internal/1009@df7jal23ls0d.invalid Overriding SIP cause 487 with 487 from the other leg
2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1009@df7jal23ls0d.invalid hanging up, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.481726 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1009@df7jal23ls0d.invalid
2017-03-01 15:38:56.481726 [DEBUG] switch_ivr_originate.c:3834 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1009@df7jal23ls0d.invalid Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP going to sleep
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_HANGUP -> CS_REPORTING
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_REPORTING (Cur 2 Tot 22)
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1009@df7jal23ls0d.invalid Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING going to sleep
2017-03-01 15:38:56.481726 [INFO] mod_dptools.c:3481 Originate Failed.  Cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_REPORTING -> CS_DESTROY
2017-03-01 15:38:56.481726 [DEBUG] switch_core_session.c:1712 Session 22 (sofia/internal/1009@df7jal23ls0d.invalid) Locked, Waiting on external entities
2017-03-01 15:38:56.481726 [NOTICE] switch_core_session.c:1730 Session 22 (sofia/internal/1009@df7jal23ls0d.invalid) Ended
2017-03-01 15:38:56.481726 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1009@df7jal23ls0d.invalid [CS_DESTROY]
2017-03-01 15:38:56.481726 [DEBUG] switch_core_session.c:2884 sofia/internal/1000@rayteldes.co.uk skip receive message [PHONE_EVENT] (channel is hungup already)
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@rayteldes.co.uk) State EXECUTE going to sleep
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_HANGUP (Cur 1 Tot 22)
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1009@df7jal23ls0d.invalid) Running State Change CS_DESTROY (Cur 1 Tot 22)
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@rayteldes.co.uk) Callstate Change RINGING -> HANGUP
2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:354 sofia/internal/1009@df7jal23ls0d.invalid SOFIA DESTROY
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1009@df7jal23ls0d.invalid Standard DESTROY
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY going to sleep
2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP
2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@rayteldes.co.uk hanging up, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@rayteldes.co.uk Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP going to sleep
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@rayteldes.co.uk) State Change CS_HANGUP -> CS_REPORTING
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_REPORTING (Cur 1 Tot 22)
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@rayteldes.co.uk Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING going to sleep
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@rayteldes.co.uk) State Change CS_REPORTING -> CS_DESTROY
2017-03-01 15:38:56.491717 [DEBUG] switch_core_session.c:1712 Session 21 (sofia/internal/1000@rayteldes.co.uk) Locked, Waiting on external entities
2017-03-01 15:38:56.491717 [NOTICE] switch_core_session.c:1730 Session 21 (sofia/internal/1000@rayteldes.co.uk) Ended
2017-03-01 15:38:56.491717 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1000@rayteldes.co.uk [CS_DESTROY]
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@rayteldes.co.uk) Running State Change CS_DESTROY (Cur 0 Tot 22)
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY
2017-03-01 15:38:56.491717 [DEBUG] mod_sofia.c:354 sofia/internal/1000@rayteldes.co.uk SOFIA DESTROY
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@rayteldes.co.uk Standard DESTROY
2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY going to sleep
freeswitch@voyage>