FreeSWITCH Pastebin

Log with sip debug + loglevel 9

From Sam, 8 Years ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/ff793521
Embed
Download Paste or View Raw
  1. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc00026cb0): events IN
  2. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc00026cb0)
  3. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc00026cb0) msg 0x7efc0002f820 from (udp/172.xx.xx.60:5060) has 1137 bytes, veclen = 1
  4. recv 1137 bytes from udp/[172.xx.xx.3]:65516 at 09:04:45.697394:
  5.    ------------------------------------------------------------------------
  6.    INVITE sip:4099@172.xx.xx.60:5060 SIP/2.0
  7.    Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A3C1F9B
  8.    From: <sip:8003@172.xx.xx.3>;tag=2E5A0858-1E87
  9.    To: <sip:4099@172.xx.xx.60>
  10.    Date: Fri, 04 Nov 2016 06:56:40 GMT
  11.    Call-ID: ABCA635E-A19211E6-BC85C7B1-C40D3FF0@172.xx.xx.3
  12.    Supported: 100rel,timer,resource-priority,replaces,sdp-anat
  13.    Min-SE:  1800
  14.    Cisco-Guid: 4277484416-0000065536-0000007232-1678944448
  15.    User-Agent: Cisco-SIPGateway/IOS-12.x
  16.   Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
  17.    CSeq: 101 INVITE
  18.    Timestamp: 1478242600
  19.    Contact: <sip:8003@172.xx.xx.3:5060>
  20.    Expires: 180
  21.    Allow-Events: telephone-event
  22.    Max-Forwards: 68
  23.    Session-Expires:  1800
  24.    Content-Type: application/sdp
  25.    Content-Disposition: session;handling=required
  26.    Content-Length: 323
  27.    
  28.    v=0
  29.    o=CiscoSystemsSIP-GW-UserAgent 920 9284 IN IP4 172.xx.xx.3
  30.    s=SIP Call
  31.    c=IN IP4 172.xx.xx.3
  32.    t=0 0
  33.    m=audio 19472 RTP/AVP 18 101 121
  34.    c=IN IP4 172.xx.xx.3
  35.    a=rtpmap:18 G729/8000
  36.    a=fmtp:18 annexb=no
  37.    a=rtpmap:101 telephone-event/8000
  38.    a=fmtp:101 0-16
  39.    a=rtpmap:121 frf-dialed-digit/8000
  40.    a=fmtp:121 0-15
  41.    a=ptime:20
  42.    ------------------------------------------------------------------------
  43. tport.c:3023 tport_deliver() tport_deliver(0x7efc00026cb0): msg 0x7efc0002f820 (1137 bytes) from udp/172.xx.xx.3:5060/sip next=(nil)
  44. nta.c:2880 agent_recv_request() nta: received INVITE sip:4099@172.xx.xx.60:5060 SIP/2.0 (CSeq 101)
  45. nta.c:3248 agent_aliases() nta: canonizing sip:4099@172.xx.xx.60:5060 with contact
  46. nta.c:3085 agent_recv_request() nta: INVITE (101) going to a default leg
  47. nta.c:1350 set_timeout() nta: timer set to 200 ms
  48. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  49. nua_stack.c:899 nh_create() nua: nh_create: entering
  50. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  51. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  52. soa.c:280 soa_clone() soa_clone(static::0x7efc00024ec0, 0x7efc000141f0, 0x7efc0002f050) called
  53. soa.c:403 soa_set_params() soa_set_params(static::0x7efc00033ad0, ...) called
  54. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7efc0002f3a0)
  55. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7efc00033ad0) called
  56. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7efc00033ad0, (nil), 0x7efc0002d3ce, 323) called
  57. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7efc0002f050): adding session usage
  58. tport.c:3257 tport_tsend() tport_tsend(0x7efc00026cb0) tpn = UDP/172.xx.xx.3:5060
  59. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.3:5060
  60. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc00026cb0): not found by name UDP/172.xx.xx.3:5060
  61. tport.c:3594 tport_vsend() tport_vsend(0x7efc00026cb0): 364 bytes of 364 to udp/172.xx.xx.3:5060
  62. tport.c:3492 tport_send_msg() tport_vsend returned 364
  63. send 364 bytes to udp/[172.xx.xx.3]:5060 at 09:04:45.714668:
  64.    ------------------------------------------------------------------------
  65.    SIP/2.0 100 Trying
  66.    Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A3C1F9B
  67.    From: <sip:8003@172.xx.xx.3>;tag=2E5A0858-1E87
  68.    To: <sip:4099@172.xx.xx.60>
  69.    Call-ID: ABCA635E-A19211E6-BC85C7B1-C40D3FF0@172.xx.xx.3
  70.    CSeq: 101 INVITE
  71.    Timestamp: 1478242600 0.000214
  72.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  73.    Content-Length: 0
  74.    
  75.    ------------------------------------------------------------------------
  76. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (101)
  77. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_invite 100 Trying
  78. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  79. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002f050): call state changed: init -> received, received offer
  80. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7efc00033ad0, [0x7efc377458c8], [0x7efc377458d0], [(nil)]) called
  81. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  82. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_state 100 Trying
  83. 2016-11-04 09:04:45.697691 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/8003@172.xx.xx.3 [544b6c82-4804-4791-bf86-f44a9e72b983]
  84. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  85. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_NEW
  86. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  87. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:9374 sofia/internal/8003@172.xx.xx.3 receiving invite from 172.xx.xx.3:65516 version: 1.6.7 git f0c3870 2016-04-01 13:40:07Z 64bit
  88. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:9486 IP 172.xx.xx.3 Approved by acl "domains[]". Access Granted.
  89. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:10676 Setting NAT mode based on via port
  90. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  91. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  92. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [received][100]
  93. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:6868 Remote SDP:
  94. v=0
  95. o=CiscoSystemsSIP-GW-UserAgent 920 9284 IN IP4 172.xx.xx.3
  96. s=SIP Call
  97. c=IN IP4 172.xx.xx.3
  98. t=0 0
  99. m=audio 19472 RTP/AVP 18 101 121
  100. c=IN IP4 172.xx.xx.3
  101. a=rtpmap:18 G729/8000
  102. a=fmtp:18 annexb=no
  103. a=rtpmap:101 telephone-event/8000
  104. a=fmtp:101 0-16
  105. a=rtpmap:121 frf-dialed-digit/8000
  106. a=fmtp:121 0-15
  107. a=ptime:20
  108.  
  109. 2016-11-04 09:04:45.697691 [DEBUG] sofia.c:7227 (sofia/internal/8003@172.xx.xx.3) State Change CS_NEW -> CS_INIT
  110. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  111. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/8003@172.xx.xx.3) State NEW
  112. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_INIT
  113. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/8003@172.xx.xx.3) State INIT
  114. 2016-11-04 09:04:45.697691 [DEBUG] mod_sofia.c:89 sofia/internal/8003@172.xx.xx.3 SOFIA INIT
  115. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:40 sofia/internal/8003@172.xx.xx.3 Standard INIT
  116. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/8003@172.xx.xx.3) State Change CS_INIT -> CS_ROUTING
  117. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/8003@172.xx.xx.3) State INIT going to sleep
  118. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_ROUTING
  119. 2016-11-04 09:04:45.697691 [DEBUG] switch_channel.c:2249 (sofia/internal/8003@172.xx.xx.3) Callstate Change DOWN -> RINGING
  120. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING
  121. 2016-11-04 09:04:45.697691 [DEBUG] mod_sofia.c:142 sofia/internal/8003@172.xx.xx.3 SOFIA ROUTING
  122. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8003@172.xx.xx.3 Standard ROUTING
  123. 2016-11-04 09:04:45.697691 [INFO] mod_dialplan_xml.c:637 Processing 8003 <8003>->4099 in context public
  124. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->unloop] continue=false
  125. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  126. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  127. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_huntgroup] continue=false
  128. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_huntgroup] destination_number(4099) =~ /^0870980891$/ break=on-false
  129. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_did_to_local] continue=false
  130. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_did_to_local] destination_number(4099) =~ /^0870980892$/ break=on-false
  131. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->outside_call] continue=true
  132. Dialplan: sofia/internal/8003@172.xx.xx.3 Absolute Condition [outside_call]
  133. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(outside_call=true)
  134. Dialplan: sofia/internal/8003@172.xx.xx.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  135. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->call_debug] continue=true
  136. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  137. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_extensions] continue=false
  138. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_extensions] destination_number(4099) =~ /^(10[01][0-9])$/ break=on-false
  139. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false
  140. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(5551212)$/ break=on-false
  141. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false
  142. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(0870980892)$/ break=on-false
  143. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false
  144. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980890$/ break=on-false
  145. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false
  146. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980893$/ break=on-false
  147. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->conf11001] continue=false
  148. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [conf11001] destination_number(4099) =~ /^11001$/ break=on-false
  149. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->UNKNOWN] continue=false
  150. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [UNKNOWN] destination_number(4099) =~ /^(4099)$/ break=on-false
  151. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(transfer_after_bridge=4099)
  152. Dialplan: sofia/internal/8003@172.xx.xx.3 Action sleep(300)
  153. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set uuid ${caller_id_number} '${uuid}')})
  154. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set type ${caller_id_number} 'uuid-standby')})
  155. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set status ${caller_id_number} 'Available')})
  156. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set state ${caller_id_number} 'idle')})
  157. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3)
  158. Dialplan: sofia/internal/8003@172.xx.xx.3 Action answer()
  159. Dialplan: sofia/internal/8003@172.xx.xx.3 Action playback(local_stream://moh)
  160. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8003@172.xx.xx.3) State Change CS_ROUTING -> CS_EXECUTE
  161. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING going to sleep
  162. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXECUTE
  163. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE
  164. 2016-11-04 09:04:45.697691 [DEBUG] mod_sofia.c:197 sofia/internal/8003@172.xx.xx.3 SOFIA EXECUTE
  165. 2016-11-04 09:04:45.697691 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8003@172.xx.xx.3 Standard EXECUTE
  166. EXECUTE sofia/internal/8003@172.xx.xx.3 set(outside_call=true)
  167. 2016-11-04 09:04:45.697691 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [outside_call]=[true]
  168. EXECUTE sofia/internal/8003@172.xx.xx.3 export(RFC2822_DATE=Fri, 04 Nov 2016 09:04:45 +0200)
  169. 2016-11-04 09:04:45.697691 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 04 Nov 2016 09:04:45 +0200]
  170. EXECUTE sofia/internal/8003@172.xx.xx.3 set(transfer_after_bridge=4099)
  171. 2016-11-04 09:04:45.717455 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [transfer_after_bridge]=[4099]
  172. EXECUTE sofia/internal/8003@172.xx.xx.3 sleep(300)
  173. nta.c:1289 agent_timer() nta: timer not set
  174. 2016-11-04 09:04:46.017461 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set uuid = 544b6c82-4804-4791-bf86-f44a9e72b983
  175. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  176. )
  177. 2016-11-04 09:04:46.017461 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  178. ]
  179. 2016-11-04 09:04:46.017461 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set type = uuid-standby
  180. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  181. )
  182. 2016-11-04 09:04:46.017461 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  183. ]
  184. 2016-11-04 09:04:46.017461 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set status = Available
  185. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  186. )
  187. 2016-11-04 09:04:46.017461 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  188. ]
  189. 2016-11-04 09:04:46.017461 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = idle
  190. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  191. )
  192. 2016-11-04 09:04:46.017461 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  193. ]
  194. EXECUTE sofia/internal/8003@172.xx.xx.3 set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3)
  195. 2016-11-04 09:04:46.017461 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [cc_warning_tone]=[tone_stream://%(200,0,500,600,700);loops=3]
  196. EXECUTE sofia/internal/8003@172.xx.xx.3 answer()
  197. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:3720 Activate Buggy RFC2833 Mode!
  198. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  199. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4266 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  200. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4127 Set telephone-event payload to 101@8000
  201. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [frf-dialed-digit:121:8000:20:0:1]/[G729:18:8000:20:8000:1]
  202. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:2946 Set Codec sofia/internal/8003@172.xx.xx.3 G729/8000 20 ms 160 samples 8000 bits 1 channels
  203. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_codec.c:111 sofia/internal/8003@172.xx.xx.3 Original read codec set to G729:18
  204. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4479 Set telephone-event payload to 101@8000
  205. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:4537 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf send payload to 101 recv payload to 101
  206. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:6320 AUDIO RTP [sofia/internal/8003@172.xx.xx.3] 172.xx.xx.60 port 19744 -> 172.xx.xx.3 port 19472 codec: 18 ms: 20
  207. 2016-11-04 09:04:46.017461 [DEBUG] switch_rtp.c:3812 Starting timer [soft] 160 bytes per 20ms
  208. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:6619 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf send payload to 101
  209. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:6626 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf receive payload to 101
  210. 2016-11-04 09:04:46.017461 [DEBUG] switch_core_media.c:6649 sofia/internal/8003@172.xx.xx.3 Set rtp dtmf delay to 40
  211. 2016-11-04 09:04:46.017461 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/8003@172.xx.xx.3!
  212. 2016-11-04 09:04:46.017461 [DEBUG] switch_channel.c:3471 (sofia/internal/8003@172.xx.xx.3) Callstate Change RINGING -> EARLY
  213. 2016-11-04 09:04:46.017461 [DEBUG] mod_sofia.c:814 Local SDP sofia/internal/8003@172.xx.xx.3:
  214. v=0
  215. o=FreeSWITCH 1478223342 1478223343 IN IP4 172.xx.xx.60
  216. s=FreeSWITCH
  217. c=IN IP4 172.xx.xx.60
  218. t=0 0
  219. m=audio 19744 RTP/AVP 18 101
  220. a=rtpmap:18 G729/8000
  221. a=fmtp:18 annexb=no
  222. a=rtpmap:101 telephone-event/8000
  223. a=fmtp:101 0-16
  224. a=ptime:20
  225. a=sendrecv
  226.  
  227. nua.c:879 nua_respond() nua: nua_respond: entering
  228. nua_stack.c:529 nua_signal() nua(0x7efc0002f050): sent signal r_respond
  229. nua_stack.c:573 nua_stack_signal() nua(0x7efc0002f050): recv signal r_respond 200 OK
  230. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  231. soa.c:403 soa_set_params() soa_set_params(static::0x7efc00033ad0, ...) called
  232. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7efc00033ad0, (nil), 0x7efc18066b44, -1) called
  233. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7efc00033ad0, (nil), 0x7efc18066b44, -1) called
  234. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  235. soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7efc00033ad0) called
  236. 2016-11-04 09:04:46.017461 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/8003@172.xx.xx.3] has been answered
  237. soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7efc00033ad0, soa_generate_answer): called
  238. soa_static.c:1187 offer_answer_step() soa_static(0x7efc00033ad0, soa_generate_answer): generating local description
  239. soa_static.c:1228 offer_answer_step() soa_static(0x7efc00033ad0, soa_generate_answer): upgrade with remote description
  240. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7efc37743b00, 0x7efc00034900, ""): called
  241. soa_static.c:1444 offer_answer_step() soa_static(0x7efc00033ad0, soa_generate_answer): storing local description
  242. soa.c:1730 soa_activate() soa_activate(static::0x7efc00033ad0, (nil)) called
  243. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc00033ad0, [(nil)], [0x7efc37745c38], [0x7efc37745c34]) called
  244. tport.c:3257 tport_tsend() tport_tsend(0x7efc00026cb0) tpn = UDP/172.xx.xx.3:5060
  245. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.3:5060
  246. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc00026cb0): not found by name UDP/172.xx.xx.3:5060
  247. tport.c:3594 tport_vsend() tport_vsend(0x7efc00026cb0): 1183 bytes of 1183 to udp/172.xx.xx.3:5060
  248. tport.c:3492 tport_send_msg() tport_vsend returned 1183
  249. send 1183 bytes to udp/[172.xx.xx.3]:5060 at 09:04:46.023692:
  250.    ------------------------------------------------------------------------
  251.    SIP/2.0 200 OK
  252.    Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A3C1F9B
  253.    From: <sip:8003@172.xx.xx.3>;tag=2E5A0858-1E87
  254.    To: <sip:4099@172.xx.xx.60>;tag=99yX2garZcp4g
  255.    Call-ID: ABCA635E-A19211E6-BC85C7B1-C40D3FF0@172.xx.xx.3
  256.    CSeq: 101 INVITE
  257.    Contact: <sip:4099@172.xx.xx.60:5060;transport=udp>
  258.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  259.    Accept: application/sdp
  260.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  261.    Require: timer
  262.    Supported: timer, path, replaces
  263.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  264.    Session-Expires: 1800;refresher=uac
  265.    Content-Type: application/sdp
  266.    Content-Disposition: session
  267.    Content-Length: 243
  268.    Remote-Party-ID: "4099" <sip:4099@172.xx.xx.60>;party=calling;privacy=off;screen=no
  269.    
  270.    v=0
  271.    o=FreeSWITCH 1478223342 1478223343 IN IP4 172.xx.xx.60
  272.    s=FreeSWITCH
  273.    c=IN IP4 172.xx.xx.60
  274.    t=0 0
  275.    m=audio 19744 RTP/AVP 18 101
  276.    a=rtpmap:18 G729/8000
  277.    a=fmtp:18 annexb=no
  278.    a=rtpmap:101 telephone-event/8000
  279.    a=fmtp:101 0-16
  280.    a=ptime:20
  281.    ------------------------------------------------------------------------
  282. nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (101)
  283. nta.c:1350 set_timeout() nta: timer set to 500 ms
  284. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002f050): call state changed: received -> completed, sent answer
  285. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc00033ad0, [0x7efc37745ce8], [0x7efc37745cf0], [(nil)]) called
  286. soa.c:616 soa_get_params() soa_get_params(static::0x7efc00033ad0, ...) called
  287. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_state 200 OK
  288. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  289. 2016-11-04 09:04:46.017461 [DEBUG] switch_channel.c:3770 (sofia/internal/8003@172.xx.xx.3) Callstate Change EARLY -> ACTIVE
  290. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  291. 2016-11-04 09:04:46.017461 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [completed][200]
  292. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  293. EXECUTE sofia/internal/8003@172.xx.xx.3 playback(local_stream://moh)
  294. 2016-11-04 09:04:46.017461 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz
  295. 2016-11-04 09:04:46.017461 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  296. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc00026cb0): events IN
  297. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc00026cb0)
  298. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc00026cb0) msg 0x7efc00032e90 from (udp/172.xx.xx.60:5060) has 388 bytes, veclen = 1
  299. recv 388 bytes from udp/[172.xx.xx.3]:65516 at 09:04:46.033007:
  300.    ------------------------------------------------------------------------
  301.    ACK sip:4099@172.xx.xx.60:5060;transport=udp SIP/2.0
  302.    Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A3D6FF
  303.    From: <sip:8003@172.xx.xx.3>;tag=2E5A0858-1E87
  304.    To: <sip:4099@172.xx.xx.60>;tag=99yX2garZcp4g
  305.    Date: Fri, 04 Nov 2016 06:56:40 GMT
  306.    Call-ID: ABCA635E-A19211E6-BC85C7B1-C40D3FF0@172.xx.xx.3
  307.    Max-Forwards: 70
  308.    CSeq: 101 ACK
  309.    Allow-Events: telephone-event
  310.    Content-Length: 0
  311.    
  312.    ------------------------------------------------------------------------
  313. tport.c:3023 tport_deliver() tport_deliver(0x7efc00026cb0): msg 0x7efc00032e90 (388 bytes) from udp/172.xx.xx.3:5060/sip next=(nil)
  314. nta.c:2880 agent_recv_request() nta: received ACK sip:4099@172.xx.xx.60:5060;transport=udp SIP/2.0 (CSeq 101)
  315. nta.c:3019 agent_recv_request() nta: ACK (101) is going to INVITE (101)
  316. nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering
  317. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7efc00033ad0) called
  318. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_ack 200 OK
  319. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002f050): call state changed: completed -> ready
  320. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_state 200 OK
  321. nua_stack.c:271 nua_stack_event() nua(0x7efc0002f050): event i_active 200 Call active
  322. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh session after 1768 seconds (in [1768..1768])
  323. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  324. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  325. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  326. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  327. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  328. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  329. 2016-11-04 09:04:46.037462 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [ready][200]
  330. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  331. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  332. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  333. 2016-11-04 09:04:46.037462 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1805dca8 0x7efc1805dca8
  334. 2016-11-04 09:04:46.037462 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1805dca8 0x7efc1805dca8
  335. 2016-11-04 09:04:46.237530 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed.
  336. nta.c:1296 agent_timer() nta: timer set next to 4509 ms
  337. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc00026cb0): events IN
  338. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc00026cb0)
  339. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc00026cb0) msg 0x7efc00032e90 from (udp/172.xx.xx.60:5060) has 4 bytes, veclen = 1
  340. tport.c:3023 tport_deliver() tport_deliver(0x7efc00026cb0): bad msg 0x7efc00032e90 (4 bytes) from udp/10.99.107.25:5060/sip next=(nil)
  341. nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response
  342. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7efc37745c60)
  343. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
  344. nta.c:1289 agent_timer() nta: timer not set
  345. 2016-11-04 09:04:57.577500 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = waiting
  346. 2016-11-04 09:05:00.897481 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  347. 2016-11-04 09:05:00.917472 [NOTICE] switch_channel.c:1104 New Channel sofia/external/0833573222 [908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb]
  348. 2016-11-04 09:05:00.917472 [DEBUG] mod_sofia.c:4799 (sofia/external/0833573222) State Change CS_NEW -> CS_INIT
  349. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_INIT
  350. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:586 (sofia/external/0833573222) State INIT
  351. 2016-11-04 09:05:00.917472 [DEBUG] mod_sofia.c:89 sofia/external/0833573222 SOFIA INIT
  352. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  353. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  354. 2016-11-04 09:05:00.917472 [DEBUG] sofia_glue.c:1257 sofia/external/0833573222 sending invite version: 1.6.7 git f0c3870 2016-04-01 13:40:07Z 64bit
  355. Local SDP:
  356. v=0
  357. o=FreeSWITCH 1478221656 1478221657 IN IP4 172.xx.xx.85
  358. s=FreeSWITCH
  359. c=IN IP4 172.xx.xx.85
  360. t=0 0
  361. m=audio 21444 RTP/AVP 18
  362. a=rtpmap:18 G729/8000
  363. a=fmtp:18 annexb=no
  364. a=ptime:20
  365. a=sendrecv
  366.  
  367. nua.c:633 nua_invite() nua: nua_invite: entering
  368. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_invite
  369. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:40 sofia/external/0833573222 Standard INIT
  370. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:48 (sofia/external/0833573222) State Change CS_INIT -> CS_ROUTING
  371. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:586 (sofia/external/0833573222) State INIT going to sleep
  372. nua_stack.c:569 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_invite
  373. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  374. soa.c:280 soa_clone() soa_clone(static::0x7efc0c0035e0, 0x7efc0c005970, 0x7efc0002eaf0) called
  375. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  376. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  377. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7efc0c03a7a0, (nil), 0x7efc00035187, -1) called
  378. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7efc0c03a7a0, (nil), 0x7efc00035187, -1) called
  379. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7efc0002eaf0): adding session usage
  380. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7efc0c02eae0)
  381. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7efc0c03a7a0) called
  382. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7efc0c03a7a0, 0) called
  383. soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7efc0c03a7a0, soa_generate_offer): called
  384. soa_static.c:1187 offer_answer_step() soa_static(0x7efc0c03a7a0, soa_generate_offer): generating local description
  385. soa_static.c:1215 offer_answer_step() soa_static(0x7efc0c03a7a0, soa_generate_offer): upgrade with local description
  386. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7efc3768fac0, (nil), ""): called
  387. soa_static.c:1444 offer_answer_step() soa_static(0x7efc0c03a7a0, soa_generate_offer): storing local description
  388. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc0c03a7a0, [(nil)], [0x7efc37691bf8], [0x7efc37691bf4]) called
  389. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  390. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = */172.xx.xx.61:5060
  391. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  392. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name */172.xx.xx.61:5060
  393. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 997 bytes of 997 to udp/172.xx.xx.61:5060
  394. tport.c:3492 tport_send_msg() tport_vsend returned 997
  395. send 997 bytes to udp/[172.xx.xx.61]:5060 at 09:05:00.919046:
  396.    ------------------------------------------------------------------------
  397.    INVITE sip:0833573222@172.xx.xx.61 SIP/2.0
  398.    Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKrvSaD1g1gacUH
  399.    Max-Forwards: 70
  400.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  401.    To: <sip:0833573222@172.xx.xx.61>
  402.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  403.    CSeq: 98785486 INVITE
  404.    Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
  405.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  406.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  407.    Supported: timer, path, replaces
  408.    Allow-Events: talk, hold, conference, refer
  409.    Content-Type: application/sdp
  410.    Content-Disposition: session
  411.    Content-Length: 187
  412.    X-FS-Support: update_display,send_info
  413.    Remote-Party-ID: <sip:0870980000@172.xx.xx.61>;party=calling;screen=yes;privacy=off
  414.    
  415.    v=0
  416.    o=FreeSWITCH 1478221656 1478221657 IN IP4 172.xx.xx.85
  417.    s=FreeSWITCH
  418.    c=IN IP4 172.xx.xx.85
  419.    t=0 0
  420.    m=audio 21444 RTP/AVP 18
  421.    a=rtpmap:18 G729/8000
  422.    a=fmtp:18 annexb=no
  423.    a=ptime:20
  424.    ------------------------------------------------------------------------
  425. nta.c:8304 outgoing_send() nta: sent INVITE (98785486) to */172.xx.xx.61:5060
  426. tport.c:4160 tport_pend() tport_pend(0x7efc0c0008c0): pending 0x7efc0c0055b0 for udp/172.xx.xx.85:5060 (already 0)
  427. nta.c:1350 set_timeout() nta: timer set to 32000 ms
  428. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  429. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: init -> calling, sent offer
  430. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc0c03a7a0, [0x7efc37691bd8], [0x7efc37691be0], [(nil)]) called
  431. nua_stack.c:269 nua_stack_event() nua(0x7efc0002eaf0): event i_state INVITE sent
  432. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  433. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING
  434. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  435. 2016-11-04 09:05:00.917472 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [calling][0]
  436. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  437. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING
  438. 2016-11-04 09:05:00.917472 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING
  439. 2016-11-04 09:05:00.917472 [DEBUG] switch_ivr_originate.c:67 (sofia/external/0833573222) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  440. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep
  441. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_CONSUME_MEDIA
  442. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:621 (sofia/external/0833573222) State CONSUME_MEDIA
  443. 2016-11-04 09:05:00.917472 [DEBUG] switch_core_state_machine.c:621 (sofia/external/0833573222) State CONSUME_MEDIA going to sleep
  444. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  445. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  446. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c041e00 from (udp/172.xx.xx.85:5060) has 291 bytes, veclen = 1
  447. recv 291 bytes from udp/[172.xx.xx.61]:5060 at 09:05:00.919777:
  448.    ------------------------------------------------------------------------
  449.    SIP/2.0 100 Trying
  450.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKrvSaD1g1gacUH
  451.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  452.    To: <sip:0833573222@172.xx.xx.61>
  453.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  454.    CSeq: 98785486 INVITE
  455.    User-Agent: FS
  456.    Content-Length: 0
  457.    
  458.    ------------------------------------------------------------------------
  459. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c041e00 (291 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  460. nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (98785486)
  461. nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction
  462. nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 0.844 ms
  463. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c0055b0 by 0x7efc0c044b60 with 0x7efc0c041e00 (preliminary)
  464. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  465. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  466. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c048450 from (udp/172.xx.xx.85:5060) has 780 bytes, veclen = 1
  467. recv 780 bytes from udp/[172.xx.xx.61]:5060 at 09:05:00.921302:
  468.    ------------------------------------------------------------------------
  469.    SIP/2.0 407 Proxy Authentication Required
  470.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKrvSaD1g1gacUH
  471.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  472.    To: <sip:0833573222@172.xx.xx.61>;tag=052X1XjKaXpUS
  473.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  474.    CSeq: 98785486 INVITE
  475.    User-Agent: FS
  476.    Accept: application/sdp
  477.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  478.    Supported: path, replaces
  479.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  480.    Proxy-Authenticate: Digest realm="172.xx.xx.61", nonce="64a7a2e8-8f79-432e-bb5d-a89650b98760", algorithm=MD5, qop="auth"
  481.    Content-Length: 0
  482.    
  483.    ------------------------------------------------------------------------
  484. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c048450 (780 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  485. nta.c:3299 agent_recv_response() nta: received 407 Proxy Authentication Required for INVITE (98785486)
  486. nta.c:3366 agent_recv_response() nta: 407 Proxy Authentication Required is going to a transaction
  487. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c0055b0 by 0x7efc0c044b60 with 0x7efc0c048450
  488. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = UDP/172.xx.xx.61:5060
  489. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  490. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name UDP/172.xx.xx.61:5060
  491. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 321 bytes of 321 to udp/172.xx.xx.61:5060
  492. tport.c:3492 tport_send_msg() tport_vsend returned 321
  493. send 321 bytes to udp/[172.xx.xx.61]:5060 at 09:05:00.921464:
  494.    ------------------------------------------------------------------------
  495.    ACK sip:0833573222@172.xx.xx.61 SIP/2.0
  496.    Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKrvSaD1g1gacUH
  497.    Max-Forwards: 70
  498.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  499.    To: <sip:0833573222@172.xx.xx.61>;tag=052X1XjKaXpUS
  500.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  501.    CSeq: 98785486 ACK
  502.    Content-Length: 0
  503.    
  504.    ------------------------------------------------------------------------
  505. nta.c:8304 outgoing_send() nta: sent ACK (98785486) to UDP/172.xx.xx.61:5060
  506. nta.c:8722 outgoing_free() nta: outgoing_free(0x7efc0c002570)
  507. auth_digest.c:105 auth_digest_challenge_get() auth_digest_challenge_get(): got 6
  508. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event r_invite 407 Proxy Authentication Required
  509. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  510. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  511. nua.c:834 nua_authenticate() nua: nua_authenticate: entering
  512. nua_stack.c:569 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_authenticate
  513. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_authenticate
  514. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  515. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7efc0c03a7a0) called
  516. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7efc0c03a7a0, 0) called
  517. soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7efc0c03a7a0, soa_generate_offer): called
  518. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7efc0c02f6b0, (nil), ""): called
  519. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc0c03a7a0, [(nil)], [0x7efc37691c38], [0x7efc37691c34]) called
  520. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(Enav8Pre:172.xx.xx.61:En@v8Pre!!@4543) = 0539d9f4459c6f955a5b6c5bce9c40b1
  521. auth_digest.c:318 auth_digest_response() A2 = MD5(INVITE:sip:0833573222@172.xx.xx.61)
  522. auth_digest.c:348 auth_digest_response() auth_response: 119008ac15c252754a4c7e73c5d4527b = MD5(0539d9f4459c6f955a5b6c5bce9c40b1:64a7a2e8-8f79-432e-bb5d-a89650b98760:00000001:2BgUXBz/EjWAOwBQVosP+A:auth:693cbb1a365f86856545c8a064b538e6) (qop=auth)
  523. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  524. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = */172.xx.xx.61:5060
  525. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  526. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name */172.xx.xx.61:5060
  527. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 1265 bytes of 1265 to udp/172.xx.xx.61:5060
  528. tport.c:3492 tport_send_msg() tport_vsend returned 1265
  529. send 1265 bytes to udp/[172.xx.xx.61]:5060 at 09:05:00.922051:
  530.    ------------------------------------------------------------------------
  531.    INVITE sip:0833573222@172.xx.xx.61 SIP/2.0
  532.    Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKS5j3ev14DK2DD
  533.    Max-Forwards: 70
  534.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  535.    To: <sip:0833573222@172.xx.xx.61>
  536.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  537.    CSeq: 98785487 INVITE
  538.    Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
  539.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  540.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  541.    Supported: timer, path, replaces
  542.    Allow-Events: talk, hold, conference, refer
  543.    Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="64a7a2e8-8f79-432e-bb5d-a89650b98760", cnonce="2BgUXBz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61", response="119008ac15c252754a4c7e73c5d4527b", qop=auth, nc=00000001
  544.    Content-Type: application/sdp
  545.    Content-Disposition: session
  546.    Content-Length: 187
  547.    X-FS-Support: update_display,send_info
  548.    Remote-Party-ID: <sip:0870980000@172.xx.xx.61>;party=calling;screen=yes;privacy=off
  549.    
  550.    v=0
  551.    o=FreeSWITCH 1478221656 1478221657 IN IP4 172.xx.xx.85
  552.    s=FreeSWITCH
  553.    c=IN IP4 172.xx.xx.85
  554.    t=0 0
  555.    m=audio 21444 RTP/AVP 18
  556.    a=rtpmap:18 G729/8000
  557.    a=fmtp:18 annexb=no
  558.    a=ptime:20
  559.    ------------------------------------------------------------------------
  560. nta.c:8304 outgoing_send() nta: sent INVITE (98785487) to */172.xx.xx.61:5060
  561. tport.c:4160 tport_pend() tport_pend(0x7efc0c0008c0): pending 0x7efc0c041820 for udp/172.xx.xx.85:5060 (already 0)
  562. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: calling -> calling, sent offer
  563. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7efc0c03a7a0, [0x7efc37691c18], [0x7efc37691c20], [(nil)]) called
  564. nua_stack.c:269 nua_stack_event() nua(0x7efc0002eaf0): event i_state INVITE sent
  565. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  566. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  567. 2016-11-04 09:05:00.917472 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [calling][0]
  568. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  569. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  570. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  571. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c041d90 from (udp/172.xx.xx.85:5060) has 291 bytes, veclen = 1
  572. recv 291 bytes from udp/[172.xx.xx.61]:5060 at 09:05:00.922619:
  573.    ------------------------------------------------------------------------
  574.    SIP/2.0 100 Trying
  575.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKS5j3ev14DK2DD
  576.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  577.    To: <sip:0833573222@172.xx.xx.61>
  578.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  579.    CSeq: 98785487 INVITE
  580.    User-Agent: FS
  581.    Content-Length: 0
  582.    
  583.    ------------------------------------------------------------------------
  584. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c041d90 (291 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  585. nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (98785487)
  586. nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction
  587. nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 0.71 ms
  588. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c041820 by 0x7efc0c048250 with 0x7efc0c041d90 (preliminary)
  589. nta.c:1296 agent_timer() nta: timer set next to 31003 ms
  590. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  591. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  592. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c041d90 from (udp/172.xx.xx.85:5060) has 1186 bytes, veclen = 1
  593. recv 1186 bytes from udp/[172.xx.xx.61]:5060 at 09:05:02.188615:
  594.    ------------------------------------------------------------------------
  595.    SIP/2.0 183 Session Progress
  596.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKS5j3ev14DK2DD
  597.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  598.    To: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  599.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  600.    CSeq: 98785487 INVITE
  601.    Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
  602.    User-Agent: FS
  603.    Accept: application/sdp
  604.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  605.    Supported: path, replaces
  606.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  607.    Content-Type: application/sdp
  608.    Content-Disposition: session
  609.    Content-Length: 187
  610.    X-FS-Display-Name: Outbound Call
  611.    X-FS-Display-Number: sip:D0820833573222@172.xx.xx.61
  612.    X-FS-Support: update_display,send_info
  613.    Remote-Party-ID: "Outbound Call" <sip:D0820833573222@172.xx.xx.61>;party=calling;privacy=off;screen=no
  614.    
  615.    v=0
  616.    o=FreeSWITCH 1478216006 1478216007 IN IP4 172.xx.xx.61
  617.    s=FreeSWITCH
  618.    c=IN IP4 172.xx.xx.61
  619.    t=0 0
  620.    m=audio 27110 RTP/AVP 18
  621.    a=rtpmap:18 G729/8000
  622.    a=fmtp:18 annexb=no
  623.    a=ptime:20
  624.    ------------------------------------------------------------------------
  625. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c041d90 (1186 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  626. nta.c:3299 agent_recv_response() nta: received 183 Session Progress for INVITE (98785487)
  627. nta.c:3366 agent_recv_response() nta: 183 Session Progress is going to a transaction
  628. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c041820 by 0x7efc0c048250 with 0x7efc0c041d90 (preliminary)
  629. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7efc0c03a7a0, (nil), 0x7efc0c002717, 187) called
  630. soa.c:1595 soa_process_answer() soa_process_answer(static::0x7efc0c03a7a0) called
  631. soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7efc0c03a7a0, soa_process_answer): called
  632. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7efc0c02f6b0, 0x7efc0c02ef70, ""): called
  633. soa_static.c:1302 offer_answer_step() soa_static(0x7efc0c03a7a0, soa_process_answer): upgrade codecs with remote description
  634. soa.c:1730 soa_activate() soa_activate(static::0x7efc0c03a7a0, (nil)) called
  635. nua_session.c:988 nua_session_client_response() nua(0x7efc0002eaf0): INVITE: processed SDP answer in 183 Session Progress
  636. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event r_invite 183 Session Progress
  637. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: calling -> proceeding, received answer
  638. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7efc0c03a7a0, [0x7efc37691648], [0x7efc37691650], [(nil)]) called
  639. soa.c:616 soa_get_params() soa_get_params(static::0x7efc0c03a7a0, ...) called
  640. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_state 183 Session Progress
  641. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  642. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  643. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  644. 2016-11-04 09:05:02.177486 [INFO] sofia.c:1255 sofia/external/0833573222 Update Callee ID to "Outbound Call" <sip:D0820833573222@172.xx.xx.61>
  645. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  646. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  647. 2016-11-04 09:05:02.177486 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [proceeding][183]
  648. 2016-11-04 09:05:02.177486 [DEBUG] sofia.c:6868 Remote SDP:
  649. v=0
  650. o=FreeSWITCH 1478216006 1478216007 IN IP4 172.xx.xx.61
  651. s=FreeSWITCH
  652. c=IN IP4 172.xx.xx.61
  653. t=0 0
  654. m=audio 27110 RTP/AVP 18
  655. a=rtpmap:18 G729/8000
  656. a=fmtp:18 annexb=no
  657. a=ptime:20
  658.  
  659. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  660. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:4266 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  661. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:2946 Set Codec sofia/external/0833573222 G729/8000 20 ms 160 samples 8000 bits 1 channels
  662. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_codec.c:111 sofia/external/0833573222 Original read codec set to G729:18
  663. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:4509 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  664. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:4537 sofia/external/0833573222 Set 2833 dtmf send payload to 101 recv payload to 101
  665. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:6320 AUDIO RTP [sofia/external/0833573222] 172.xx.xx.85 port 21444 -> 172.xx.xx.61 port 27110 codec: 18 ms: 20
  666. 2016-11-04 09:05:02.177486 [DEBUG] switch_rtp.c:3812 Starting timer [soft] 160 bytes per 20ms
  667. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:6619 sofia/external/0833573222 Set 2833 dtmf send payload to 101
  668. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:6626 sofia/external/0833573222 Set 2833 dtmf receive payload to 101
  669. 2016-11-04 09:05:02.177486 [DEBUG] switch_core_media.c:6649 sofia/external/0833573222 Set rtp dtmf delay to 40
  670. 2016-11-04 09:05:02.177486 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/0833573222!
  671. 2016-11-04 09:05:02.177486 [DEBUG] switch_channel.c:3471 (sofia/external/0833573222) Callstate Change DOWN -> EARLY
  672. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  673. 2016-11-04 09:05:02.197460 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/external/0833573222]
  674. 2016-11-04 09:05:02.197460 [DEBUG] switch_ivr.c:2160 (sofia/external/0833573222) State Change CS_CONSUME_MEDIA -> CS_ROUTING
  675. 2016-11-04 09:05:02.197460 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/0833573222 to XML[0870980890@default]
  676. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING
  677. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING
  678. 2016-11-04 09:05:02.197460 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING
  679. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:236 sofia/external/0833573222 Standard ROUTING
  680. 2016-11-04 09:05:02.197460 [INFO] mod_dialplan_xml.c:637 Processing  <0870980000>->0870980890 in context default
  681. Dialplan: sofia/external/0833573222 parsing [default->unloop] continue=false
  682. Dialplan: sofia/external/0833573222 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  683. Dialplan: sofia/external/0833573222 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  684. Dialplan: sofia/external/0833573222 parsing [default->tod_example] continue=true
  685. Dialplan: sofia/external/0833573222 Date/Time Match (PASS) [tod_example] break=on-false
  686. Dialplan: sofia/external/0833573222 Action set(open=true)
  687. Dialplan: sofia/external/0833573222 parsing [default->holiday_example] continue=true
  688. Dialplan: sofia/external/0833573222 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  689. Dialplan: sofia/external/0833573222 parsing [default->global-intercept] continue=false
  690. Dialplan: sofia/external/0833573222 Regex (FAIL) [global-intercept] destination_number(0870980890) =~ /^886$/ break=on-false
  691. Dialplan: sofia/external/0833573222 parsing [default->group-intercept] continue=false
  692. Dialplan: sofia/external/0833573222 Regex (FAIL) [group-intercept] destination_number(0870980890) =~ /^\*8$/ break=on-false
  693. Dialplan: sofia/external/0833573222 parsing [default->intercept-ext] continue=false
  694. Dialplan: sofia/external/0833573222 Regex (FAIL) [intercept-ext] destination_number(0870980890) =~ /^\*\*(\d+)$/ break=on-false
  695. Dialplan: sofia/external/0833573222 parsing [default->redial] continue=false
  696. Dialplan: sofia/external/0833573222 Regex (FAIL) [redial] destination_number(0870980890) =~ /^(redial|870)$/ break=on-false
  697. Dialplan: sofia/external/0833573222 parsing [default->global] continue=true
  698. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  699. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never
  700. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  701. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${endpoint_disposition}(EARLY MEDIA) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  702. Dialplan: sofia/external/0833573222 parsing [default->snom-demo-2] continue=false
  703. Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-2] destination_number(0870980890) =~ /^9001$/ break=on-false
  704. Dialplan: sofia/external/0833573222 parsing [default->snom-demo-1] continue=false
  705. Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-1] destination_number(0870980890) =~ /^9000$/ break=on-false
  706. Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false
  707. Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(0870980890) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  708. Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false
  709. Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(0870980890) =~ /^779$/ break=on-false
  710. Dialplan: sofia/external/0833573222 parsing [default->call_return] continue=false
  711. Dialplan: sofia/external/0833573222 Regex (FAIL) [call_return] destination_number(0870980890) =~ /^\*69$|^869$|^lcr$/ break=on-false
  712. Dialplan: sofia/external/0833573222 parsing [default->del-group] continue=false
  713. Dialplan: sofia/external/0833573222 Regex (FAIL) [del-group] destination_number(0870980890) =~ /^80(\d{2})$/ break=on-false
  714. Dialplan: sofia/external/0833573222 parsing [default->add-group] continue=false
  715. Dialplan: sofia/external/0833573222 Regex (FAIL) [add-group] destination_number(0870980890) =~ /^81(\d{2})$/ break=on-false
  716. Dialplan: sofia/external/0833573222 parsing [default->call-group-simo] continue=false
  717. Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-simo] destination_number(0870980890) =~ /^82(\d{2})$/ break=on-false
  718. Dialplan: sofia/external/0833573222 parsing [default->call-group-order] continue=false
  719. Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-order] destination_number(0870980890) =~ /^83(\d{2})$/ break=on-false
  720. Dialplan: sofia/external/0833573222 parsing [default->extension-intercom] continue=false
  721. Dialplan: sofia/external/0833573222 Regex (FAIL) [extension-intercom] destination_number(0870980890) =~ /^8(10[01][0-9])$/ break=on-false
  722. Dialplan: sofia/external/0833573222 parsing [default->Local_Ext] continue=false
  723. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Ext] destination_number(0870980890) =~ /^(30[01][0-9])$/ break=on-false
  724. Dialplan: sofia/external/0833573222 parsing [default->Local_Extension] continue=false
  725. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension] destination_number(0870980890) =~ /^(10[01][0-9])$/ break=on-false
  726. Dialplan: sofia/external/0833573222 parsing [default->Local_Extension_Skinny] continue=false
  727. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension_Skinny] destination_number(0870980890) =~ /^(11[01][0-9])$/ break=on-false
  728. Dialplan: sofia/external/0833573222 parsing [default->group_dial_sales] continue=false
  729. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_sales] destination_number(0870980890) =~ /^2000$/ break=on-false
  730. Dialplan: sofia/external/0833573222 parsing [default->group_dial_support] continue=false
  731. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_support] destination_number(0870980890) =~ /^2001$/ break=on-false
  732. Dialplan: sofia/external/0833573222 parsing [default->group_dial_billing] continue=false
  733. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_billing] destination_number(0870980890) =~ /^2002$/ break=on-false
  734. Dialplan: sofia/external/0833573222 parsing [default->group_dial_huntgroup] continue=false
  735. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_huntgroup] destination_number(0870980890) =~ /^0870980891$/ break=on-false
  736. Dialplan: sofia/external/0833573222 parsing [default->group_dial_did_to_local] continue=false
  737. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_did_to_local] destination_number(0870980890) =~ /^0870980892$/ break=on-false
  738. Dialplan: sofia/external/0833573222 parsing [default->operator] continue=false
  739. Dialplan: sofia/external/0833573222 Regex (FAIL) [operator] destination_number(0870980890) =~ /^(operator|0)$/ break=on-false
  740. Dialplan: sofia/external/0833573222 parsing [default->vmain] continue=false
  741. Dialplan: sofia/external/0833573222 Regex (FAIL) [vmain] destination_number(0870980890) =~ /^vmain$|^4000$|^\*98$/ break=on-false
  742. Dialplan: sofia/external/0833573222 parsing [default->sip_uri] continue=false
  743. Dialplan: sofia/external/0833573222 Regex (FAIL) [sip_uri] destination_number(0870980890) =~ /^sip:(.*)$/ break=on-false
  744. Dialplan: sofia/external/0833573222 parsing [default->nb_conferences] continue=false
  745. Dialplan: sofia/external/0833573222 Regex (FAIL) [nb_conferences] destination_number(0870980890) =~ /^(30\d{2})$/ break=on-false
  746. Dialplan: sofia/external/0833573222 parsing [default->wb_conferences] continue=false
  747. Dialplan: sofia/external/0833573222 Regex (FAIL) [wb_conferences] destination_number(0870980890) =~ /^(31\d{2})$/ break=on-false
  748. Dialplan: sofia/external/0833573222 parsing [default->uwb_conferences] continue=false
  749. Dialplan: sofia/external/0833573222 Regex (FAIL) [uwb_conferences] destination_number(0870980890) =~ /^(32\d{2})$/ break=on-false
  750. Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false
  751. Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(0870980890) =~ /^(33\d{2})$/ break=on-false
  752. Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false
  753. Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(0870980890) =~ /^(35\d{2})$/ break=on-false
  754. Dialplan: sofia/external/0833573222 parsing [default->freeswitch_public_conf_via_sip] continue=false
  755. Dialplan: sofia/external/0833573222 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(0870980890) =~ /^9(888|8888|1616|3232)$/ break=on-false
  756. Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false
  757. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(0870980890) =~ /^0911$/ break=on-false
  758. Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false
  759. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(0870980890) =~ /^0912$/ break=on-false
  760. Dialplan: sofia/external/0833573222 parsing [default->mad_boss] continue=false
  761. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss] destination_number(0870980890) =~ /^0913$/ break=on-false
  762. Dialplan: sofia/external/0833573222 parsing [default->ivr_demo] continue=false
  763. Dialplan: sofia/external/0833573222 Regex (FAIL) [ivr_demo] destination_number(0870980890) =~ /^5000$/ break=on-false
  764. Dialplan: sofia/external/0833573222 parsing [default->dynamic_conference] continue=false
  765. Dialplan: sofia/external/0833573222 Regex (FAIL) [dynamic_conference] destination_number(0870980890) =~ /^5001$/ break=on-false
  766. Dialplan: sofia/external/0833573222 parsing [default->rtp_multicast_page] continue=false
  767. Dialplan: sofia/external/0833573222 Regex (FAIL) [rtp_multicast_page] destination_number(0870980890) =~ /^pagegroup$|^7243$/ break=on-false
  768. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  769. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] destination_number(0870980890) =~ /^5900$/ break=on-false
  770. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  771. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] destination_number(0870980890) =~ /^5901$/ break=on-false
  772. Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false
  773. Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(0870980890) =~ /^(6000)$/ break=on-false
  774. Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false
  775. Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(0870980890) =~ /^((?!6000)60\d{2})$/ break=on-false
  776. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  777. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  778. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  779. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  780. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  781. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  782. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  783. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  784. Dialplan: sofia/external/0833573222 parsing [default->wait] continue=false
  785. Dialplan: sofia/external/0833573222 Regex (FAIL) [wait] destination_number(0870980890) =~ /^wait$/ break=on-false
  786. Dialplan: sofia/external/0833573222 parsing [default->fax_receive] continue=false
  787. Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_receive] destination_number(0870980890) =~ /^9178$/ break=on-false
  788. Dialplan: sofia/external/0833573222 parsing [default->fax_transmit] continue=false
  789. Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_transmit] destination_number(0870980890) =~ /^9179$/ break=on-false
  790. Dialplan: sofia/external/0833573222 parsing [default->ringback_180] continue=false
  791. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_180] destination_number(0870980890) =~ /^9180$/ break=on-false
  792. Dialplan: sofia/external/0833573222 parsing [default->ringback_183_uk_ring] continue=false
  793. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_uk_ring] destination_number(0870980890) =~ /^9181$/ break=on-false
  794. Dialplan: sofia/external/0833573222 parsing [default->ringback_183_music_ring] continue=false
  795. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_music_ring] destination_number(0870980890) =~ /^9182$/ break=on-false
  796. Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_uk_ring] continue=false
  797. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(0870980890) =~ /^9183$/ break=on-false
  798. Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_music] continue=false
  799. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_music] destination_number(0870980890) =~ /^9184$/ break=on-false
  800. Dialplan: sofia/external/0833573222 parsing [default->ClueCon] continue=false
  801. Dialplan: sofia/external/0833573222 Regex (FAIL) [ClueCon] destination_number(0870980890) =~ /^9191$/ break=on-false
  802. Dialplan: sofia/external/0833573222 parsing [default->show_info] continue=false
  803. Dialplan: sofia/external/0833573222 Regex (FAIL) [show_info] destination_number(0870980890) =~ /^9192$/ break=on-false
  804. Dialplan: sofia/external/0833573222 parsing [default->video_record] continue=false
  805. Dialplan: sofia/external/0833573222 Regex (FAIL) [video_record] destination_number(0870980890) =~ /^9193$/ break=on-false
  806. Dialplan: sofia/external/0833573222 parsing [default->video_playback] continue=false
  807. Dialplan: sofia/external/0833573222 Regex (FAIL) [video_playback] destination_number(0870980890) =~ /^9194$/ break=on-false
  808. Dialplan: sofia/external/0833573222 parsing [default->delay_echo] continue=false
  809. Dialplan: sofia/external/0833573222 Regex (FAIL) [delay_echo] destination_number(0870980890) =~ /^9195$/ break=on-false
  810. Dialplan: sofia/external/0833573222 parsing [default->echo] continue=false
  811. Dialplan: sofia/external/0833573222 Regex (FAIL) [echo] destination_number(0870980890) =~ /^9196$/ break=on-false
  812. Dialplan: sofia/external/0833573222 parsing [default->milliwatt] continue=false
  813. Dialplan: sofia/external/0833573222 Regex (FAIL) [milliwatt] destination_number(0870980890) =~ /^9197$/ break=on-false
  814. Dialplan: sofia/external/0833573222 parsing [default->tone_stream] continue=false
  815. Dialplan: sofia/external/0833573222 Regex (FAIL) [tone_stream] destination_number(0870980890) =~ /^9198$/ break=on-false
  816. Dialplan: sofia/external/0833573222 parsing [default->zrtp_enrollement] continue=false
  817. Dialplan: sofia/external/0833573222 Regex (FAIL) [zrtp_enrollement] destination_number(0870980890) =~ /^9787$/ break=on-false
  818. Dialplan: sofia/external/0833573222 parsing [default->hold_music] continue=false
  819. Dialplan: sofia/external/0833573222 Regex (FAIL) [hold_music] destination_number(0870980890) =~ /^9664$/ break=on-false
  820. Dialplan: sofia/external/0833573222 parsing [default->laugh break] continue=false
  821. Dialplan: sofia/external/0833573222 Regex (FAIL) [laugh break] destination_number(0870980890) =~ /^9386$/ break=on-false
  822. Dialplan: sofia/external/0833573222 parsing [default->101] continue=false
  823. Dialplan: sofia/external/0833573222 Regex (FAIL) [101] destination_number(0870980890) =~ /^101$/ break=on-false
  824. Dialplan: sofia/external/0833573222 parsing [default->pizza_demo] continue=false
  825. Dialplan: sofia/external/0833573222 Regex (FAIL) [pizza_demo] destination_number(0870980890) =~ /^(pizza|74992)$/ break=on-false
  826. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Time] continue=false
  827. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Time] destination_number(0870980890) =~ /^9170$/ break=on-false
  828. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date] continue=false
  829. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date] destination_number(0870980890) =~ /^9171$/ break=on-false
  830. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date and Time] continue=false
  831. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date and Time] destination_number(0870980890) =~ /^9172$/ break=on-false
  832. Dialplan: sofia/external/0833573222 parsing [default->exe_on_ans] continue=false
  833. Dialplan: sofia/external/0833573222 Regex (PASS) [exe_on_ans] destination_number(0870980890) =~ /^0870980890$/ break=on-false
  834. Dialplan: sofia/external/0833573222 Action set(execute_on_answer=transfer ANSWEREDCALL XML default)
  835. Dialplan: sofia/external/0833573222 Action log(INFO Waiting 30 seconds for $1 to answer...)
  836. Dialplan: sofia/external/0833573222 Action sleep(30000)
  837. Dialplan: sofia/external/0833573222 Action log(INFO Call to $1 was not answered, taking alternative action...)
  838. Dialplan: sofia/external/0833573222 Action transfer(UNANSWEREDCALL XML default)
  839. 2016-11-04 09:05:02.197460 [INFO] switch_channel.c:3127 sofia/external/0833573222 Flipping CID from "" <0870980000> to "Outbound Call" <D0820833573222>
  840. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:286 (sofia/external/0833573222) State Change CS_ROUTING -> CS_EXECUTE
  841. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep
  842. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_EXECUTE
  843. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE
  844. 2016-11-04 09:05:02.197460 [DEBUG] mod_sofia.c:197 sofia/external/0833573222 SOFIA EXECUTE
  845. 2016-11-04 09:05:02.197460 [DEBUG] switch_core_state_machine.c:328 sofia/external/0833573222 Standard EXECUTE
  846. EXECUTE sofia/external/0833573222 set(open=true)
  847. 2016-11-04 09:05:02.197460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [open]=[true]
  848. EXECUTE sofia/external/0833573222 set(execute_on_answer=transfer ANSWEREDCALL XML default)
  849. 2016-11-04 09:05:02.197460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [execute_on_answer]=[transfer ANSWEREDCALL XML default]
  850. EXECUTE sofia/external/0833573222 log(INFO Waiting 30 seconds for $1 to answer...)
  851. 2016-11-04 09:05:02.197460 [INFO] mod_dptools.c:1713 Waiting 30 seconds for $1 to answer...
  852. EXECUTE sofia/external/0833573222 sleep(30000)
  853. 2016-11-04 09:05:02.217472 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed.
  854. 2016-11-04 09:05:02.877480 [DEBUG] switch_core_media.c:2386 Correcting calculated ptime value from 300 to 150 to compensate for 1 lost packet(s)
  855. 2016-11-04 09:05:02.997457 [WARNING] switch_core_media.c:2418 Asynchronous PTIME not supported, changing our end from 20 to 60
  856. 2016-11-04 09:05:03.017520 [DEBUG] switch_core_media.c:2844 Changing Codec from G729@20ms@8000hz to G729@60ms@8000hz
  857. 2016-11-04 09:05:03.057541 [DEBUG] switch_rtp.c:3690 RE-Starting timer [soft] 480 bytes per 60ms
  858. 2016-11-04 09:05:03.057541 [DEBUG] switch_core_media.c:2946 Set Codec sofia/external/0833573222 G729/8000 60 ms 480 samples 8000 bits 1 channels
  859. 2016-11-04 09:05:03.057541 [DEBUG] switch_core_codec.c:123 sofia/external/0833573222 Original read codec replaced with G729:18
  860. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  861. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  862. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c002ae0 from (udp/172.xx.xx.85:5060) has 1147 bytes, veclen = 1
  863. recv 1147 bytes from udp/[172.xx.xx.61]:5060 at 09:05:06.545536:
  864.    ------------------------------------------------------------------------
  865.    SIP/2.0 200 OK
  866.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKS5j3ev14DK2DD
  867.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  868.    To: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  869.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  870.    CSeq: 98785487 INVITE
  871.    Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
  872.    User-Agent: FS
  873.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  874.    Supported: path, replaces
  875.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  876.    Content-Type: application/sdp
  877.    Content-Disposition: session
  878.    Content-Length: 187
  879.    X-FS-Display-Name: Outbound Call
  880.    X-FS-Display-Number: sip:D0820833573222@172.xx.xx.61
  881.    X-FS-Support: update_display,send_info
  882.    Remote-Party-ID: "Outbound Call" <sip:D0820833573222@172.xx.xx.61>;party=calling;privacy=off;screen=no
  883.    
  884.    v=0
  885.    o=FreeSWITCH 1478216006 1478216007 IN IP4 172.xx.xx.61
  886.    s=FreeSWITCH
  887.    c=IN IP4 172.xx.xx.61
  888.    t=0 0
  889.    m=audio 27110 RTP/AVP 18
  890.    a=rtpmap:18 G729/8000
  891.    a=fmtp:18 annexb=no
  892.    a=ptime:20
  893.    ------------------------------------------------------------------------
  894. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c002ae0 (1147 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  895. nta.c:3299 agent_recv_response() nta: received 200 OK for INVITE (98785487)
  896. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  897. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c041820 by 0x7efc0c048250 with 0x7efc0c002ae0
  898. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7efc0c03a7a0, (nil), 0x7efc0c006f20, 187) called
  899. soa.c:1595 soa_process_answer() soa_process_answer(static::0x7efc0c03a7a0) called
  900. nua_session.c:978 nua_session_client_response() nua(0x7efc0002eaf0): INVITE: error processing SDP answer in 200 OK
  901. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event r_invite 200 OK
  902. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: proceeding -> completing, received answer
  903. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7efc0c03a7a0, [0x7efc376917d8], [0x7efc376917e0], [(nil)]) called
  904. soa.c:616 soa_get_params() soa_get_params(static::0x7efc0c03a7a0, ...) called
  905. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_state 200 OK
  906. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  907. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  908. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  909. 2016-11-04 09:05:06.537480 [INFO] sofia.c:1244 sofia/external/0833573222 Update Caller ID to "Outbound Call" <sip:D0820833573222@172.xx.xx.61>
  910. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  911. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  912. 2016-11-04 09:05:06.537480 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [completing][200]
  913. 2016-11-04 09:05:06.537480 [DEBUG] sofia.c:6865 Duplicate SDP
  914. v=0
  915. o=FreeSWITCH 1478216006 1478216007 IN IP4 172.xx.xx.61
  916. s=FreeSWITCH
  917. c=IN IP4 172.xx.xx.61
  918. t=0 0
  919. m=audio 27110 RTP/AVP 18
  920. a=rtpmap:18 G729/8000
  921. a=fmtp:18 annexb=no
  922. a=ptime:20
  923.  
  924. nua.c:639 nua_ack() nua: nua_ack: entering
  925. nua_stack.c:569 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_ack
  926. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  927. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  928. soa.c:1730 soa_activate() soa_activate(static::0x7efc0c03a7a0, (nil)) called
  929. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_ack
  930. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  931. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  932. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = udp/172.xx.xx.61:5060
  933. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  934. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name udp/172.xx.xx.61:5060
  935. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 674 bytes of 674 to udp/172.xx.xx.61:5060
  936. tport.c:3492 tport_send_msg() tport_vsend returned 674
  937. send 674 bytes to udp/[172.xx.xx.61]:5060 at 09:05:06.551756:
  938.    ------------------------------------------------------------------------
  939.    ACK sip:0833573222@172.xx.xx.61:5060;transport=udp SIP/2.0
  940.    Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKtecvgQj8avr0r
  941.    Max-Forwards: 70
  942.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  943.    To: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  944.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  945.    CSeq: 98785487 ACK
  946.    Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
  947.    Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="64a7a2e8-8f79-432e-bb5d-a89650b98760", cnonce="2BgUXBz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61", response="119008ac15c252754a4c7e73c5d4527b", qop=auth, nc=00000001
  948.    Content-Length: 0
  949.    
  950.    ------------------------------------------------------------------------
  951. nta.c:8304 outgoing_send() nta: sent ACK (98785487) to udp/172.xx.xx.61:5060
  952. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: completing -> ready
  953. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_state 200 ACK sent
  954. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_active 200 Call active
  955. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  956. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  957. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  958. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  959. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c043c00 from (udp/172.xx.xx.85:5060) has 666 bytes, veclen = 1
  960. recv 666 bytes from udp/[172.xx.xx.61]:5060 at 09:05:06.584465:
  961.    ------------------------------------------------------------------------
  962.   INFO sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0
  963.    Via: SIP/2.0/UDP 172.xx.xx.61;rport;branch=z9hG4bK0gFgrycDKvFNB
  964.    Max-Forwards: 70
  965.    From: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  966.    To: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  967.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  968.   CSeq: 98785496 INFO
  969.    Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
  970.    User-Agent: FS
  971.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  972.    Supported: path, replaces
  973.    Content-Type: message/update_display
  974.    Content-Length: 0
  975.    X-FS-Display-Name: Outbound Call
  976.    X-FS-Display-Number: D0820833573222
  977.    
  978.    ------------------------------------------------------------------------
  979. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c043c00 (666 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  980. nta.c:2880 agent_recv_request() nta: received INFO sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0 (CSeq 98785496)
  981. nta.c:3248 agent_aliases() nta: canonizing sip:gw+Enav8@172.xx.xx.85:5060 with contact
  982. nta.c:3060 agent_recv_request() nta: INFO (98785496) going to existing leg
  983. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  984. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_info 100 Trying
  985. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  986. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  987. 2016-11-04 09:05:06.597460 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [ready][200]
  988. 2016-11-04 09:05:06.597460 [NOTICE] sofia.c:7765 Channel [sofia/external/0833573222] has been answered
  989. EXECUTE sofia/external/0833573222 transfer(ANSWEREDCALL XML default)
  990. 2016-11-04 09:05:06.597460 [DEBUG] switch_ivr.c:2160 (sofia/external/0833573222) State Change CS_EXECUTE -> CS_ROUTING
  991. 2016-11-04 09:05:06.597460 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/0833573222 to XML[ANSWEREDCALL@default]
  992. 2016-11-04 09:05:06.597460 [DEBUG] switch_channel.c:3770 (sofia/external/0833573222) Callstate Change EARLY -> ACTIVE
  993. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  994. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  995. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  996. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  997. nua.c:879 nua_respond() nua: nua_respond: entering
  998. nua_stack.c:573 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_respond 200 OK
  999. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  1000. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  1001. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = UDP/172.xx.xx.61:5060
  1002. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  1003. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name UDP/172.xx.xx.61:5060
  1004. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_respond
  1005. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1006. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE going to sleep
  1007. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 486 bytes of 486 to udp/172.xx.xx.61:5060
  1008. tport.c:3492 tport_send_msg() tport_vsend returned 486
  1009. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING
  1010. send 486 bytes to udp/[172.xx.xx.61]:5060 at 09:05:06.613417:
  1011.    ------------------------------------------------------------------------
  1012.    SIP/2.0 200 OK
  1013.    Via: SIP/2.0/UDP 172.xx.xx.61;rport=5060;branch=z9hG4bK0gFgrycDKvFNB
  1014.    From: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  1015.    To: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  1016.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  1017.   CSeq: 98785496 INFO
  1018.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  1019.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1020.    Supported: timer, path, replaces
  1021.    Content-Length: 0
  1022.    
  1023.    ------------------------------------------------------------------------
  1024. nta.c:6791 incoming_reply() nta: sent 200 OK for INFO (98785496)
  1025. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING
  1026. 2016-11-04 09:05:06.597460 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING
  1027. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:236 sofia/external/0833573222 Standard ROUTING
  1028. 2016-11-04 09:05:06.597460 [INFO] mod_dialplan_xml.c:637 Processing Outbound Call <D0820833573222>->ANSWEREDCALL in context default
  1029. Dialplan: sofia/external/0833573222 parsing [default->unloop] continue=false
  1030. Dialplan: sofia/external/0833573222 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  1031. Dialplan: sofia/external/0833573222 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  1032. Dialplan: sofia/external/0833573222 parsing [default->tod_example] continue=true
  1033. Dialplan: sofia/external/0833573222 Date/Time Match (PASS) [tod_example] break=on-false
  1034. Dialplan: sofia/external/0833573222 Action set(open=true)
  1035. Dialplan: sofia/external/0833573222 parsing [default->holiday_example] continue=true
  1036. Dialplan: sofia/external/0833573222 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  1037. Dialplan: sofia/external/0833573222 parsing [default->global-intercept] continue=false
  1038. Dialplan: sofia/external/0833573222 Regex (FAIL) [global-intercept] destination_number(ANSWEREDCALL) =~ /^886$/ break=on-false
  1039. Dialplan: sofia/external/0833573222 parsing [default->group-intercept] continue=false
  1040. Dialplan: sofia/external/0833573222 Regex (FAIL) [group-intercept] destination_number(ANSWEREDCALL) =~ /^\*8$/ break=on-false
  1041. Dialplan: sofia/external/0833573222 parsing [default->intercept-ext] continue=false
  1042. Dialplan: sofia/external/0833573222 Regex (FAIL) [intercept-ext] destination_number(ANSWEREDCALL) =~ /^\*\*(\d+)$/ break=on-false
  1043. Dialplan: sofia/external/0833573222 parsing [default->redial] continue=false
  1044. Dialplan: sofia/external/0833573222 Regex (FAIL) [redial] destination_number(ANSWEREDCALL) =~ /^(redial|870)$/ break=on-false
  1045. Dialplan: sofia/external/0833573222 parsing [default->global] continue=true
  1046. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  1047. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never
  1048. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  1049. Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${endpoint_disposition}(ANSWER) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  1050. Dialplan: sofia/external/0833573222 parsing [default->snom-demo-2] continue=false
  1051. Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-2] destination_number(ANSWEREDCALL) =~ /^9001$/ break=on-false
  1052. Dialplan: sofia/external/0833573222 parsing [default->snom-demo-1] continue=false
  1053. Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-1] destination_number(ANSWEREDCALL) =~ /^9000$/ break=on-false
  1054. Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false
  1055. Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(ANSWEREDCALL) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  1056. Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false
  1057. Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(ANSWEREDCALL) =~ /^779$/ break=on-false
  1058. Dialplan: sofia/external/0833573222 parsing [default->call_return] continue=false
  1059. Dialplan: sofia/external/0833573222 Regex (FAIL) [call_return] destination_number(ANSWEREDCALL) =~ /^\*69$|^869$|^lcr$/ break=on-false
  1060. Dialplan: sofia/external/0833573222 parsing [default->del-group] continue=false
  1061. Dialplan: sofia/external/0833573222 Regex (FAIL) [del-group] destination_number(ANSWEREDCALL) =~ /^80(\d{2})$/ break=on-false
  1062. Dialplan: sofia/external/0833573222 parsing [default->add-group] continue=false
  1063. Dialplan: sofia/external/0833573222 Regex (FAIL) [add-group] destination_number(ANSWEREDCALL) =~ /^81(\d{2})$/ break=on-false
  1064. Dialplan: sofia/external/0833573222 parsing [default->call-group-simo] continue=false
  1065. Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-simo] destination_number(ANSWEREDCALL) =~ /^82(\d{2})$/ break=on-false
  1066. Dialplan: sofia/external/0833573222 parsing [default->call-group-order] continue=false
  1067. Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-order] destination_number(ANSWEREDCALL) =~ /^83(\d{2})$/ break=on-false
  1068. Dialplan: sofia/external/0833573222 parsing [default->extension-intercom] continue=false
  1069. Dialplan: sofia/external/0833573222 Regex (FAIL) [extension-intercom] destination_number(ANSWEREDCALL) =~ /^8(10[01][0-9])$/ break=on-false
  1070. Dialplan: sofia/external/0833573222 parsing [default->Local_Ext] continue=false
  1071. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Ext] destination_number(ANSWEREDCALL) =~ /^(30[01][0-9])$/ break=on-false
  1072. Dialplan: sofia/external/0833573222 parsing [default->Local_Extension] continue=false
  1073. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension] destination_number(ANSWEREDCALL) =~ /^(10[01][0-9])$/ break=on-false
  1074. Dialplan: sofia/external/0833573222 parsing [default->Local_Extension_Skinny] continue=false
  1075. Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension_Skinny] destination_number(ANSWEREDCALL) =~ /^(11[01][0-9])$/ break=on-false
  1076. Dialplan: sofia/external/0833573222 parsing [default->group_dial_sales] continue=false
  1077. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_sales] destination_number(ANSWEREDCALL) =~ /^2000$/ break=on-false
  1078. Dialplan: sofia/external/0833573222 parsing [default->group_dial_support] continue=false
  1079. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_support] destination_number(ANSWEREDCALL) =~ /^2001$/ break=on-false
  1080. Dialplan: sofia/external/0833573222 parsing [default->group_dial_billing] continue=false
  1081. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_billing] destination_number(ANSWEREDCALL) =~ /^2002$/ break=on-false
  1082. Dialplan: sofia/external/0833573222 parsing [default->group_dial_huntgroup] continue=false
  1083. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_huntgroup] destination_number(ANSWEREDCALL) =~ /^0870980891$/ break=on-false
  1084. Dialplan: sofia/external/0833573222 parsing [default->group_dial_did_to_local] continue=false
  1085. Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_did_to_local] destination_number(ANSWEREDCALL) =~ /^0870980892$/ break=on-false
  1086. Dialplan: sofia/external/0833573222 parsing [default->operator] continue=false
  1087. Dialplan: sofia/external/0833573222 Regex (FAIL) [operator] destination_number(ANSWEREDCALL) =~ /^(operator|0)$/ break=on-false
  1088. Dialplan: sofia/external/0833573222 parsing [default->vmain] continue=false
  1089. Dialplan: sofia/external/0833573222 Regex (FAIL) [vmain] destination_number(ANSWEREDCALL) =~ /^vmain$|^4000$|^\*98$/ break=on-false
  1090. Dialplan: sofia/external/0833573222 parsing [default->sip_uri] continue=false
  1091. Dialplan: sofia/external/0833573222 Regex (FAIL) [sip_uri] destination_number(ANSWEREDCALL) =~ /^sip:(.*)$/ break=on-false
  1092. Dialplan: sofia/external/0833573222 parsing [default->nb_conferences] continue=false
  1093. Dialplan: sofia/external/0833573222 Regex (FAIL) [nb_conferences] destination_number(ANSWEREDCALL) =~ /^(30\d{2})$/ break=on-false
  1094. Dialplan: sofia/external/0833573222 parsing [default->wb_conferences] continue=false
  1095. Dialplan: sofia/external/0833573222 Regex (FAIL) [wb_conferences] destination_number(ANSWEREDCALL) =~ /^(31\d{2})$/ break=on-false
  1096. Dialplan: sofia/external/0833573222 parsing [default->uwb_conferences] continue=false
  1097. Dialplan: sofia/external/0833573222 Regex (FAIL) [uwb_conferences] destination_number(ANSWEREDCALL) =~ /^(32\d{2})$/ break=on-false
  1098. Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false
  1099. Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(ANSWEREDCALL) =~ /^(33\d{2})$/ break=on-false
  1100. Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false
  1101. Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(ANSWEREDCALL) =~ /^(35\d{2})$/ break=on-false
  1102. Dialplan: sofia/external/0833573222 parsing [default->freeswitch_public_conf_via_sip] continue=false
  1103. Dialplan: sofia/external/0833573222 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(ANSWEREDCALL) =~ /^9(888|8888|1616|3232)$/ break=on-false
  1104. Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false
  1105. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(ANSWEREDCALL) =~ /^0911$/ break=on-false
  1106. Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false
  1107. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(ANSWEREDCALL) =~ /^0912$/ break=on-false
  1108. Dialplan: sofia/external/0833573222 parsing [default->mad_boss] continue=false
  1109. Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss] destination_number(ANSWEREDCALL) =~ /^0913$/ break=on-false
  1110. Dialplan: sofia/external/0833573222 parsing [default->ivr_demo] continue=false
  1111. Dialplan: sofia/external/0833573222 Regex (FAIL) [ivr_demo] destination_number(ANSWEREDCALL) =~ /^5000$/ break=on-false
  1112. Dialplan: sofia/external/0833573222 parsing [default->dynamic_conference] continue=false
  1113. Dialplan: sofia/external/0833573222 Regex (FAIL) [dynamic_conference] destination_number(ANSWEREDCALL) =~ /^5001$/ break=on-false
  1114. Dialplan: sofia/external/0833573222 parsing [default->rtp_multicast_page] continue=false
  1115. Dialplan: sofia/external/0833573222 Regex (FAIL) [rtp_multicast_page] destination_number(ANSWEREDCALL) =~ /^pagegroup$|^7243$/ break=on-false
  1116. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  1117. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] destination_number(ANSWEREDCALL) =~ /^5900$/ break=on-false
  1118. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  1119. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] destination_number(ANSWEREDCALL) =~ /^5901$/ break=on-false
  1120. Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false
  1121. Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(ANSWEREDCALL) =~ /^(6000)$/ break=on-false
  1122. Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false
  1123. Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(ANSWEREDCALL) =~ /^((?!6000)60\d{2})$/ break=on-false
  1124. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  1125. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  1126. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  1127. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  1128. Dialplan: sofia/external/0833573222 parsing [default->park] continue=false
  1129. Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  1130. Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false
  1131. Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false
  1132. Dialplan: sofia/external/0833573222 parsing [default->wait] continue=false
  1133. Dialplan: sofia/external/0833573222 Regex (FAIL) [wait] destination_number(ANSWEREDCALL) =~ /^wait$/ break=on-false
  1134. Dialplan: sofia/external/0833573222 parsing [default->fax_receive] continue=false
  1135. Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_receive] destination_number(ANSWEREDCALL) =~ /^9178$/ break=on-false
  1136. Dialplan: sofia/external/0833573222 parsing [default->fax_transmit] continue=false
  1137. Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_transmit] destination_number(ANSWEREDCALL) =~ /^9179$/ break=on-false
  1138. Dialplan: sofia/external/0833573222 parsing [default->ringback_180] continue=false
  1139. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_180] destination_number(ANSWEREDCALL) =~ /^9180$/ break=on-false
  1140. Dialplan: sofia/external/0833573222 parsing [default->ringback_183_uk_ring] continue=false
  1141. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_uk_ring] destination_number(ANSWEREDCALL) =~ /^9181$/ break=on-false
  1142. Dialplan: sofia/external/0833573222 parsing [default->ringback_183_music_ring] continue=false
  1143. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_music_ring] destination_number(ANSWEREDCALL) =~ /^9182$/ break=on-false
  1144. Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_uk_ring] continue=false
  1145. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(ANSWEREDCALL) =~ /^9183$/ break=on-false
  1146. Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_music] continue=false
  1147. Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_music] destination_number(ANSWEREDCALL) =~ /^9184$/ break=on-false
  1148. Dialplan: sofia/external/0833573222 parsing [default->ClueCon] continue=false
  1149. Dialplan: sofia/external/0833573222 Regex (FAIL) [ClueCon] destination_number(ANSWEREDCALL) =~ /^9191$/ break=on-false
  1150. Dialplan: sofia/external/0833573222 parsing [default->show_info] continue=false
  1151. Dialplan: sofia/external/0833573222 Regex (FAIL) [show_info] destination_number(ANSWEREDCALL) =~ /^9192$/ break=on-false
  1152. Dialplan: sofia/external/0833573222 parsing [default->video_record] continue=false
  1153. Dialplan: sofia/external/0833573222 Regex (FAIL) [video_record] destination_number(ANSWEREDCALL) =~ /^9193$/ break=on-false
  1154. Dialplan: sofia/external/0833573222 parsing [default->video_playback] continue=false
  1155. Dialplan: sofia/external/0833573222 Regex (FAIL) [video_playback] destination_number(ANSWEREDCALL) =~ /^9194$/ break=on-false
  1156. Dialplan: sofia/external/0833573222 parsing [default->delay_echo] continue=false
  1157. Dialplan: sofia/external/0833573222 Regex (FAIL) [delay_echo] destination_number(ANSWEREDCALL) =~ /^9195$/ break=on-false
  1158. Dialplan: sofia/external/0833573222 parsing [default->echo] continue=false
  1159. Dialplan: sofia/external/0833573222 Regex (FAIL) [echo] destination_number(ANSWEREDCALL) =~ /^9196$/ break=on-false
  1160. Dialplan: sofia/external/0833573222 parsing [default->milliwatt] continue=false
  1161. Dialplan: sofia/external/0833573222 Regex (FAIL) [milliwatt] destination_number(ANSWEREDCALL) =~ /^9197$/ break=on-false
  1162. Dialplan: sofia/external/0833573222 parsing [default->tone_stream] continue=false
  1163. Dialplan: sofia/external/0833573222 Regex (FAIL) [tone_stream] destination_number(ANSWEREDCALL) =~ /^9198$/ break=on-false
  1164. Dialplan: sofia/external/0833573222 parsing [default->zrtp_enrollement] continue=false
  1165. Dialplan: sofia/external/0833573222 Regex (FAIL) [zrtp_enrollement] destination_number(ANSWEREDCALL) =~ /^9787$/ break=on-false
  1166. Dialplan: sofia/external/0833573222 parsing [default->hold_music] continue=false
  1167. Dialplan: sofia/external/0833573222 Regex (FAIL) [hold_music] destination_number(ANSWEREDCALL) =~ /^9664$/ break=on-false
  1168. Dialplan: sofia/external/0833573222 parsing [default->laugh break] continue=false
  1169. Dialplan: sofia/external/0833573222 Regex (FAIL) [laugh break] destination_number(ANSWEREDCALL) =~ /^9386$/ break=on-false
  1170. Dialplan: sofia/external/0833573222 parsing [default->101] continue=false
  1171. Dialplan: sofia/external/0833573222 Regex (FAIL) [101] destination_number(ANSWEREDCALL) =~ /^101$/ break=on-false
  1172. Dialplan: sofia/external/0833573222 parsing [default->pizza_demo] continue=false
  1173. Dialplan: sofia/external/0833573222 Regex (FAIL) [pizza_demo] destination_number(ANSWEREDCALL) =~ /^(pizza|74992)$/ break=on-false
  1174. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Time] continue=false
  1175. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Time] destination_number(ANSWEREDCALL) =~ /^9170$/ break=on-false
  1176. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date] continue=false
  1177. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date] destination_number(ANSWEREDCALL) =~ /^9171$/ break=on-false
  1178. Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date and Time] continue=false
  1179. Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date and Time] destination_number(ANSWEREDCALL) =~ /^9172$/ break=on-false
  1180. Dialplan: sofia/external/0833573222 parsing [default->exe_on_ans] continue=false
  1181. Dialplan: sofia/external/0833573222 Regex (FAIL) [exe_on_ans] destination_number(ANSWEREDCALL) =~ /^0870980890$/ break=on-false
  1182. Dialplan: sofia/external/0833573222 parsing [default->nb_conferences_answered] continue=false
  1183. Dialplan: sofia/external/0833573222 Regex (PASS) [nb_conferences_answered] destination_number(ANSWEREDCALL) =~ /^ANSWEREDCALL$/ break=on-false
  1184. Dialplan: sofia/external/0833573222 Action answer()
  1185. Dialplan: sofia/external/0833573222 Action set(hangup_after_bridge=true)
  1186. Dialplan: sofia/external/0833573222 Action set(continue_on_fail=true)
  1187. Dialplan: sofia/external/0833573222 Action callcenter(agent8003@default)
  1188. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:286 (sofia/external/0833573222) State Change CS_ROUTING -> CS_EXECUTE
  1189. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep
  1190. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_EXECUTE
  1191. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE
  1192. 2016-11-04 09:05:06.597460 [DEBUG] mod_sofia.c:197 sofia/external/0833573222 SOFIA EXECUTE
  1193. 2016-11-04 09:05:06.597460 [DEBUG] switch_core_state_machine.c:328 sofia/external/0833573222 Standard EXECUTE
  1194. EXECUTE sofia/external/0833573222 set(open=true)
  1195. 2016-11-04 09:05:06.597460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [open]=[true]
  1196. EXECUTE sofia/external/0833573222 answer()
  1197. EXECUTE sofia/external/0833573222 set(hangup_after_bridge=true)
  1198. 2016-11-04 09:05:06.597460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [hangup_after_bridge]=[true]
  1199. EXECUTE sofia/external/0833573222 set(continue_on_fail=true)
  1200. 2016-11-04 09:05:06.597460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [continue_on_fail]=[true]
  1201. EXECUTE sofia/external/0833573222 callcenter(agent8003@default)
  1202. 2016-11-04 09:05:06.617484 [DEBUG] mod_callcenter.c:2731 Member Outbound Call <D0820833573222> joining queue agent8003@default
  1203. 2016-11-04 09:05:06.617484 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz
  1204. 2016-11-04 09:05:06.617484 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 60ms
  1205. 2016-11-04 09:05:06.617484 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = Receiving
  1206. 2016-11-04 09:05:06.637472 [DEBUG] mod_callcenter.c:1236 Updated tier: Agent 8003 in Queue agent8003@default set state = Active Inbound
  1207. 2016-11-04 09:05:06.637472 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = In a queue call
  1208. 2016-11-04 09:05:06.637472 [DEBUG] switch_ivr.c:623 sofia/internal/8003@172.xx.xx.3 Command Execute playback(tone_stream://%(200,0,500,600,700);loops=3)
  1209. EXECUTE sofia/internal/8003@172.xx.xx.3 playback(tone_stream://%(200,0,500,600,700);loops=3)
  1210. 2016-11-04 09:05:06.637472 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  1211. 2016-11-04 09:05:06.637472 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/external/0833573222
  1212. 2016-11-04 09:05:06.637472 [DEBUG] mod_callcenter.c:1776 Agent 8003 answered "Outbound Call" <D0820833573222> from queue agent8003@default (Recorded)
  1213. 2016-11-04 09:05:06.637472 [DEBUG] switch_ivr_bridge.c:2010 (sofia/external/0833573222) State Change CS_EXECUTE -> CS_HIBERNATE
  1214. 2016-11-04 09:05:06.637472 [DEBUG] switch_ivr_bridge.c:2012 (sofia/internal/8003@172.xx.xx.3) State Change CS_EXECUTE -> CS_HIBERNATE
  1215. 2016-11-04 09:05:06.657461 [DEBUG] switch_ivr_play_say.c:1910 done playing file tone_stream://%(200,0,500,600,700);loops=3
  1216. 2016-11-04 09:05:06.657461 [DEBUG] switch_ivr_async.c:1496 No silence detection configured; assuming start of speech
  1217. 2016-11-04 09:05:06.657461 [DEBUG] switch_ivr_play_say.c:1910 done playing file local_stream://moh
  1218. 2016-11-04 09:05:06.657461 [DEBUG] mod_callcenter.c:2887 Member Outbound Call <D0820833573222> is answered by an agent in queue agent8003@default
  1219. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE going to sleep
  1220. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_HIBERNATE
  1221. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:624 (sofia/external/0833573222) State HIBERNATE
  1222. 2016-11-04 09:05:06.677541 [DEBUG] mod_sofia.c:179 sofia/external/0833573222 SOFIA HIBERNATE
  1223. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:964 (sofia/external/0833573222) State Change CS_HIBERNATE -> CS_RESET
  1224. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:624 (sofia/external/0833573222) State HIBERNATE going to sleep
  1225. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_RESET
  1226. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:605 (sofia/external/0833573222) State RESET
  1227. 2016-11-04 09:05:06.677541 [DEBUG] mod_sofia.c:160 sofia/external/0833573222 SOFIA RESET
  1228. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:949 sofia/external/0833573222 CUSTOM RESET
  1229. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:956 (sofia/external/0833573222) State Change CS_RESET -> CS_SOFT_EXECUTE
  1230. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:605 (sofia/external/0833573222) State RESET going to sleep
  1231. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_SOFT_EXECUTE
  1232. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_play_say.c:1910 done playing file local_stream://moh
  1233. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:615 (sofia/external/0833573222) State SOFT_EXECUTE
  1234. 2016-11-04 09:05:06.677541 [DEBUG] mod_sofia.c:634 SOFIA SOFT_EXECUTE
  1235. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:974 sofia/external/0833573222 CUSTOM SOFT_EXECUTE
  1236. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE going to sleep
  1237. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_HIBERNATE
  1238. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/8003@172.xx.xx.3) State HIBERNATE
  1239. 2016-11-04 09:05:06.677541 [DEBUG] mod_sofia.c:179 sofia/internal/8003@172.xx.xx.3 SOFIA HIBERNATE
  1240. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:964 (sofia/internal/8003@172.xx.xx.3) State Change CS_HIBERNATE -> CS_RESET
  1241. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/8003@172.xx.xx.3) State HIBERNATE going to sleep
  1242. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_RESET
  1243. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:605 (sofia/internal/8003@172.xx.xx.3) State RESET
  1244. 2016-11-04 09:05:06.677541 [DEBUG] mod_sofia.c:160 sofia/internal/8003@172.xx.xx.3 SOFIA RESET
  1245. 2016-11-04 09:05:06.677541 [DEBUG] switch_ivr_bridge.c:949 sofia/internal/8003@172.xx.xx.3 CUSTOM RESET
  1246. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:188 sofia/internal/8003@172.xx.xx.3 Standard RESET
  1247. 2016-11-04 09:05:06.677541 [DEBUG] switch_core_state_machine.c:605 (sofia/internal/8003@172.xx.xx.3) State RESET going to sleep
  1248. 2016-11-04 09:05:06.697469 [DEBUG] switch_ivr_bridge.c:1006 (sofia/internal/8003@172.xx.xx.3) State Change CS_RESET -> CS_SOFT_EXECUTE
  1249. 2016-11-04 09:05:06.697469 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_SOFT_EXECUTE
  1250. 2016-11-04 09:05:06.697469 [DEBUG] switch_core_state_machine.c:615 (sofia/internal/8003@172.xx.xx.3) State SOFT_EXECUTE
  1251. 2016-11-04 09:05:06.697469 [DEBUG] mod_sofia.c:634 SOFIA SOFT_EXECUTE
  1252. 2016-11-04 09:05:06.697469 [DEBUG] switch_ivr_bridge.c:974 sofia/internal/8003@172.xx.xx.3 CUSTOM SOFT_EXECUTE
  1253. 2016-11-04 09:05:06.697469 [DEBUG] switch_core_state_machine.c:400 sofia/internal/8003@172.xx.xx.3 Standard SOFT_EXECUTE
  1254. 2016-11-04 09:05:06.697469 [DEBUG] switch_core_state_machine.c:615 (sofia/internal/8003@172.xx.xx.3) State SOFT_EXECUTE going to sleep
  1255. 2016-11-04 09:05:06.717485 [DEBUG] switch_ivr_bridge.c:1489 (sofia/internal/8003@172.xx.xx.3) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
  1256. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_CONSUME_MEDIA
  1257. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/8003@172.xx.xx.3) State CONSUME_MEDIA
  1258. 2016-11-04 09:05:06.717485 [DEBUG] switch_ivr_bridge.c:913 sofia/internal/8003@172.xx.xx.3 CUSTOM HOLD
  1259. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/8003@172.xx.xx.3) State CONSUME_MEDIA going to sleep
  1260. 2016-11-04 09:05:06.717485 [DEBUG] switch_ivr_bridge.c:1594 (sofia/internal/8003@172.xx.xx.3) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  1261. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXCHANGE_MEDIA
  1262. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/8003@172.xx.xx.3) State EXCHANGE_MEDIA
  1263. 2016-11-04 09:05:06.717485 [DEBUG] mod_sofia.c:628 SOFIA EXCHANGE_MEDIA
  1264. 2016-11-04 09:05:06.717485 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1805dc28 0x7efc1805dc28
  1265. 2016-11-04 09:05:06.717485 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1805dc28 0x7efc1805dc28
  1266. 2016-11-04 09:05:06.717485 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc1805dc28 0x7efc1805dc30
  1267. 2016-11-04 09:05:06.717485 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc1805dc28 0x7efc1805dc30
  1268. 2016-11-04 09:05:06.717485 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 960 bytes to accommodate 320->960
  1269. nua.c:798 nua_info() nua: nua_info: entering
  1270. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_info
  1271. nua_stack.c:569 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_info
  1272. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  1273. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  1274. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(Enav8Pre:172.xx.xx.61:En@v8Pre!!@4543) = 0539d9f4459c6f955a5b6c5bce9c40b1
  1275. auth_digest.c:318 auth_digest_response() A2 = MD5(INFO:sip:0833573222@172.xx.xx.61:5060;transport=udp)
  1276. auth_digest.c:348 auth_digest_response() auth_response: 958346cb56b8c5b979ea29812d109909 = MD5(0539d9f4459c6f955a5b6c5bce9c40b1:64a7a2e8-8f79-432e-bb5d-a89650b98760:00000002:2BgUXBz/EjWAOwBQVosP+A:auth:4741e082bbc515e1cd4bc5c629e44c28) (qop=auth)
  1277. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  1278. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = udp/172.xx.xx.61:5060
  1279. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  1280. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name udp/172.xx.xx.61:5060
  1281. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 987 bytes of 987 to udp/172.xx.xx.61:5060
  1282. tport.c:3492 tport_send_msg() tport_vsend returned 987
  1283. send 987 bytes to udp/[172.xx.xx.61]:5060 at 09:05:06.731883:
  1284.    ------------------------------------------------------------------------
  1285.   INFO sip:0833573222@172.xx.xx.61:5060;transport=udp SIP/2.0
  1286.    Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKUQ5mjj3B84eKm
  1287.    Max-Forwards: 70
  1288.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  1289.    To: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  1290.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  1291.   CSeq: 98785488 INFO
  1292.    Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
  1293.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  1294.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1295.    Supported: timer, path, replaces
  1296.    Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="64a7a2e8-8f79-432e-bb5d-a89650b98760", cnonce="2BgUXBz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61:5060;transport=udp", response="958346cb56b8c5b979ea29812d109909", qop=auth, nc=00000002
  1297.    Content-Type: message/update_display
  1298.    Content-Length: 0
  1299.    X-FS-Display-Name: 8003
  1300.    X-FS-Display-Number: 8003
  1301.    
  1302.    ------------------------------------------------------------------------
  1303. nta.c:8304 outgoing_send() nta: sent INFO (98785488) to udp/172.xx.xx.61:5060
  1304. tport.c:4160 tport_pend() tport_pend(0x7efc0c0008c0): pending 0x7efc0c03d7e0 for udp/172.xx.xx.85:5060 (already 0)
  1305. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  1306. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  1307. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  1308. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c04a1e0 from (udp/172.xx.xx.85:5060) has 433 bytes, veclen = 1
  1309. recv 433 bytes from udp/[172.xx.xx.61]:5060 at 09:05:06.747736:
  1310.    ------------------------------------------------------------------------
  1311.    SIP/2.0 200 OK
  1312.    Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKUQ5mjj3B84eKm
  1313.    From: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  1314.    To: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  1315.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  1316.   CSeq: 98785488 INFO
  1317.    User-Agent: FS
  1318.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  1319.    Supported: path, replaces
  1320.    Content-Length: 0
  1321.    
  1322.    ------------------------------------------------------------------------
  1323. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c04a1e0 (433 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  1324. nta.c:3299 agent_recv_response() nta: received 200 OK for INFO (98785488)
  1325. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  1326. nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 16 ms
  1327. tport.c:4222 tport_release() tport_release(0x7efc0c0008c0): 0x7efc0c03d7e0 by 0x7efc0c045cb0 with 0x7efc0c04a1e0
  1328. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event r_info 200 OK
  1329. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1330. 2016-11-04 09:05:06.757472 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc28027798 0x7efc28027798
  1331. 2016-11-04 09:05:06.757472 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc28027798 0x7efc28027798
  1332. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1333. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1334. 2016-11-04 09:05:06.837473 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed.
  1335. 2016-11-04 09:05:06.837473 [DEBUG] switch_core_io.c:448 Setting BUG Codec G729:18
  1336. 2016-11-04 09:05:06.837473 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc00065110 0x7efc00065118
  1337. 2016-11-04 09:05:06.837473 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc00065110 0x7efc00065118
  1338. 2016-11-04 09:05:06.837473 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc280277b8 0x7efc280277c0
  1339. 2016-11-04 09:05:06.837473 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc280277b8 0x7efc280277c0
  1340. 2016-11-04 09:05:06.837473 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 320 bytes to accommodate 960->320
  1341. nta.c:1296 agent_timer() nta: timer set next to 4016 ms
  1342. nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate INFO (98785488)
  1343. nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7efc37691d40)
  1344. nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/3 term, 1/4 free
  1345. nta.c:1296 agent_timer() nta: timer set next to 21174 ms
  1346. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc0c0008c0): events IN
  1347. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc0c0008c0)
  1348. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc0c0008c0) msg 0x7efc0c04a1e0 from (udp/172.xx.xx.85:5060) has 584 bytes, veclen = 1
  1349. recv 584 bytes from udp/[172.xx.xx.61]:5060 at 09:05:14.529516:
  1350.    ------------------------------------------------------------------------
  1351.    BYE sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0
  1352.    Via: SIP/2.0/UDP 172.xx.xx.61;rport;branch=z9hG4bK2211UmemDevtj
  1353.    Max-Forwards: 70
  1354.    From: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  1355.    To: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  1356.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  1357.    CSeq: 98785497 BYE
  1358.    User-Agent: FS
  1359.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
  1360.    Supported: path, replaces
  1361.    Reason: Q.850;cause=16
  1362.    Content-Length: 0
  1363.    P-RTP-Stat: PS=204,OS=12240,PR=126,OR=7560,PL=0,JI=0,LA=0,DU=8
  1364.    
  1365.    ------------------------------------------------------------------------
  1366. tport.c:3023 tport_deliver() tport_deliver(0x7efc0c0008c0): msg 0x7efc0c04a1e0 (584 bytes) from udp/172.xx.xx.61:5060/sip next=(nil)
  1367. nta.c:2880 agent_recv_request() nta: received BYE sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0 (CSeq 98785497)
  1368. nta.c:3248 agent_aliases() nta: canonizing sip:gw+Enav8@172.xx.xx.85:5060 with contact
  1369. nta.c:3060 agent_recv_request() nta: BYE (98785497) going to existing leg
  1370. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1371. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_bye 100 Trying
  1372. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1373. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1374. 2016-11-04 09:05:14.517547 [NOTICE] sofia.c:988 Hangup sofia/external/0833573222 [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
  1375. nua.c:879 nua_respond() nua: nua_respond: entering
  1376. nua_stack.c:573 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_respond 200 OK
  1377. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  1378. soa.c:403 soa_set_params() soa_set_params(static::0x7efc0c03a7a0, ...) called
  1379. tport.c:3257 tport_tsend() tport_tsend(0x7efc0c0008c0) tpn = UDP/172.xx.xx.61:5060
  1380. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_respond
  1381. tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.xx.xx.61:5060
  1382. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7efc0c0008c0): not found by name UDP/172.xx.xx.61:5060
  1383. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  1384. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1385. nua_stack.c:529 nua_signal() nua(0x7efc0002eaf0): sent signal r_destroy
  1386. tport.c:3594 tport_vsend() tport_vsend(0x7efc0c0008c0): 485 bytes of 485 to udp/172.xx.xx.61:5060
  1387. tport.c:3492 tport_send_msg() tport_vsend returned 485
  1388. send 485 bytes to udp/[172.xx.xx.61]:5060 at 09:05:14.532177:
  1389.    ------------------------------------------------------------------------
  1390.    SIP/2.0 200 OK
  1391.    Via: SIP/2.0/UDP 172.xx.xx.61;rport=5060;branch=z9hG4bK2211UmemDevtj
  1392.    From: <sip:0833573222@172.xx.xx.61>;tag=1evp3r3p75ceN
  1393.    To: "" <sip:Enav8Pre@172.xx.xx.61>;tag=HXvB6137Kycrc
  1394.    Call-ID: d817aae3-1cff-1235-3b80-0050568b0ff8
  1395.    CSeq: 98785497 BYE
  1396.    User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit
  1397.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1398.    Supported: timer, path, replaces
  1399.    Content-Length: 0
  1400.    
  1401.    ------------------------------------------------------------------------
  1402. nta.c:6791 incoming_reply() nta: sent 200 OK for BYE (98785497)
  1403. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7efc0002eaf0): removing session usage
  1404. nua_session.c:4139 signal_call_state_change() nua(0x7efc0002eaf0): call state changed: ready -> terminated
  1405. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_state 200 Session Terminated
  1406. nua_stack.c:271 nua_stack_event() nua(0x7efc0002eaf0): event i_terminated 200 Session Terminated
  1407. soa.c:356 soa_destroy() soa_destroy(static::0x7efc0c03a7a0) called
  1408. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7efc0c02eae0)
  1409. nua_stack.c:569 nua_stack_signal() nua(0x7efc0002eaf0): recv signal r_destroy
  1410. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  1411. 2016-11-04 09:05:14.517547 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/external/0833573222]
  1412. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr_bridge.c:701 sofia/external/0833573222 ending bridge by request from write function
  1413. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/8003@172.xx.xx.3]
  1414. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr.c:2160 (sofia/internal/8003@172.xx.xx.3) State Change CS_EXCHANGE_MEDIA -> CS_ROUTING
  1415. 2016-11-04 09:05:14.537459 [NOTICE] switch_ivr.c:2167 Transfer sofia/internal/8003@172.xx.xx.3 to XML[4099@public]
  1416. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/8003@172.xx.xx.3) State EXCHANGE_MEDIA going to sleep
  1417. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_ROUTING
  1418. 2016-11-04 09:05:14.537459 [DEBUG] switch_channel.c:2249 (sofia/internal/8003@172.xx.xx.3) Callstate Change ACTIVE -> RINGING
  1419. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING
  1420. 2016-11-04 09:05:14.537459 [DEBUG] mod_sofia.c:142 sofia/internal/8003@172.xx.xx.3 SOFIA ROUTING
  1421. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8003@172.xx.xx.3 Standard ROUTING
  1422. 2016-11-04 09:05:14.537459 [INFO] mod_dialplan_xml.c:637 Processing Outbound Call <D0820833573222>->4099 in context public
  1423. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->unloop] continue=false
  1424. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  1425. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  1426. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_huntgroup] continue=false
  1427. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_huntgroup] destination_number(4099) =~ /^0870980891$/ break=on-false
  1428. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_did_to_local] continue=false
  1429. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_did_to_local] destination_number(4099) =~ /^0870980892$/ break=on-false
  1430. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->outside_call] continue=true
  1431. Dialplan: sofia/internal/8003@172.xx.xx.3 Absolute Condition [outside_call]
  1432. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(outside_call=true)
  1433. Dialplan: sofia/internal/8003@172.xx.xx.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  1434. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->call_debug] continue=true
  1435. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  1436. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_extensions] continue=false
  1437. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_extensions] destination_number(4099) =~ /^(10[01][0-9])$/ break=on-false
  1438. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false
  1439. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(5551212)$/ break=on-false
  1440. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false
  1441. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(0870980892)$/ break=on-false
  1442. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false
  1443. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980890$/ break=on-false
  1444. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false
  1445. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980893$/ break=on-false
  1446. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->conf11001] continue=false
  1447. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr_bridge.c:1695 sofia/external/0833573222 skip receive message [UNBRIDGE] (channel is hungup already)
  1448. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [conf11001] destination_number(4099) =~ /^11001$/ break=on-false
  1449. Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->UNKNOWN] continue=false
  1450. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:615 (sofia/external/0833573222) State SOFT_EXECUTE going to sleep
  1451. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_HANGUP
  1452. Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [UNKNOWN] destination_number(4099) =~ /^(4099)$/ break=on-false
  1453. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(transfer_after_bridge=4099)
  1454. Dialplan: sofia/internal/8003@172.xx.xx.3 Action sleep(300)
  1455. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set uuid ${caller_id_number} '${uuid}')})
  1456. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set type ${caller_id_number} 'uuid-standby')})
  1457. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set status ${caller_id_number} 'Available')})
  1458. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set state ${caller_id_number} 'idle')})
  1459. Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3)
  1460. Dialplan: sofia/internal/8003@172.xx.xx.3 Action answer()
  1461. Dialplan: sofia/internal/8003@172.xx.xx.3 Action playback(local_stream://moh)
  1462. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr_async.c:1312 Stop recording file /usr/local/freeswitch/recordings/2016-11-04-09-05-06.ANSWEREDCALL.D0820833573222.908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb.wav
  1463. 2016-11-04 09:05:14.537459 [INFO] switch_channel.c:3127 sofia/internal/8003@172.xx.xx.3 Flipping CID from "Outbound Call" <D0820833573222> to "8003" <8003>
  1464. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8003@172.xx.xx.3) State Change CS_ROUTING -> CS_EXECUTE
  1465. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING going to sleep
  1466. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXECUTE
  1467. 2016-11-04 09:05:14.537459 [DEBUG] switch_channel.c:2251 (sofia/internal/8003@172.xx.xx.3) Callstate Change RINGING -> ACTIVE
  1468. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE
  1469. 2016-11-04 09:05:14.537459 [DEBUG] mod_sofia.c:197 sofia/internal/8003@172.xx.xx.3 SOFIA EXECUTE
  1470. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8003@172.xx.xx.3 Standard EXECUTE
  1471. EXECUTE sofia/internal/8003@172.xx.xx.3 set(outside_call=true)
  1472. 2016-11-04 09:05:14.537459 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [outside_call]=[true]
  1473. EXECUTE sofia/internal/8003@172.xx.xx.3 export(RFC2822_DATE=Fri, 04 Nov 2016 09:05:14 +0200)
  1474. 2016-11-04 09:05:14.537459 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 04 Nov 2016 09:05:14 +0200]
  1475. EXECUTE sofia/internal/8003@172.xx.xx.3 set(transfer_after_bridge=4099)
  1476. 2016-11-04 09:05:14.537459 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [transfer_after_bridge]=[4099]
  1477. EXECUTE sofia/internal/8003@172.xx.xx.3 sleep(300)
  1478. 2016-11-04 09:05:14.537459 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = Waiting
  1479. 2016-11-04 09:05:14.537459 [DEBUG] switch_ivr_async.c:1376 Channel is hung up
  1480. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_media_bug.c:1120 Removing BUG from sofia/external/0833573222
  1481. 2016-11-04 09:05:14.537459 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc00065110 0x7efc00065118
  1482. 2016-11-04 09:05:14.537459 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc00065110 0x7efc00065118
  1483. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:809 (sofia/external/0833573222) Callstate Change ACTIVE -> HANGUP
  1484. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:811 (sofia/external/0833573222) State HANGUP
  1485. 2016-11-04 09:05:14.537459 [DEBUG] mod_sofia.c:437 Channel sofia/external/0833573222 hanging up, cause: NORMAL_CLEARING
  1486. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:60 sofia/external/0833573222 Standard HANGUP, cause: NORMAL_CLEARING
  1487. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:811 (sofia/external/0833573222) State HANGUP going to sleep
  1488. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:578 (sofia/external/0833573222) State Change CS_HANGUP -> CS_REPORTING
  1489. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_REPORTING
  1490. 2016-11-04 09:05:14.537459 [DEBUG] switch_core_state_machine.c:897 (sofia/external/0833573222) State REPORTING
  1491. 2016-11-04 09:05:14.537459 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_both (start_stamp, CallId, TEST_id, end_stamp) VALUES ('2016-11-04 09:05:00', '908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb', 'Enav8Pre@172.xx.xx.61', '2016-11-04 09:05:14')
  1492. 2016-11-04 09:05:14.630112 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_a_leg (start_stamp, TelNumberFull, CallId, sip_endpoint_disposition, orig_id, CallerID, CODEC, sip_current_application, IP, term_id, ClientId, end_stamp) VALUES ('2016-11-04 09:05:00', '0833573222', '908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb', 'ANSWER', '908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb', 'Enav8Pre', 'G729', 'callcenter', '172.xx.xx.61', 'd817aae3-1cff-1235-3b80-0050568b0ff8', '908b0bfc-4bec-4fc6-bd3d-dfa7aea869bb', '2016-11-04 09:05:14')
  1493. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:174 sofia/external/0833573222 Standard REPORTING, cause: NORMAL_CLEARING
  1494. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:897 (sofia/external/0833573222) State REPORTING going to sleep
  1495. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:569 (sofia/external/0833573222) State Change CS_REPORTING -> CS_DESTROY
  1496. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_session.c:1646 Session 103 (sofia/external/0833573222) Locked, Waiting on external entities
  1497. 2016-11-04 09:05:14.630112 [NOTICE] switch_core_session.c:1664 Session 103 (sofia/external/0833573222) Ended
  1498. 2016-11-04 09:05:14.630112 [NOTICE] switch_core_session.c:1668 Close Channel sofia/external/0833573222 [CS_DESTROY]
  1499. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:700 (sofia/external/0833573222) Running State Change CS_DESTROY
  1500. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:710 (sofia/external/0833573222) State DESTROY
  1501. 2016-11-04 09:05:14.630112 [DEBUG] mod_sofia.c:342 sofia/external/0833573222 SOFIA DESTROY
  1502. 2016-11-04 09:05:14.630112 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc280277b8 0x7efc280277c0
  1503. 2016-11-04 09:05:14.630112 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc280277b8 0x7efc280277c0
  1504. 2016-11-04 09:05:14.630112 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc28027798 0x7efc28027798
  1505. 2016-11-04 09:05:14.630112 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc28027798 0x7efc28027798
  1506. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:181 sofia/external/0833573222 Standard DESTROY
  1507. 2016-11-04 09:05:14.630112 [DEBUG] switch_core_state_machine.c:710 (sofia/external/0833573222) State DESTROY going to sleep
  1508. 2016-11-04 09:05:14.837564 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set uuid = 544b6c82-4804-4791-bf86-f44a9e72b983
  1509. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  1510. )
  1511. 2016-11-04 09:05:14.837564 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  1512. ]
  1513. 2016-11-04 09:05:14.837564 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set type = uuid-standby
  1514. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  1515. )
  1516. 2016-11-04 09:05:14.837564 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  1517. ]
  1518. 2016-11-04 09:05:14.837564 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set status = Available
  1519. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  1520. )
  1521. 2016-11-04 09:05:14.837564 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  1522. ]
  1523. 2016-11-04 09:05:14.837564 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = idle
  1524. EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK
  1525. )
  1526. 2016-11-04 09:05:14.837564 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK
  1527. ]
  1528. EXECUTE sofia/internal/8003@172.xx.xx.3 set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3)
  1529. 2016-11-04 09:05:14.837564 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [cc_warning_tone]=[tone_stream://%(200,0,500,600,700);loops=3]
  1530. EXECUTE sofia/internal/8003@172.xx.xx.3 answer()
  1531. EXECUTE sofia/internal/8003@172.xx.xx.3 playback(local_stream://moh)
  1532. 2016-11-04 09:05:14.837564 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz
  1533. 2016-11-04 09:05:14.837564 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  1534. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7efc00026cb0): events IN
  1535. tport.c:2864 tport_recv_event() tport_recv_event(0x7efc00026cb0)
  1536. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7efc00026cb0) msg 0x7efc0004df80 from (udp/172.xx.xx.60:5060) has 4 bytes, veclen = 1
  1537. tport.c:3023 tport_deliver() tport_deliver(0x7efc00026cb0): bad msg 0x7efc0004df80 (4 bytes) from udp/10.99.107.25:5060/sip next=(nil)

Reply to "Log with sip debug + loglevel 9"