From Annalisa, 2 Years ago, written in Plain Text.
- view diff
Embed
  1. 2016-05-23 11:19:19.189827 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/3000@10.30.80.37 [1c895388-bdd1-4943-a5ae-823639c9d9b0]
  2. 2016-05-23 11:19:19.189827 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_NEW
  3. 2016-05-23 11:19:19.189827 [DEBUG] sofia.c:9376 sofia/internal/3000@10.30.80.37 receiving invite from 10.2.250.73:63361 version: 1.6.8 git 99de0ad 2016-05-05 15:38:32Z 64bit
  4. 2016-05-23 11:19:19.189827 [DEBUG] sofia.c:9543 IP 10.2.250.73 Rejected by acl "domains". Falling back to Digest auth.
  5. 2016-05-23 11:19:19.189827 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/3000@10.30.80.37) State NEW
  6. 2016-05-23 11:19:19.189827 [DEBUG] sofia.c:2214 detaching session 1c895388-bdd1-4943-a5ae-823639c9d9b0
  7. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:2322 Re-attaching to session 1c895388-bdd1-4943-a5ae-823639c9d9b0
  8. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:9376 sofia/internal/3000@10.30.80.37 receiving invite from 10.2.250.73:63361 version: 1.6.8 git 99de0ad 2016-05-05 15:38:32Z 64bit
  9. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:9543 IP 10.2.250.73 Rejected by acl "domains". Falling back to Digest auth.
  10. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:6858 Channel sofia/internal/3000@10.30.80.37 entering state [received][100]
  11. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:6868 Remote SDP:
  12. v=0
  13. o=- 13108472367345806 1 IN IP4 10.2.251.5
  14. s=X-Lite release 4.9.3 stamp 79961
  15. c=IN IP4 10.2.251.5
  16. t=0 0
  17. m=audio 54922 RTP/AVP 9 8 120 0 84 101
  18. a=rtpmap:120 opus/48000/2
  19. a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  20. a=rtpmap:84 speex/16000
  21. a=rtpmap:101 telephone-event/8000
  22. a=fmtp:101 0-15
  23.  
  24. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:7227 (sofia/internal/3000@10.30.80.37) State Change CS_NEW -> CS_INIT
  25. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_INIT
  26. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/3000@10.30.80.37) State INIT
  27. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:89 sofia/internal/3000@10.30.80.37 SOFIA INIT
  28. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:40 sofia/internal/3000@10.30.80.37 Standard INIT
  29. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/3000@10.30.80.37) State Change CS_INIT -> CS_ROUTING
  30. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/3000@10.30.80.37) State INIT going to sleep
  31. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_ROUTING
  32. 2016-05-23 11:19:19.229892 [DEBUG] switch_channel.c:2249 (sofia/internal/3000@10.30.80.37) Callstate Change DOWN -> RINGING
  33. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/3000@10.30.80.37) State ROUTING
  34. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:142 sofia/internal/3000@10.30.80.37 SOFIA ROUTING
  35. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:236 sofia/internal/3000@10.30.80.37 Standard ROUTING
  36. 2016-05-23 11:19:19.229892 [INFO] mod_dialplan_xml.c:637 Processing 3000 <3000>->2000 in context default
  37. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->unloop] continue=false
  38. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  39. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  40. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->holiday_example] continue=true
  41. Dialplan: sofia/internal/3000@10.30.80.37 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  42. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->tod_3002_xfer] continue=false
  43. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [tod_3002_xfer] destination_number(2000) =~ /^3002$/ break=on-false
  44. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->global-intercept] continue=false
  45. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [global-intercept] destination_number(2000) =~ /^886$/ break=on-false
  46. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->group-intercept] continue=false
  47. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [group-intercept] destination_number(2000) =~ /^\*8$/ break=on-false
  48. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->intercept-ext] continue=false
  49. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [intercept-ext] destination_number(2000) =~ /^\*\*(\d+)$/ break=on-false
  50. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->redial] continue=false
  51. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [redial] destination_number(2000) =~ /^(redial|870)$/ break=on-false
  52. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->global] continue=true
  53. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  54. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [global] ${default_password}(1356) =~ /^1234$/ break=never
  55. Dialplan: sofia/internal/3000@10.30.80.37 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
  56. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  57. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  58. o=- 13108472367345806 1 IN IP4 10.2.251.5
  59. s=X-Lite release 4.9.3 stamp 79961
  60. c=IN IP4 10.2.251.5
  61. t=0 0
  62. m=audio 54922 RTP/AVP 9 8 120 0 84 101
  63. a=rtpmap:120 opus/48000/2
  64. a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  65. a=rtpmap:84 speex/16000
  66. a=rtpmap:101 telephone-event/8000
  67. a=fmtp:101 0-15
  68. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  69. Dialplan: sofia/internal/3000@10.30.80.37 Absolute Condition [global]
  70. Dialplan: sofia/internal/3000@10.30.80.37 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  71. Dialplan: sofia/internal/3000@10.30.80.37 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  72. Dialplan: sofia/internal/3000@10.30.80.37 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  73. Dialplan: sofia/internal/3000@10.30.80.37 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  74. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->snom-demo-2] continue=false
  75. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [snom-demo-2] destination_number(2000) =~ /^9001$/ break=on-false
  76. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->snom-demo-1] continue=false
  77. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [snom-demo-1] destination_number(2000) =~ /^9000$/ break=on-false
  78. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->eavesdrop] continue=false
  79. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [eavesdrop] destination_number(2000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  80. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->eavesdrop] continue=false
  81. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [eavesdrop] destination_number(2000) =~ /^779$/ break=on-false
  82. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->call_return] continue=false
  83. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [call_return] destination_number(2000) =~ /^\*69$|^869$|^lcr$/ break=on-false
  84. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->del-group] continue=false
  85. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [del-group] destination_number(2000) =~ /^80(\d{2})$/ break=on-false
  86. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->add-group] continue=false
  87. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [add-group] destination_number(2000) =~ /^81(\d{2})$/ break=on-false
  88. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->call-group-simo] continue=false
  89. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [call-group-simo] destination_number(2000) =~ /^82(\d{2})$/ break=on-false
  90. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->call-group-order] continue=false
  91. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [call-group-order] destination_number(2000) =~ /^83(\d{2})$/ break=on-false
  92. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->extension-intercom] continue=false
  93. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [extension-intercom] destination_number(2000) =~ /^8(10[01][0-9])$/ break=on-false
  94. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->Local_Extension] continue=false
  95. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Local_Extension] destination_number(2000) =~ /^(300[0-9])$/ break=on-false
  96. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->Local_Extension_Skinny] continue=false
  97. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Local_Extension_Skinny] destination_number(2000) =~ /^(11[01][0-9])$/ break=on-false
  98. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->operator] continue=false
  99. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [operator] destination_number(2000) =~ /^(operator|0)$/ break=on-false
  100. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->vmain] continue=false
  101. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [vmain] destination_number(2000) =~ /^vmain$|^4000$|^\*98$/ break=on-false
  102. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->sip_uri] continue=false
  103. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [sip_uri] destination_number(2000) =~ /^sip:(.*)$/ break=on-false
  104. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->nb_conferences] continue=false
  105. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [nb_conferences] destination_number(2000) =~ /^(30\d{2})$/ break=on-false
  106. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->wb_conferences] continue=false
  107. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [wb_conferences] destination_number(2000) =~ /^(31\d{2})$/ break=on-false
  108. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->uwb_conferences] continue=false
  109. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [uwb_conferences] destination_number(2000) =~ /^(32\d{2})$/ break=on-false
  110. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->cdquality_conferences] continue=false
  111. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [cdquality_conferences] destination_number(2000) =~ /^(33\d{2})$/ break=on-false
  112. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->cdquality_conferences] continue=false
  113. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [cdquality_conferences] destination_number(2000) =~ /^(35\d{2})$/ break=on-false
  114. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->freeswitch_public_conf_via_sip] continue=false
  115. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(2000) =~ /^9(888|8888|1616|3232)$/ break=on-false
  116. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->mad_boss_intercom] continue=false
  117. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [mad_boss_intercom] destination_number(2000) =~ /^0911$/ break=on-false
  118. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->mad_boss_intercom] continue=false
  119. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [mad_boss_intercom] destination_number(2000) =~ /^0912$/ break=on-false
  120. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->mad_boss] continue=false
  121. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [mad_boss] destination_number(2000) =~ /^0913$/ break=on-false
  122. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ivr_demo] continue=false
  123. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ivr_demo] destination_number(2000) =~ /^5000$/ break=on-false
  124. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->dynamic_conference] continue=false
  125. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [dynamic_conference] destination_number(2000) =~ /^5001$/ break=on-false
  126. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->rtp_multicast_page] continue=false
  127. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [rtp_multicast_page] destination_number(2000) =~ /^pagegroup$|^7243$/ break=on-false
  128. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->park] continue=false
  129. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [park] destination_number(2000) =~ /^5900$/ break=on-false
  130. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->unpark] continue=false
  131. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [unpark] destination_number(2000) =~ /^5901$/ break=on-false
  132. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->valet_park] continue=false
  133. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [valet_park] destination_number(2000) =~ /^(6000)$/ break=on-false
  134. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->valet_park] continue=false
  135. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [valet_park] destination_number(2000) =~ /^((?!6000)60\d{2})$/ break=on-false
  136. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->park] continue=false
  137. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
  138. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [park] destination_number(2000) =~ /park\+(\d+)/ break=on-false
  139. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->unpark] continue=false
  140. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
  141. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [unpark] destination_number(2000) =~ /^parking$/ break=on-false
  142. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->park] continue=false
  143. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
  144. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [park] destination_number(2000) =~ /callpark/ break=on-false
  145. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->unpark] continue=false
  146. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
  147. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [unpark] destination_number(2000) =~ /pickup/ break=on-false
  148. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->wait] continue=false
  149. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [wait] destination_number(2000) =~ /^wait$/ break=on-false
  150. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->fax_receive] continue=false
  151. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [fax_receive] destination_number(2000) =~ /^9178$/ break=on-false
  152. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->fax_transmit] continue=false
  153. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [fax_transmit] destination_number(2000) =~ /^9179$/ break=on-false
  154. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ringback_180] continue=false
  155. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ringback_180] destination_number(2000) =~ /^9180$/ break=on-false
  156. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ringback_183_uk_ring] continue=false
  157. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ringback_183_uk_ring] destination_number(2000) =~ /^9181$/ break=on-false
  158. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ringback_183_music_ring] continue=false
  159. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ringback_183_music_ring] destination_number(2000) =~ /^9182$/ break=on-false
  160. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ringback_post_answer_uk_ring] continue=false
  161. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(2000) =~ /^9183$/ break=on-false
  162. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ringback_post_answer_music] continue=false
  163. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ringback_post_answer_music] destination_number(2000) =~ /^9184$/ break=on-false
  164. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->ClueCon] continue=false
  165. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [ClueCon] destination_number(2000) =~ /^9191$/ break=on-false
  166. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->show_info] continue=false
  167. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [show_info] destination_number(2000) =~ /^9192$/ break=on-false
  168. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->video_record] continue=false
  169. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [video_record] destination_number(2000) =~ /^9193$/ break=on-false
  170. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->video_playback] continue=false
  171. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [video_playback] destination_number(2000) =~ /^9194$/ break=on-false
  172. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->delay_echo] continue=false
  173. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [delay_echo] destination_number(2000) =~ /^9195$/ break=on-false
  174. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->echo] continue=false
  175. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [echo] destination_number(2000) =~ /^9196$/ break=on-false
  176. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->milliwatt] continue=false
  177. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [milliwatt] destination_number(2000) =~ /^9197$/ break=on-false
  178. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->tone_stream] continue=false
  179. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [tone_stream] destination_number(2000) =~ /^9198$/ break=on-false
  180. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->zrtp_enrollement] continue=false
  181. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [zrtp_enrollement] destination_number(2000) =~ /^9787$/ break=on-false
  182. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->hold_music] continue=false
  183. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [hold_music] destination_number(2000) =~ /^9664$/ break=on-false
  184. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->laugh break] continue=false
  185. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [laugh break] destination_number(2000) =~ /^9386$/ break=on-false
  186. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->101] continue=false
  187. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [101] destination_number(2000) =~ /^101$/ break=on-false
  188. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->pizza_demo] continue=false
  189. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [pizza_demo] destination_number(2000) =~ /^(pizza|74992)$/ break=on-false
  190. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->Talking Clock Time] continue=false
  191. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Talking Clock Time] destination_number(2000) =~ /^9170$/ break=on-false
  192. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->Talking Clock Date] continue=false
  193. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Talking Clock Date] destination_number(2000) =~ /^9171$/ break=on-false
  194. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->Talking Clock Date and Time] continue=false
  195. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Talking Clock Date and Time] destination_number(2000) =~ /^9172$/ break=on-false
  196. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->local.example.com] continue=false
  197. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [local.example.com] ${toll_allow}(domestic,international,local) =~ /local/ break=on-false
  198. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [local.example.com] destination_number(2000) =~ /^(\d{7})$/ break=on-false
  199. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->domestic.example.com] continue=false
  200. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [domestic.example.com] ${toll_allow}(domestic,international,local) =~ /domestic/ break=on-false
  201. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [domestic.example.com] destination_number(2000) =~ /^(\d{11})$/ break=on-false
  202. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->international.example.com] continue=false
  203. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [international.example.com] ${toll_allow}(domestic,international,local) =~ /international/ break=on-false
  204. Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [international.example.com] destination_number(2000) =~ /^(011\d+)$/ break=on-false
  205. Dialplan: sofia/internal/3000@10.30.80.37 parsing [default->DialToCharlotteFreeSwitch-TEST] continue=false
  206. Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [DialToCharlotteFreeSwitch-TEST] destination_number(2000) =~ /^(20[01][0-9])$/ break=on-false
  207. Dialplan: sofia/internal/3000@10.30.80.37 Action bridge(sofia/internal/2000@10.30.88.12)
  208. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/3000@10.30.80.37) State Change CS_ROUTING -> CS_EXECUTE
  209. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/3000@10.30.80.37) State ROUTING going to sleep
  210. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_EXECUTE
  211. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/3000@10.30.80.37) State EXECUTE
  212. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:197 sofia/internal/3000@10.30.80.37 SOFIA EXECUTE
  213. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:328 sofia/internal/3000@10.30.80.37 Standard EXECUTE
  214. EXECUTE sofia/internal/3000@10.30.80.37 hash(insert/10.30.80.37-spymap/3000/1c895388-bdd1-4943-a5ae-823639c9d9b0)
  215. EXECUTE sofia/internal/3000@10.30.80.37 hash(insert/10.30.80.37-last_dial/3000/2000)
  216. EXECUTE sofia/internal/3000@10.30.80.37 hash(insert/10.30.80.37-last_dial/global/1c895388-bdd1-4943-a5ae-823639c9d9b0)
  217. EXECUTE sofia/internal/3000@10.30.80.37 export(RFC2822_DATE=Mon, 23 May 2016 11:19:19 +0100)
  218. 2016-05-23 11:19:19.229892 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 23 May 2016 11:19:19 +0100]
  219. EXECUTE sofia/internal/3000@10.30.80.37 bridge(sofia/internal/2000@10.30.88.12)
  220. 2016-05-23 11:19:19.229892 [DEBUG] switch_channel.c:1250 sofia/internal/3000@10.30.80.37 EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 23 May 2016 11:19:19 +0100] to event
  221. 2016-05-23 11:19:19.229892 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  222. 2016-05-23 11:19:19.229892 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/2000@10.30.88.12 [465dfcac-6356-43cb-88ca-71f2aacfbfe6]
  223. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:4813 (sofia/internal/2000@10.30.88.12) State Change CS_NEW -> CS_INIT
  224. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_INIT
  225. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/2000@10.30.88.12) State INIT
  226. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:89 sofia/internal/2000@10.30.88.12 SOFIA INIT
  227. 2016-05-23 11:19:19.229892 [DEBUG] sofia_glue.c:1257 sofia/internal/2000@10.30.88.12 sending invite version: 1.6.8 git 99de0ad 2016-05-05 15:38:32Z 64bit
  228. Local SDP:
  229. v=0
  230. o=FreeSWITCH 1463979859 1463979860 IN IP4 10.30.80.37
  231. s=FreeSWITCH
  232. c=IN IP4 10.30.80.37
  233. t=0 0
  234. m=audio 18900 RTP/AVP 9 8 120 0 101 102
  235. a=rtpmap:9 G722/8000
  236. a=rtpmap:8 PCMA/8000
  237. a=rtpmap:120 opus/48000/2
  238. a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
  239. a=rtpmap:0 PCMU/8000
  240. a=rtpmap:101 telephone-event/8000
  241. a=fmtp:101 0-16
  242. a=rtpmap:102 telephone-event/48000
  243. a=fmtp:102 0-16
  244. a=ptime:20
  245. a=sendrecv
  246.  
  247. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2000@10.30.88.12 Standard INIT
  248. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2000@10.30.88.12) State Change CS_INIT -> CS_ROUTING
  249. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/2000@10.30.88.12) State INIT going to sleep
  250. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_ROUTING
  251. 2016-05-23 11:19:19.229892 [DEBUG] sofia.c:6858 Channel sofia/internal/2000@10.30.88.12 entering state [calling][0]
  252. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/2000@10.30.88.12) State ROUTING
  253. 2016-05-23 11:19:19.229892 [DEBUG] mod_sofia.c:142 sofia/internal/2000@10.30.88.12 SOFIA ROUTING
  254. 2016-05-23 11:19:19.229892 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2000@10.30.88.12) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  255. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/2000@10.30.88.12) State ROUTING going to sleep
  256. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_CONSUME_MEDIA
  257. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/2000@10.30.88.12) State CONSUME_MEDIA
  258. 2016-05-23 11:19:19.229892 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/2000@10.30.88.12) State CONSUME_MEDIA going to sleep
  259. 2016-05-23 11:19:29.769887 [INFO] sofia.c:1255 sofia/internal/2000@10.30.88.12 Update Callee ID to "2000" <sip:2000@10.30.88.12>
  260. 2016-05-23 11:19:29.769887 [DEBUG] sofia.c:6858 Channel sofia/internal/2000@10.30.88.12 entering state [proceeding][183]
  261. 2016-05-23 11:19:29.769887 [DEBUG] sofia.c:6868 Remote SDP:
  262. v=0
  263. o=FreeSWITCH 1463977384 1463977385 IN IP4 10.30.88.12
  264. s=FreeSWITCH
  265. c=IN IP4 10.30.88.12
  266. t=0 0
  267. m=audio 21210 RTP/AVP 9 101
  268. a=rtpmap:9 G722/8000
  269. a=rtpmap:101 telephone-event/8000
  270. a=fmtp:101 0-16
  271. a=ptime:20
  272.  
  273. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  274. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  275. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  276. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:2]
  277. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  278. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  279. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:3090 Set Codec sofia/internal/2000@10.30.88.12 G722/8000 20 ms 160 samples 64000 bits 1 channels
  280. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_codec.c:111 sofia/internal/2000@10.30.88.12 Original read codec set to G722:9
  281. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  282. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4681 sofia/internal/2000@10.30.88.12 Set 2833 dtmf send payload to 101 recv payload to 101
  283. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/internal/2000@10.30.88.12] 10.30.80.37 port 18900 -> 10.30.88.12 port 21210 codec: 9 ms: 20
  284. 2016-05-23 11:19:29.769887 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  285. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6763 sofia/internal/2000@10.30.88.12 Set 2833 dtmf send payload to 101
  286. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6770 sofia/internal/2000@10.30.88.12 Set 2833 dtmf receive payload to 101
  287. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6793 sofia/internal/2000@10.30.88.12 Set rtp dtmf delay to 40
  288. 2016-05-23 11:19:29.769887 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/2000@10.30.88.12!
  289. 2016-05-23 11:19:29.769887 [DEBUG] switch_channel.c:3471 (sofia/internal/2000@10.30.88.12) Callstate Change DOWN -> EARLY
  290. 2016-05-23 11:19:29.769887 [INFO] switch_ivr_originate.c:3556 Sending early media
  291. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  292. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  293. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  294. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  295. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  296. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  297. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  298. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  299. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  300. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  301. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
  302. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  303. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
  304. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  305. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  306. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  307. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  308. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  309. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  310. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  311. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [speex:84:16000:20:0:1]/[opus:116:48000:20:0:1]
  312. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [speex:84:16000:20:0:1]/[G722:9:8000:20:64000:1]
  313. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  314. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  315. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
  316. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:3090 Set Codec sofia/internal/3000@10.30.80.37 G722/8000 20 ms 160 samples 64000 bits 1 channels
  317. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_codec.c:111 sofia/internal/3000@10.30.80.37 Original read codec set to G722:9
  318. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
  319. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:4681 sofia/internal/3000@10.30.80.37 Set 2833 dtmf send payload to 101 recv payload to 101
  320. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/internal/3000@10.30.80.37] 10.30.80.37 port 32720 -> 10.2.251.5 port 54922 codec: 9 ms: 20
  321. 2016-05-23 11:19:29.769887 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  322. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6763 sofia/internal/3000@10.30.80.37 Set 2833 dtmf send payload to 101
  323. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6770 sofia/internal/3000@10.30.80.37 Set 2833 dtmf receive payload to 101
  324. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_media.c:6793 sofia/internal/3000@10.30.80.37 Set rtp dtmf delay to 40
  325. 2016-05-23 11:19:29.769887 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/3000@10.30.80.37!
  326. 2016-05-23 11:19:29.769887 [DEBUG] switch_channel.c:3471 (sofia/internal/3000@10.30.80.37) Callstate Change RINGING -> EARLY
  327. 2016-05-23 11:19:29.769887 [DEBUG] mod_sofia.c:2367 Ring SDP:
  328. v=0
  329. o=FreeSWITCH 1463966049 1463966050 IN IP4 10.30.80.37
  330. s=FreeSWITCH
  331. c=IN IP4 10.30.80.37
  332. t=0 0
  333. m=audio 32720 RTP/AVP 9 101
  334. a=rtpmap:9 G722/8000
  335. a=rtpmap:101 telephone-event/8000
  336. a=fmtp:101 0-16
  337. a=ptime:20
  338. a=sendrecv
  339.  
  340. 2016-05-23 11:19:29.769887 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/2000@10.30.88.12]
  341. 2016-05-23 11:19:29.769887 [DEBUG] sofia.c:6858 Channel sofia/internal/3000@10.30.80.37 entering state [early][183]
  342. 2016-05-23 11:19:29.769887 [DEBUG] switch_ivr_bridge.c:1594 (sofia/internal/2000@10.30.88.12) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  343. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_EXCHANGE_MEDIA
  344. 2016-05-23 11:19:29.769887 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/2000@10.30.88.12) State EXCHANGE_MEDIA
  345. 2016-05-23 11:19:29.769887 [DEBUG] mod_sofia.c:628 SOFIA EXCHANGE_MEDIA
  346. 2016-05-23 11:19:29.849882 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
  347. 2016-05-23 11:19:30.169840 [INFO] switch_rtp.c:6669 Auto Changing audio port from 10.2.251.5:54922 to 10.2.250.73:54922
  348. 2016-05-23 11:19:31.009886 [DEBUG] sofia.c:6858 Channel sofia/internal/3000@10.30.80.37 entering state [terminated][487]
  349. 2016-05-23 11:19:31.009886 [NOTICE] sofia.c:7881 Hangup sofia/internal/3000@10.30.80.37 [CS_EXECUTE] [ORIGINATOR_CANCEL]
  350. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:707 sofia/internal/3000@10.30.80.37 ending bridge by request from read function
  351. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/3000@10.30.80.37]
  352. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:701 sofia/internal/3000@10.30.80.37 ending bridge by request from write function
  353. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/2000@10.30.88.12]
  354. 2016-05-23 11:19:31.009886 [NOTICE] switch_ivr_bridge.c:882 Hangup sofia/internal/2000@10.30.88.12 [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
  355. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/2000@10.30.88.12) State EXCHANGE_MEDIA going to sleep
  356. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_HANGUP
  357. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:1692 sofia/internal/2000@10.30.88.12 skip receive message [UNBRIDGE] (channel is hungup already)
  358. 2016-05-23 11:19:31.009886 [DEBUG] switch_ivr_bridge.c:1695 sofia/internal/3000@10.30.80.37 skip receive message [UNBRIDGE] (channel is hungup already)
  359. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_session.c:2796 sofia/internal/3000@10.30.80.37 skip receive message [PHONE_EVENT] (channel is hungup already)
  360. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/3000@10.30.80.37) State EXECUTE going to sleep
  361. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_HANGUP
  362. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/3000@10.30.80.37) Callstate Change EARLY -> HANGUP
  363. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/2000@10.30.88.12) Callstate Change EARLY -> HANGUP
  364. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/3000@10.30.80.37) State HANGUP
  365. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:437 Channel sofia/internal/3000@10.30.80.37 hanging up, cause: ORIGINATOR_CANCEL
  366. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/2000@10.30.88.12) State HANGUP
  367. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:431 sofia/internal/2000@10.30.88.12 Overriding SIP cause 487 with 487 from the other leg
  368. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:437 Channel sofia/internal/2000@10.30.88.12 hanging up, cause: ORIGINATOR_CANCEL
  369. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:60 sofia/internal/3000@10.30.80.37 Standard HANGUP, cause: ORIGINATOR_CANCEL
  370. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/3000@10.30.80.37) State HANGUP going to sleep
  371. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/3000@10.30.80.37) State Change CS_HANGUP -> CS_REPORTING
  372. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_REPORTING
  373. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/3000@10.30.80.37) State REPORTING
  374. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:501 Sending CANCEL to sofia/internal/2000@10.30.88.12
  375. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:174 sofia/internal/3000@10.30.80.37 Standard REPORTING, cause: ORIGINATOR_CANCEL
  376. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/3000@10.30.80.37) State REPORTING going to sleep
  377. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/3000@10.30.80.37) State Change CS_REPORTING -> CS_DESTROY
  378. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_session.c:1646 Session 166 (sofia/internal/3000@10.30.80.37) Locked, Waiting on external entities
  379. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2000@10.30.88.12 Standard HANGUP, cause: ORIGINATOR_CANCEL
  380. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/2000@10.30.88.12) State HANGUP going to sleep
  381. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/2000@10.30.88.12) State Change CS_HANGUP -> CS_REPORTING
  382. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/2000@10.30.88.12) Running State Change CS_REPORTING
  383. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/2000@10.30.88.12) State REPORTING
  384. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2000@10.30.88.12 Standard REPORTING, cause: ORIGINATOR_CANCEL
  385. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/2000@10.30.88.12) State REPORTING going to sleep
  386. 2016-05-23 11:19:31.009886 [NOTICE] switch_core_session.c:1664 Session 166 (sofia/internal/3000@10.30.80.37) Ended
  387. 2016-05-23 11:19:31.009886 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/3000@10.30.80.37 [CS_DESTROY]
  388. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/3000@10.30.80.37) Running State Change CS_DESTROY
  389. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/3000@10.30.80.37) State DESTROY
  390. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:342 sofia/internal/3000@10.30.80.37 SOFIA DESTROY
  391. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:181 sofia/internal/3000@10.30.80.37 Standard DESTROY
  392. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/3000@10.30.80.37) State DESTROY going to sleep
  393. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/2000@10.30.88.12) State Change CS_REPORTING -> CS_DESTROY
  394. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_session.c:1646 Session 167 (sofia/internal/2000@10.30.88.12) Locked, Waiting on external entities
  395. 2016-05-23 11:19:31.009886 [NOTICE] switch_core_session.c:1664 Session 167 (sofia/internal/2000@10.30.88.12) Ended
  396. 2016-05-23 11:19:31.009886 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/2000@10.30.88.12 [CS_DESTROY]
  397. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/2000@10.30.88.12) Running State Change CS_DESTROY
  398. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/2000@10.30.88.12) State DESTROY
  399. 2016-05-23 11:19:31.009886 [DEBUG] mod_sofia.c:342 sofia/internal/2000@10.30.88.12 SOFIA DESTROY
  400. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2000@10.30.88.12 Standard DESTROY
  401. 2016-05-23 11:19:31.009886 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/2000@10.30.88.12) State DESTROY going to sleep
  402.