From awalin, 7 Years ago, written in Plain Text.
- view diff
Embed
  1. freeswitch@voyage>
  2. 2017-03-01 15:38:35.581718 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [terminated][487]
  3. 2017-03-01 15:38:35.581718 [NOTICE] sofia.c:8420 Hangup sofia/internal/1000@rayteldes.co.uk [CS_EXECUTE] [ORIGINATOR_CANCEL]
  4. 2017-03-01 15:38:35.601727 [NOTICE] switch_ivr_originate.c:3606 Hangup sofia/internal/1009@df7jal23ls0d.invalid [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
  5. 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)
  6. 2017-03-01 15:38:35.601727 [DEBUG] switch_ivr_originate.c:3823 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
  7. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1009@df7jal23ls0d.invalid) Callstate Change DOWN -> HANGUP
  8. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP
  9. 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
  10. 2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1009@df7jal23ls0d.invalid hanging up, cause: ORIGINATOR_CANCEL
  11. 2017-03-01 15:38:35.601727 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
  12. 2017-03-01 15:38:35.601727 [DEBUG] switch_ivr_originate.c:3834 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
  13. 2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1009@df7jal23ls0d.invalid
  14. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1009@df7jal23ls0d.invalid Standard HANGUP, cause: ORIGINATOR_CANCEL
  15. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP going to sleep
  16. 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
  17. 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)
  18. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING
  19. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1009@df7jal23ls0d.invalid Standard REPORTING, cause: ORIGINATOR_CANCEL
  20. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING going to sleep
  21. 2017-03-01 15:38:35.601727 [INFO] mod_dptools.c:3481 Originate Failed.  Cause: ORIGINATOR_CANCEL
  22. 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
  23. 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
  24. 2017-03-01 15:38:35.601727 [NOTICE] switch_core_session.c:1730 Session 20 (sofia/internal/1009@df7jal23ls0d.invalid) Ended
  25. 2017-03-01 15:38:35.601727 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1009@df7jal23ls0d.invalid [CS_DESTROY]
  26. 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)
  27. 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
  28. 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)
  29. 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)
  30. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@rayteldes.co.uk) Callstate Change RINGING -> HANGUP
  31. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP
  32. 2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@rayteldes.co.uk hanging up, cause: ORIGINATOR_CANCEL
  33. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY
  34. 2017-03-01 15:38:35.601727 [DEBUG] mod_sofia.c:354 sofia/internal/1009@df7jal23ls0d.invalid SOFIA DESTROY
  35. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1009@df7jal23ls0d.invalid Standard DESTROY
  36. 2017-03-01 15:38:35.601727 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY going to sleep
  37. 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
  38. 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
  39. 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
  40. 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)
  41. 2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING
  42. 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
  43. 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
  44. 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
  45. 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
  46. 2017-03-01 15:38:35.611746 [NOTICE] switch_core_session.c:1730 Session 19 (sofia/internal/1000@rayteldes.co.uk) Ended
  47. 2017-03-01 15:38:35.611746 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1000@rayteldes.co.uk [CS_DESTROY]
  48. 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)
  49. 2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY
  50. 2017-03-01 15:38:35.611746 [DEBUG] mod_sofia.c:354 sofia/internal/1000@rayteldes.co.uk SOFIA DESTROY
  51. 2017-03-01 15:38:35.611746 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@rayteldes.co.uk Standard DESTROY
  52. 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
  53. 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]
  54. 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)
  55. 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
  56. 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.
  57. 2017-03-01 15:38:40.341737 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@rayteldes.co.uk) State NEW
  58. 2017-03-01 15:38:40.341737 [DEBUG] sofia.c:2405 detaching session 40cc7932-3cca-4129-bce4-a0bbe70b7d89
  59. 2017-03-01 15:38:40.391733 [DEBUG] sofia.c:2514 Re-attaching to session 40cc7932-3cca-4129-bce4-a0bbe70b7d89
  60. 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
  61. 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.
  62. 2017-03-01 15:38:40.411727 [DEBUG] sofia.c:11331 Setting NAT mode based on websockets
  63. 2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [received][100]
  64. 2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7251 Remote SDP:
  65. v=0
  66. o=mozilla...THIS_IS_SDPARTA-47.0 2664357058889094700 0 IN IP4 127.0.0.1
  67. s=Doubango Telecom - firefox
  68. t=0 0
  69. a=sendrecv
  70. 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
  71. a=group:BUNDLE sdparta_0 sdparta_1
  72. a=ice-options:trickle
  73. a=msid-semantic:WMS *
  74. m=audio 15507 UDP/TLS/RTP/SAVPF 109 9 0 8
  75. c=IN IP4 89.197.91.230
  76. a=rtpmap:109 opus/48000/2
  77. a=fmtp:109 maxplaybackrate=48000;stereo=1
  78. a=rtpmap:9 G722/8000/1
  79. a=rtpmap:0 PCMU/8000
  80. a=rtpmap:8 PCMA/8000
  81. a=candidate:0 1 UDP 2122252543 192.168.0.102 54524 typ host
  82. a=candidate:2 1 UDP 2122187007 192.168.122.1 44666 typ host
  83. a=candidate:0 2 UDP 2122252542 192.168.0.102 41853 typ host
  84. a=candidate:2 2 UDP 2122187006 192.168.122.1 39628 typ host
  85. a=candidate:1 1 UDP 1686052863 89.197.91.230 15507 typ srflx raddr 192.168.0.102 rport 54524
  86. a=candidate:3 1 UDP 1685987327 89.197.91.230 35005 typ srflx raddr 192.168.122.1 rport 44666
  87. a=candidate:1 2 UDP 1686052862 89.197.91.230 46543 typ srflx raddr 192.168.0.102 rport 41853
  88. a=candidate:3 2 UDP 1685987326 89.197.91.230 23183 typ srflx raddr 192.168.122.1 rport 39628
  89. a=end-of-candidates
  90. a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
  91. a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
  92. a=ice-ufrag:14e5dc97
  93. a=mid:sdparta_0
  94. a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {082d70f9-788b-4b41-b93f-83618c22d435}
  95. a=rtcp:46543 IN IP4 89.197.91.230
  96. a=rtcp-mux
  97. a=setup:actpass
  98. a=ssrc:2074604834 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
  99. m=video 53618 UDP/TLS/RTP/SAVPF 120 126 97
  100. c=IN IP4 89.197.91.230
  101. a=rtpmap:120 VP8/90000
  102. a=fmtp:120 max-fs=12288;max-fr=60
  103. a=rtpmap:126 H264/90000
  104. a=fmtp:126 profile-level-id=42e01f;level-asymmetry-allowed=1;packetization-mode=1
  105. a=rtpmap:97 H264/90000
  106. a=fmtp:97 profile-level-id=42e01f;level-asymmetry-allowed=1
  107. a=candidate:0 1 UDP 2122252543 192.168.0.102 48991 typ host
  108. a=candidate:2 1 UDP 2122187007 192.168.122.1 32851 typ host
  109. a=candidate:0 2 UDP 2122252542 192.168.0.102 35312 typ host
  110. a=candidate:2 2 UDP 2122187006 192.168.122.1 57587 typ host
  111. a=candidate:1 1 UDP 1686052863 89.197.91.230 53618 typ srflx raddr 192.168.0.102 rport 48991
  112. a=candidate:3 1 UDP 1685987327 89.197.91.230 56064 typ srflx raddr 192.168.122.1 rport 32851
  113. a=candidate:1 2 UDP 1686052862 89.197.91.230 28368 typ srflx raddr 192.168.0.102 rport 35312
  114. a=candidate:3 2 UDP 1685987326 89.197.91.230 21405 typ srflx raddr 192.168.122.1 rport 57587
  115. a=end-of-candidates
  116. a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
  117. a=ice-ufrag:14e5dc97
  118. a=mid:sdparta_1
  119. a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {e13a6c33-b68d-4896-9129-6730102bc3ae}
  120. a=rtcp:28368 IN IP4 89.197.91.230
  121. a=rtcp-fb:120 nack
  122. a=rtcp-fb:120 nack pli
  123. a=rtcp-fb:120 ccm fir
  124. a=rtcp-fb:126 nack
  125. a=rtcp-fb:126 nack pli
  126. a=rtcp-fb:126 ccm fir
  127. a=rtcp-fb:97 nack
  128. a=rtcp-fb:97 nack pli
  129. a=rtcp-fb:97 ccm fir
  130. a=rtcp-mux
  131. a=setup:actpass
  132. a=ssrc:3036601547 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
  133.  
  134. 2017-03-01 15:38:40.411727 [DEBUG] sofia.c:7643 (sofia/internal/1000@rayteldes.co.uk) State Change CS_NEW -> CS_INIT
  135. 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)
  136. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@rayteldes.co.uk) State INIT
  137. 2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:93 sofia/internal/1000@rayteldes.co.uk SOFIA INIT
  138. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@rayteldes.co.uk Standard INIT
  139. 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
  140. 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
  141. 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)
  142. 2017-03-01 15:38:40.411727 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@rayteldes.co.uk) Callstate Change DOWN -> RINGING
  143. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@rayteldes.co.uk) State ROUTING
  144. 2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:154 sofia/internal/1000@rayteldes.co.uk SOFIA ROUTING
  145. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@rayteldes.co.uk Standard ROUTING
  146. 2017-03-01 15:38:40.411727 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1009 in context default
  147. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->unloop] continue=false
  148. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  149. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  150. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->tod_example] continue=true
  151. Dialplan: sofia/internal/1000@rayteldes.co.uk Date/Time Match (PASS) [tod_example] break=on-false
  152. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(open=true)
  153. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->holiday_example] continue=true
  154. Dialplan: sofia/internal/1000@rayteldes.co.uk Date/TimeMatch (FAIL) [holiday_example] break=on-false
  155. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->global-intercept] continue=false
  156. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global-intercept] destination_number(1009) =~ /^886$/ break=on-false
  157. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->group-intercept] continue=false
  158. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [group-intercept] destination_number(1009) =~ /^\*8$/ break=on-false
  159. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->intercept-ext] continue=false
  160. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [intercept-ext] destination_number(1009) =~ /^\*\*(\d+)$/ break=on-false
  161. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->redial] continue=false
  162. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [redial] destination_number(1009) =~ /^(redial|870)$/ break=on-false
  163. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->global] continue=true
  164. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  165. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
  166. 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
  167. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  168. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [global] ${switch_r_sdp}(v=0
  169. o=mozilla...THIS_IS_SDPARTA-47.0 2664357058889094700 0 IN IP4 127.0.0.1
  170. s=Doubango Telecom - firefox
  171. t=0 0
  172. a=sendrecv
  173. 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
  174. a=group:BUNDLE sdparta_0 sdparta_1
  175. a=ice-options:trickle
  176. a=msid-semantic:WMS *
  177. m=audio 15507 UDP/TLS/RTP/SAVPF 109 9 0 8
  178. c=IN IP4 89.197.91.230
  179. a=rtpmap:109 opus/48000/2
  180. a=fmtp:109 maxplaybackrate=48000;stereo=1
  181. a=rtpmap:9 G722/8000/1
  182. a=rtpmap:0 PCMU/8000
  183. a=rtpmap:8 PCMA/8000
  184. a=candidate:0 1 UDP 2122252543 192.168.0.102 54524 typ host
  185. a=candidate:2 1 UDP 2122187007 192.168.122.1 44666 typ host
  186. a=candidate:0 2 UDP 2122252542 192.168.0.102 41853 typ host
  187. a=candidate:2 2 UDP 2122187006 192.168.122.1 39628 typ host
  188. a=candidate:1 1 UDP 1686052863 89.197.91.230 15507 typ srflx raddr 192.168.0.102 rport 54524
  189. a=candidate:3 1 UDP 1685987327 89.197.91.230 35005 typ srflx raddr 192.168.122.1 rport 44666
  190. a=candidate:1 2 UDP 1686052862 89.197.91.230 46543 typ srflx raddr 192.168.0.102 rport 41853
  191. a=candidate:3 2 UDP 1685987326 89.197.91.230 23183 typ srflx raddr 192.168.122.1 rport 39628
  192. a=end-of-candidates
  193. a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
  194. a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
  195. a=ice-ufrag:14e5dc97
  196. a=mid:sdparta_0
  197. a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {082d70f9-788b-4b41-b93f-83618c22d435}
  198. a=rtcp:46543 IN IP4 89.197.91.230
  199. a=rtcp-mux
  200. a=setup:actpass
  201. a=ssrc:2074604834 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
  202. m=video 53618 UDP/TLS/RTP/SAVPF 120 126 97
  203. c=IN IP4 89.197.91.230
  204. a=rtpmap:120 VP8/90000
  205. a=fmtp:120 max-fs=12288;max-fr=60
  206. a=rtpmap:126 H264/90000
  207. a=fmtp:126 profile-level-id=42e01f;level-asymmetry-allowed=1;packetization-mode=1
  208. a=rtpmap:97 H264/90000
  209. a=fmtp:97 profile-level-id=42e01f;level-asymmetry-allowed=1
  210. a=candidate:0 1 UDP 2122252543 192.168.0.102 48991 typ host
  211. a=candidate:2 1 UDP 2122187007 192.168.122.1 32851 typ host
  212. a=candidate:0 2 UDP 2122252542 192.168.0.102 35312 typ host
  213. a=candidate:2 2 UDP 2122187006 192.168.122.1 57587 typ host
  214. a=candidate:1 1 UDP 1686052863 89.197.91.230 53618 typ srflx raddr 192.168.0.102 rport 48991
  215. a=candidate:3 1 UDP 1685987327 89.197.91.230 56064 typ srflx raddr 192.168.122.1 rport 32851
  216. a=candidate:1 2 UDP 1686052862 89.197.91.230 28368 typ srflx raddr 192.168.0.102 rport 35312
  217. a=candidate:3 2 UDP 1685987326 89.197.91.230 21405 typ srflx raddr 192.168.122.1 rport 57587
  218. a=end-of-candidates
  219. a=ice-pwd:59d1e027437ffc273e7e41b82bcf6f34
  220. a=ice-ufrag:14e5dc97
  221. a=mid:sdparta_1
  222. a=msid:{6a968897-db71-49fd-bb08-f4a480718e9e} {e13a6c33-b68d-4896-9129-6730102bc3ae}
  223. a=rtcp:28368 IN IP4 89.197.91.230
  224. a=rtcp-fb:120 nack
  225. a=rtcp-fb:120 nack pli
  226. a=rtcp-fb:120 ccm fir
  227. a=rtcp-fb:126 nack
  228. a=rtcp-fb:126 nack pli
  229. a=rtcp-fb:126 ccm fir
  230. a=rtcp-fb:97 nack
  231. a=rtcp-fb:97 nack pli
  232. a=rtcp-fb:97 ccm fir
  233. a=rtcp-mux
  234. a=setup:actpass
  235. a=ssrc:3036601547 cname:{aad37d1e-b298-4a61-b212-60386c5486e6}
  236. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  237. Dialplan: sofia/internal/1000@rayteldes.co.uk Absolute Condition [global]
  238. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  239. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  240. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/global/${uuid})
  241. Dialplan: sofia/internal/1000@rayteldes.co.uk Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  242. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->snom-demo-2] continue=false
  243. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [snom-demo-2] destination_number(1009) =~ /^9001$/ break=on-false
  244. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->snom-demo-1] continue=false
  245. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [snom-demo-1] destination_number(1009) =~ /^9000$/ break=on-false
  246. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->eavesdrop] continue=false
  247. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  248. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->eavesdrop] continue=false
  249. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [eavesdrop] destination_number(1009) =~ /^779$/ break=on-false
  250. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call_return] continue=false
  251. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call_return] destination_number(1009) =~ /^\*69$|^869$|^lcr$/ break=on-false
  252. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->del-group] continue=false
  253. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [del-group] destination_number(1009) =~ /^80(\d{2})$/ break=on-false
  254. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->add-group] continue=false
  255. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [add-group] destination_number(1009) =~ /^81(\d{2})$/ break=on-false
  256. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call-group-simo] continue=false
  257. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call-group-simo] destination_number(1009) =~ /^82(\d{2})$/ break=on-false
  258. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->call-group-order] continue=false
  259. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [call-group-order] destination_number(1009) =~ /^83(\d{2})$/ break=on-false
  260. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->extension-intercom] continue=false
  261. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (FAIL) [extension-intercom] destination_number(1009) =~ /^8(10[01][0-9])$/ break=on-false
  262. Dialplan: sofia/internal/1000@rayteldes.co.uk parsing [default->Local_Extension] continue=false
  263. Dialplan: sofia/internal/1000@rayteldes.co.uk Regex (PASS) [Local_Extension] destination_number(1009) =~ /^(10[01][0-9])$/ break=on-false
  264. Dialplan: sofia/internal/1000@rayteldes.co.uk Action export(dialed_extension=1009)
  265. Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(1 b s execute_extension::dx XML features)
  266. 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)
  267. Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(3 b s execute_extension::cf XML features)
  268. Dialplan: sofia/internal/1000@rayteldes.co.uk Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  269. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(ringback=${us-ring})
  270. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(transfer_ringback=local_stream://moh)
  271. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(call_timeout=30)
  272. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(hangup_after_bridge=true)
  273. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(continue_on_fail=true)
  274. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  275. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  276. Dialplan: sofia/internal/1000@rayteldes.co.uk Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  277. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  278. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  279. Dialplan: sofia/internal/1000@rayteldes.co.uk Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  280. Dialplan: sofia/internal/1000@rayteldes.co.uk Action bridge(user/${dialed_extension}@${domain_name})
  281. Dialplan: sofia/internal/1000@rayteldes.co.uk Action answer()
  282. Dialplan: sofia/internal/1000@rayteldes.co.uk Action sleep(1000)
  283. Dialplan: sofia/internal/1000@rayteldes.co.uk Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  284. 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
  285. 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
  286. 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)
  287. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@rayteldes.co.uk) State EXECUTE
  288. 2017-03-01 15:38:40.411727 [DEBUG] mod_sofia.c:209 sofia/internal/1000@rayteldes.co.uk SOFIA EXECUTE
  289. 2017-03-01 15:38:40.411727 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@rayteldes.co.uk Standard EXECUTE
  290. EXECUTE sofia/internal/1000@rayteldes.co.uk set(open=true)
  291. 2017-03-01 15:38:40.411727 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [open]=[true]
  292. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-spymap/1000/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  293. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/1000/1009)
  294. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/global/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  295. EXECUTE sofia/internal/1000@rayteldes.co.uk export(RFC2822_DATE=Wed, 01 Mar 2017 15:38:40 +0000)
  296. 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]
  297. EXECUTE sofia/internal/1000@rayteldes.co.uk export(dialed_extension=1009)
  298. 2017-03-01 15:38:40.421714 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1009]
  299. EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(1 b s execute_extension::dx XML features)
  300. 2017-03-01 15:38:40.421714 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *1 execute_extension::dx XML features
  301. 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)
  302. 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
  303. EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(3 b s execute_extension::cf XML features)
  304. 2017-03-01 15:38:40.421714 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *3 execute_extension::cf XML features
  305. EXECUTE sofia/internal/1000@rayteldes.co.uk bind_meta_app(4 b s execute_extension::att_xfer XML features)
  306. 2017-03-01 15:38:40.431736 [INFO] switch_ivr_async.c:4247 Bound B-Leg: *4 execute_extension::att_xfer XML features
  307. EXECUTE sofia/internal/1000@rayteldes.co.uk set(ringback=%(2000,4000,440,480))
  308. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [ringback]=[%(2000,4000,440,480)]
  309. EXECUTE sofia/internal/1000@rayteldes.co.uk set(transfer_ringback=local_stream://moh)
  310. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [transfer_ringback]=[local_stream://moh]
  311. EXECUTE sofia/internal/1000@rayteldes.co.uk set(call_timeout=30)
  312. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [call_timeout]=[30]
  313. EXECUTE sofia/internal/1000@rayteldes.co.uk set(hangup_after_bridge=true)
  314. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [hangup_after_bridge]=[true]
  315. EXECUTE sofia/internal/1000@rayteldes.co.uk set(continue_on_fail=true)
  316. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [continue_on_fail]=[true]
  317. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-call_return/1009/1000)
  318. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/1009/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  319. EXECUTE sofia/internal/1000@rayteldes.co.uk set(called_party_callgroup=techsupport)
  320. 2017-03-01 15:38:40.431736 [DEBUG] mod_dptools.c:1567 SET sofia/internal/1000@rayteldes.co.uk [called_party_callgroup]=[techsupport]
  321. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/techsupport/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  322. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial_ext/global/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  323. EXECUTE sofia/internal/1000@rayteldes.co.uk hash(insert/192.168.0.104-last_dial/techsupport/40cc7932-3cca-4129-bce4-a0bbe70b7d89)
  324. EXECUTE sofia/internal/1000@rayteldes.co.uk bridge(user/1009@192.168.0.104)
  325. 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
  326. 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
  327. 2017-03-01 15:38:40.441712 [DEBUG] switch_ivr_originate.c:2143 Parsing global variables
  328. 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
  329. 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
  330. 2017-03-01 15:38:40.451709 [DEBUG] switch_ivr_originate.c:2143 Parsing global variables
  331. 2017-03-01 15:38:40.451709 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1009@df7jal23ls0d.invalid [be33b115-8099-4125-b006-389cdab79078]
  332. 2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:5002 (sofia/internal/1009@df7jal23ls0d.invalid) State Change CS_NEW -> CS_INIT
  333. 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)
  334. 2017-03-01 15:38:40.451709 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  335. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1009@df7jal23ls0d.invalid) State INIT
  336. 2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:93 sofia/internal/1009@df7jal23ls0d.invalid SOFIA INIT
  337. 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
  338. 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
  339. Local SDP:
  340. v=0
  341. o=FreeSWITCH 1488350132 1488350133 IN IP4 192.168.0.104
  342. s=FreeSWITCH
  343. c=IN IP4 192.168.0.104
  344. t=0 0
  345. a=msid-semantic: WMS 0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
  346. m=audio 32588 RTP/SAVPF 102 9 0 8 103 101
  347. a=rtpmap:102 opus/48000/2
  348. a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
  349. a=rtpmap:9 G722/8000
  350. a=rtpmap:0 PCMU/8000
  351. a=rtpmap:8 PCMA/8000
  352. a=rtpmap:103 telephone-event/48000
  353. a=rtpmap:101 telephone-event/8000
  354. 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
  355. a=setup:actpass
  356. a=rtcp-mux
  357. a=rtcp:32588 IN IP4 192.168.0.104
  358. a=ssrc:2630432881 cname:r35MOsLRUMDxbkbm
  359. a=ssrc:2630432881 msid:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4 a0
  360. a=ssrc:2630432881 mslabel:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
  361. a=ssrc:2630432881 label:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4a0
  362. a=ice-ufrag:jnl1U7iHv2OABQuS
  363. a=ice-pwd:JquoI55tIzQJJSVT57KQ5Tor
  364. a=candidate:3802157812 1 udp 659136 192.168.0.104 32588 typ host generation 0
  365. a=candidate:3802157812 2 udp 659136 192.168.0.104 32588 typ host generation 0
  366. a=ptime:20
  367. a=sendrecv
  368. m=video 32638 RTP/SAVPF 120
  369. b=AS:1024
  370. a=rtpmap:120 VP8/90000
  371. a=fmtp:120 max-fs=12288;max-fr=60
  372. a=sendrecv
  373. 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
  374. a=setup:actpass
  375. a=rtcp-mux
  376. a=rtcp:32638 IN IP4 192.168.0.104
  377. a=rtcp-fb:120 ccm fir
  378. a=rtcp-fb:120 ccm tmmbr
  379. a=rtcp-fb:120 nack
  380. a=rtcp-fb:120 nack pli
  381. a=ssrc:1886262480 cname:r35MOsLRUMDxbkbm
  382. a=ssrc:1886262480 msid:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4 v0
  383. a=ssrc:1886262480 mslabel:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4
  384. a=ssrc:1886262480 label:0S2bvUw8cCbWNzQOk8l9RHWrWyTheIb4v0
  385. a=ice-ufrag:yaRX2BwfgFkBpsqQ
  386. a=ice-pwd:kbxO3b3ynt9OpYpNZ6BRxXXE
  387. a=candidate:0169582455 1 udp 659136 192.168.0.104 32638 typ host generation 0
  388. a=candidate:0169582455 2 udp 659135 192.168.0.104 32638 typ host generation 0
  389. a=end-of-candidates
  390.  
  391. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1009@df7jal23ls0d.invalid Standard INIT
  392. 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
  393. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1009@df7jal23ls0d.invalid) State INIT going to sleep
  394. 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)
  395. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1009@df7jal23ls0d.invalid) State ROUTING
  396. 2017-03-01 15:38:40.451709 [DEBUG] mod_sofia.c:154 sofia/internal/1009@df7jal23ls0d.invalid SOFIA ROUTING
  397. 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
  398. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1009@df7jal23ls0d.invalid) State ROUTING going to sleep
  399. 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)
  400. 2017-03-01 15:38:40.451709 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1009@df7jal23ls0d.invalid) State CONSUME_MEDIA
  401. 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
  402. 2017-03-01 15:38:40.451709 [DEBUG] sofia.c:7241 Channel sofia/internal/1009@df7jal23ls0d.invalid entering state [calling][0]
  403. 2017-03-01 15:38:56.461732 [DEBUG] sofia.c:7241 Channel sofia/internal/1000@rayteldes.co.uk entering state [terminated][487]
  404. 2017-03-01 15:38:56.461732 [NOTICE] sofia.c:8420 Hangup sofia/internal/1000@rayteldes.co.uk [CS_EXECUTE] [ORIGINATOR_CANCEL]
  405. 2017-03-01 15:38:56.481726 [NOTICE] switch_ivr_originate.c:3606 Hangup sofia/internal/1009@df7jal23ls0d.invalid [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
  406. 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)
  407. 2017-03-01 15:38:56.481726 [DEBUG] switch_ivr_originate.c:3823 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
  408. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1009@df7jal23ls0d.invalid) Callstate Change DOWN -> HANGUP
  409. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP
  410. 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
  411. 2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1009@df7jal23ls0d.invalid hanging up, cause: ORIGINATOR_CANCEL
  412. 2017-03-01 15:38:56.481726 [NOTICE] switch_ivr_originate.c:2846 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
  413. 2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1009@df7jal23ls0d.invalid
  414. 2017-03-01 15:38:56.481726 [DEBUG] switch_ivr_originate.c:3834 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
  415. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1009@df7jal23ls0d.invalid Standard HANGUP, cause: ORIGINATOR_CANCEL
  416. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1009@df7jal23ls0d.invalid) State HANGUP going to sleep
  417. 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
  418. 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)
  419. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING
  420. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1009@df7jal23ls0d.invalid Standard REPORTING, cause: ORIGINATOR_CANCEL
  421. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1009@df7jal23ls0d.invalid) State REPORTING going to sleep
  422. 2017-03-01 15:38:56.481726 [INFO] mod_dptools.c:3481 Originate Failed.  Cause: ORIGINATOR_CANCEL
  423. 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
  424. 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
  425. 2017-03-01 15:38:56.481726 [NOTICE] switch_core_session.c:1730 Session 22 (sofia/internal/1009@df7jal23ls0d.invalid) Ended
  426. 2017-03-01 15:38:56.481726 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1009@df7jal23ls0d.invalid [CS_DESTROY]
  427. 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)
  428. 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
  429. 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)
  430. 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)
  431. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY
  432. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@rayteldes.co.uk) Callstate Change RINGING -> HANGUP
  433. 2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:354 sofia/internal/1009@df7jal23ls0d.invalid SOFIA DESTROY
  434. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1009@df7jal23ls0d.invalid Standard DESTROY
  435. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1009@df7jal23ls0d.invalid) State DESTROY going to sleep
  436. 2017-03-01 15:38:56.481726 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@rayteldes.co.uk) State HANGUP
  437. 2017-03-01 15:38:56.481726 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@rayteldes.co.uk hanging up, cause: ORIGINATOR_CANCEL
  438. 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
  439. 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
  440. 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
  441. 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)
  442. 2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@rayteldes.co.uk) State REPORTING
  443. 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
  444. 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
  445. 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
  446. 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
  447. 2017-03-01 15:38:56.491717 [NOTICE] switch_core_session.c:1730 Session 21 (sofia/internal/1000@rayteldes.co.uk) Ended
  448. 2017-03-01 15:38:56.491717 [NOTICE] switch_core_session.c:1734 Close Channel sofia/internal/1000@rayteldes.co.uk [CS_DESTROY]
  449. 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)
  450. 2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@rayteldes.co.uk) State DESTROY
  451. 2017-03-01 15:38:56.491717 [DEBUG] mod_sofia.c:354 sofia/internal/1000@rayteldes.co.uk SOFIA DESTROY
  452. 2017-03-01 15:38:56.491717 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@rayteldes.co.uk Standard DESTROY
  453. 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
  454. freeswitch@voyage>
  455.