FreeSWITCH Pastebin

recordings

From emike09, 6 Years ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/85b210dd
Embed
Download Paste or View Raw
  1. +OK log level  [7]
  2. 2017-06-12 11:38:16.832244 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [601@pbx.domain.com] from ip 10.1.10.150
  3. 2017-06-12 11:38:16.932252 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f21f004fbb0 Connected.
  4. 2017-06-12 11:38:16.932252 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f21f004fbb0 released.
  5. 2017-06-12 11:40:48.612287 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f21f0058170 Connected.
  6. 2017-06-12 11:40:48.612287 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f21f0058170 released.
  7. 2017-06-12 11:41:48.052298 [ERR] switch_core_sqldb.c:1197 SQL ERR: [select name, description, syntax, ikey from interfaces where hostname='pbx.domain.com' and type = 'application' and description != '' order by type,name] database disk image is malformed
  8. 2017-06-12 11:45:30.032256 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/8012790596@67.211.74.200 [d60e4737-94ed-4341-a352-ac554deff4bb]
  9. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_NEW (Cur 1 Tot 177)
  10. 2017-06-12 11:45:30.032256 [DEBUG] sofia.c:9834 sofia/internal/8012790596@67.211.74.200 receiving invite from 67.211.74.200:5060 version: 1.6.17 -34-0fc0946 64bit
  11. 2017-06-12 11:45:30.032256 [DEBUG] sofia.c:9950 IP 67.211.74.200 Approved by acl "domains[]". Access Granted.
  12. 2017-06-12 11:45:30.032256 [DEBUG] sofia.c:7048 Channel sofia/internal/8012790596@67.211.74.200 entering state [received][100]
  13. 2017-06-12 11:45:30.032256 [DEBUG] sofia.c:7058 Remote SDP:
  14. v=0
  15. o=- 3326058550 3326058550 IN IP4 67.207.47.117
  16. s=-
  17. c=IN IP4 67.207.47.117
  18. t=0 0
  19. m=audio 35212 RTP/AVP 0 101
  20. a=rtpmap:0 PCMU/8000
  21. a=rtpmap:101 telephone-event/8000
  22. a=fmtp:101 0-15
  23. a=ptime:10
  24. a=silenceSupp:off - - - -
  25.  
  26. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:10:64000:1]/[G722:9:8000:20:64000:1]
  27. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:10:64000:1]/[PCMU:0:8000:20:64000:1]
  28. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4472 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
  29. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:10:64000:1]/[PCMA:8:8000:20:64000:1]
  30. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:10:64000:1]/[GSM:3:8000:20:13200:1]
  31. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  32. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4543 Substituting codec PCMU@10i@8000h@1c
  33. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/8012790596@67.211.74.200 PCMU/8000 10 ms 80 samples 64000 bits 1 channels
  34. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_codec.c:111 sofia/internal/8012790596@67.211.74.200 Original read codec set to PCMU:0
  35. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  36. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_media.c:4754 sofia/internal/8012790596@67.211.74.200 Set 2833 dtmf send payload to 101 recv payload to 101
  37. 2017-06-12 11:45:30.032256 [DEBUG] sofia.c:7471 (sofia/internal/8012790596@67.211.74.200) State Change CS_NEW -> CS_INIT
  38. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/8012790596@67.211.74.200) State NEW
  39. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_INIT (Cur 1 Tot 177)
  40. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/8012790596@67.211.74.200) State INIT
  41. 2017-06-12 11:45:30.032256 [DEBUG] mod_sofia.c:90 sofia/internal/8012790596@67.211.74.200 SOFIA INIT
  42. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:40 sofia/internal/8012790596@67.211.74.200 Standard INIT
  43. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/8012790596@67.211.74.200) State Change CS_INIT -> CS_ROUTING
  44. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/8012790596@67.211.74.200) State INIT going to sleep
  45. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_ROUTING (Cur 1 Tot 177)
  46. 2017-06-12 11:45:30.032256 [DEBUG] switch_channel.c:2249 (sofia/internal/8012790596@67.211.74.200) Callstate Change DOWN -> RINGING
  47. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING
  48. 2017-06-12 11:45:30.032256 [DEBUG] mod_sofia.c:143 sofia/internal/8012790596@67.211.74.200 SOFIA ROUTING
  49. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8012790596@67.211.74.200 Standard ROUTING
  50. 2017-06-12 11:45:30.032256 [INFO] mod_dialplan_xml.c:637 Processing MICHAEL JOHNSON <8012790596>->8018545166 in context public
  51. 2017-06-12 11:45:30.032256 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  52. 2017-06-12 11:45:30.032256 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  53. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [public->After_Hours_Sunday] continue=true
  54. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [After_Hours_Sunday] context(public) =~ /public/ break=on-false
  55. Dialplan: sofia/internal/8012790596@67.211.74.200 Date/TimeMatch (FAIL) [After_Hours_Sunday] break=on-false
  56. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [public->After_Hours_Saturdays] continue=true
  57. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [After_Hours_Saturdays] context(public) =~ /public/ break=on-false
  58. Dialplan: sofia/internal/8012790596@67.211.74.200 Date/TimeMatch (FAIL) [After_Hours_Saturdays] break=on-false
  59. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [public->After_Hours_Evenings] continue=true
  60. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [After_Hours_Evenings] context(public) =~ /public/ break=on-false
  61. Dialplan: sofia/internal/8012790596@67.211.74.200 Date/TimeMatch (FAIL) [After_Hours_Evenings] break=on-false
  62. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [public->After_Hours_Mornings] continue=true
  63. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [After_Hours_Mornings] context(public) =~ /public/ break=on-false
  64. Dialplan: sofia/internal/8012790596@67.211.74.200 Date/TimeMatch (FAIL) [After_Hours_Mornings] break=on-false
  65. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [public->Normal_Open_Hours] continue=false
  66. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [Normal_Open_Hours] context(public) =~ /public/ break=on-false
  67. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [Normal_Open_Hours] destination_number(8018545166) =~ /^.*$/ break=on-false
  68. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(call_direction=inbound) INLINE
  69. EXECUTE sofia/internal/8012790596@67.211.74.200 set(call_direction=inbound)
  70. 2017-06-12 11:45:30.032256 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [call_direction]=[inbound]
  71. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(domain_uuid=cb0d02b2-e91e-42c4-b233-9786ecd723a4) INLINE
  72. EXECUTE sofia/internal/8012790596@67.211.74.200 set(domain_uuid=cb0d02b2-e91e-42c4-b233-9786ecd723a4)
  73. 2017-06-12 11:45:30.032256 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [domain_uuid]=[cb0d02b2-e91e-42c4-b233-9786ecd723a4]
  74. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(domain_name=pbx.domain.com) INLINE
  75. EXECUTE sofia/internal/8012790596@67.211.74.200 set(domain_name=pbx.domain.com)
  76. 2017-06-12 11:45:30.032256 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [domain_name]=[pbx.domain.com]
  77. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(call_direction=inbound)
  78. Dialplan: sofia/internal/8012790596@67.211.74.200 Action transfer(5001 XML pbx.domain.com)
  79. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8012790596@67.211.74.200) State Change CS_ROUTING -> CS_EXECUTE
  80. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING going to sleep
  81. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_EXECUTE (Cur 1 Tot 177)
  82. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE
  83. 2017-06-12 11:45:30.032256 [DEBUG] mod_sofia.c:198 sofia/internal/8012790596@67.211.74.200 SOFIA EXECUTE
  84. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8012790596@67.211.74.200 Standard EXECUTE
  85. EXECUTE sofia/internal/8012790596@67.211.74.200 set(call_direction=inbound)
  86. 2017-06-12 11:45:30.032256 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [call_direction]=[inbound]
  87. EXECUTE sofia/internal/8012790596@67.211.74.200 transfer(5001 XML pbx.domain.com)
  88. 2017-06-12 11:45:30.032256 [DEBUG] switch_ivr.c:2165 (sofia/internal/8012790596@67.211.74.200) State Change CS_EXECUTE -> CS_ROUTING
  89. 2017-06-12 11:45:30.032256 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/8012790596@67.211.74.200 to XML[5001@pbx.domain.com]
  90. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE going to sleep
  91. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_ROUTING (Cur 1 Tot 177)
  92. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING
  93. 2017-06-12 11:45:30.032256 [DEBUG] mod_sofia.c:143 sofia/internal/8012790596@67.211.74.200 SOFIA ROUTING
  94. 2017-06-12 11:45:30.032256 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8012790596@67.211.74.200 Standard ROUTING
  95. 2017-06-12 11:45:30.032256 [INFO] mod_dialplan_xml.c:637 Processing MICHAEL JOHNSON <8012790596>->5001 in context pbx.domain.com
  96. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  97. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  98. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->user_exists] continue=true
  99. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_exists] () =~ // break=on-false
  100. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
  101. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  102. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  103. EXECUTE sofia/internal/8012790596@67.211.74.200 set(user_exists=false)
  104. 2017-06-12 11:45:30.052239 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [user_exists]=[false]
  105. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
  106. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->call-direction] continue=true
  107. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
  108. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->variables] continue=true
  109. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [variables] () =~ // break=on-false
  110. Dialplan: sofia/internal/8012790596@67.211.74.200 Action export(origination_callee_id_name=${destination_number})
  111. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  112. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->user_record] continue=true
  113. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] () =~ // break=on-false
  114. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
  115. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  116. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  117. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  118. 2017-06-12 11:45:30.052239 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  119. EXECUTE sofia/internal/8012790596@67.211.74.200 set(user_record=)
  120. 2017-06-12 11:45:30.052239 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [user_record]=[UNDEF]
  121. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
  122. 2017-06-12 11:45:30.072242 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  123. 2017-06-12 11:45:30.072242 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  124. EXECUTE sofia/internal/8012790596@67.211.74.200 set(from_user_exists=false)
  125. 2017-06-12 11:45:30.072242 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [from_user_exists]=[false]
  126. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  127. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
  128. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  129. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
  130. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
  131. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  132. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
  133. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
  134. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  135. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
  136. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
  137. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  138. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  139. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
  140. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  141. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
  142. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
  143. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  144. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
  145. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
  146. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  147. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
  148. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
  149. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
  150. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->redial] continue=true
  151. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [redial] destination_number(5001) =~ /^(redial|\*870)$/ break=on-true
  152. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [redial] () =~ // break=never
  153. Dialplan: sofia/internal/8012790596@67.211.74.200 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  154. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->speed_dial] continue=false
  155. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [speed_dial] destination_number(5001) =~ /^\*0(.*)$/ break=on-false
  156. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->CentraCom.1d10] continue=false
  157. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [CentraCom.1d10] destination_number(5001) =~ /^\+?1?(\d{10})$/ break=on-false
  158. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->CentraCom.911] continue=false
  159. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [CentraCom.911] destination_number(5001) =~ /^(911)$/ break=on-false
  160. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->agent_status] continue=false
  161. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [agent_status] destination_number(5001) =~ /^\*22$/ break=on-false
  162. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->agent_status_id] continue=false
  163. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [agent_status_id] destination_number(5001) =~ /^\*23$/ break=on-false
  164. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Canada] continue=false
  165. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Canada] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  166. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Canada] destination_number(5001) =~ /^5502$/ break=on-false
  167. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->FrontDesk] continue=false
  168. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [FrontDesk] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  169. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [FrontDesk] destination_number(5001) =~ /^5503$/ break=on-false
  170. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Payments] continue=false
  171. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Payments] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  172. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Payments] destination_number(5001) =~ /^5505$/ break=on-false
  173. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Spanish_Support] continue=false
  174. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Spanish_Support] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  175. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Spanish_Support] destination_number(5001) =~ /^5501$/ break=on-false
  176. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Support] continue=false
  177. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Support] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  178. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Support] destination_number(5001) =~ /^5500$/ break=on-false
  179. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->WillCall] continue=false
  180. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [WillCall] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  181. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [WillCall] destination_number(5001) =~ /^5504$/ break=on-false
  182. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->group-intercept] continue=false
  183. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [group-intercept] destination_number(5001) =~ /^\*8$/ break=on-false
  184. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->page-extension] continue=false
  185. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [page-extension] destination_number(5001) =~ /^\*8(\d{2,7})$/ break=on-false
  186. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->eavesdrop] continue=false
  187. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [eavesdrop] destination_number(5001) =~ /^\*33(\d{2,7})$/ break=on-false
  188. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->call_privacy] continue=false
  189. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [call_privacy] destination_number(5001) =~ /^\*67(\d+)$/ break=on-false
  190. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->call_return] continue=false
  191. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [call_return] destination_number(5001) =~ /^\*69$/ break=on-false
  192. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->extension_queue] continue=false
  193. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [extension_queue] destination_number(5001) =~ /^\*800(.*)$/ break=on-false
  194. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->intercept-ext] continue=false
  195. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [intercept-ext] destination_number(5001) =~ /^\*\*(\d+)$/ break=on-false
  196. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->intercept-ext-polycom] continue=false
  197. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [intercept-ext-polycom] destination_number(5001) =~ /^\*97(\d+)$/ break=on-false
  198. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->dx] continue=false
  199. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [dx] destination_number(5001) =~ /^dx$/ break=on-false
  200. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->att_xfer] continue=false
  201. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [att_xfer] destination_number(5001) =~ /^att_xfer$/ break=on-false
  202. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->extension-to-voicemail] continue=false
  203. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
  204. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->send_to_voicemail] continue=false
  205. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [send_to_voicemail] destination_number(5001) =~ /^\*99(\d{2,10})$/ break=on-false
  206. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->vmain] continue=false
  207. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [vmain] destination_number(5001) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
  208. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->xfer_vm] continue=false
  209. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [xfer_vm] destination_number(5001) =~ /^xfer_vm$/ break=on-false
  210. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->is_transfer] continue=false
  211. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [is_transfer] destination_number(5001) =~ /^is_transfer$/ break=on-false
  212. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->vmain_user] continue=false
  213. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [vmain_user] destination_number(5001) =~ /^\*97$/ break=on-false
  214. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->After_Hours] continue=
  215. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [After_Hours] destination_number(5001) =~ /^5003$/ break=on-false
  216. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Open_Hours] continue=
  217. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [Open_Hours] destination_number(5001) =~ /^5001$/ break=on-false
  218. Dialplan: sofia/internal/8012790596@67.211.74.200 Action answer()
  219. Dialplan: sofia/internal/8012790596@67.211.74.200 Action sleep(1000)
  220. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(hangup_after_bridge=true)
  221. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(ringback=local_stream://pbx.domain.com/Main_-_Thrive_Life)
  222. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(transfer_ringback=local_stream://pbx.domain.com/Main_-_Thrive_Life)
  223. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(ivr_menu_uuid=ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188)
  224. Dialplan: sofia/internal/8012790596@67.211.74.200 Action ivr(ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188)
  225. Dialplan: sofia/internal/8012790596@67.211.74.200 Action transfer(5503 XML pbx.domain.com)
  226. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8012790596@67.211.74.200) State Change CS_ROUTING -> CS_EXECUTE
  227. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING going to sleep
  228. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_EXECUTE (Cur 1 Tot 177)
  229. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE
  230. 2017-06-12 11:45:30.072242 [DEBUG] mod_sofia.c:198 sofia/internal/8012790596@67.211.74.200 SOFIA EXECUTE
  231. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8012790596@67.211.74.200 Standard EXECUTE
  232. EXECUTE sofia/internal/8012790596@67.211.74.200 export(origination_callee_id_name=5001)
  233. 2017-06-12 11:45:30.072242 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[5001]
  234. EXECUTE sofia/internal/8012790596@67.211.74.200 set(RFC2822_DATE=Mon, 12 Jun 2017 11:45:30 -0600)
  235. 2017-06-12 11:45:30.072242 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [RFC2822_DATE]=[Mon, 12 Jun 2017 11:45:30 -0600]
  236. EXECUTE sofia/internal/8012790596@67.211.74.200 hash(insert/pbx.domain.com-last_dial/8012790596/5001)
  237. EXECUTE sofia/internal/8012790596@67.211.74.200 answer()
  238. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/8012790596@67.211.74.200] 192.168.3.40 port 29882 -> 67.207.47.117 port 35212 codec: 0 ms: 10
  239. 2017-06-12 11:45:30.072242 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 80 bytes per 10ms
  240. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_media.c:7166 sofia/internal/8012790596@67.211.74.200 Set 2833 dtmf send payload to 101
  241. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_media.c:7173 sofia/internal/8012790596@67.211.74.200 Set 2833 dtmf receive payload to 101
  242. 2017-06-12 11:45:30.072242 [DEBUG] switch_core_media.c:7196 sofia/internal/8012790596@67.211.74.200 Set rtp dtmf delay to 40
  243. 2017-06-12 11:45:30.072242 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/8012790596@67.211.74.200:
  244. v=0
  245. o=FreeSWITCH 1497259648 1497259649 IN IP4 63.78.119.44
  246. s=FreeSWITCH
  247. c=IN IP4 63.78.119.44
  248. t=0 0
  249. m=audio 29882 RTP/AVP 0 101
  250. a=rtpmap:0 PCMU/8000
  251. a=rtpmap:101 telephone-event/8000
  252. a=fmtp:101 0-16
  253. a=ptime:10
  254. a=sendrecv
  255.  
  256. 2017-06-12 11:45:30.072242 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/8012790596@67.211.74.200] has been answered
  257. 2017-06-12 11:45:30.072242 [DEBUG] switch_channel.c:3772 (sofia/internal/8012790596@67.211.74.200) Callstate Change RINGING -> ACTIVE
  258. 2017-06-12 11:45:30.072242 [DEBUG] sofia.c:7048 Channel sofia/internal/8012790596@67.211.74.200 entering state [completed][200]
  259. EXECUTE sofia/internal/8012790596@67.211.74.200 sleep(1000)
  260. 2017-06-12 11:45:30.072242 [DEBUG] sofia.c:7048 Channel sofia/internal/8012790596@67.211.74.200 entering state [ready][200]
  261. EXECUTE sofia/internal/8012790596@67.211.74.200 set(hangup_after_bridge=true)
  262. 2017-06-12 11:45:31.092240 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [hangup_after_bridge]=[true]
  263. EXECUTE sofia/internal/8012790596@67.211.74.200 set(ringback=local_stream://pbx.domain.com/Main_-_Thrive_Life)
  264. 2017-06-12 11:45:31.092240 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [ringback]=[local_stream://pbx.domain.com/Main_-_Thrive_Life]
  265. EXECUTE sofia/internal/8012790596@67.211.74.200 set(transfer_ringback=local_stream://pbx.domain.com/Main_-_Thrive_Life)
  266. 2017-06-12 11:45:31.092240 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [transfer_ringback]=[local_stream://pbx.domain.com/Main_-_Thrive_Life]
  267. EXECUTE sofia/internal/8012790596@67.211.74.200 set(ivr_menu_uuid=ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188)
  268. 2017-06-12 11:45:31.092240 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [ivr_menu_uuid]=[ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188]
  269. EXECUTE sofia/internal/8012790596@67.211.74.200 ivr(ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188)
  270. 2017-06-12 11:45:31.092240 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  271. 2017-06-12 11:45:31.092240 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  272. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-exit'
  273. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-sub'
  274. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-exec-app'
  275. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-play-sound'
  276. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-back'
  277. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-top'
  278. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:880 building menu 'ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188'
  279. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '0'
  280. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '1'
  281. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '2'
  282. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '3'
  283. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '4'
  284. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '6'
  285. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '/^(\d{2,11})$/'
  286. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '/^(\d{2,11})$/'
  287. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '/^(\d{2,11})$/'
  288. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_menu.c:483 Executing IVR menu ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188
  289. 2017-06-12 11:45:31.092240 [DEBUG] switch_core_file.c:342 File /var/lib/freeswitch/recordings/pbx.domain.com/PHONE_TREE_During_Business_Hours_Main_Menu_-_With_Canada_REMOVED_JAPANESE.wav sample rate 44100 doesn't match requested rate 8000
  290. 2017-06-12 11:45:31.092240 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
  291. 2017-06-12 11:45:31.092240 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 10ms
  292. 2017-06-12 11:45:31.192252 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  293. 2017-06-12 11:45:37.492234 [DEBUG] switch_rtp.c:7455 RTP RECV DTMF 2:1400
  294. 2017-06-12 11:45:37.492234 [INFO] switch_channel.c:515 RECV DTMF 2:1400
  295. 2017-06-12 11:45:37.492234 [DEBUG] switch_ivr_play_say.c:1942 done playing file /var/lib/freeswitch/recordings/pbx.domain.com/PHONE_TREE_During_Business_Hours_Main_Menu_-_With_Canada_REMOVED_JAPANESE.wav
  296. 2017-06-12 11:45:37.492234 [DEBUG] switch_ivr_menu.c:377 waiting for 4/5 digits t/o 2000
  297. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:424 digits '2'
  298. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:577 IVR action on menu 'ba7bbc6d-5b2d-44c0-a1c4-ff5ba85ed188' matched '2' param 'transfer 5500 XML pbx.domain.com'
  299. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:581 switch_ivr_menu_execute todo=[2]
  300. EXECUTE sofia/internal/8012790596@67.211.74.200 transfer(5500 XML pbx.domain.com)
  301. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr.c:2165 (sofia/internal/8012790596@67.211.74.200) State Change CS_EXECUTE -> CS_ROUTING
  302. 2017-06-12 11:45:39.492259 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/8012790596@67.211.74.200 to XML[5500@pbx.domain.com]
  303. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:559 action regex [2] [/^(\d{2,11})$/] [0]
  304. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:559 action regex [2] [/^(\d{2,11})$/] [0]
  305. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:559 action regex [2] [/^(\d{2,11})$/] [0]
  306. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_menu.c:673 exit-sound '(null)'
  307. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE going to sleep
  308. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_ROUTING (Cur 1 Tot 177)
  309. 2017-06-12 11:45:39.492259 [DEBUG] switch_channel.c:2249 (sofia/internal/8012790596@67.211.74.200) Callstate Change ACTIVE -> RINGING
  310. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING
  311. 2017-06-12 11:45:39.492259 [DEBUG] mod_sofia.c:143 sofia/internal/8012790596@67.211.74.200 SOFIA ROUTING
  312. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8012790596@67.211.74.200 Standard ROUTING
  313. 2017-06-12 11:45:39.492259 [INFO] mod_dialplan_xml.c:637 Processing MICHAEL JOHNSON <8012790596>->5500 in context pbx.domain.com
  314. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->user_exists] continue=true
  315. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_exists] () =~ // break=on-false
  316. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
  317. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  318. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  319. EXECUTE sofia/internal/8012790596@67.211.74.200 set(user_exists=false)
  320. 2017-06-12 11:45:39.492259 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [user_exists]=[false]
  321. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
  322. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->call-direction] continue=true
  323. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
  324. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->variables] continue=true
  325. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [variables] () =~ // break=on-false
  326. Dialplan: sofia/internal/8012790596@67.211.74.200 Action export(origination_callee_id_name=${destination_number})
  327. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  328. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->user_record] continue=true
  329. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] () =~ // break=on-false
  330. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
  331. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  332. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  333. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  334. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  335. EXECUTE sofia/internal/8012790596@67.211.74.200 set(user_record=)
  336. 2017-06-12 11:45:39.492259 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [user_record]=[UNDEF]
  337. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
  338. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  339. 2017-06-12 11:45:39.492259 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  340. EXECUTE sofia/internal/8012790596@67.211.74.200 set(from_user_exists=false)
  341. 2017-06-12 11:45:39.492259 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [from_user_exists]=[false]
  342. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  343. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
  344. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  345. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
  346. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
  347. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  348. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
  349. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
  350. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  351. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
  352. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
  353. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  354. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  355. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
  356. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  357. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
  358. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
  359. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  360. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
  361. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
  362. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
  363. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
  364. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
  365. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
  366. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->redial] continue=true
  367. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [redial] destination_number(5500) =~ /^(redial|\*870)$/ break=on-true
  368. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [redial] () =~ // break=never
  369. Dialplan: sofia/internal/8012790596@67.211.74.200 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  370. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->speed_dial] continue=false
  371. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [speed_dial] destination_number(5500) =~ /^\*0(.*)$/ break=on-false
  372. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->CentraCom.1d10] continue=false
  373. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [CentraCom.1d10] destination_number(5500) =~ /^\+?1?(\d{10})$/ break=on-false
  374. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->CentraCom.911] continue=false
  375. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [CentraCom.911] destination_number(5500) =~ /^(911)$/ break=on-false
  376. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->agent_status] continue=false
  377. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [agent_status] destination_number(5500) =~ /^\*22$/ break=on-false
  378. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->agent_status_id] continue=false
  379. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [agent_status_id] destination_number(5500) =~ /^\*23$/ break=on-false
  380. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Canada] continue=false
  381. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Canada] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  382. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Canada] destination_number(5500) =~ /^5502$/ break=on-false
  383. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->FrontDesk] continue=false
  384. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [FrontDesk] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  385. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [FrontDesk] destination_number(5500) =~ /^5503$/ break=on-false
  386. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Payments] continue=false
  387. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Payments] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  388. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Payments] destination_number(5500) =~ /^5505$/ break=on-false
  389. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Spanish_Support] continue=false
  390. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Spanish_Support] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  391. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Spanish_Support] destination_number(5500) =~ /^5501$/ break=on-false
  392. Dialplan: sofia/internal/8012790596@67.211.74.200 parsing [pbx.domain.com->Support] continue=false
  393. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (FAIL) [Support] ${caller_id_name}(MICHAEL JOHNSON) =~ /^([^#]+#)(.*)$/ break=never
  394. Dialplan: sofia/internal/8012790596@67.211.74.200 Regex (PASS) [Support] destination_number(5500) =~ /^5500$/ break=on-false
  395. Dialplan: sofia/internal/8012790596@67.211.74.200 Action answer()
  396. Dialplan: sofia/internal/8012790596@67.211.74.200 Action set(hangup_after_bridge=true)
  397. Dialplan: sofia/internal/8012790596@67.211.74.200 Action callcenter(Support@pbx.domain.com)
  398. Dialplan: sofia/internal/8012790596@67.211.74.200 Action hangup()
  399. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8012790596@67.211.74.200) State Change CS_ROUTING -> CS_EXECUTE
  400. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/8012790596@67.211.74.200) State ROUTING going to sleep
  401. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_EXECUTE (Cur 1 Tot 177)
  402. 2017-06-12 11:45:39.492259 [DEBUG] switch_channel.c:2251 (sofia/internal/8012790596@67.211.74.200) Callstate Change RINGING -> ACTIVE
  403. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE
  404. 2017-06-12 11:45:39.492259 [DEBUG] mod_sofia.c:198 sofia/internal/8012790596@67.211.74.200 SOFIA EXECUTE
  405. 2017-06-12 11:45:39.492259 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8012790596@67.211.74.200 Standard EXECUTE
  406. EXECUTE sofia/internal/8012790596@67.211.74.200 export(origination_callee_id_name=5500)
  407. 2017-06-12 11:45:39.492259 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[5500]
  408. EXECUTE sofia/internal/8012790596@67.211.74.200 set(RFC2822_DATE=Mon, 12 Jun 2017 11:45:39 -0600)
  409. 2017-06-12 11:45:39.492259 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [RFC2822_DATE]=[Mon, 12 Jun 2017 11:45:39 -0600]
  410. EXECUTE sofia/internal/8012790596@67.211.74.200 hash(insert/pbx.domain.com-last_dial/8012790596/5500)
  411. EXECUTE sofia/internal/8012790596@67.211.74.200 answer()
  412. EXECUTE sofia/internal/8012790596@67.211.74.200 set(hangup_after_bridge=true)
  413. 2017-06-12 11:45:39.492259 [DEBUG] mod_dptools.c:1530 SET sofia/internal/8012790596@67.211.74.200 [hangup_after_bridge]=[true]
  414. EXECUTE sofia/internal/8012790596@67.211.74.200 callcenter(Support@pbx.domain.com)
  415. 2017-06-12 11:45:39.492259 [DEBUG] mod_callcenter.c:2885 Member MICHAEL JOHNSON <8012790596> joining queue Support@pbx.domain.com
  416. 2017-06-12 11:45:39.492259 [WARNING] mod_local_stream.c:831 Unknown source pbx.domain.com/Main_-_Thrive_Life, trying 'default'
  417. 2017-06-12 11:45:39.492259 [DEBUG] mod_local_stream.c:868 Opening Stream [default/8000] 8000hz
  418. 2017-06-12 11:45:39.492259 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 10ms
  419. 2017-06-12 11:45:39.512233 [DEBUG] mod_callcenter.c:1135 Updated Agent mJOHNSON@pbx.domain.com set state = Receiving
  420. 2017-06-12 11:45:39.512233 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Receiving
  421. 2017-06-12 11:45:39.512233 [DEBUG] mod_callcenter.c:1615 Setting outbound caller_id_name to: MICHAEL JOHNSON
  422. 2017-06-12 11:45:39.512233 [DEBUG] mod_callcenter.c:1615 Setting outbound caller_id_name to: MICHAEL JOHNSON
  423. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  424. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  425. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  426. 2017-06-12 11:45:39.512233 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/111@10.1.10.65:5060 [7045041d-9bce-4ecc-8af7-e9d66dc1d372]
  427. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:4818 (sofia/internal/111@10.1.10.65:5060) State Change CS_NEW -> CS_INIT
  428. 2017-06-12 11:45:39.512233 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  429. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_INIT (Cur 2 Tot 178)
  430. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/111@10.1.10.65:5060) State INIT
  431. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:90 sofia/internal/111@10.1.10.65:5060 SOFIA INIT
  432. 2017-06-12 11:45:39.512233 [DEBUG] sofia_glue.c:1295 sofia/internal/111@10.1.10.65:5060 sending invite version: 1.6.17 -34-0fc0946 64bit
  433. Local SDP:
  434. v=0
  435. o=FreeSWITCH 1497270419 1497270420 IN IP4 192.168.3.40
  436. s=FreeSWITCH
  437. c=IN IP4 192.168.3.40
  438. t=0 0
  439. m=audio 19120 RTP/AVP 9 0 8 3 101 13
  440. a=rtpmap:9 G722/8000
  441. a=rtpmap:0 PCMU/8000
  442. a=rtpmap:8 PCMA/8000
  443. a=rtpmap:3 GSM/8000
  444. a=rtpmap:101 telephone-event/8000
  445. a=fmtp:101 0-16
  446. a=rtpmap:13 CN/8000
  447. a=ptime:20
  448. a=sendrecv
  449.  
  450. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:40 sofia/internal/111@10.1.10.65:5060 Standard INIT
  451. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/111@10.1.10.65:5060) State Change CS_INIT -> CS_ROUTING
  452. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/111@10.1.10.65:5060) State INIT going to sleep
  453. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_ROUTING (Cur 2 Tot 178)
  454. 2017-06-12 11:45:39.512233 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [calling][0]
  455. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/111@10.1.10.65:5060) State ROUTING
  456. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:143 sofia/internal/111@10.1.10.65:5060 SOFIA ROUTING
  457. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/111@10.1.10.65:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  458. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/111@10.1.10.65:5060) State ROUTING going to sleep
  459. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 178)
  460. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/111@10.1.10.65:5060) State CONSUME_MEDIA
  461. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/111@10.1.10.65:5060) State CONSUME_MEDIA going to sleep
  462. 2017-06-12 11:45:39.512233 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  463. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  464. 2017-06-12 11:45:39.512233 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/601@10.1.10.150:5062 [6faabab6-d842-479d-a779-e1064f2a5544]
  465. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:4818 (sofia/internal/601@10.1.10.150:5062) State Change CS_NEW -> CS_INIT
  466. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_INIT (Cur 3 Tot 179)
  467. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT
  468. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:90 sofia/internal/601@10.1.10.150:5062 SOFIA INIT
  469. 2017-06-12 11:45:39.512233 [DEBUG] sofia_glue.c:1295 sofia/internal/601@10.1.10.150:5062 sending invite version: 1.6.17 -34-0fc0946 64bit
  470. Local SDP:
  471. v=0
  472. o=FreeSWITCH 1497266725 1497266726 IN IP4 192.168.3.40
  473. s=FreeSWITCH
  474. c=IN IP4 192.168.3.40
  475. t=0 0
  476. m=audio 22814 RTP/AVP 9 0 8 3 101 13
  477. a=rtpmap:9 G722/8000
  478. a=rtpmap:0 PCMU/8000
  479. a=rtpmap:8 PCMA/8000
  480. a=rtpmap:3 GSM/8000
  481. a=rtpmap:101 telephone-event/8000
  482. a=fmtp:101 0-16
  483. a=rtpmap:13 CN/8000
  484. a=ptime:20
  485. a=sendrecv
  486.  
  487. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:40 sofia/internal/601@10.1.10.150:5062 Standard INIT
  488. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/601@10.1.10.150:5062) State Change CS_INIT -> CS_ROUTING
  489. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT going to sleep
  490. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_ROUTING (Cur 3 Tot 179)
  491. 2017-06-12 11:45:39.512233 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [calling][0]
  492. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING
  493. 2017-06-12 11:45:39.512233 [DEBUG] mod_sofia.c:143 sofia/internal/601@10.1.10.150:5062 SOFIA ROUTING
  494. 2017-06-12 11:45:39.512233 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/601@10.1.10.150:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  495. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING going to sleep
  496. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 179)
  497. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA
  498. 2017-06-12 11:45:39.512233 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA going to sleep
  499. 2017-06-12 11:45:39.572240 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [proceeding][180]
  500. 2017-06-12 11:45:39.572240 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/111@10.1.10.65:5060!
  501. 2017-06-12 11:45:39.572240 [DEBUG] switch_channel.c:3345 (sofia/internal/111@10.1.10.65:5060) Callstate Change DOWN -> RINGING
  502. 2017-06-12 11:45:39.772254 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [proceeding][180]
  503. 2017-06-12 11:45:39.772254 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/601@10.1.10.150:5062!
  504. 2017-06-12 11:45:39.772254 [DEBUG] switch_channel.c:3345 (sofia/internal/601@10.1.10.150:5062) Callstate Change DOWN -> RINGING
  505. 2017-06-12 11:45:44.672235 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [completing][200]
  506. 2017-06-12 11:45:44.672235 [DEBUG] sofia.c:7058 Remote SDP:
  507. v=0
  508. o=- 20167 20167 IN IP4 10.1.10.65
  509. s=SDP data
  510. c=IN IP4 10.1.10.65
  511. t=0 0
  512. m=audio 12158 RTP/AVP 9 101
  513. a=rtpmap:9 G722/8000
  514. a=rtpmap:101 telephone-event/8000
  515. a=fmtp:101 0-15
  516. a=ptime:20
  517.  
  518. 2017-06-12 11:45:44.672235 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [ready][200]
  519. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  520. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  521. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  522. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  523. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  524. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  525. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/111@10.1.10.65:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels
  526. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_codec.c:111 sofia/internal/111@10.1.10.65:5060 Original read codec set to G722:9
  527. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  528. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:4754 sofia/internal/111@10.1.10.65:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  529. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/111@10.1.10.65:5060] 192.168.3.40 port 19120 -> 10.1.10.65 port 12158 codec: 9 ms: 20
  530. 2017-06-12 11:45:44.672235 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
  531. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:7166 sofia/internal/111@10.1.10.65:5060 Set 2833 dtmf send payload to 101
  532. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:7173 sofia/internal/111@10.1.10.65:5060 Set 2833 dtmf receive payload to 101
  533. 2017-06-12 11:45:44.672235 [DEBUG] switch_core_media.c:7196 sofia/internal/111@10.1.10.65:5060 Set rtp dtmf delay to 40
  534. 2017-06-12 11:45:44.672235 [NOTICE] sofia.c:8182 Channel [sofia/internal/111@10.1.10.65:5060] has been answered
  535. 2017-06-12 11:45:44.672235 [DEBUG] switch_channel.c:3772 (sofia/internal/111@10.1.10.65:5060) Callstate Change RINGING -> ACTIVE
  536. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/111@10.1.10.65:5060]
  537. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/111@10.1.10.65:5060]
  538. 2017-06-12 11:45:44.692241 [NOTICE] switch_core_session.c:249 Hangup sofia/internal/601@10.1.10.150:5062 [CS_CONSUME_MEDIA] [LOSE_RACE]
  539. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_HANGUP (Cur 3 Tot 179)
  540. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/601@10.1.10.150:5062) Callstate Change RINGING -> HANGUP
  541. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP
  542. 2017-06-12 11:45:44.692241 [DEBUG] mod_sofia.c:438 Channel sofia/internal/601@10.1.10.150:5062 hanging up, cause: LOSE_RACE
  543. 2017-06-12 11:45:44.692241 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/601@10.1.10.150:5062
  544. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:60 sofia/internal/601@10.1.10.150:5062 Standard HANGUP, cause: LOSE_RACE
  545. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP going to sleep
  546. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/601@10.1.10.150:5062) State Change CS_HANGUP -> CS_REPORTING
  547. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_REPORTING (Cur 3 Tot 179)
  548. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING
  549. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE]
  550. 2017-06-12 11:45:44.692241 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE]
  551. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE]
  552. 2017-06-12 11:45:44.692241 [DEBUG] mod_callcenter.c:1951 Agent tester@pbx.domain.com Origination Canceled : LOSE_RACE
  553. 2017-06-12 11:45:44.692241 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set ready_time = 1497289574
  554. 2017-06-12 11:45:44.692241 [DEBUG] mod_callcenter.c:1996 Agent tester@pbx.domain.com sleeping for 30 seconds
  555. 2017-06-12 11:45:44.692241 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Waiting
  556. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/internal/8012790596@67.211.74.200
  557. 2017-06-12 11:45:44.692241 [DEBUG] mod_callcenter.c:1798 Agent mJOHNSON@pbx.domain.com answered "MICHAEL JOHNSON" <8012790596> from queue Support@pbx.domain.com (Recorded)
  558. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_bridge.c:2017 (sofia/internal/8012790596@67.211.74.200) State Change CS_EXECUTE -> CS_HIBERNATE
  559. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_bridge.c:2019 (sofia/internal/111@10.1.10.65:5060) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
  560. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_HIBERNATE (Cur 3 Tot 179)
  561. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/111@10.1.10.65:5060) State HIBERNATE
  562. 2017-06-12 11:45:44.692241 [DEBUG] mod_sofia.c:180 sofia/internal/111@10.1.10.65:5060 SOFIA HIBERNATE
  563. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_bridge.c:971 (sofia/internal/111@10.1.10.65:5060) State Change CS_HIBERNATE -> CS_RESET
  564. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/111@10.1.10.65:5060) State HIBERNATE going to sleep
  565. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_RESET (Cur 3 Tot 179)
  566. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/111@10.1.10.65:5060) State RESET
  567. 2017-06-12 11:45:44.692241 [DEBUG] mod_sofia.c:161 sofia/internal/111@10.1.10.65:5060 SOFIA RESET
  568. 2017-06-12 11:45:44.692241 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/111@10.1.10.65:5060 CUSTOM RESET
  569. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:188 sofia/internal/111@10.1.10.65:5060 Standard RESET
  570. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/111@10.1.10.65:5060) State RESET going to sleep
  571. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:174 sofia/internal/601@10.1.10.150:5062 Standard REPORTING, cause: LOSE_RACE
  572. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING going to sleep
  573. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/601@10.1.10.150:5062) State Change CS_REPORTING -> CS_DESTROY
  574. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_session.c:1664 Session 179 (sofia/internal/601@10.1.10.150:5062) Locked, Waiting on external entities
  575. 2017-06-12 11:45:44.692241 [NOTICE] switch_core_session.c:1682 Session 179 (sofia/internal/601@10.1.10.150:5062) Ended
  576. 2017-06-12 11:45:44.692241 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/601@10.1.10.150:5062 [CS_DESTROY]
  577. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_DESTROY (Cur 2 Tot 179)
  578. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY
  579. 2017-06-12 11:45:44.692241 [DEBUG] mod_sofia.c:343 sofia/internal/601@10.1.10.150:5062 SOFIA DESTROY
  580. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:181 sofia/internal/601@10.1.10.150:5062 Standard DESTROY
  581. 2017-06-12 11:45:44.692241 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY going to sleep
  582. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_async.c:1500 No silence detection configured; assuming start of speech
  583. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_play_say.c:1942 done playing file local_stream://pbx.domain.com/Main_-_Thrive_Life
  584. 2017-06-12 11:45:44.712234 [DEBUG] mod_callcenter.c:3050 Member MICHAEL JOHNSON <8012790596> is answered by an agent in queue Support@pbx.domain.com
  585. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/8012790596@67.211.74.200) State EXECUTE going to sleep
  586. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_HIBERNATE (Cur 2 Tot 179)
  587. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/8012790596@67.211.74.200) State HIBERNATE
  588. 2017-06-12 11:45:44.712234 [DEBUG] mod_sofia.c:180 sofia/internal/8012790596@67.211.74.200 SOFIA HIBERNATE
  589. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:971 (sofia/internal/8012790596@67.211.74.200) State Change CS_HIBERNATE -> CS_RESET
  590. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/8012790596@67.211.74.200) State HIBERNATE going to sleep
  591. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_RESET (Cur 2 Tot 179)
  592. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/8012790596@67.211.74.200) State RESET
  593. 2017-06-12 11:45:44.712234 [DEBUG] mod_sofia.c:161 sofia/internal/8012790596@67.211.74.200 SOFIA RESET
  594. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/8012790596@67.211.74.200 CUSTOM RESET
  595. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:963 (sofia/internal/8012790596@67.211.74.200) State Change CS_RESET -> CS_SOFT_EXECUTE
  596. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/8012790596@67.211.74.200) State RESET going to sleep
  597. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_SOFT_EXECUTE (Cur 2 Tot 179)
  598. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/8012790596@67.211.74.200) State SOFT_EXECUTE
  599. 2017-06-12 11:45:44.712234 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  600. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/8012790596@67.211.74.200 CUSTOM SOFT_EXECUTE
  601. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:1013 (sofia/internal/111@10.1.10.65:5060) State Change CS_RESET -> CS_SOFT_EXECUTE
  602. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_SOFT_EXECUTE (Cur 2 Tot 179)
  603. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/111@10.1.10.65:5060) State SOFT_EXECUTE
  604. 2017-06-12 11:45:44.712234 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  605. 2017-06-12 11:45:44.712234 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/111@10.1.10.65:5060 CUSTOM SOFT_EXECUTE
  606. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:400 sofia/internal/111@10.1.10.65:5060 Standard SOFT_EXECUTE
  607. 2017-06-12 11:45:44.712234 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/111@10.1.10.65:5060) State SOFT_EXECUTE going to sleep
  608. 2017-06-12 11:45:44.732262 [DEBUG] switch_ivr_bridge.c:1496 (sofia/internal/111@10.1.10.65:5060) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
  609. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 179)
  610. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/111@10.1.10.65:5060) State CONSUME_MEDIA
  611. 2017-06-12 11:45:44.732262 [DEBUG] switch_ivr_bridge.c:920 sofia/internal/111@10.1.10.65:5060 CUSTOM HOLD
  612. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/111@10.1.10.65:5060) State CONSUME_MEDIA going to sleep
  613. 2017-06-12 11:45:44.732262 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/111@10.1.10.65:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  614. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 179)
  615. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/111@10.1.10.65:5060) State EXCHANGE_MEDIA
  616. 2017-06-12 11:45:44.732262 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  617. 2017-06-12 11:45:44.732262 [NOTICE] switch_core_io.c:1202 Activating write resampler
  618. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 160 bytes to accommodate 320->160
  619. 2017-06-12 11:45:44.732262 [DEBUG] mod_callcenter.c:1842 Member "MICHAEL JOHNSON" 8012790596 is bridged to agent mJOHNSON@pbx.domain.com
  620. 2017-06-12 11:45:44.732262 [DEBUG] mod_callcenter.c:1256 Updated tier: Agent mJOHNSON@pbx.domain.com in Queue Support@pbx.domain.com set state = Active Inbound
  621. 2017-06-12 11:45:44.732262 [DEBUG] mod_callcenter.c:1135 Updated Agent mJOHNSON@pbx.domain.com set state = In a queue call
  622. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
  623. 2017-06-12 11:45:44.732262 [NOTICE] switch_core_io.c:1202 Activating write resampler
  624. 2017-06-12 11:45:44.732262 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 640 bytes to accommodate 320->640
  625. 2017-06-12 11:45:44.772495 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [calling][0]
  626. 2017-06-12 11:45:44.772495 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [ready][200]
  627. 2017-06-12 11:45:44.772495 [DEBUG] sofia.c:7058 Remote SDP:
  628. v=0
  629. o=- 20167 20168 IN IP4 10.1.10.65
  630. s=SDP data
  631. c=IN IP4 10.1.10.65
  632. t=0 0
  633. m=audio 12158 RTP/AVP 9 101
  634. a=rtpmap:9 G722/8000
  635. a=rtpmap:101 telephone-event/8000
  636. a=fmtp:101 0-15
  637. a=ptime:20
  638.  
  639. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  640. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  641. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  642. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  643. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  644. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  645. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  646. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:4754 sofia/internal/111@10.1.10.65:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  647. 2017-06-12 11:45:44.772495 [DEBUG] sofia.c:8025 Processing updated SDP
  648. 2017-06-12 11:45:44.772495 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/111@10.1.10.65:5060.
  649. 2017-06-12 11:45:44.892257 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  650. 2017-06-12 11:45:48.012237 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [received][100]
  651. 2017-06-12 11:45:48.012237 [DEBUG] sofia.c:7058 Remote SDP:
  652. v=0
  653. o=- 20167 20169 IN IP4 10.1.10.65
  654. s=SDP data
  655. c=IN IP4 10.1.10.65
  656. t=0 0
  657. m=audio 12158 RTP/AVP 9 0 8 18 105 101
  658. a=rtpmap:9 G722/8000
  659. a=rtpmap:0 PCMU/8000
  660. a=rtpmap:8 PCMA/8000
  661. a=rtpmap:18 G729/8000
  662. a=fmtp:18 annexb=no
  663. a=rtpmap:105 G726-40/8000
  664. a=rtpmap:101 telephone-event/8000
  665. a=fmtp:101 0-15
  666. a=sendonly
  667. a=ptime:20
  668.  
  669. 2017-06-12 11:45:48.012237 [DEBUG] switch_channel.c:1844 (sofia/internal/111@10.1.10.65:5060) Callstate Change ACTIVE -> HELD
  670. 2017-06-12 11:45:48.072237 [DEBUG] switch_ivr.c:623 sofia/internal/8012790596@67.211.74.200 Command Execute playback(local_stream://default)
  671. EXECUTE sofia/internal/8012790596@67.211.74.200 playback(local_stream://default)
  672. 2017-06-12 11:45:48.072237 [DEBUG] mod_local_stream.c:868 Opening Stream [default/8000] 8000hz
  673. 2017-06-12 11:45:48.072237 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 10ms
  674. 2017-06-12 11:45:48.092284 [NOTICE] switch_core_io.c:1229 Deactivating write resampler
  675. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  676. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  677. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  678. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  679. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  680. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  681. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  682. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  683. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  684. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  685. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  686. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  687. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  688. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  689. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  690. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  691. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  692. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  693. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
  694. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[G722:9:8000:20:64000:1]
  695. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  696. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  697. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[GSM:3:8000:20:13200:1]
  698. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  699. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  700. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:4754 sofia/internal/111@10.1.10.65:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  701. 2017-06-12 11:45:48.252238 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/111@10.1.10.65:5060.
  702. 2017-06-12 11:45:48.252238 [DEBUG] sofia.c:7963 Processing updated SDP
  703. 2017-06-12 11:45:48.272239 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [completed][200]
  704. 2017-06-12 11:45:48.272239 [DEBUG] sofia.c:7048 Channel sofia/internal/111@10.1.10.65:5060 entering state [ready][200]
  705. 2017-06-12 11:45:50.772237 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/111@pbx.domain.com:5060 [61fbdb67-d782-474f-9e42-a2ea9460e71b]
  706. 2017-06-12 11:45:50.772237 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_NEW (Cur 3 Tot 180)
  707. 2017-06-12 11:45:50.772237 [DEBUG] sofia.c:9834 sofia/internal/111@pbx.domain.com:5060 receiving invite from 10.1.10.65:5060 version: 1.6.17 -34-0fc0946 64bit
  708. 2017-06-12 11:45:50.772237 [DEBUG] sofia.c:10005 IP 10.1.10.65 Rejected by acl "domains". Falling back to Digest auth.
  709. 2017-06-12 11:45:50.772237 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [5505@pbx.domain.com] from ip 10.1.10.65
  710. 2017-06-12 11:45:50.772237 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/111@pbx.domain.com:5060) State NEW
  711. 2017-06-12 11:45:50.772237 [DEBUG] sofia.c:2334 detaching session 61fbdb67-d782-474f-9e42-a2ea9460e71b
  712. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:2442 Re-attaching to session 61fbdb67-d782-474f-9e42-a2ea9460e71b
  713. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:9834 sofia/internal/111@pbx.domain.com:5060 receiving invite from 10.1.10.65:5060 version: 1.6.17 -34-0fc0946 64bit
  714. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:10005 IP 10.1.10.65 Rejected by acl "domains". Falling back to Digest auth.
  715. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:7048 Channel sofia/internal/111@pbx.domain.com:5060 entering state [received][100]
  716. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:7058 Remote SDP:
  717. v=0
  718. o=- 20168 20168 IN IP4 10.1.10.65
  719. s=SDP data
  720. c=IN IP4 10.1.10.65
  721. t=0 0
  722. m=audio 12162 RTP/AVP 9 0 8 18 105 101
  723. a=rtpmap:9 G722/8000
  724. a=rtpmap:0 PCMU/8000
  725. a=rtpmap:8 PCMA/8000
  726. a=rtpmap:18 G729/8000
  727. a=fmtp:18 annexb=no
  728. a=rtpmap:105 G726-40/8000
  729. a=rtpmap:101 telephone-event/8000
  730. a=fmtp:101 0-15
  731. a=ptime:20
  732.  
  733. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  734. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  735. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  736. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  737. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  738. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  739. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  740. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  741. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  742. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  743. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  744. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  745. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  746. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  747. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  748. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  749. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  750. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  751. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
  752. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[G722:9:8000:20:64000:1]
  753. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  754. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  755. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-40:105:8000:20:0:1]/[GSM:3:8000:20:13200:1]
  756. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  757. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/111@pbx.domain.com:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels
  758. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_codec.c:111 sofia/internal/111@pbx.domain.com:5060 Original read codec set to G722:9
  759. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  760. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_media.c:4754 sofia/internal/111@pbx.domain.com:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  761. 2017-06-12 11:45:50.792253 [DEBUG] sofia.c:7471 (sofia/internal/111@pbx.domain.com:5060) State Change CS_NEW -> CS_INIT
  762. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_INIT (Cur 3 Tot 180)
  763. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/111@pbx.domain.com:5060) State INIT
  764. 2017-06-12 11:45:50.792253 [DEBUG] mod_sofia.c:90 sofia/internal/111@pbx.domain.com:5060 SOFIA INIT
  765. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:40 sofia/internal/111@pbx.domain.com:5060 Standard INIT
  766. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/111@pbx.domain.com:5060) State Change CS_INIT -> CS_ROUTING
  767. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/111@pbx.domain.com:5060) State INIT going to sleep
  768. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_ROUTING (Cur 3 Tot 180)
  769. 2017-06-12 11:45:50.792253 [DEBUG] switch_channel.c:2249 (sofia/internal/111@pbx.domain.com:5060) Callstate Change DOWN -> RINGING
  770. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/111@pbx.domain.com:5060) State ROUTING
  771. 2017-06-12 11:45:50.792253 [DEBUG] mod_sofia.c:143 sofia/internal/111@pbx.domain.com:5060 SOFIA ROUTING
  772. 2017-06-12 11:45:50.792253 [DEBUG] switch_core_state_machine.c:236 sofia/internal/111@pbx.domain.com:5060 Standard ROUTING
  773. 2017-06-12 11:45:50.792253 [INFO] mod_dialplan_xml.c:637 Processing Mike JOHNSON <111>->5505 in context pbx.domain.com
  774. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->user_exists] continue=true
  775. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_exists] () =~ // break=on-false
  776. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
  777. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  778. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  779. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(user_exists=false)
  780. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [user_exists]=[false]
  781. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
  782. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->call-direction] continue=true
  783. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
  784. Dialplan: sofia/internal/111@pbx.domain.com:5060 ANTI-Action set(call_direction=local)
  785. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->variables] continue=true
  786. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [variables] () =~ // break=on-false
  787. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action export(origination_callee_id_name=${destination_number})
  788. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  789. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->user_record] continue=true
  790. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] () =~ // break=on-false
  791. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
  792. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  793. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  794. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f219005f3b0 Connected.
  795. 2017-06-12 11:45:50.812238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f219005f3b0 released.
  796. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(user_record=)
  797. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [user_record]=[UNDEF]
  798. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
  799. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(from_user_exists=true)
  800. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [from_user_exists]=[true]
  801. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  802. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
  803. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  804. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  805. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
  806. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  807. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  808. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
  809. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
  810. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  811. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
  812. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  813. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
  814. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(from_user_record=all)
  815. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [from_user_record]=[all]
  816. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  817. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
  818. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(record_session=true) INLINE
  819. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(record_session=true)
  820. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [record_session]=[true]
  821. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  822. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
  823. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
  824. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  825. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
  826. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
  827. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
  828. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
  829. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
  830. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
  831. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action export(nolocal:api_on_answer=uuid_record ${uuid} start ${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext})
  832. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->redial] continue=true
  833. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [redial] destination_number(5505) =~ /^(redial|\*870)$/ break=on-true
  834. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [redial] () =~ // break=never
  835. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  836. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->speed_dial] continue=false
  837. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [speed_dial] destination_number(5505) =~ /^\*0(.*)$/ break=on-false
  838. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->CentraCom.1d10] continue=false
  839. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [CentraCom.1d10] destination_number(5505) =~ /^\+?1?(\d{10})$/ break=on-false
  840. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->CentraCom.911] continue=false
  841. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [CentraCom.911] destination_number(5505) =~ /^(911)$/ break=on-false
  842. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->agent_status] continue=false
  843. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [agent_status] destination_number(5505) =~ /^\*22$/ break=on-false
  844. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->agent_status_id] continue=false
  845. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [agent_status_id] destination_number(5505) =~ /^\*23$/ break=on-false
  846. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->Canada] continue=false
  847. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [Canada] ${caller_id_name}(111) =~ /^([^#]+#)(.*)$/ break=never
  848. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [Canada] destination_number(5505) =~ /^5502$/ break=on-false
  849. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->FrontDesk] continue=false
  850. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [FrontDesk] ${caller_id_name}(111) =~ /^([^#]+#)(.*)$/ break=never
  851. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [FrontDesk] destination_number(5505) =~ /^5503$/ break=on-false
  852. Dialplan: sofia/internal/111@pbx.domain.com:5060 parsing [pbx.domain.com->Payments] continue=false
  853. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (FAIL) [Payments] ${caller_id_name}(111) =~ /^([^#]+#)(.*)$/ break=never
  854. Dialplan: sofia/internal/111@pbx.domain.com:5060 Regex (PASS) [Payments] destination_number(5505) =~ /^5505$/ break=on-false
  855. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action answer()
  856. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action set(hangup_after_bridge=true)
  857. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action callcenter(Payments@pbx.domain.com)
  858. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action transfer(5500 XML pbx.domain.com)
  859. Dialplan: sofia/internal/111@pbx.domain.com:5060 Action hangup()
  860. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/111@pbx.domain.com:5060) State Change CS_ROUTING -> CS_EXECUTE
  861. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/111@pbx.domain.com:5060) State ROUTING going to sleep
  862. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_EXECUTE (Cur 3 Tot 180)
  863. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/111@pbx.domain.com:5060) State EXECUTE
  864. 2017-06-12 11:45:50.812238 [DEBUG] mod_sofia.c:198 sofia/internal/111@pbx.domain.com:5060 SOFIA EXECUTE
  865. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_state_machine.c:328 sofia/internal/111@pbx.domain.com:5060 Standard EXECUTE
  866. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(call_direction=local)
  867. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [call_direction]=[local]
  868. EXECUTE sofia/internal/111@pbx.domain.com:5060 export(origination_callee_id_name=5505)
  869. 2017-06-12 11:45:50.812238 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[5505]
  870. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(RFC2822_DATE=Mon, 12 Jun 2017 11:45:50 -0600)
  871. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [RFC2822_DATE]=[Mon, 12 Jun 2017 11:45:50 -0600]
  872. EXECUTE sofia/internal/111@pbx.domain.com:5060 export(nolocal:api_on_answer=uuid_record 61fbdb67-d782-474f-9e42-a2ea9460e71b start /var/lib/freeswitch/recordings/pbx.domain.com/archive/2017/Jun/12/61fbdb67-d782-474f-9e42-a2ea9460e71b.wav)
  873. 2017-06-12 11:45:50.812238 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [api_on_answer]=[uuid_record 61fbdb67-d782-474f-9e42-a2ea9460e71b start /var/lib/freeswitch/recordings/pbx.domain.com/archive/2017/Jun/12/61fbdb67-d782-474f-9e42-a2ea9460e71b.wav]
  874. EXECUTE sofia/internal/111@pbx.domain.com:5060 hash(insert/pbx.domain.com-last_dial/111/5505)
  875. EXECUTE sofia/internal/111@pbx.domain.com:5060 answer()
  876. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/111@pbx.domain.com:5060] 192.168.3.40 port 22828 -> 10.1.10.65 port 12162 codec: 9 ms: 20
  877. 2017-06-12 11:45:50.812238 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
  878. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_media.c:7166 sofia/internal/111@pbx.domain.com:5060 Set 2833 dtmf send payload to 101
  879. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_media.c:7173 sofia/internal/111@pbx.domain.com:5060 Set 2833 dtmf receive payload to 101
  880. 2017-06-12 11:45:50.812238 [DEBUG] switch_core_media.c:7196 sofia/internal/111@pbx.domain.com:5060 Set rtp dtmf delay to 40
  881. 2017-06-12 11:45:50.812238 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/111@pbx.domain.com:5060:
  882. v=0
  883. o=FreeSWITCH 1497266722 1497266723 IN IP4 192.168.3.40
  884. s=FreeSWITCH
  885. c=IN IP4 192.168.3.40
  886. t=0 0
  887. m=audio 22828 RTP/AVP 9 101
  888. a=rtpmap:9 G722/8000
  889. a=rtpmap:101 telephone-event/8000
  890. a=fmtp:101 0-16
  891. a=ptime:20
  892. a=sendrecv
  893.  
  894. 2017-06-12 11:45:50.812238 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/111@pbx.domain.com:5060] has been answered
  895. 2017-06-12 11:45:50.812238 [DEBUG] switch_channel.c:3772 (sofia/internal/111@pbx.domain.com:5060) Callstate Change RINGING -> ACTIVE
  896. 2017-06-12 11:45:50.812238 [DEBUG] sofia.c:7048 Channel sofia/internal/111@pbx.domain.com:5060 entering state [completed][200]
  897. EXECUTE sofia/internal/111@pbx.domain.com:5060 set(hangup_after_bridge=true)
  898. 2017-06-12 11:45:50.812238 [DEBUG] mod_dptools.c:1530 SET sofia/internal/111@pbx.domain.com:5060 [hangup_after_bridge]=[true]
  899. EXECUTE sofia/internal/111@pbx.domain.com:5060 callcenter(Payments@pbx.domain.com)
  900. 2017-06-12 11:45:50.812238 [DEBUG] mod_callcenter.c:2885 Member 111 <111> joining queue Payments@pbx.domain.com
  901. 2017-06-12 11:45:50.812238 [WARNING] mod_local_stream.c:831 Unknown source pbx.domain.com/Main_-_Thrive_Life, trying 'default'
  902. 2017-06-12 11:45:50.812238 [DEBUG] mod_local_stream.c:868 Opening Stream [default/16000] 16000hz
  903. 2017-06-12 11:45:50.812238 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@16000hz 1 channels 20ms
  904. 2017-06-12 11:45:50.832258 [DEBUG] sofia.c:7048 Channel sofia/internal/111@pbx.domain.com:5060 entering state [ready][200]
  905. 2017-06-12 11:45:50.972258 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  906. 2017-06-12 11:46:14.092252 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Receiving
  907. 2017-06-12 11:46:14.092252 [DEBUG] mod_callcenter.c:1615 Setting outbound caller_id_name to: Mike JOHNSON
  908. 2017-06-12 11:46:14.092252 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  909. 2017-06-12 11:46:14.092252 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  910. 2017-06-12 11:46:14.092252 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/601@10.1.10.150:5062 [31be99d0-f54d-4dc6-87b8-f0bc971ec380]
  911. 2017-06-12 11:46:14.092252 [DEBUG] mod_sofia.c:4818 (sofia/internal/601@10.1.10.150:5062) State Change CS_NEW -> CS_INIT
  912. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_INIT (Cur 4 Tot 181)
  913. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT
  914. 2017-06-12 11:46:14.092252 [DEBUG] mod_sofia.c:90 sofia/internal/601@10.1.10.150:5062 SOFIA INIT
  915. 2017-06-12 11:46:14.092252 [DEBUG] sofia_glue.c:1295 sofia/internal/601@10.1.10.150:5062 sending invite version: 1.6.17 -34-0fc0946 64bit
  916. Local SDP:
  917. v=0
  918. o=FreeSWITCH 1497262848 1497262849 IN IP4 192.168.3.40
  919. s=FreeSWITCH
  920. c=IN IP4 192.168.3.40
  921. t=0 0
  922. m=audio 26726 RTP/AVP 9 0 8 3 101 13
  923. a=rtpmap:9 G722/8000
  924. a=rtpmap:0 PCMU/8000
  925. a=rtpmap:8 PCMA/8000
  926. a=rtpmap:3 GSM/8000
  927. a=rtpmap:101 telephone-event/8000
  928. a=fmtp:101 0-16
  929. a=rtpmap:13 CN/8000
  930. a=ptime:20
  931. a=sendrecv
  932.  
  933. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:40 sofia/internal/601@10.1.10.150:5062 Standard INIT
  934. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/601@10.1.10.150:5062) State Change CS_INIT -> CS_ROUTING
  935. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT going to sleep
  936. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_ROUTING (Cur 4 Tot 181)
  937. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING
  938. 2017-06-12 11:46:14.092252 [DEBUG] mod_sofia.c:143 sofia/internal/601@10.1.10.150:5062 SOFIA ROUTING
  939. 2017-06-12 11:46:14.092252 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/601@10.1.10.150:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  940. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING going to sleep
  941. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 181)
  942. 2017-06-12 11:46:14.092252 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [calling][0]
  943. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA
  944. 2017-06-12 11:46:14.092252 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA going to sleep
  945. 2017-06-12 11:46:14.212251 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set contact = {call_timeout=15,sip_invite_domain=pbx.domain.com}user/601@pbx.domain.com
  946. 2017-06-12 11:46:14.232257 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [proceeding][180]
  947. 2017-06-12 11:46:14.232257 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/601@10.1.10.150:5062!
  948. 2017-06-12 11:46:14.232257 [DEBUG] switch_channel.c:3345 (sofia/internal/601@10.1.10.150:5062) Callstate Change DOWN -> RINGING
  949. 2017-06-12 11:46:14.252242 [NOTICE] switch_core_session.c:249 Hangup sofia/internal/601@10.1.10.150:5062 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
  950. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_HANGUP (Cur 4 Tot 181)
  951. 2017-06-12 11:46:14.252242 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set status = Logged Out
  952. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/601@10.1.10.150:5062) Callstate Change RINGING -> HANGUP
  953. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP
  954. 2017-06-12 11:46:14.252242 [DEBUG] mod_sofia.c:438 Channel sofia/internal/601@10.1.10.150:5062 hanging up, cause: ORIGINATOR_CANCEL
  955. 2017-06-12 11:46:14.252242 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/601@10.1.10.150:5062
  956. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:60 sofia/internal/601@10.1.10.150:5062 Standard HANGUP, cause: ORIGINATOR_CANCEL
  957. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP going to sleep
  958. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/601@10.1.10.150:5062) State Change CS_HANGUP -> CS_REPORTING
  959. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_REPORTING (Cur 4 Tot 181)
  960. 2017-06-12 11:46:14.252242 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING
  961. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:174 sofia/internal/601@10.1.10.150:5062 Standard REPORTING, cause: ORIGINATOR_CANCEL
  962. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING going to sleep
  963. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/601@10.1.10.150:5062) State Change CS_REPORTING -> CS_DESTROY
  964. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_session.c:1664 Session 181 (sofia/internal/601@10.1.10.150:5062) Locked, Waiting on external entities
  965. 2017-06-12 11:46:14.272244 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
  966. 2017-06-12 11:46:14.272244 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
  967. 2017-06-12 11:46:14.272244 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
  968. 2017-06-12 11:46:14.272244 [NOTICE] switch_core_session.c:1682 Session 181 (sofia/internal/601@10.1.10.150:5062) Ended
  969. 2017-06-12 11:46:14.272244 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/601@10.1.10.150:5062 [CS_DESTROY]
  970. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_DESTROY (Cur 3 Tot 181)
  971. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY
  972. 2017-06-12 11:46:14.272244 [DEBUG] mod_sofia.c:343 sofia/internal/601@10.1.10.150:5062 SOFIA DESTROY
  973. 2017-06-12 11:46:14.272244 [DEBUG] mod_callcenter.c:1951 Agent tester@pbx.domain.com Origination Canceled : ORIGINATOR_CANCEL
  974. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:181 sofia/internal/601@10.1.10.150:5062 Standard DESTROY
  975. 2017-06-12 11:46:14.272244 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY going to sleep
  976. 2017-06-12 11:46:14.272244 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Waiting
  977. 2017-06-12 11:46:14.292233 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set reject_delay_time = 90
  978. 2017-06-12 11:46:14.332236 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set busy_delay_time = 90
  979. 2017-06-12 11:46:14.372252 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set no_answer_delay_time = 30
  980. 2017-06-12 11:46:14.412251 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set max_no_answer = 0
  981. 2017-06-12 11:46:14.452252 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set wrap_up_time = 90
  982. 2017-06-12 11:46:19.332235 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set contact = {call_timeout=15,sip_invite_domain=pbx.domain.com}user/601@pbx.domain.com
  983. 2017-06-12 11:46:19.372235 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set status = Available
  984. 2017-06-12 11:46:19.412242 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Receiving
  985. 2017-06-12 11:46:19.412242 [DEBUG] mod_callcenter.c:1615 Setting outbound caller_id_name to: Mike JOHNSON
  986. 2017-06-12 11:46:19.412242 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  987. 2017-06-12 11:46:19.412242 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  988. 2017-06-12 11:46:19.412242 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/601@10.1.10.150:5062 [b80d97e1-ca90-4cf4-a030-2c32baf23c18]
  989. 2017-06-12 11:46:19.412242 [DEBUG] mod_sofia.c:4818 (sofia/internal/601@10.1.10.150:5062) State Change CS_NEW -> CS_INIT
  990. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_INIT (Cur 4 Tot 182)
  991. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT
  992. 2017-06-12 11:46:19.412242 [DEBUG] mod_sofia.c:90 sofia/internal/601@10.1.10.150:5062 SOFIA INIT
  993. 2017-06-12 11:46:19.412242 [DEBUG] sofia_glue.c:1295 sofia/internal/601@10.1.10.150:5062 sending invite version: 1.6.17 -34-0fc0946 64bit
  994. Local SDP:
  995. v=0
  996. o=FreeSWITCH 1497258613 1497258614 IN IP4 192.168.3.40
  997. s=FreeSWITCH
  998. c=IN IP4 192.168.3.40
  999. t=0 0
  1000. m=audio 30966 RTP/AVP 9 0 8 3 101 13
  1001. a=rtpmap:9 G722/8000
  1002. a=rtpmap:0 PCMU/8000
  1003. a=rtpmap:8 PCMA/8000
  1004. a=rtpmap:3 GSM/8000
  1005. a=rtpmap:101 telephone-event/8000
  1006. a=fmtp:101 0-16
  1007. a=rtpmap:13 CN/8000
  1008. a=ptime:20
  1009. a=sendrecv
  1010.  
  1011. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:40 sofia/internal/601@10.1.10.150:5062 Standard INIT
  1012. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/601@10.1.10.150:5062) State Change CS_INIT -> CS_ROUTING
  1013. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/601@10.1.10.150:5062) State INIT going to sleep
  1014. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_ROUTING (Cur 4 Tot 182)
  1015. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING
  1016. 2017-06-12 11:46:19.412242 [DEBUG] mod_sofia.c:143 sofia/internal/601@10.1.10.150:5062 SOFIA ROUTING
  1017. 2017-06-12 11:46:19.412242 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/601@10.1.10.150:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  1018. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/601@10.1.10.150:5062) State ROUTING going to sleep
  1019. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 182)
  1020. 2017-06-12 11:46:19.412242 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [calling][0]
  1021. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA
  1022. 2017-06-12 11:46:19.412242 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA going to sleep
  1023. 2017-06-12 11:46:19.412242 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set reject_delay_time = 90
  1024. 2017-06-12 11:46:19.452234 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set busy_delay_time = 90
  1025. 2017-06-12 11:46:19.492258 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set no_answer_delay_time = 30
  1026. 2017-06-12 11:46:19.532238 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [proceeding][180]
  1027. 2017-06-12 11:46:19.532238 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/601@10.1.10.150:5062!
  1028. 2017-06-12 11:46:19.532238 [DEBUG] switch_channel.c:3345 (sofia/internal/601@10.1.10.150:5062) Callstate Change DOWN -> RINGING
  1029. 2017-06-12 11:46:19.532238 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set max_no_answer = 0
  1030. 2017-06-12 11:46:19.572253 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set wrap_up_time = 90
  1031. 2017-06-12 11:46:23.432249 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [completing][200]
  1032. 2017-06-12 11:46:23.432249 [DEBUG] sofia.c:7058 Remote SDP:
  1033. v=0
  1034. o=- 20000 20000 IN IP4 10.1.10.150
  1035. s=SDP data
  1036. c=IN IP4 10.1.10.150
  1037. t=0 0
  1038. a=sendrecv
  1039. m=audio 11780 RTP/AVP 9 101
  1040. a=rtpmap:9 G722/8000
  1041. a=rtpmap:101 telephone-event/8000
  1042. a=fmtp:101 0-15
  1043. a=ptime:20
  1044.  
  1045. 2017-06-12 11:46:23.432249 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [ready][200]
  1046. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  1047. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  1048. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  1049. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  1050. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  1051. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  1052. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/601@10.1.10.150:5062 G722/8000 20 ms 160 samples 64000 bits 1 channels
  1053. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_codec.c:111 sofia/internal/601@10.1.10.150:5062 Original read codec set to G722:9
  1054. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  1055. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:4754 sofia/internal/601@10.1.10.150:5062 Set 2833 dtmf send payload to 101 recv payload to 101
  1056. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/601@10.1.10.150:5062] 192.168.3.40 port 30966 -> 10.1.10.150 port 11780 codec: 9 ms: 20
  1057. 2017-06-12 11:46:23.432249 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
  1058. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:7166 sofia/internal/601@10.1.10.150:5062 Set 2833 dtmf send payload to 101
  1059. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:7173 sofia/internal/601@10.1.10.150:5062 Set 2833 dtmf receive payload to 101
  1060. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_media.c:7196 sofia/internal/601@10.1.10.150:5062 Set rtp dtmf delay to 40
  1061. 2017-06-12 11:46:23.432249 [NOTICE] sofia.c:8182 Channel [sofia/internal/601@10.1.10.150:5062] has been answered
  1062. 2017-06-12 11:46:23.432249 [DEBUG] switch_channel.c:3772 (sofia/internal/601@10.1.10.150:5062) Callstate Change RINGING -> ACTIVE
  1063. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/601@10.1.10.150:5062]
  1064. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/601@10.1.10.150:5062]
  1065. 2017-06-12 11:46:23.432249 [DEBUG] mod_callcenter.c:1798 Agent tester@pbx.domain.com answered "111" <111> from queue Payments@pbx.domain.com
  1066. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_bridge.c:2017 (sofia/internal/111@pbx.domain.com:5060) State Change CS_EXECUTE -> CS_HIBERNATE
  1067. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_bridge.c:2019 (sofia/internal/601@10.1.10.150:5062) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
  1068. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_HIBERNATE (Cur 4 Tot 182)
  1069. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/601@10.1.10.150:5062) State HIBERNATE
  1070. 2017-06-12 11:46:23.432249 [DEBUG] mod_sofia.c:180 sofia/internal/601@10.1.10.150:5062 SOFIA HIBERNATE
  1071. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_bridge.c:971 (sofia/internal/601@10.1.10.150:5062) State Change CS_HIBERNATE -> CS_RESET
  1072. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/601@10.1.10.150:5062) State HIBERNATE going to sleep
  1073. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_RESET (Cur 4 Tot 182)
  1074. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/601@10.1.10.150:5062) State RESET
  1075. 2017-06-12 11:46:23.432249 [DEBUG] mod_sofia.c:161 sofia/internal/601@10.1.10.150:5062 SOFIA RESET
  1076. 2017-06-12 11:46:23.432249 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/601@10.1.10.150:5062 CUSTOM RESET
  1077. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:188 sofia/internal/601@10.1.10.150:5062 Standard RESET
  1078. 2017-06-12 11:46:23.432249 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/601@10.1.10.150:5062) State RESET going to sleep
  1079. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_play_say.c:1942 done playing file local_stream://pbx.domain.com/Main_-_Thrive_Life
  1080. 2017-06-12 11:46:23.452235 [DEBUG] mod_callcenter.c:3050 Member 111 <111> is answered by an agent in queue Payments@pbx.domain.com
  1081. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/111@pbx.domain.com:5060) State EXECUTE going to sleep
  1082. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_HIBERNATE (Cur 4 Tot 182)
  1083. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/111@pbx.domain.com:5060) State HIBERNATE
  1084. 2017-06-12 11:46:23.452235 [DEBUG] mod_sofia.c:180 sofia/internal/111@pbx.domain.com:5060 SOFIA HIBERNATE
  1085. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:971 (sofia/internal/111@pbx.domain.com:5060) State Change CS_HIBERNATE -> CS_RESET
  1086. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/111@pbx.domain.com:5060) State HIBERNATE going to sleep
  1087. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_RESET (Cur 4 Tot 182)
  1088. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/111@pbx.domain.com:5060) State RESET
  1089. 2017-06-12 11:46:23.452235 [DEBUG] mod_sofia.c:161 sofia/internal/111@pbx.domain.com:5060 SOFIA RESET
  1090. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/111@pbx.domain.com:5060 CUSTOM RESET
  1091. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:963 (sofia/internal/111@pbx.domain.com:5060) State Change CS_RESET -> CS_SOFT_EXECUTE
  1092. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/111@pbx.domain.com:5060) State RESET going to sleep
  1093. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_SOFT_EXECUTE (Cur 4 Tot 182)
  1094. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/111@pbx.domain.com:5060) State SOFT_EXECUTE
  1095. 2017-06-12 11:46:23.452235 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  1096. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/111@pbx.domain.com:5060 CUSTOM SOFT_EXECUTE
  1097. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:1013 (sofia/internal/601@10.1.10.150:5062) State Change CS_RESET -> CS_SOFT_EXECUTE
  1098. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_SOFT_EXECUTE (Cur 4 Tot 182)
  1099. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/601@10.1.10.150:5062) State SOFT_EXECUTE
  1100. 2017-06-12 11:46:23.452235 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  1101. 2017-06-12 11:46:23.452235 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/601@10.1.10.150:5062 CUSTOM SOFT_EXECUTE
  1102. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:400 sofia/internal/601@10.1.10.150:5062 Standard SOFT_EXECUTE
  1103. 2017-06-12 11:46:23.452235 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/601@10.1.10.150:5062) State SOFT_EXECUTE going to sleep
  1104. 2017-06-12 11:46:23.472238 [DEBUG] switch_ivr_bridge.c:1496 (sofia/internal/601@10.1.10.150:5062) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
  1105. 2017-06-12 11:46:23.472238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 182)
  1106. 2017-06-12 11:46:23.472238 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA
  1107. 2017-06-12 11:46:23.472238 [DEBUG] switch_ivr_bridge.c:920 sofia/internal/601@10.1.10.150:5062 CUSTOM HOLD
  1108. 2017-06-12 11:46:23.472238 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA going to sleep
  1109. 2017-06-12 11:46:23.472238 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/601@10.1.10.150:5062) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  1110. 2017-06-12 11:46:23.472238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 182)
  1111. 2017-06-12 11:46:23.472238 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/601@10.1.10.150:5062) State EXCHANGE_MEDIA
  1112. 2017-06-12 11:46:23.472238 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  1113. 2017-06-12 11:46:23.472238 [DEBUG] mod_callcenter.c:1842 Member "111" 111 is bridged to agent tester@pbx.domain.com
  1114. 2017-06-12 11:46:23.472238 [DEBUG] mod_callcenter.c:1256 Updated tier: Agent tester@pbx.domain.com in Queue Payments@pbx.domain.com set state = Active Inbound
  1115. 2017-06-12 11:46:23.472238 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = In a queue call
  1116. 2017-06-12 11:46:23.492237 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [calling][0]
  1117. 2017-06-12 11:46:23.492237 [DEBUG] sofia.c:7048 Channel sofia/internal/111@pbx.domain.com:5060 entering state [calling][0]
  1118. 2017-06-12 11:46:23.492237 [DEBUG] sofia.c:7048 Channel sofia/internal/111@pbx.domain.com:5060 entering state [ready][200]
  1119. 2017-06-12 11:46:23.492237 [DEBUG] sofia.c:7058 Remote SDP:
  1120. v=0
  1121. o=- 20168 20169 IN IP4 10.1.10.65
  1122. s=SDP data
  1123. c=IN IP4 10.1.10.65
  1124. t=0 0
  1125. m=audio 12162 RTP/AVP 9 101
  1126. a=rtpmap:9 G722/8000
  1127. a=rtpmap:101 telephone-event/8000
  1128. a=fmtp:101 0-15
  1129. a=ptime:20
  1130.  
  1131. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  1132. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  1133. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  1134. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  1135. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  1136. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  1137. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  1138. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:4754 sofia/internal/111@pbx.domain.com:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  1139. 2017-06-12 11:46:23.492237 [DEBUG] sofia.c:8025 Processing updated SDP
  1140. 2017-06-12 11:46:23.492237 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/111@pbx.domain.com:5060.
  1141. 2017-06-12 11:46:23.652279 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [ready][200]
  1142. 2017-06-12 11:46:23.652279 [DEBUG] sofia.c:7058 Remote SDP:
  1143. v=0
  1144. o=- 20000 20001 IN IP4 10.1.10.150
  1145. s=SDP data
  1146. c=IN IP4 10.1.10.150
  1147. t=0 0
  1148. a=sendrecv
  1149. m=audio 11780 RTP/AVP 9 101
  1150. a=rtpmap:9 G722/8000
  1151. a=rtpmap:101 telephone-event/8000
  1152. a=fmtp:101 0-15
  1153. a=ptime:20
  1154.  
  1155. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  1156. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  1157. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  1158. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  1159. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  1160. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  1161. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  1162. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:4754 sofia/internal/601@10.1.10.150:5062 Set 2833 dtmf send payload to 101 recv payload to 101
  1163. 2017-06-12 11:46:23.652279 [DEBUG] sofia.c:8025 Processing updated SDP
  1164. 2017-06-12 11:46:23.652279 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/601@10.1.10.150:5062.
  1165. 2017-06-12 11:46:23.792240 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  1166. 2017-06-12 11:46:25.732253 [DEBUG] sofia.c:8508 Process REFER to [5505@63.78.119.44]
  1167. 2017-06-12 11:46:25.732253 [DEBUG] sofia.c:8534 Replaces: [0_3321424007@10.1.10.65]
  1168. 2017-06-12 11:46:25.732253 [NOTICE] sofia.c:8731 Attended Transfer [d60e4737-94ed-4341-a352-ac554deff4bb][b80d97e1-ca90-4cf4-a030-2c32baf23c18]
  1169. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:2017 (sofia/internal/8012790596@67.211.74.200) State Change CS_SOFT_EXECUTE -> CS_HIBERNATE
  1170. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:2019 (sofia/internal/601@10.1.10.150:5062) State Change CS_EXCHANGE_MEDIA -> CS_HIBERNATE
  1171. 2017-06-12 11:46:25.732253 [DEBUG] sofia.c:8806 (sofia/internal/111@pbx.domain.com:5060) State Change CS_SOFT_EXECUTE -> CS_PARK
  1172. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/601@10.1.10.150:5062]
  1173. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/601@10.1.10.150:5062) State EXCHANGE_MEDIA going to sleep
  1174. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_HIBERNATE (Cur 4 Tot 182)
  1175. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/601@10.1.10.150:5062) State HIBERNATE
  1176. 2017-06-12 11:46:25.732253 [DEBUG] mod_sofia.c:180 sofia/internal/601@10.1.10.150:5062 SOFIA HIBERNATE
  1177. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:971 (sofia/internal/601@10.1.10.150:5062) State Change CS_HIBERNATE -> CS_RESET
  1178. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/601@10.1.10.150:5062) State HIBERNATE going to sleep
  1179. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_RESET (Cur 4 Tot 182)
  1180. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/601@10.1.10.150:5062) State RESET
  1181. 2017-06-12 11:46:25.732253 [DEBUG] mod_sofia.c:161 sofia/internal/601@10.1.10.150:5062 SOFIA RESET
  1182. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/601@10.1.10.150:5062 CUSTOM RESET
  1183. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:188 sofia/internal/601@10.1.10.150:5062 Standard RESET
  1184. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/601@10.1.10.150:5062) State RESET going to sleep
  1185. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/601@10.1.10.150:5062 ending bridge by request from write function
  1186. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/111@pbx.domain.com:5060]
  1187. 2017-06-12 11:46:25.732253 [NOTICE] switch_ivr_bridge.c:1751 Hangup sofia/internal/111@pbx.domain.com:5060 [CS_PARK] [NORMAL_CLEARING]
  1188. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/111@pbx.domain.com:5060) State SOFT_EXECUTE going to sleep
  1189. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_HANGUP (Cur 4 Tot 182)
  1190. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/111@pbx.domain.com:5060) Callstate Change ACTIVE -> HANGUP
  1191. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/111@pbx.domain.com:5060) State HANGUP
  1192. 2017-06-12 11:46:25.732253 [DEBUG] mod_sofia.c:438 Channel sofia/internal/111@pbx.domain.com:5060 hanging up, cause: NORMAL_CLEARING
  1193. 2017-06-12 11:46:25.732253 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/111@pbx.domain.com:5060
  1194. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:60 sofia/internal/111@pbx.domain.com:5060 Standard HANGUP, cause: NORMAL_CLEARING
  1195. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/111@pbx.domain.com:5060) State HANGUP going to sleep
  1196. 2017-06-12 11:46:25.732253 [DEBUG] switch_ivr_play_say.c:1942 done playing file local_stream://default
  1197. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/111@pbx.domain.com:5060) State Change CS_HANGUP -> CS_REPORTING
  1198. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_REPORTING (Cur 4 Tot 182)
  1199. 2017-06-12 11:46:25.732253 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/111@pbx.domain.com:5060) State REPORTING
  1200. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/8012790596@67.211.74.200]
  1201. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:174 sofia/internal/111@pbx.domain.com:5060 Standard REPORTING, cause: NORMAL_CLEARING
  1202. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/111@pbx.domain.com:5060) State REPORTING going to sleep
  1203. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/111@pbx.domain.com:5060) State Change CS_REPORTING -> CS_DESTROY
  1204. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_session.c:1664 Session 180 (sofia/internal/111@pbx.domain.com:5060) Locked, Waiting on external entities
  1205. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/111@10.1.10.65:5060]
  1206. 2017-06-12 11:46:25.752254 [DEBUG] switch_channel.c:2029 (sofia/internal/111@10.1.10.65:5060) Callstate Change HELD -> UNHELD
  1207. 2017-06-12 11:46:25.752254 [NOTICE] switch_ivr_bridge.c:891 Hangup sofia/internal/111@10.1.10.65:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  1208. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/111@10.1.10.65:5060) State EXCHANGE_MEDIA going to sleep
  1209. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_HANGUP (Cur 4 Tot 182)
  1210. 2017-06-12 11:46:25.752254 [DEBUG] sofia.c:1453 Channel is already hungup.
  1211. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/111@10.1.10.65:5060) Callstate Change UNHELD -> HANGUP
  1212. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/111@10.1.10.65:5060) State HANGUP
  1213. 2017-06-12 11:46:25.752254 [DEBUG] mod_sofia.c:438 Channel sofia/internal/111@10.1.10.65:5060 hanging up, cause: NORMAL_CLEARING
  1214. 2017-06-12 11:46:25.752254 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/111@10.1.10.65:5060
  1215. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:1699 sofia/internal/111@10.1.10.65:5060 skip receive message [UNBRIDGE] (channel is hungup already)
  1216. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:60 sofia/internal/111@10.1.10.65:5060 Standard HANGUP, cause: NORMAL_CLEARING
  1217. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:1764 (sofia/internal/8012790596@67.211.74.200) State Change CS_HIBERNATE -> CS_RESET
  1218. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/8012790596@67.211.74.200) State SOFT_EXECUTE going to sleep
  1219. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/111@10.1.10.65:5060) State HANGUP going to sleep
  1220. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_RESET (Cur 4 Tot 182)
  1221. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/111@10.1.10.65:5060) State Change CS_HANGUP -> CS_REPORTING
  1222. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/8012790596@67.211.74.200) State RESET
  1223. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_REPORTING (Cur 4 Tot 182)
  1224. 2017-06-12 11:46:25.752254 [DEBUG] mod_sofia.c:161 sofia/internal/8012790596@67.211.74.200 SOFIA RESET
  1225. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:956 sofia/internal/8012790596@67.211.74.200 CUSTOM RESET
  1226. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:963 (sofia/internal/8012790596@67.211.74.200) State Change CS_RESET -> CS_SOFT_EXECUTE
  1227. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/8012790596@67.211.74.200) State RESET going to sleep
  1228. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_SOFT_EXECUTE (Cur 4 Tot 182)
  1229. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/8012790596@67.211.74.200) State SOFT_EXECUTE
  1230. 2017-06-12 11:46:25.752254 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  1231. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/8012790596@67.211.74.200 CUSTOM SOFT_EXECUTE
  1232. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:1013 (sofia/internal/601@10.1.10.150:5062) State Change CS_RESET -> CS_SOFT_EXECUTE
  1233. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_SOFT_EXECUTE (Cur 4 Tot 182)
  1234. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/111@10.1.10.65:5060) State REPORTING
  1235. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:174 sofia/internal/111@10.1.10.65:5060 Standard REPORTING, cause: NORMAL_CLEARING
  1236. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/111@10.1.10.65:5060) State REPORTING going to sleep
  1237. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/601@10.1.10.150:5062) State SOFT_EXECUTE
  1238. 2017-06-12 11:46:25.752254 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
  1239. 2017-06-12 11:46:25.752254 [DEBUG] switch_ivr_bridge.c:981 sofia/internal/601@10.1.10.150:5062 CUSTOM SOFT_EXECUTE
  1240. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:400 sofia/internal/601@10.1.10.150:5062 Standard SOFT_EXECUTE
  1241. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/601@10.1.10.150:5062) State SOFT_EXECUTE going to sleep
  1242. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/111@10.1.10.65:5060) State Change CS_REPORTING -> CS_DESTROY
  1243. 2017-06-12 11:46:25.752254 [DEBUG] switch_core_session.c:1664 Session 178 (sofia/internal/111@10.1.10.65:5060) Locked, Waiting on external entities
  1244. 2017-06-12 11:46:25.772240 [DEBUG] switch_ivr_bridge.c:1496 (sofia/internal/601@10.1.10.150:5062) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
  1245. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 182)
  1246. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA
  1247. 2017-06-12 11:46:25.772240 [DEBUG] switch_ivr_bridge.c:920 sofia/internal/601@10.1.10.150:5062 CUSTOM HOLD
  1248. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/601@10.1.10.150:5062) State CONSUME_MEDIA going to sleep
  1249. 2017-06-12 11:46:25.772240 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/601@10.1.10.150:5062) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  1250. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 182)
  1251. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/601@10.1.10.150:5062) State EXCHANGE_MEDIA
  1252. 2017-06-12 11:46:25.772240 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  1253. 2017-06-12 11:46:25.772240 [NOTICE] switch_core_io.c:1202 Activating write resampler
  1254. 2017-06-12 11:46:25.772240 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 160 bytes to accommodate 320->160
  1255. 2017-06-12 11:46:25.792253 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [calling][0]
  1256. 2017-06-12 11:46:25.812239 [NOTICE] switch_core_io.c:1202 Activating write resampler
  1257. 2017-06-12 11:46:25.812239 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 640 bytes to accommodate 320->640
  1258. 2017-06-12 11:46:25.832259 [DEBUG] mod_callcenter.c:1135 Updated Agent mJOHNSON@pbx.domain.com set state = Waiting
  1259. 2017-06-12 11:46:25.832259 [NOTICE] switch_core_session.c:1682 Session 178 (sofia/internal/111@10.1.10.65:5060) Ended
  1260. 2017-06-12 11:46:25.832259 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/111@10.1.10.65:5060 [CS_DESTROY]
  1261. 2017-06-12 11:46:25.832259 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/111@10.1.10.65:5060) Running State Change CS_DESTROY (Cur 3 Tot 182)
  1262. 2017-06-12 11:46:25.832259 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/111@10.1.10.65:5060) State DESTROY
  1263. 2017-06-12 11:46:25.832259 [DEBUG] mod_sofia.c:343 sofia/internal/111@10.1.10.65:5060 SOFIA DESTROY
  1264. 2017-06-12 11:46:25.832259 [DEBUG] switch_core_state_machine.c:181 sofia/internal/111@10.1.10.65:5060 Standard DESTROY
  1265. 2017-06-12 11:46:25.832259 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/111@10.1.10.65:5060) State DESTROY going to sleep
  1266. 2017-06-12 11:46:25.912250 [DEBUG] sofia.c:7048 Channel sofia/internal/601@10.1.10.150:5062 entering state [ready][200]
  1267. 2017-06-12 11:46:25.912250 [DEBUG] sofia.c:7058 Remote SDP:
  1268. v=0
  1269. o=- 20000 20002 IN IP4 10.1.10.150
  1270. s=SDP data
  1271. c=IN IP4 10.1.10.150
  1272. t=0 0
  1273. a=sendrecv
  1274. m=audio 11780 RTP/AVP 9 101
  1275. a=rtpmap:9 G722/8000
  1276. a=rtpmap:101 telephone-event/8000
  1277. a=fmtp:101 0-15
  1278. a=ptime:20
  1279.  
  1280. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  1281. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  1282. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  1283. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  1284. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  1285. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
  1286. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
  1287. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:4754 sofia/internal/601@10.1.10.150:5062 Set 2833 dtmf send payload to 101 recv payload to 101
  1288. 2017-06-12 11:46:25.912250 [DEBUG] sofia.c:8025 Processing updated SDP
  1289. 2017-06-12 11:46:25.912250 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/601@10.1.10.150:5062.
  1290. 2017-06-12 11:47:50.012255 [DEBUG] switch_rtp.c:1460  [  zrtp cache]:   Storing ZRTP cache to </var/lib/freeswitch/db/zrtp.dat>...
  1291. 2017-06-12 11:47:50.012255 [DEBUG] switch_rtp.c:1321 Saving ZRTP cache: OK
  1292. 2017-06-12 11:48:03.812253 [NOTICE] sofia.c:1012 Hangup sofia/internal/601@10.1.10.150:5062 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  1293. 2017-06-12 11:48:03.812253 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/601@10.1.10.150:5062]
  1294. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/601@10.1.10.150:5062) State EXCHANGE_MEDIA going to sleep
  1295. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_HANGUP (Cur 3 Tot 182)
  1296. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/601@10.1.10.150:5062) Callstate Change ACTIVE -> HANGUP
  1297. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP
  1298. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:438 Channel sofia/internal/601@10.1.10.150:5062 hanging up, cause: NORMAL_CLEARING
  1299. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:60 sofia/internal/601@10.1.10.150:5062 Standard HANGUP, cause: NORMAL_CLEARING
  1300. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/601@10.1.10.150:5062) State HANGUP going to sleep
  1301. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/601@10.1.10.150:5062) State Change CS_HANGUP -> CS_REPORTING
  1302. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_REPORTING (Cur 3 Tot 182)
  1303. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING
  1304. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:174 sofia/internal/601@10.1.10.150:5062 Standard REPORTING, cause: NORMAL_CLEARING
  1305. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/601@10.1.10.150:5062) State REPORTING going to sleep
  1306. 2017-06-12 11:48:03.812253 [DEBUG] mod_callcenter.c:1135 Updated Agent tester@pbx.domain.com set state = Waiting
  1307. 2017-06-12 11:48:03.812253 [NOTICE] switch_core_session.c:1682 Session 180 (sofia/internal/111@pbx.domain.com:5060) Ended
  1308. 2017-06-12 11:48:03.812253 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/111@pbx.domain.com:5060 [CS_DESTROY]
  1309. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/601@10.1.10.150:5062) State Change CS_REPORTING -> CS_DESTROY
  1310. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_session.c:1664 Session 182 (sofia/internal/601@10.1.10.150:5062) Locked, Waiting on external entities
  1311. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/111@pbx.domain.com:5060) Running State Change CS_DESTROY (Cur 2 Tot 182)
  1312. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/111@pbx.domain.com:5060) State DESTROY
  1313. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:343 sofia/internal/111@pbx.domain.com:5060 SOFIA DESTROY
  1314. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:181 sofia/internal/111@pbx.domain.com:5060 Standard DESTROY
  1315. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/111@pbx.domain.com:5060) State DESTROY going to sleep
  1316. 2017-06-12 11:48:03.812253 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/601@10.1.10.150:5062 ending bridge by request from write function
  1317. 2017-06-12 11:48:03.812253 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/8012790596@67.211.74.200]
  1318. 2017-06-12 11:48:03.812253 [NOTICE] switch_ivr_bridge.c:1751 Hangup sofia/internal/8012790596@67.211.74.200 [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
  1319. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/8012790596@67.211.74.200) State SOFT_EXECUTE going to sleep
  1320. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_HANGUP (Cur 2 Tot 182)
  1321. 2017-06-12 11:48:03.812253 [NOTICE] switch_core_session.c:1682 Session 182 (sofia/internal/601@10.1.10.150:5062) Ended
  1322. 2017-06-12 11:48:03.812253 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/601@10.1.10.150:5062 [CS_DESTROY]
  1323. 2017-06-12 11:48:03.812253 [DEBUG] switch_ivr_async.c:1316 Stop recording file /media/fusionpbx/pbx.domain.com/recordings/2017/Jun/12/d60e4737-94ed-4341-a352-ac554deff4bb.wav
  1324. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/601@10.1.10.150:5062) Running State Change CS_DESTROY (Cur 1 Tot 182)
  1325. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY
  1326. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:343 sofia/internal/601@10.1.10.150:5062 SOFIA DESTROY
  1327. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:181 sofia/internal/601@10.1.10.150:5062 Standard DESTROY
  1328. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/601@10.1.10.150:5062) State DESTROY going to sleep
  1329. 2017-06-12 11:48:03.812253 [DEBUG] switch_ivr_async.c:1380 Channel is hung up
  1330. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_media_bug.c:1124 Removing BUG from sofia/internal/8012790596@67.211.74.200
  1331. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/8012790596@67.211.74.200) Callstate Change ACTIVE -> HANGUP
  1332. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/8012790596@67.211.74.200) State HANGUP
  1333. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:432 sofia/internal/8012790596@67.211.74.200 Overriding SIP cause 480 with 200 from the other leg
  1334. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:438 Channel sofia/internal/8012790596@67.211.74.200 hanging up, cause: NORMAL_CLEARING
  1335. 2017-06-12 11:48:03.812253 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/8012790596@67.211.74.200
  1336. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:60 sofia/internal/8012790596@67.211.74.200 Standard HANGUP, cause: NORMAL_CLEARING
  1337. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/8012790596@67.211.74.200) State HANGUP going to sleep
  1338. 2017-06-12 11:48:03.812253 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/8012790596@67.211.74.200) State Change CS_HANGUP -> CS_REPORTING
  1339. 2017-06-12 11:48:03.832255 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_REPORTING (Cur 1 Tot 182)
  1340. 2017-06-12 11:48:03.832255 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/8012790596@67.211.74.200) State REPORTING
  1341. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:174 sofia/internal/8012790596@67.211.74.200 Standard REPORTING, cause: NORMAL_CLEARING
  1342. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/8012790596@67.211.74.200) State REPORTING going to sleep
  1343. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/8012790596@67.211.74.200) State Change CS_REPORTING -> CS_DESTROY
  1344. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_session.c:1664 Session 177 (sofia/internal/8012790596@67.211.74.200) Locked, Waiting on external entities
  1345. 2017-06-12 11:48:03.852276 [NOTICE] switch_core_session.c:1682 Session 177 (sofia/internal/8012790596@67.211.74.200) Ended
  1346. 2017-06-12 11:48:03.852276 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/8012790596@67.211.74.200 [CS_DESTROY]
  1347. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/8012790596@67.211.74.200) Running State Change CS_DESTROY (Cur 0 Tot 182)
  1348. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/8012790596@67.211.74.200) State DESTROY
  1349. 2017-06-12 11:48:03.852276 [DEBUG] mod_sofia.c:343 sofia/internal/8012790596@67.211.74.200 SOFIA DESTROY
  1350. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:181 sofia/internal/8012790596@67.211.74.200 Standard DESTROY
  1351. 2017-06-12 11:48:03.852276 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/8012790596@67.211.74.200) State DESTROY going to sleep
  1352. freeswitch@pbx.domain.com> /bye
  1353. root@pbx:/etc# /media/fusionpbx/pbx.domain.com/recordings/2017/Jun/12/
  1354. bash: /media/fusionpbx/pbx.domain.com/recordings/2017/Jun/12/: Is a directory
  1355. root@pbx:/etc# cd /media/fusionpbx/pbx.domain.com/recordings/2017/Jun/12/
  1356. root@pbx:/media/fusionpbx/pbx.domain.com/recordings/2017/Jun/12# ll
  1357. total 2176
  1358. -rw-rw---- 1 www-data www-data 2224474 Jun 12 11:49 d60e4737-94ed-4341-a352-ac554deff4bb.wav
  1359.  

Reply to "recordings"