From josh, 7 Years ago, written in Plain Text.
- go back
Embed
Viewing differences between and Firefox log
  1. 2017-06-21 17:15:39.637766 [DEBUG] mod_rtc.c:392 () State Change CS_NEW -> CS_INIT
  2. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_session.c:640 N/A set UUID=a3d97826-91a9-51c2-b4e6-549a1e02db53
  3. 2017-06-21 17:15:39.637766 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/1007 [a3d97826-91a9-51c2-b4e6-549a1e02db53]
  4. 2017-06-21 17:15:39.637766 [DEBUG] mod_verto.c:3728 Remote SDP verto.rtc/1007:
  5. v=0
  6. o=- 7530509066109054019 2 IN IP4 127.0.0.1
  7. s=-
  8. t=0 0
  9. a=group:BUNDLE audio video
  10. a=msid-semantic: WMS Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO
  11. m=audio 33538 UDP/TLS/RTP/SAVPF 111 103 9 0 8 105 13 110 113 126
  12. c=IN IP4 65.15.69.32
  13. a=rtcp:9 IN IP4 0.0.0.0
  14. a=candidate:356246754 1 udp 2122262783 2600:1005:8102:840c:0:47:ca5d:9a01 55789 typ host generation 0 network-id 1 network-cost 50
  15. a=candidate:2902406287 1 udp 2122194687 192.168.150.144 33538 typ host generation 0 network-id 2 network-cost 10
  16. a=candidate:1538791442 1 tcp 1518283007 2600:1005:8102:840c:0:47:ca5d:9a01 9 typ host tcptype active generation 0 network-id 1 network-cost 50
  17. a=candidate:3308616526 1 udp 1685987071 65.15.69.32 33538 typ srflx raddr 192.168.150.144 rport 33538 generation 0 network-id 2 network-cost 10
  18. a=candidate:3799828607 1 tcp 1518214911 192.168.150.144 9 typ host tcptype active generation 0 network-id 2 network-cost 10
  19. a=ice-ufrag:vS+Q
  20. a=ice-pwd:ghVLfUlIZpp2A3rE6FMuQGfz
  21. a=fingerprint:sha-256 AB:2B:67:CB:A2:8C:56:3C:5E:B9:29:20:86:FB:2C:BF:4A:A6:01:BD:E1:8C:28:C8:D3:2A:A4:85:59:D2:BF:2F
  22. a=setup:actpass
  23. a=mid:audio
  24. a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
  25. a=sendrecv
  26. a=rtcp-mux
  27. a=rtpmap:111 opus/48000/2
  28. a=rtcp-fb:111 transport-cc
  29. a=fmtp:111 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1
  30. a=rtpmap:103 ISAC/16000
  31. a=rtpmap:9 G722/8000
  32. a=rtpmap:0 PCMU/8000
  33. a=rtpmap:8 PCMA/8000
  34. a=rtpmap:105 CN/16000
  35. a=rtpmap:13 CN/8000
  36. a=rtpmap:110 telephone-event/48000
  37. a=rtpmap:113 telephone-event/16000
  38. a=rtpmap:126 telephone-event/8000
  39. a=ssrc:2623231321 cname:6rt6aYbfSGZzkR7G
  40. a=ssrc:2623231321 msid:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO de62be94-2fa6-4725-9188-4d90dae38bb2
  41. a=ssrc:2623231321 mslabel:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO
  42. a=ssrc:2623231321 label:de62be94-2fa6-4725-9188-4d90dae38bb2
  43. m=video 59965 UDP/TLS/RTP/SAVPF 96 98 100 102 127 97 99 101 104
  44. c=IN IP4 65.15.69.32
  45. a=rtcp:9 IN IP4 0.0.0.0
  46. a=candidate:356246754 1 udp 2122262783 2600:1005:8102:840c:0:47:ca5d:9a01 45863 typ host generation 0 network-id 1 network-cost 50
  47. a=candidate:2902406287 1 udp 2122194687 192.168.150.144 59965 typ host generation 0 network-id 2 network-cost 10
  48. a=candidate:1538791442 1 tcp 1518283007 2600:1005:8102:840c:0:47:ca5d:9a01 9 typ host tcptype active generation 0 network-id 1 network-cost 50
  49. a=candidate:3799828607 1 tcp 1518214911 192.168.150.144 9 typ host tcptype active generation 0 network-id 2 network-cost 10
  50. a=candidate:3308616526 1 udp 1685987071 65.15.69.32 59965 typ srflx raddr 192.168.150.144 rport 59965 generation 0 network-id 2 network-cost 10
  51. a=ice-ufrag:vS+Q
  52. a=ice-pwd:ghVLfUlIZpp2A3rE6FMuQGfz
  53. a=fingerprint:sha-256 AB:2B:67:CB:A2:8C:56:3C:5E:B9:29:20:86:FB:2C:BF:4A:A6:01:BD:E1:8C:28:C8:D3:2A:A4:85:59:D2:BF:2F
  54. a=setup:actpass
  55. a=mid:video
  56. a=extmap:2 urn:ietf:params:rtp-hdrext:toffset
  57. a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
  58. a=extmap:4 urn:3gpp:video-orientation
  59. a=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
  60. a=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay
  61. a=sendrecv
  62. a=rtcp-mux
  63. a=rtcp-rsize
  64. a=rtpmap:96 VP8/90000
  65. a=rtcp-fb:96 ccm fir
  66. a=rtcp-fb:96 nack
  67. a=rtcp-fb:96 nack pli
  68. a=rtcp-fb:96 goog-remb
  69. a=rtcp-fb:96 transport-cc
  70. a=rtpmap:98 VP9/90000
  71. a=rtcp-fb:98 ccm fir
  72. a=rtcp-fb:98 nack
  73. a=rtcp-fb:98 nack pli
  74. a=rtcp-fb:98 goog-remb
  75. a=rtcp-fb:98 transport-cc
  76. a=rtpmap:100 red/90000
  77. a=rtpmap:102 ulpfec/90000
  78. a=rtpmap:127 H264/90000
  79. a=rtcp-fb:127 ccm fir
  80. a=rtcp-fb:127 nack
  81. a=rtcp-fb:127 nack pli
  82. a=rtcp-fb:127 goog-remb
  83. a=rtcp-fb:127 transport-cc
  84. a=fmtp:127 packetization-mode=1
  85. a=rtpmap:97 rtx/90000
  86. a=fmtp:97 apt=96
  87. a=rtpmap:99 rtx/90000
  88. a=fmtp:99 apt=98
  89. a=rtpmap:101 rtx/90000
  90. a=fmtp:101 apt=100
  91. a=rtpmap:104 rtx/90000
  92. a=fmtp:104 apt=127
  93. a=ssrc-group:FID 3760859939 2102148952
  94. a=ssrc:3760859939 cname:6rt6aYbfSGZzkR7G
  95. a=ssrc:3760859939 msid:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO f870fd74-8bd1-44d2-9e1c-9ad50c58f8e4
  96. a=ssrc:3760859939 mslabel:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO
  97. a=ssrc:3760859939 label:f870fd74-8bd1-44d2-9e1c-9ad50c58f8e4
  98. a=ssrc:2102148952 cname:6rt6aYbfSGZzkR7G
  99. a=ssrc:2102148952 msid:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO f870fd74-8bd1-44d2-9e1c-9ad50c58f8e4
  100. a=ssrc:2102148952 mslabel:Lss2ZdDeasdYftqmPZdHyKL6aPgc8YfCfoHO
  101. a=ssrc:2102148952 label:f870fd74-8bd1-44d2-9e1c-9ad50c58f8e4
  102.  
  103. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1007) Running State Change CS_INIT (Cur 1 Tot 23)
  104. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1007) State INIT
  105. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:40 verto.rtc/1007 Standard INIT
  106. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/1007) State Change CS_INIT -> CS_ROUTING
  107. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1007) State INIT going to sleep
  108. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1007) Running State Change CS_ROUTING (Cur 1 Tot 23)
  109. 2017-06-21 17:15:39.637766 [DEBUG] switch_channel.c:2249 (verto.rtc/1007) Callstate Change DOWN -> RINGING
  110. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1007) State ROUTING
  111. 2017-06-21 17:15:39.637766 [DEBUG] mod_rtc.c:89 verto.rtc/1007 RTC ROUTING
  112. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:236 verto.rtc/1007 Standard ROUTING
  113. 2017-06-21 17:15:39.637766 [INFO] mod_dialplan_xml.c:637 Processing Galaxy <galaxy@joshebosh.com>->1007 in context default
  114. Dialplan: verto.rtc/1007 parsing [default->unloop] continue=false
  115. Dialplan: verto.rtc/1007 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  116. Dialplan: verto.rtc/1007 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  117. Dialplan: verto.rtc/1007 parsing [default->tod_example] continue=true
  118. Dialplan: verto.rtc/1007 Date/Time Match (PASS) [tod_example] break=on-false
  119. Dialplan: verto.rtc/1007 Action set(open=true)
  120. Dialplan: verto.rtc/1007 parsing [default->holiday_example] continue=true
  121. Dialplan: verto.rtc/1007 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  122. Dialplan: verto.rtc/1007 parsing [default->global-intercept] continue=false
  123. Dialplan: verto.rtc/1007 Regex (FAIL) [global-intercept] destination_number(1007) =~ /^886$/ break=on-false
  124. Dialplan: verto.rtc/1007 parsing [default->group-intercept] continue=false
  125. Dialplan: verto.rtc/1007 Regex (FAIL) [group-intercept] destination_number(1007) =~ /^\*8$/ break=on-false
  126. Dialplan: verto.rtc/1007 parsing [default->intercept-ext] continue=false
  127. Dialplan: verto.rtc/1007 Regex (FAIL) [intercept-ext] destination_number(1007) =~ /^\*\*(\d+)$/ break=on-false
  128. Dialplan: verto.rtc/1007 parsing [default->redial] continue=false
  129. Dialplan: verto.rtc/1007 Regex (FAIL) [redial] destination_number(1007) =~ /^(redial|870)$/ break=on-false
  130. Dialplan: verto.rtc/1007 parsing [default->global] continue=true
  131. Dialplan: verto.rtc/1007 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  132. Dialplan: verto.rtc/1007 Regex (FAIL) [global] ${default_password}(j0sh3b0sh) =~ /^1234$/ break=never
  133. Dialplan: verto.rtc/1007 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
  134. Dialplan: verto.rtc/1007 Regex (FAIL) [global] ${endpoint_disposition}() =~ /^(DELAYED NEGOTIATION)/ break=on-false
  135. Dialplan: verto.rtc/1007 parsing [default->snom-demo-2] continue=false
  136. Dialplan: verto.rtc/1007 Regex (FAIL) [snom-demo-2] destination_number(1007) =~ /^9001$/ break=on-false
  137. Dialplan: verto.rtc/1007 parsing [default->snom-demo-1] continue=false
  138. Dialplan: verto.rtc/1007 Regex (FAIL) [snom-demo-1] destination_number(1007) =~ /^9000$/ break=on-false
  139. Dialplan: verto.rtc/1007 parsing [default->eavesdrop] continue=false
  140. Dialplan: verto.rtc/1007 Regex (FAIL) [eavesdrop] destination_number(1007) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  141. Dialplan: verto.rtc/1007 parsing [default->eavesdrop] continue=false
  142. Dialplan: verto.rtc/1007 Regex (FAIL) [eavesdrop] destination_number(1007) =~ /^779$/ break=on-false
  143. Dialplan: verto.rtc/1007 parsing [default->call_return] continue=false
  144. Dialplan: verto.rtc/1007 Regex (FAIL) [call_return] destination_number(1007) =~ /^\*69$|^869$|^lcr$/ break=on-false
  145. Dialplan: verto.rtc/1007 parsing [default->del-group] continue=false
  146. Dialplan: verto.rtc/1007 Regex (FAIL) [del-group] destination_number(1007) =~ /^80(\d{2})$/ break=on-false
  147. Dialplan: verto.rtc/1007 parsing [default->add-group] continue=false
  148. Dialplan: verto.rtc/1007 Regex (FAIL) [add-group] destination_number(1007) =~ /^81(\d{2})$/ break=on-false
  149. Dialplan: verto.rtc/1007 parsing [default->call-group-simo] continue=false
  150. Dialplan: verto.rtc/1007 Regex (FAIL) [call-group-simo] destination_number(1007) =~ /^82(\d{2})$/ break=on-false
  151. Dialplan: verto.rtc/1007 parsing [default->call-group-order] continue=false
  152. Dialplan: verto.rtc/1007 Regex (FAIL) [call-group-order] destination_number(1007) =~ /^83(\d{2})$/ break=on-false
  153. Dialplan: verto.rtc/1007 parsing [default->extension-intercom] continue=false
  154. Dialplan: verto.rtc/1007 Regex (FAIL) [extension-intercom] destination_number(1007) =~ /^8(10[01][0-9])$/ break=on-false
  155. Dialplan: verto.rtc/1007 parsing [default->Local_Extension] continue=false
  156. Dialplan: verto.rtc/1007 Regex (PASS) [Local_Extension] destination_number(1007) =~ /^(10[01][0-9])$/ break=on-false
  157. Dialplan: verto.rtc/1007 Action export(dialed_extension=1007)
  158. Dialplan: verto.rtc/1007 Action bind_meta_app(1 b s execute_extension::dx XML features)
  159. Dialplan: verto.rtc/1007 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  160. Dialplan: verto.rtc/1007 Action bind_meta_app(3 b s execute_extension::cf XML features)
  161. Dialplan: verto.rtc/1007 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  162. Dialplan: verto.rtc/1007 Action set(ringback=${us-ring})
  163. Dialplan: verto.rtc/1007 Action set(transfer_ringback=local_stream://moh)
  164. Dialplan: verto.rtc/1007 Action set(call_timeout=30)
  165. Dialplan: verto.rtc/1007 Action set(hangup_after_bridge=true)
  166. Dialplan: verto.rtc/1007 Action set(continue_on_fail=true)
  167. Dialplan: verto.rtc/1007 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  168. Dialplan: verto.rtc/1007 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  169. Dialplan: verto.rtc/1007 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  170. Dialplan: verto.rtc/1007 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  171. Dialplan: verto.rtc/1007 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  172. Dialplan: verto.rtc/1007 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  173. Dialplan: verto.rtc/1007 Action bridge(user/${dialed_extension}@${domain_name})
  174. Dialplan: verto.rtc/1007 Action answer()
  175. Dialplan: verto.rtc/1007 Action sleep(1000)
  176. Dialplan: verto.rtc/1007 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  177. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:286 (verto.rtc/1007) State Change CS_ROUTING -> CS_EXECUTE
  178. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1007) State ROUTING going to sleep
  179. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1007) Running State Change CS_EXECUTE (Cur 1 Tot 23)
  180. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1007) State EXECUTE
  181. 2017-06-21 17:15:39.637766 [DEBUG] mod_rtc.c:120 verto.rtc/1007 RTC EXECUTE
  182. 2017-06-21 17:15:39.637766 [DEBUG] switch_core_state_machine.c:328 verto.rtc/1007 Standard EXECUTE
  183. EXECUTE verto.rtc/1007 set(open=true)
  184. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [open]=[true]
  185. EXECUTE verto.rtc/1007 export(dialed_extension=1007)
  186. 2017-06-21 17:15:39.637766 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1007]
  187. EXECUTE verto.rtc/1007 bind_meta_app(1 b s execute_extension::dx XML features)
  188. 2017-06-21 17:15:39.637766 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *1 execute_extension::dx XML features
  189. EXECUTE verto.rtc/1007 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/galaxy@joshebosh.com.2017-06-21-17-15-39.wav)
  190. 2017-06-21 17:15:39.637766 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/galaxy@joshebosh.com.2017-06-21-17-15-39.wav
  191. EXECUTE verto.rtc/1007 bind_meta_app(3 b s execute_extension::cf XML features)
  192. 2017-06-21 17:15:39.637766 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *3 execute_extension::cf XML features
  193. EXECUTE verto.rtc/1007 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  194. 2017-06-21 17:15:39.637766 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *4 execute_extension::att_xfer XML features
  195. EXECUTE verto.rtc/1007 set(ringback=%(2000,4000,440,480))
  196. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [ringback]=[%(2000,4000,440,480)]
  197. EXECUTE verto.rtc/1007 set(transfer_ringback=local_stream://moh)
  198. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [transfer_ringback]=[local_stream://moh]
  199. EXECUTE verto.rtc/1007 set(call_timeout=30)
  200. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [call_timeout]=[30]
  201. EXECUTE verto.rtc/1007 set(hangup_after_bridge=true)
  202. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [hangup_after_bridge]=[true]
  203. EXECUTE verto.rtc/1007 set(continue_on_fail=true)
  204. 2017-06-21 17:15:39.637766 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [continue_on_fail]=[true]
  205. EXECUTE verto.rtc/1007 hash(insert/192.168.150.3-call_return/1007/galaxy@joshebosh.com)
  206. EXECUTE verto.rtc/1007 hash(insert/192.168.150.3-last_dial_ext/1007/a3d97826-91a9-51c2-b4e6-549a1e02db53)
  207. EXECUTE verto.rtc/1007 set(called_party_callgroup=techsupport)
  208. 2017-06-21 17:15:39.647735 [DEBUG] mod_dptools.c:1570 SET verto.rtc/1007 [called_party_callgroup]=[techsupport]
  209. EXECUTE verto.rtc/1007 hash(insert/192.168.150.3-last_dial_ext/techsupport/a3d97826-91a9-51c2-b4e6-549a1e02db53)
  210. EXECUTE verto.rtc/1007 hash(insert/192.168.150.3-last_dial_ext/global/a3d97826-91a9-51c2-b4e6-549a1e02db53)
  211. EXECUTE verto.rtc/1007 hash(insert/192.168.150.3-last_dial/techsupport/a3d97826-91a9-51c2-b4e6-549a1e02db53)
  212. EXECUTE verto.rtc/1007 bridge(user/1007@192.168.150.3)
  213. 2017-06-21 17:15:39.647735 [DEBUG] switch_channel.c:1250 verto.rtc/1007 EXPORTING[export_vars] [dialed_extension]=[1007] to event
  214. 2017-06-21 17:15:39.647735 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  215. 2017-06-21 17:15:39.647735 [DEBUG] switch_channel.c:1250 verto.rtc/1007 EXPORTING[export_vars] [dialed_extension]=[1007] to event
  216. 2017-06-21 17:15:39.647735 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  217. 2017-06-21 17:15:39.647735 [NOTICE] switch_ivr_originate.c:2856 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  218. 2017-06-21 17:15:39.647735 [DEBUG] mod_rtc.c:392 () State Change CS_NEW -> CS_INIT
  219. 2017-06-21 17:15:39.647735 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 [0ce12d5a-d47c-47d0-9658-8425484ed126]
  220. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_INIT (Cur 2 Tot 24)
  221. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State INIT
  222. 2017-06-21 17:15:39.647735 [DEBUG] mod_verto.c:2245 Local verto.invite SDP verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44:
  223. v=0
  224. o=FreeSWITCH 1498057757 1498057758 IN IP4 192.168.150.3
  225. s=FreeSWITCH
  226. c=IN IP4 192.168.150.3
  227. t=0 0
  228. a=msid-semantic: WMS f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7
  229. m=audio 21982 RTP/SAVPF 102 9 0 8
  230. a=rtpmap:102 opus/48000/2
  231. a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
  232. a=rtpmap:9 G722/8000
  233. a=rtpmap:0 PCMU/8000
  234. a=rtpmap:8 PCMA/8000
  235. a=fingerprint:sha-256 A8:37:47:E9:6B:02:93:D6:06:AF:E4:10:72:A8:44:32:A2:EB:3D:03:E9:48:BC:9B:28:CA:59:4A:A6:B6:02:90
  236. a=setup:actpass
  237. a=rtcp-mux
  238. a=rtcp:21982 IN IP4 192.168.150.3
  239. a=ssrc:491973651 cname:jL6F9SNEVKhJED8r
  240. a=ssrc:491973651 msid:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7 a0
  241. a=ssrc:491973651 mslabel:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7
  242. a=ssrc:491973651 label:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7a0
  243. a=ice-ufrag:cOFSVdBNQlOIDBGN
  244. a=ice-pwd:dCidkWH6wOF1iDilhO33RuHy
  245. a=candidate:7152099570 1 udp 659136 192.168.150.3 21982 typ host generation 0
  246. a=candidate:7152099570 2 udp 659136 192.168.150.3 21982 typ host generation 0
  247. a=silenceSupp:off - - - -
  248. a=ptime:20
  249. a=sendrecv
  250. m=video 21984 RTP/SAVPF 96 98
  251. b=AS:1024
  252. a=rtpmap:96 VP8/90000
  253. a=rtpmap:98 VP9/90000
  254. a=sendrecv
  255. a=fingerprint:sha-256 A8:37:47:E9:6B:02:93:D6:06:AF:E4:10:72:A8:44:32:A2:EB:3D:03:E9:48:BC:9B:28:CA:59:4A:A6:B6:02:90
  256. a=setup:actpass
  257. a=rtcp-mux
  258. a=rtcp:21984 IN IP4 192.168.150.3
  259. a=rtcp-fb:96 ccm fir
  260. a=rtcp-fb:96 ccm tmmbr
  261. a=rtcp-fb:96 nack
  262. a=rtcp-fb:96 nack pli
  263. a=rtcp-fb:98 ccm fir
  264. a=rtcp-fb:98 ccm tmmbr
  265. a=rtcp-fb:98 nack
  266. a=rtcp-fb:98 nack pli
  267. a=ssrc:4037922053 cname:jL6F9SNEVKhJED8r
  268. a=ssrc:4037922053 msid:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7 v0
  269. a=ssrc:4037922053 mslabel:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7
  270. a=ssrc:4037922053 label:f0Y8vyViEd6NX4vzXJPnPhIT2MTb2sX7v0
  271. a=ice-ufrag:x0i4hlZdTLhWFx6d
  272. a=ice-pwd:Gau9K88xK6XOH3Q4UYZ29P6T
  273. a=candidate:9019478234 1 udp 659136 192.168.150.3 21984 typ host generation 0
  274. a=candidate:9019478234 2 udp 659135 192.168.150.3 21984 typ host generation 0
  275. a=end-of-candidates
  276.  
  277. 2017-06-21 17:15:39.647735 [NOTICE] mod_verto.c:2345 Ring-Ready verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44!
  278. 2017-06-21 17:15:39.647735 [DEBUG] switch_channel.c:3354 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Callstate Change DOWN -> RINGING
  279. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:40 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 Standard INIT
  280. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State Change CS_INIT -> CS_ROUTING
  281. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State INIT going to sleep
  282. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_ROUTING (Cur 2 Tot 24)
  283. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State ROUTING
  284. 2017-06-21 17:15:39.647735 [DEBUG] mod_rtc.c:89 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 RTC ROUTING
  285. 2017-06-21 17:15:39.647735 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  286. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State ROUTING going to sleep
  287. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 24)
  288. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State CONSUME_MEDIA
  289. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State CONSUME_MEDIA going to sleep
  290. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [opus:111:48000:20:0:2]/[opus:116:48000:20:0:1]
  291. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5168 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  292. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
  293. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  294. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  295. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  296. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [CN:105:16000:20:0:1]/[opus:116:48000:20:0:1]
  297. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5113 Audio Codec Compare [CN:13:8000:20:0:1]/[opus:116:48000:20:0:1]
  298. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5029 Set telephone-event payload to 110@48000
  299. 2017-06-21 17:15:39.647735 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [120000bps]
  300. 2017-06-21 17:15:39.647735 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [120000bps]
  301. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3428 Set Codec verto.rtc/1007 opus/48000 20 ms 960 samples 0 bits 2 channels
  302. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_codec.c:111 verto.rtc/1007 Original read codec set to opus:116
  303. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3852 Drop audio Candidate cid: 1 proto: udp type: host addr: 2600:1005:8102:840c:0:47:ca5d:9a01:55789 (no network path)
  304. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3858 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.150.144:33538
  305. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3858 Save audio Candidate cid: 1 proto: udp type: srflx addr: 65.15.69.32:33538
  306. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3900 Searching for rtp candidate.
  307. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3905 Choose rtp candidate, index 0, 192.168.150.144:33538
  308. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3678 verto.rtc/1007 choosing family v4
  309. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3916 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 192.168.150.144:33538
  310. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3963 setting remote audio ice addr to index 0 192.168.150.144:33538 based on candidate
  311. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3998 Setting remote rtcp audio addr to 192.168.150.144:33538 based on candidate
  312. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5372 Set telephone-event payload to 110@48000
  313. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5430 verto.rtc/1007 Set 2833 dtmf send payload to 110 recv payload to 110
  314. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [VP8:96]/[VP8:99]
  315. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5745 Video Codec Compare [VP8:96] +++ is saved as a match
  316. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [VP9:98]/[VP8:99]
  317. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [red:100]/[VP8:99]
  318. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [ulpfec:102]/[VP8:99]
  319. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [H264:127]/[VP8:99]
  320. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [rtx:97]/[VP8:99]
  321. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [rtx:99]/[VP8:99]
  322. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [rtx:101]/[VP8:99]
  323. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:5713 Video Codec Compare [rtx:104]/[VP8:99]
  324. 2017-06-21 17:15:39.647735 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  325. 2017-06-21 17:15:39.647735 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
  326. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3238 Set VIDEO Codec verto.rtc/1007 VP8/90000 0 ms
  327. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3852 Drop video Candidate cid: 1 proto: udp type: host addr: 2600:1005:8102:840c:0:47:ca5d:9a01:45863 (no network path)
  328. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3858 Save video Candidate cid: 1 proto: udp type: host addr: 192.168.150.144:59965
  329. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3858 Save video Candidate cid: 1 proto: udp type: srflx addr: 65.15.69.32:59965
  330. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3900 Searching for rtp candidate.
  331. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3905 Choose rtp candidate, index 0, 192.168.150.144:59965
  332. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3678 verto.rtc/1007 choosing family v4
  333. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3916 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 192.168.150.144:59965
  334. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3963 setting remote video ice addr to index 0 192.168.150.144:59965 based on candidate
  335. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:3998 Setting remote rtcp video addr to 192.168.150.144:59965 based on candidate
  336. 2017-06-21 17:15:39.647735 [DEBUG] switch_core_media.c:8147 AUDIO RTP [verto.rtc/1007] 192.168.150.3 port 29582 -> 192.168.150.144 port 33538 codec: 111 ms: 20
  337. 2017-06-21 17:15:39.647735 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 960 bytes per 20ms
  338. 2017-06-21 17:15:39.657741 [INFO] switch_core_media.c:8326 Activating Audio ICE
  339. 2017-06-21 17:15:39.657741 [NOTICE] switch_rtp.c:4610 Activating RTP audio ICE: vS+Q:kKrm5u3rLQwOmcC7 192.168.150.144:33538
  340. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8369 Activating RTCP PORT 33538
  341. 2017-06-21 17:15:39.657741 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 33538
  342. 2017-06-21 17:15:39.657741 [INFO] switch_core_media.c:8377 Skipping RTCP ICE (Same as RTP)
  343. 2017-06-21 17:15:39.657741 [INFO] switch_rtp.c:3581 Activate RTP/RTCP audio DTLS client
  344. 2017-06-21 17:15:39.657741 [INFO] switch_rtp.c:3730 Changing audio DTLS state from OFF to HANDSHAKE
  345. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:2190 Setting Jitterbuffer to 20ms (1 frames) (50 max frames)
  346. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8450 verto.rtc/1007 Set 2833 dtmf send payload to 110
  347. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8457 verto.rtc/1007 Set 2833 dtmf receive payload to 110
  348. 2017-06-21 17:15:39.657741 [DEBUG] switch_rtp.c:4126 Starting video timer.
  349. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8975 VIDEO RTP [verto.rtc/1007] 192.168.150.3:25278->192.168.150.144:59965 codec: 96 ms: 0 [SUCCESS]
  350. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:7139 verto.rtc/1007 Starting Video thread
  351. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:7005 verto.rtc/1007 Video thread started. Echo is off
  352. 2017-06-21 17:15:39.657741 [INFO] switch_core_media.c:9017 Activating Video ICE
  353. 2017-06-21 17:15:39.657741 [NOTICE] switch_rtp.c:4610 Activating RTP video ICE: vS+Q:kAJsrVgVmRRmpVqS 192.168.150.144:59965
  354. 2017-06-21 17:15:39.657741 [INFO] switch_core_media.c:9055 Activating VIDEO RTCP PORT 59965 interval 1000 mux 1
  355. 2017-06-21 17:15:39.657741 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 59965
  356. 2017-06-21 17:15:39.657741 [INFO] switch_core_media.c:9066 Skipping VIDEO RTCP ICE (Same as VIDEO RTP)
  357. 2017-06-21 17:15:39.657741 [INFO] switch_rtp.c:3581 Activate RTP/RTCP video DTLS client
  358. 2017-06-21 17:15:39.657741 [INFO] switch_rtp.c:3730 Changing video DTLS state from OFF to HANDSHAKE
  359. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8130 Audio params are unchanged for verto.rtc/1007.
  360. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_media.c:8833 Video params are unchanged for verto.rtc/1007.
  361. 2017-06-21 17:15:39.657741 [DEBUG] mod_verto.c:2480 Local SDP verto.rtc/1007:
  362. v=0
  363. o=FreeSWITCH 1498050157 1498050158 IN IP4 192.168.150.3
  364. s=FreeSWITCH
  365. c=IN IP4 192.168.150.3
  366. t=0 0
  367. a=msid-semantic: WMS UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPX
  368. m=audio 29582 UDP/TLS/RTP/SAVPF 111 110
  369. a=rtpmap:111 opus/48000/2
  370. a=fmtp:111 useinbandfec=1; minptime=10; stereo=1; sprop-stereo=1
  371. a=rtpmap:110 telephone-event/48000
  372. a=silenceSupp:off - - - -
  373. a=ptime:20
  374. a=sendrecv
  375. a=fingerprint:sha-256 A8:37:47:E9:6B:02:93:D6:06:AF:E4:10:72:A8:44:32:A2:EB:3D:03:E9:48:BC:9B:28:CA:59:4A:A6:B6:02:90
  376. a=setup:active
  377. a=rtcp-mux
  378. a=rtcp:29582 IN IP4 192.168.150.3
  379. a=ice-ufrag:kKrm5u3rLQwOmcC7
  380. a=ice-pwd:iU8dXR5JnBwAnMgxmyJiTDzv
  381. a=candidate:0668217445 1 udp 659136 192.168.150.3 29582 typ host generation 0
  382. a=end-of-candidates
  383. a=ssrc:558869187 cname:Ufsb5cS1WGFWmVqQ
  384. a=ssrc:558869187 msid:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPX a0
  385. a=ssrc:558869187 mslabel:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPX
  386. a=ssrc:558869187 label:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPXa0
  387. m=video 25278 UDP/TLS/RTP/SAVPF 96
  388. b=AS:1024
  389. a=rtpmap:96 VP8/90000
  390. a=sendrecv
  391. a=fingerprint:sha-256 A8:37:47:E9:6B:02:93:D6:06:AF:E4:10:72:A8:44:32:A2:EB:3D:03:E9:48:BC:9B:28:CA:59:4A:A6:B6:02:90
  392. a=setup:active
  393. a=rtcp-mux
  394. a=rtcp:25278 IN IP4 192.168.150.3
  395. a=rtcp-fb:96 ccm fir
  396. a=rtcp-fb:96 nack
  397. a=rtcp-fb:96 nack pli
  398. a=ssrc:4104817589 cname:Ufsb5cS1WGFWmVqQ
  399. a=ssrc:4104817589 msid:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPX v0
  400. a=ssrc:4104817589 mslabel:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPX
  401. a=ssrc:4104817589 label:UoAEqZUQ6TYOaPpDEyuLcvdRvqWfcGPXv0
  402. a=ice-ufrag:kAJsrVgVmRRmpVqS
  403. a=ice-pwd:ZfHt3e0MEYkt08MaymtQ7zBk
  404. a=candidate:4771692337 1 udp 659136 192.168.150.3 25278 typ host generation 0
  405. a=end-of-candidates
  406.  
  407. 2017-06-21 17:15:39.657741 [NOTICE] switch_ivr_originate.c:1220 Pre-Answer verto.rtc/1007!
  408. 2017-06-21 17:15:39.657741 [DEBUG] switch_channel.c:3482 (verto.rtc/1007) Callstate Change RINGING -> EARLY
  409. 2017-06-21 17:15:39.657741 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@48000hz 2 channel 20ms
  410. 2017-06-21 17:15:39.657741 [DEBUG] switch_core_codec.c:223 verto.rtc/1007 Push codec L16:100
  411. 2017-06-21 17:15:39.657741 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
  412. 2017-06-21 17:15:39.777738 [NOTICE] switch_vpx.c:406 VPX reset encoder picture from 320x240 to 352x288 1024 BW
  413. 2017-06-21 17:15:39.937742 [INFO] switch_rtp.c:3192 Changing audio DTLS state from HANDSHAKE to SETUP
  414. 2017-06-21 17:15:39.937742 [INFO] switch_rtp.c:3101 audio Fingerprint Verified.
  415. 2017-06-21 17:15:39.937742 [INFO] switch_rtp.c:3915 Activating audio Secure RTP SEND
  416. 2017-06-21 17:15:39.937742 [INFO] switch_rtp.c:3893 Activating audio Secure RTP RECV
  417. 2017-06-21 17:15:39.937742 [INFO] switch_rtp.c:3141 Changing audio DTLS state from SETUP to READY
  418. 2017-06-21 17:15:39.937742 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
  419. 2017-06-21 17:15:39.937742 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
  420. 2017-06-21 17:15:39.957766 [INFO] switch_rtp.c:3192 Changing video DTLS state from HANDSHAKE to SETUP
  421. 2017-06-21 17:15:39.957766 [INFO] switch_rtp.c:3101 video Fingerprint Verified.
  422. 2017-06-21 17:15:39.957766 [INFO] switch_rtp.c:3915 Activating video Secure RTP SEND
  423. 2017-06-21 17:15:39.957766 [INFO] switch_rtp.c:3893 Activating video Secure RTP RECV
  424. 2017-06-21 17:15:39.957766 [INFO] switch_rtp.c:3141 Changing video DTLS state from SETUP to READY
  425. 2017-06-21 17:15:39.957766 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
  426. 2017-06-21 17:15:39.957766 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
  427. 2017-06-21 17:15:39.977737 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: audio ssrc[2623231321] base_seq[24332]
  428. 2017-06-21 17:15:40.007767 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: video ssrc[3760859939] base_seq[26553]
  429. 2017-06-21 17:15:48.207767 [NOTICE] mod_verto.c:2807 Hangup verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
  430. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_HANGUP (Cur 2 Tot 24)
  431. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Callstate Change RINGING -> HANGUP
  432. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State HANGUP
  433. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:60 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 Standard HANGUP, cause: NORMAL_CLEARING
  434. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State HANGUP going to sleep
  435. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State Change CS_HANGUP -> CS_REPORTING
  436. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_REPORTING (Cur 2 Tot 24)
  437. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State REPORTING
  438. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:174 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 Standard REPORTING, cause: NORMAL_CLEARING
  439. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State REPORTING going to sleep
  440. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State Change CS_REPORTING -> CS_DESTROY
  441. 2017-06-21 17:15:48.207767 [DEBUG] switch_core_session.c:1712 Session 24 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Locked, Waiting on external entities
  442. 2017-06-21 17:15:48.217742 [DEBUG] switch_core_codec.c:248 verto.rtc/1007 Restore previous codec opus:116.
  443. 2017-06-21 17:15:48.217742 [DEBUG] switch_ivr_originate.c:3853 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
  444. 2017-06-21 17:15:48.217742 [NOTICE] switch_core_session.c:1730 Session 24 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Ended
  445. 2017-06-21 17:15:48.217742 [NOTICE] switch_core_session.c:1734 Close Channel verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 [CS_DESTROY]
  446. 2017-06-21 17:15:48.217742 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) Running State Change CS_DESTROY (Cur 1 Tot 24)
  447. 2017-06-21 17:15:48.217742 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State DESTROY
  448. 2017-06-21 17:15:48.217742 [DEBUG] mod_rtc.c:132 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 RTC DESTROY
  449. 2017-06-21 17:15:48.217742 [DEBUG] switch_core_state_machine.c:181 verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44 Standard DESTROY
  450. 2017-06-21 17:15:48.217742 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/8383c106-bb13-be6d-9916-e9b282d85e44) State DESTROY going to sleep
  451. 2017-06-21 17:15:48.217742 [NOTICE] switch_ivr_originate.c:2856 Cannot create outgoing channel of type [user] cause: [NORMAL_CLEARING]
  452. 2017-06-21 17:15:48.217742 [DEBUG] switch_ivr_originate.c:3853 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
  453. 2017-06-21 17:15:48.217742 [INFO] mod_dptools.c:3490 Originate Failed.  Cause: NORMAL_CLEARING
  454. EXECUTE verto.rtc/1007 answer()
  455. 2017-06-21 17:15:48.217742 [NOTICE] mod_dptools.c:1352 Channel [verto.rtc/1007] has been answered
  456. 2017-06-21 17:15:48.217742 [DEBUG] switch_channel.c:3781 (verto.rtc/1007) Callstate Change EARLY -> ACTIVE
  457. EXECUTE verto.rtc/1007 sleep(1000)
  458. 2017-06-21 17:15:48.217742 [DEBUG] switch_ivr.c:195 Codec Activated L16@48000hz 2 channels 20ms
  459. EXECUTE verto.rtc/1007 bridge(loopback/app=voicemail:default 192.168.150.3 1007)
  460. 2017-06-21 17:15:49.237741 [DEBUG] switch_channel.c:1823 (verto.rtc/1007) Callstate Change ACTIVE -> RING_WAIT
  461. 2017-06-21 17:15:49.237741 [DEBUG] switch_channel.c:1250 verto.rtc/1007 EXPORTING[export_vars] [dialed_extension]=[1007] to event
  462. 2017-06-21 17:15:49.237741 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  463. 2017-06-21 17:15:49.237741 [NOTICE] switch_channel.c:1104 New Channel loopback/app=voicemail:default 192.168.150.3 1007-a [b5546862-0122-4007-a276-2bd1c5694d7d]
  464. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:158 loopback/app=voicemail:default 192.168.150.3 1007-a setup codec opus/48000/20
  465. 2017-06-21 17:15:49.237741 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
  466. 2017-06-21 17:15:49.237741 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
  467. 2017-06-21 17:15:49.237741 [NOTICE] switch_channel.c:1102 Rename Channel loopback/app=voicemail:default 192.168.150.3 1007-a->loopback/voicemail-a [b5546862-0122-4007-a276-2bd1c5694d7d]
  468. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:1176 (loopback/voicemail-a) State Change CS_NEW -> CS_INIT
  469. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  470. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_INIT (Cur 2 Tot 25)
  471. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:627 (loopback/voicemail-a) State INIT
  472. 2017-06-21 17:15:49.237741 [NOTICE] switch_channel.c:1104 New Channel loopback/voicemail-b [585b3b9c-6cc9-4f40-a00d-3203ccdcaec0]
  473. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:158 loopback/voicemail-b setup codec opus/48000/20
  474. 2017-06-21 17:15:49.237741 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
  475. 2017-06-21 17:15:49.237741 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
  476. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:276 (loopback/voicemail-b) State Change CS_NEW -> CS_INIT
  477. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  478. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:364 (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING
  479. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  480. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-b) Running State Change CS_INIT (Cur 3 Tot 26)
  481. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:627 (loopback/voicemail-a) State INIT going to sleep
  482. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:627 (loopback/voicemail-b) State INIT
  483. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:364 (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING
  484. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  485. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:627 (loopback/voicemail-b) State INIT going to sleep
  486. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-b) Running State Change CS_ROUTING (Cur 3 Tot 26)
  487. 2017-06-21 17:15:49.237741 [DEBUG] switch_channel.c:2249 (loopback/voicemail-b) Callstate Change DOWN -> RINGING
  488. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_ROUTING (Cur 3 Tot 26)
  489. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:643 (loopback/voicemail-b) State ROUTING
  490. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:396 loopback/voicemail-b CHANNEL ROUTING
  491. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:415 (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE
  492. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  493. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:643 (loopback/voicemail-b) State ROUTING going to sleep
  494. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-b) Running State Change CS_EXECUTE (Cur 3 Tot 26)
  495. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:650 (loopback/voicemail-b) State EXECUTE
  496. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:643 (loopback/voicemail-a) State ROUTING
  497. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:438 loopback/voicemail-b CHANNEL EXECUTE
  498. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:396 loopback/voicemail-a CHANNEL ROUTING
  499. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:328 loopback/voicemail-b Standard EXECUTE
  500. 2017-06-21 17:15:49.237741 [DEBUG] switch_ivr_originate.c:67 (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  501. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  502. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:643 (loopback/voicemail-a) State ROUTING going to sleep
  503. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 26)
  504. EXECUTE loopback/voicemail-b pre_answer()
  505. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State CONSUME_MEDIA
  506. 2017-06-21 17:15:49.237741 [NOTICE] mod_loopback.c:963 Pre-Answer loopback/voicemail-a!
  507. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:663 CHANNEL CONSUME_MEDIA
  508. 2017-06-21 17:15:49.237741 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State CONSUME_MEDIA going to sleep
  509. 2017-06-21 17:15:49.237741 [DEBUG] switch_channel.c:3482 (loopback/voicemail-a) Callstate Change DOWN -> EARLY
  510. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  511. 2017-06-21 17:15:49.237741 [NOTICE] mod_dptools.c:1395 Pre-Answer loopback/voicemail-b!
  512. 2017-06-21 17:15:49.237741 [DEBUG] switch_channel.c:3482 (loopback/voicemail-b) Callstate Change RINGING -> EARLY
  513. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  514. EXECUTE loopback/voicemail-b voicemail(default 192.168.150.3 1007)
  515. 2017-06-21 17:15:49.237741 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  516. 2017-06-21 17:15:49.247744 [DEBUG] switch_ivr_originate.c:3710 Originate Resulted in Success: [loopback/voicemail-a]
  517. 2017-06-21 17:15:49.247744 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  518. 2017-06-21 17:15:49.247744 [DEBUG] switch_channel.c:2047 (verto.rtc/1007) Callstate Change RING_WAIT -> ACTIVE
  519. 2017-06-21 17:15:49.247744 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  520. 2017-06-21 17:15:49.257739 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  521. 2017-06-21 17:15:49.257739 [DEBUG] switch_ivr_bridge.c:1744 (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  522. 2017-06-21 17:15:49.257739 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  523. 2017-06-21 17:15:49.257739 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA (Cur 3 Tot 26)
  524. 2017-06-21 17:15:49.257739 [DEBUG] switch_core_state_machine.c:653 (loopback/voicemail-a) State EXCHANGE_MEDIA
  525. 2017-06-21 17:15:49.257739 [DEBUG] mod_loopback.c:625 CHANNEL LOOPBACK
  526. 2017-06-21 17:15:49.267766 [DEBUG] switch_core_media.c:15436 Engaging Write Buffer at 1920 bytes to accommodate 1920->1920
  527. 2017-06-21 17:15:49.337742 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
  528. 2017-06-21 17:15:49.347743 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-person.wav] (en:en)
  529. 2017-06-21 17:15:49.347743 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  530. 2017-06-21 17:15:49.347743 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
  531. 2017-06-21 17:15:49.377742 [DEBUG] switch_core_media.c:15436 Engaging Write Buffer at 3840 bytes to accommodate 3840->3840
  532. 2017-06-21 17:15:50.697743 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
  533. 2017-06-21 17:15:50.797743 [DEBUG] switch_ivr_play_say.c:250 Handle say:[1007] (en:en)
  534. 2017-06-21 17:15:50.797743 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  535. 2017-06-21 17:15:50.797743 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
  536. 2017-06-21 17:15:53.097743 [DEBUG] switch_ivr_play_say.c:1942 done playing file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/7.wav
  537. 2017-06-21 17:15:53.197743 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-not_available.wav] (en:en)
  538. 2017-06-21 17:15:53.197743 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  539. 2017-06-21 17:15:53.197743 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
  540. 2017-06-21 17:15:53.287767 [NOTICE] mod_verto.c:2807 Hangup verto.rtc/1007 [CS_EXECUTE] [NORMAL_CLEARING]
  541. 2017-06-21 17:15:53.287767 [DEBUG] switch_core_media.c:7106 verto.rtc/1007 Video thread ended
  542. 2017-06-21 17:15:53.287767 [DEBUG] switch_ivr_bridge.c:831 verto.rtc/1007 ending bridge by request from read function
  543. 2017-06-21 17:15:53.287767 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [verto.rtc/1007]
  544. 2017-06-21 17:15:53.287767 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  545. 2017-06-21 17:15:53.287767 [DEBUG] switch_core_media.c:13746 verto.rtc/1007 skip receive message [DISPLAY] (channel is hungup already)
  546. 2017-06-21 17:15:53.297766 [DEBUG] switch_ivr_bridge.c:825 verto.rtc/1007 ending bridge by request from write function
  547. 2017-06-21 17:15:53.297766 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [loopback/voicemail-a]
  548. 2017-06-21 17:15:53.297766 [NOTICE] switch_ivr_bridge.c:1030 Hangup loopback/voicemail-a [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
  549. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  550. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  551. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:653 (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
  552. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_HANGUP (Cur 3 Tot 26)
  553. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:850 (loopback/voicemail-a) Callstate Change EARLY -> HANGUP
  554. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (loopback/voicemail-a) State HANGUP
  555. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:550 loopback/voicemail-a CHANNEL HANGUP
  556. 2017-06-21 17:15:53.297766 [NOTICE] mod_loopback.c:566 Hangup loopback/voicemail-b [CS_EXECUTE] [ORIGINATOR_CANCEL]
  557. 2017-06-21 17:15:53.297766 [DEBUG] switch_ivr_bridge.c:1843 loopback/voicemail-a skip receive message [TRANSFER] (channel is hungup already)
  558. 2017-06-21 17:15:53.297766 [DEBUG] switch_ivr_bridge.c:1846 verto.rtc/1007 skip receive message [TRANSFER] (channel is hungup already)
  559. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_session.c:2884 verto.rtc/1007 skip receive message [PHONE_EVENT] (channel is hungup already)
  560. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1007) State EXECUTE going to sleep
  561. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1007) Running State Change CS_HANGUP (Cur 3 Tot 26)
  562. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/1007) Callstate Change ACTIVE -> HANGUP
  563. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1007) State HANGUP
  564. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:60 verto.rtc/1007 Standard HANGUP, cause: NORMAL_CLEARING
  565. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1007) State HANGUP going to sleep
  566. 2017-06-21 17:15:53.297766 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
  567. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  568. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  569. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:60 loopback/voicemail-a Standard HANGUP, cause: ORIGINATOR_CANCEL
  570. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (loopback/voicemail-a) State HANGUP going to sleep
  571. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/1007) State Change CS_HANGUP -> CS_REPORTING
  572. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:619 (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
  573. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  574. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-a) Running State Change CS_REPORTING (Cur 3 Tot 26)
  575. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1007) Running State Change CS_REPORTING (Cur 3 Tot 26)
  576. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (loopback/voicemail-a) State REPORTING
  577. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:174 loopback/voicemail-a Standard REPORTING, cause: ORIGINATOR_CANCEL
  578. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (loopback/voicemail-a) State REPORTING going to sleep
  579. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1007) State REPORTING
  580. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:174 verto.rtc/1007 Standard REPORTING, cause: NORMAL_CLEARING
  581. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1007) State REPORTING going to sleep
  582. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:610 (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
  583. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-a CHANNEL KILL
  584. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_session.c:1712 Session 25 (loopback/voicemail-a) Locked, Waiting on external entities
  585. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/1007) State Change CS_REPORTING -> CS_DESTROY
  586. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_session.c:1712 Session 23 (verto.rtc/1007) Locked, Waiting on external entities
  587. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1730 Session 23 (verto.rtc/1007) Ended
  588. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1734 Close Channel verto.rtc/1007 [CS_DESTROY]
  589. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/1007) Running State Change CS_DESTROY (Cur 2 Tot 26)
  590. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1007) State DESTROY
  591. 2017-06-21 17:15:53.297766 [DEBUG] mod_rtc.c:132 verto.rtc/1007 RTC DESTROY
  592. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[614] PLC[0] FEC[0]
  593. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
  594. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  595. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[663] Bytes encoded[119516] Encoded length ms[13260] Average encoded bitrate bps[73548]
  596. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_session.c:2884 loopback/voicemail-b skip receive message [PHONE_EVENT] (channel is hungup already)
  597. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:650 (loopback/voicemail-b) State EXECUTE going to sleep
  598. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-b) Running State Change CS_HANGUP (Cur 2 Tot 26)
  599. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:850 (loopback/voicemail-b) Callstate Change EARLY -> HANGUP
  600. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (loopback/voicemail-b) State HANGUP
  601. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:550 loopback/voicemail-b CHANNEL HANGUP
  602. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:60 loopback/voicemail-b Standard HANGUP, cause: ORIGINATOR_CANCEL
  603. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:852 (loopback/voicemail-b) State HANGUP going to sleep
  604. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:619 (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
  605. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  606. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1730 Session 25 (loopback/voicemail-a) Ended
  607. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:584 (loopback/voicemail-b) Running State Change CS_REPORTING (Cur 2 Tot 26)
  608. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1734 Close Channel loopback/voicemail-a [CS_DESTROY]
  609. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:181 verto.rtc/1007 Standard DESTROY
  610. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1007) State DESTROY going to sleep
  611. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (loopback/voicemail-b) State REPORTING
  612. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:174 loopback/voicemail-b Standard REPORTING, cause: ORIGINATOR_CANCEL
  613. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:938 (loopback/voicemail-b) State REPORTING going to sleep
  614. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:741 (loopback/voicemail-a) Running State Change CS_DESTROY (Cur 1 Tot 26)
  615. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:610 (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
  616. 2017-06-21 17:15:53.297766 [DEBUG] mod_loopback.c:603 loopback/voicemail-b CHANNEL KILL
  617. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_session.c:1712 Session 26 (loopback/voicemail-b) Locked, Waiting on external entities
  618. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1730 Session 26 (loopback/voicemail-b) Ended
  619. 2017-06-21 17:15:53.297766 [NOTICE] switch_core_session.c:1734 Close Channel loopback/voicemail-b [CS_DESTROY]
  620. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (loopback/voicemail-a) State DESTROY
  621. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:741 (loopback/voicemail-b) Running State Change CS_DESTROY (Cur 0 Tot 26)
  622. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[186] PLC[0] FEC[0]
  623. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
  624. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  625. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[201] Bytes encoded[21583] Encoded length ms[4020] Average encoded bitrate bps[43166]
  626. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:181 loopback/voicemail-a Standard DESTROY
  627. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (loopback/voicemail-a) State DESTROY going to sleep
  628. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (loopback/voicemail-b) State DESTROY
  629. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  630. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
  631. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
  632. 2017-06-21 17:15:53.297766 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[187] Bytes encoded[23210] Encoded length ms[3740] Average encoded bitrate bps[61893]
  633. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:181 loopback/voicemail-b Standard DESTROY
  634. 2017-06-21 17:15:53.297766 [DEBUG] switch_core_state_machine.c:751 (loopback/voicemail-b) State DESTROY going to sleep
  635.