From Nick Tunstall, 6 Years ago, written in Plain Text.
- view diff
Embed
  1. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  2. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  3. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c01c6d0 from (udp/195.74.100.112:5060) has 940 bytes, veclen = 1
  4. recv 940 bytes from udp/[87.127.251.183]:1277 at 14:17:57.950451:
  5.    ------------------------------------------------------------------------
  6.    INVITE sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0
  7.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK1801519108
  8.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  9.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>
  10.    Call-ID: 2_1100593423@10.8.32.151
  11.    CSeq: 1 INVITE
  12.    Contact: <sip:1000@10.8.32.151:5060>
  13.    Content-Type: application/sdp
  14.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  15.    Max-Forwards: 70
  16.    User-Agent: Yealink SIP-T23G 44.80.0.137
  17.    Allow-Events: talk,hold,conference,refer,check-sync
  18.    Supported: replaces
  19.    Content-Length: 304
  20.    
  21.    v=0
  22.    o=- 20111 20111 IN IP4 10.8.32.151
  23.    s=SDP data
  24.    c=IN IP4 10.8.32.151
  25.    t=0 0
  26.    m=audio 11930 RTP/AVP 9 0 8 18 101
  27.    a=rtpmap:9 G722/8000
  28.    a=rtpmap:0 PCMU/8000
  29.    a=rtpmap:8 PCMA/8000
  30.    a=rtpmap:18 G729/8000
  31.    a=fmtp:18 annexb=no
  32.    a=ptime:20
  33.    a=sendrecv
  34.    a=rtpmap:101 telephone-event/8000
  35.    a=fmtp:101 0-15
  36.    ------------------------------------------------------------------------
  37. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c01c6d0 (940 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  38. nta.c:2880 agent_recv_request() nta: received INVITE sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 1)
  39. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  40. nta.c:3085 agent_recv_request() nta: INVITE (1) going to a default leg
  41. nta.c:1348 set_timeout() nta: timer shortened to 200 ms
  42. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  43. nua_stack.c:899 nh_create() nua: nh_create: entering
  44. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  45. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  46. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c0116a0) called
  47. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c011ee0, ...) called
  48. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f812c00e0f0)
  49. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f812c011ee0) called
  50. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f812c011ee0, (nil), 0x7f812c019a2c, 304) called
  51. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f812c0116a0): adding session usage
  52. nua_stack.c:271 nua_stack_event() nua(0x7f812c0116a0): event i_invite 100 Trying
  53. nua_session.c:4139 signal_call_state_change() nua(0x7f812c0116a0): call state changed: init -> received, received offer
  54. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f812c011ee0, [0x7f813111b8d8], [0x7f813111b8e0], [(nil)]) called
  55. nua_stack.c:271 nua_stack_event() nua(0x7f812c0116a0): event i_state 100 Trying
  56. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  57. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  58. 2017-09-05 14:17:57.946224 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 [b0c70bf2-9b56-4421-ab85-5336899fafdc]
  59. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  60. 2017-09-05 14:17:57.946224 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_NEW (Cur 1 Tot 7)
  61. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  62. 2017-09-05 14:17:57.946224 [DEBUG] sofia.c:10067 sofia/internal/1000@fspbx1.evoip.enta.net:5060 receiving invite from 87.127.251.183:1277 version: 1.9.0 -556-68fc3b5 64bit
  63. 2017-09-05 14:17:57.946224 [DEBUG] sofia.c:10238 IP 87.127.251.183 Rejected by acl "domains". Falling back to Digest auth.
  64. nua.c:879 nua_respond() nua: nua_respond: entering
  65. nua_stack.c:573 nua_stack_signal() nua(0x7f812c0116a0): recv signal r_respond 407 Proxy Authentication Required
  66. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  67. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c011ee0, ...) called
  68. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  69. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f812c011ee0) called
  70. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  71. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  72. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  73. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 874 bytes of 874 to udp/87.127.251.183:1277
  74. tport.c:3492 tport_send_msg() tport_vsend returned 874
  75. send 874 bytes to udp/[87.127.251.183]:1277 at 14:17:57.954156:
  76.    ------------------------------------------------------------------------
  77.    SIP/2.0 407 Proxy Authentication Required
  78.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK1801519108;received=87.127.251.183
  79.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  80.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=m33NFK15p62yr
  81.    Call-ID: 2_1100593423@10.8.32.151
  82.    CSeq: 1 INVITE
  83.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  84.    Accept: application/sdp
  85.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  86.    Supported: timer, path, replaces
  87.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  88.    Proxy-Authenticate: Digest realm="fspbx1.evoip.enta.net", nonce="21e292a6-2542-4628-ae3f-2b3b4bcdee63", algorithm=MD5, qop="auth"
  89.    Content-Length: 0
  90.    
  91.    ------------------------------------------------------------------------
  92. nta.c:6797 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (1)
  93. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f812c0116a0): removing session usage
  94. nua_session.c:4139 signal_call_state_change() nua(0x7f812c0116a0): call state changed: received -> terminated
  95. nua_stack.c:271 nua_stack_event() nua(0x7f812c0116a0): event i_state 407 Proxy Authentication Required
  96. nua_stack.c:271 nua_stack_event() nua(0x7f812c0116a0): event i_terminated 407 Proxy Authentication Required
  97. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c011ee0) called
  98. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f812c00e0f0)
  99. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  100. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  101. 2017-09-05 14:17:57.946224 [DEBUG] sofia.c:2405 detaching session b0c70bf2-9b56-4421-ab85-5336899fafdc
  102. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  103. nua_stack.c:529 nua_signal() nua(0x7f812c0116a0): sent signal r_destroy
  104. nua_stack.c:569 nua_stack_signal() nua(0x7f812c0116a0): recv signal r_destroy
  105. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  106. nua_stack.c:529 nua_signal() nua(0x7f812c0116a0): sent signal r_respond
  107. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  108. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  109. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  110. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  111. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  112. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  113. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  114. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  115. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  116. 2017-09-05 14:17:57.946224 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State NEW
  117. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  118. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  119. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c0126a0 from (udp/195.74.100.112:5060) has 326 bytes, veclen = 1
  120. recv 326 bytes from udp/[87.127.251.183]:1277 at 14:17:57.960315:
  121.    ------------------------------------------------------------------------
  122.    ACK sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0
  123.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK1801519108
  124.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  125.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=m33NFK15p62yr
  126.    Call-ID: 2_1100593423@10.8.32.151
  127.    CSeq: 1 ACK
  128.    Content-Length: 0
  129.    
  130.    ------------------------------------------------------------------------
  131. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c0126a0 (326 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  132. nta.c:2880 agent_recv_request() nta: received ACK sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 1)
  133. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  134. nta.c:3019 agent_recv_request() nta: ACK (1) is going to INVITE (1)
  135. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  136. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  137. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c0126a0 from (udp/195.74.100.112:5060) has 1214 bytes, veclen = 1
  138. recv 1214 bytes from udp/[87.127.251.183]:1277 at 14:17:57.967938:
  139.    ------------------------------------------------------------------------
  140.    INVITE sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0
  141.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK4245134600
  142.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  143.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>
  144.    Call-ID: 2_1100593423@10.8.32.151
  145.    CSeq: 2 INVITE
  146.    Contact: <sip:1000@10.8.32.151:5060>
  147.    Proxy-Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="21e292a6-2542-4628-ae3f-2b3b4bcdee63", uri="sip:03331019574@fspbx1.evoip.enta.net:5060", response="5c8c1d3c1e93369dd6e29c7481d3e6fe", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
  148.    Content-Type: application/sdp
  149.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  150.    Max-Forwards: 70
  151.    User-Agent: Yealink SIP-T23G 44.80.0.137
  152.    Allow-Events: talk,hold,conference,refer,check-sync
  153.    Supported: replaces
  154.    Content-Length: 304
  155.    
  156.    v=0
  157.    o=- 20111 20111 IN IP4 10.8.32.151
  158.    s=SDP data
  159.    c=IN IP4 10.8.32.151
  160.    t=0 0
  161.    m=audio 11930 RTP/AVP 9 0 8 18 101
  162.    a=rtpmap:9 G722/8000
  163.    a=rtpmap:0 PCMU/8000
  164.    a=rtpmap:8 PCMA/8000
  165.    a=rtpmap:18 G729/8000
  166.    a=fmtp:18 annexb=no
  167.    a=ptime:20
  168.    a=sendrecv
  169.    a=rtpmap:101 telephone-event/8000
  170.    a=fmtp:101 0-15
  171.    ------------------------------------------------------------------------
  172. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c0126a0 (1214 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  173. nta.c:2880 agent_recv_request() nta: received INVITE sip:03331019574@fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 2)
  174. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  175. nta.c:3085 agent_recv_request() nta: INVITE (2) going to a default leg
  176. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  177. nua_stack.c:899 nh_create() nua: nh_create: entering
  178. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  179. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  180. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c014200) called
  181. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  182. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f812c0234c0)
  183. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f812c0281e0) called
  184. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f812c0281e0, (nil), 0x7f812c012dde, 304) called
  185. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f812c014200): adding session usage
  186. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_invite 100 Trying
  187. nua_session.c:4139 signal_call_state_change() nua(0x7f812c014200): call state changed: init -> received, received offer
  188. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f812c0281e0, [0x7f813111b8d8], [0x7f813111b8e0], [(nil)]) called
  189. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 100 Trying
  190. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  191. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  192. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:2514 Re-attaching to session b0c70bf2-9b56-4421-ab85-5336899fafdc
  193. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  194. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  195. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:10067 sofia/internal/1000@fspbx1.evoip.enta.net:5060 receiving invite from 87.127.251.183:1277 version: 1.9.0 -556-68fc3b5 64bit
  196. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:10238 IP 87.127.251.183 Rejected by acl "domains". Falling back to Digest auth.
  197. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:11366 Setting NAT mode based on nat.auto
  198. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  199. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  200. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [received][100]
  201. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:7293 Remote SDP:
  202. v=0
  203. o=- 20111 20111 IN IP4 10.8.32.151
  204. s=SDP data
  205. c=IN IP4 10.8.32.151
  206. t=0 0
  207. m=audio 11930 RTP/AVP 9 0 8 18 101
  208. a=rtpmap:9 G722/8000
  209. a=rtpmap:0 PCMU/8000
  210. a=rtpmap:8 PCMA/8000
  211. a=rtpmap:18 G729/8000
  212. a=fmtp:18 annexb=no
  213. a=rtpmap:101 telephone-event/8000
  214. a=fmtp:101 0-15
  215. a=ptime:20
  216.  
  217. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:7685 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State Change CS_NEW -> CS_INIT
  218. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  219. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_INIT (Cur 1 Tot 7)
  220. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State INIT
  221. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:93 sofia/internal/1000@fspbx1.evoip.enta.net:5060 SOFIA INIT
  222. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard INIT
  223. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State Change CS_INIT -> CS_ROUTING
  224. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State INIT going to sleep
  225. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_ROUTING (Cur 1 Tot 7)
  226. 2017-09-05 14:17:57.966225 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Callstate Change DOWN -> RINGING
  227. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State ROUTING
  228. nua.c:879 nua_respond() nua: nua_respond: entering
  229. nua_stack.c:573 nua_stack_signal() nua(0x7f812c014200): recv signal r_respond 100 Trying
  230. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  231. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  232. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  233. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  234. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  235. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 362 bytes of 362 to udp/87.127.251.183:1277
  236. tport.c:3492 tport_send_msg() tport_vsend returned 362
  237. send 362 bytes to udp/[87.127.251.183]:1277 at 14:17:57.977325:
  238.    ------------------------------------------------------------------------
  239.    SIP/2.0 100 Trying
  240.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK4245134600;received=87.127.251.183
  241.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  242.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>
  243.    Call-ID: 2_1100593423@10.8.32.151
  244.    CSeq: 2 INVITE
  245.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  246.    Content-Length: 0
  247.    
  248.    ------------------------------------------------------------------------
  249. nta.c:6797 incoming_reply() nta: sent 100 Trying for INVITE (2)
  250. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_respond
  251. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:154 sofia/internal/1000@fspbx1.evoip.enta.net:5060 SOFIA ROUTING
  252. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard ROUTING
  253. 2017-09-05 14:17:57.966225 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->03331019574 in context public
  254. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->unloop] continue=false
  255. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  256. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  257. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->outside_call] continue=true
  258. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Absolute Condition [outside_call]
  259. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Action set(outside_call=true)
  260. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  261. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->call_debug] continue=true
  262. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  263. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->public_extensions] continue=false
  264. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (FAIL) [public_extensions] destination_number(03331019574) =~ /^(10[01][0-9])$/ break=on-false
  265. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->public_did] continue=false
  266. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (FAIL) [public_did] destination_number(03331019574) =~ /^(5551212)$/ break=on-false
  267. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 parsing [public->ddi out] continue=false
  268. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Regex (PASS) [ddi out] destination_number(03331019574) =~ /^(\d{6,})$/ break=on-false
  269. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Action set(hangup_after_bridge=true)
  270. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Action set(effective_caller_id_number=441156870140)
  271. Dialplan: sofia/internal/1000@fspbx1.evoip.enta.net:5060 Action bridge(sofia/gateway/entanet/03331019574)
  272. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State Change CS_ROUTING -> CS_EXECUTE
  273. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State ROUTING going to sleep
  274. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_EXECUTE (Cur 1 Tot 7)
  275. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State EXECUTE
  276. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:209 sofia/internal/1000@fspbx1.evoip.enta.net:5060 SOFIA EXECUTE
  277. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard EXECUTE
  278. EXECUTE sofia/internal/1000@fspbx1.evoip.enta.net:5060 set(outside_call=true)
  279. 2017-09-05 14:17:57.966225 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1000@fspbx1.evoip.enta.net:5060 [outside_call]=[true]
  280. EXECUTE sofia/internal/1000@fspbx1.evoip.enta.net:5060 export(RFC2822_DATE=Tue, 05 Sep 2017 14:17:57 +0000)
  281. 2017-09-05 14:17:57.966225 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 05 Sep 2017 14:17:57 +0000]
  282. EXECUTE sofia/internal/1000@fspbx1.evoip.enta.net:5060 set(hangup_after_bridge=true)
  283. 2017-09-05 14:17:57.966225 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1000@fspbx1.evoip.enta.net:5060 [hangup_after_bridge]=[true]
  284. EXECUTE sofia/internal/1000@fspbx1.evoip.enta.net:5060 set(effective_caller_id_number=441156870140)
  285. 2017-09-05 14:17:57.966225 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1000@fspbx1.evoip.enta.net:5060 [effective_caller_id_number]=[441156870140]
  286. EXECUTE sofia/internal/1000@fspbx1.evoip.enta.net:5060 bridge(sofia/gateway/entanet/03331019574)
  287. 2017-09-05 14:17:57.966225 [DEBUG] switch_channel.c:1250 sofia/internal/1000@fspbx1.evoip.enta.net:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 05 Sep 2017 14:17:57 +0000] to event
  288. 2017-09-05 14:17:57.966225 [DEBUG] switch_ivr_originate.c:2157 Parsing global variables
  289. 2017-09-05 14:17:57.966225 [NOTICE] switch_channel.c:1104 New Channel sofia/external/03331019574 [123b8876-f919-45a4-80ac-7290fad950f6]
  290. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:5026 (sofia/external/03331019574) State Change CS_NEW -> CS_INIT
  291. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_INIT (Cur 2 Tot 8)
  292. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:627 (sofia/external/03331019574) State INIT
  293. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:93 sofia/external/03331019574 SOFIA INIT
  294. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  295. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  296. 2017-09-05 14:17:57.966225 [DEBUG] sofia_glue.c:1299 sofia/external/03331019574 sending invite version: 1.9.0 -556-68fc3b5 64bit
  297. Local SDP:
  298. v=0
  299. o=FreeSWITCH 1504592205 1504592206 IN IP4 195.74.100.112
  300. s=FreeSWITCH
  301. c=IN IP4 195.74.100.112
  302. t=0 0
  303. m=audio 28872 RTP/AVP 9 0 8 101
  304. a=rtpmap:9 G722/8000
  305. a=rtpmap:0 PCMU/8000
  306. a=rtpmap:8 PCMA/8000
  307. a=rtpmap:101 telephone-event/8000
  308. a=fmtp:101 0-16
  309. a=ptime:20
  310. a=sendrecv
  311.  
  312. nua.c:633 nua_invite() nua: nua_invite: entering
  313. nua_stack.c:569 nua_stack_signal() nua(0x7f8128007c00): recv signal r_invite
  314. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  315. soa.c:280 soa_clone() soa_clone(static::0x7f8118036f30, 0x7f8118004e40, 0x7f8128007c00) called
  316. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  317. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  318. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f8118084a90, (nil), 0x7f81280082ce, -1) called
  319. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f8118084a90, (nil), 0x7f81280082ce, -1) called
  320. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f8128007c00): adding session usage
  321. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f8118084980)
  322. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f8118084a90) called
  323. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f8118084a90, 0) called
  324. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f8118084a90, soa_generate_offer): called
  325. soa_static.c:1189 offer_answer_step() soa_static(0x7f8118084a90, soa_generate_offer): generating local description
  326. soa_static.c:1217 offer_answer_step() soa_static(0x7f8118084a90, soa_generate_offer): upgrade with local description
  327. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f813165ba70, (nil), ""): called
  328. soa_static.c:1446 offer_answer_step() soa_static(0x7f8118084a90, soa_generate_offer): storing local description
  329. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f8118084a90, [(nil)], [0x7f813165dbf8], [0x7f813165dbf4]) called
  330. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  331. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, NAPTR, "EN33510464.voip-portal.co.uk.") called
  332. nta.c:10404 outgoing_query_naptr() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" NAPTR
  333. sres.c:968 sres_query() sres_query(0x7f8118037e00, 0x7f8118080680, NAPTR, "EN33510464.voip-portal.co.uk") called
  334. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803d8d0) called
  335. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803d8d0) id=62402 NAPTR EN33510464.voip-portal.co.uk (to [195.74.100.89]:53)
  336. nua_session.c:4139 signal_call_state_change() nua(0x7f8128007c00): call state changed: init -> calling, sent offer
  337. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f8118084a90, [0x7f813165dbd8], [0x7f813165dbe0], [(nil)]) called
  338. nua_stack.c:269 nua_stack_event() nua(0x7f8128007c00): event i_state INVITE sent
  339. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  340. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_invite
  341. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:40 sofia/external/03331019574 Standard INIT
  342. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:48 (sofia/external/03331019574) State Change CS_INIT -> CS_ROUTING
  343. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:627 (sofia/external/03331019574) State INIT going to sleep
  344. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_ROUTING (Cur 2 Tot 8)
  345. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  346. 2017-09-05 14:17:57.966225 [DEBUG] sofia.c:7283 Channel sofia/external/03331019574 entering state [calling][0]
  347. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  348. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:643 (sofia/external/03331019574) State ROUTING
  349. 2017-09-05 14:17:57.966225 [DEBUG] mod_sofia.c:154 sofia/external/03331019574 SOFIA ROUTING
  350. 2017-09-05 14:17:57.966225 [DEBUG] switch_ivr_originate.c:67 (sofia/external/03331019574) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  351. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:643 (sofia/external/03331019574) State ROUTING going to sleep
  352. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 8)
  353. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:662 (sofia/external/03331019574) State CONSUME_MEDIA
  354. 2017-09-05 14:17:57.966225 [DEBUG] switch_core_state_machine.c:662 (sofia/external/03331019574) State CONSUME_MEDIA going to sleep
  355. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8118037e00, 53) called
  356. sres.c:3781 sres_create_record() ANSWER RR received EN33510464.voip-portal.co.uk. CNAME IN 46 rdlen=10
  357. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. SOA IN 10 rdlen=46
  358. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8118037e00, 0x7f811803d8d0) id=62402 (from [195.74.100.89]:53)
  359. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, NAPTR, "sipgate.voip-portal.co.uk.") called
  360. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803f2d0) called
  361. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803f2d0) id=62403 NAPTR sipgate.voip-portal.co.uk. (to [195.74.100.89]:53)
  362. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8118037e00, 53) called
  363. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. SOA IN 10 rdlen=46
  364. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8118037e00, 0x7f811803f2d0) id=62403 (from [195.74.100.89]:53)
  365. sres.c:2987 sres_query_report_error() sres(q=0x7f811803f2d0): reporting error RECORD_ERR for NAPTR sipgate.voip-portal.co.uk.
  366. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  367. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  368. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  369. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  370. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  371. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  372. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  373. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  374. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  375. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  376. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 1170 bytes of 1170 to udp/195.74.100.80:5060
  377. tport.c:3492 tport_send_msg() tport_vsend returned 1170
  378. send 1170 bytes to udp/[195.74.100.80]:5060 at 14:17:57.986565:
  379.    ------------------------------------------------------------------------
  380.    INVITE sip:03331019574@EN33510464.voip-portal.co.uk SIP/2.0
  381.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK5B8aH1gNg046H
  382.    Max-Forwards: 69
  383.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  384.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>
  385.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  386.    CSeq: 111974474 INVITE
  387.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  388.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  389.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  390.    Supported: timer, path, replaces
  391.    Allow-Events: talk, hold, conference, refer
  392.    Content-Type: application/sdp
  393.    Content-Disposition: session
  394.    Content-Length: 272
  395.    X-FS-Support: update_display,send_info
  396.    Remote-Party-ID: "Extension 1000" <sip:441156870140@EN33510464.voip-portal.co.uk>;party=calling;screen=yes;privacy=off
  397.    
  398.    v=0
  399.    o=FreeSWITCH 1504592205 1504592206 IN IP4 195.74.100.112
  400.    s=FreeSWITCH
  401.    c=IN IP4 195.74.100.112
  402.    t=0 0
  403.    m=audio 28872 RTP/AVP 9 0 8 101
  404.    a=rtpmap:9 G722/8000
  405.    a=rtpmap:0 PCMU/8000
  406.    a=rtpmap:8 PCMA/8000
  407.    a=rtpmap:101 telephone-event/8000
  408.    a=fmtp:101 0-16
  409.    a=ptime:20
  410.    ------------------------------------------------------------------------
  411. nta.c:8310 outgoing_send() nta: sent INVITE (111974474) to */195.74.100.80:5060
  412. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808fb60 for udp/195.74.100.112:5080 (already 0)
  413. nta.c:1350 set_timeout() nta: timer set to 32000 ms
  414. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  415. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  416. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  417. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f811803e800 from (udp/195.74.100.112:5080) has 385 bytes, veclen = 1
  418. recv 385 bytes from udp/[195.74.100.80]:5060 at 14:17:57.997273:
  419.    ------------------------------------------------------------------------
  420.    SIP/2.0 100 Giving a try
  421.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bK5B8aH1gNg046H
  422.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  423.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>
  424.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  425.    CSeq: 111974474 INVITE
  426.    Server: Entanet SIP Proxy V8.24
  427.    Content-Length: 0
  428.    
  429.    ------------------------------------------------------------------------
  430. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f811803e800 (385 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  431. nta.c:3299 agent_recv_response() nta: received 100 Giving a try for INVITE (111974474)
  432. nta.c:3366 agent_recv_response() nta: 100 Giving a try is going to a transaction
  433. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 10.837 ms
  434. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808fb60 by 0x7f8118080680 with 0x7f811803e800 (preliminary)
  435. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  436. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  437. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f811803e800 from (udp/195.74.100.112:5080) has 1260 bytes, veclen = 1
  438. recv 1260 bytes from udp/[195.74.100.80]:5060 at 14:17:58.116159:
  439.    ------------------------------------------------------------------------
  440.    SIP/2.0 180 Ringing
  441.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bK5B8aH1gNg046H
  442.    Record-Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  443.    Record-Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  444.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  445.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  446.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  447.    CSeq: 111974474 INVITE
  448.    Contact: <sip:03331019574@195.74.100.81:5080;transport=tcp>
  449.    User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit
  450.    Accept: application/sdp
  451.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  452.    Supported: timer, path, replaces
  453.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  454.    Content-Length: 0
  455.    X-FS-Display-Name: +443331019574
  456.    X-FS-Display-Number: sip:+443331019574@EN33510464.voip-portal.co.uk
  457.    X-FS-Support: update_display,send_info
  458.    Remote-Party-ID: "+443331019574" <sip:+443331019574@EN33510464.voip-portal.co.uk>;party=calling;privacy=off;screen=no
  459.    
  460.    ------------------------------------------------------------------------
  461. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f811803e800 (1260 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  462. nta.c:3299 agent_recv_response() nta: received 180 Ringing for INVITE (111974474)
  463. nta.c:3366 agent_recv_response() nta: 180 Ringing is going to a transaction
  464. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808fb60 by 0x7f8118080680 with 0x7f811803e800 (preliminary)
  465. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event r_invite 180 Ringing
  466. nua_session.c:4139 signal_call_state_change() nua(0x7f8128007c00): call state changed: calling -> proceeding
  467. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_state 180 Ringing
  468. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  469. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  470. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  471. 2017-09-05 14:17:58.106226 [INFO] sofia.c:1348 sofia/external/03331019574 Update Callee ID to "+443331019574" <sip:+443331019574@EN33510464.voip-portal.co.uk>
  472. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  473. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  474. 2017-09-05 14:17:58.106226 [DEBUG] sofia.c:7283 Channel sofia/external/03331019574 entering state [proceeding][180]
  475. 2017-09-05 14:17:58.106226 [NOTICE] sofia.c:7391 Ring-Ready sofia/external/03331019574!
  476. 2017-09-05 14:17:58.106226 [DEBUG] switch_channel.c:3354 (sofia/external/03331019574) Callstate Change DOWN -> RINGING
  477. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  478. nua.c:879 nua_respond() nua: nua_respond: entering
  479. nua_stack.c:573 nua_stack_signal() nua(0x7f812c014200): recv signal r_respond 180 Ringing
  480. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  481. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  482. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  483. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  484. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  485. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  486. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 895 bytes of 895 to udp/87.127.251.183:1277
  487. tport.c:3492 tport_send_msg() tport_vsend returned 895
  488. send 895 bytes to udp/[87.127.251.183]:1277 at 14:17:58.125140:
  489.    ------------------------------------------------------------------------
  490.    SIP/2.0 180 Ringing
  491.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK4245134600;received=87.127.251.183
  492.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  493.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  494.    Call-ID: 2_1100593423@10.8.32.151
  495.    CSeq: 2 INVITE
  496.    Contact: <sip:03331019574@195.74.100.112:5060;transport=udp>
  497.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  498.    Accept: application/sdp
  499.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  500.    Supported: timer, path, replaces
  501.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  502.    Content-Length: 0
  503.    Remote-Party-ID: "+443331019574" <sip:+443331019574@fspbx1.evoip.enta.net>;party=calling;privacy=off;screen=no
  504.    
  505.    ------------------------------------------------------------------------
  506. nta.c:6797 incoming_reply() nta: sent 180 Ringing for INVITE (2)
  507. nua_session.c:4139 signal_call_state_change() nua(0x7f812c014200): call state changed: received -> early
  508. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 180 Ringing
  509. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  510. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_respond
  511. 2017-09-05 14:17:58.106226 [NOTICE] mod_sofia.c:2417 Ring-Ready sofia/internal/1000@fspbx1.evoip.enta.net:5060!
  512. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  513. 2017-09-05 14:17:58.106226 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [early][180]
  514. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  515. 2017-09-05 14:17:58.106226 [NOTICE] switch_ivr_originate.c:527 Ring Ready sofia/internal/1000@fspbx1.evoip.enta.net:5060!
  516. nta.c:1296 agent_timer() nta: timer set next to 4809 ms
  517. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  518. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  519. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c029a30 from (udp/195.74.100.112:5060) has 4 bytes, veclen = 1
  520. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): bad msg 0x7f812c029a30 (4 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  521. nta.c:1289 agent_timer() nta: timer not set
  522. nta.c:7140 _nta_incoming_timer() nta: timer I fired, terminate 407 response
  523. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  524. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/5 term, 1/6 free
  525. nta.c:1296 agent_timer() nta: timer set next to 6111 ms
  526. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  527. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  528. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c027dd0 from (udp/195.74.100.112:5060) has 844 bytes, veclen = 1
  529. recv 844 bytes from udp/[87.127.251.183]:1272 at 14:18:07.068363:
  530.    ------------------------------------------------------------------------
  531.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  532.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK2822826693;rport
  533.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  534.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>
  535.    Call-ID: 2_2750365493@10.8.32.108
  536.    CSeq: 119 REGISTER
  537.    Contact: <sip:1001@10.8.32.108:5060>
  538.    Authorization: Digest username="1001", realm="fspbx1.evoip.enta.net", nonce="c7cb569d-64b5-4376-be1f-14c4d91114db", uri="sip:fspbx1.evoip.enta.net:5060", response="cafb6465b6aab6c65c7621d73af79ba8", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000039
  539.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  540.    Max-Forwards: 70
  541.    User-Agent: Yealink SIP-T23G 44.81.0.70
  542.    Expires: 60
  543.    Allow-Events: talk,hold,conference,refer,check-sync
  544.    Content-Length: 0
  545.    
  546.    ------------------------------------------------------------------------
  547. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c027dd0 (844 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  548. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 119)
  549. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  550. nta.c:3085 agent_recv_request() nta: REGISTER (119) going to a default leg
  551. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  552. nua_stack.c:899 nh_create() nua: nh_create: entering
  553. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  554. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  555. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c0106e0) called
  556. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c01c6d0, ...) called
  557. nua_stack.c:271 nua_stack_event() nua(0x7f812c0106e0): event i_register 100 Trying
  558. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  559. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  560. nua.c:879 nua_respond() nua: nua_respond: entering
  561. nua_stack.c:573 nua_stack_signal() nua(0x7f812c0106e0): recv signal r_respond 200 OK
  562. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  563. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c01c6d0, ...) called
  564. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1272
  565. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1272
  566. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1272
  567. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 613 bytes of 613 to udp/87.127.251.183:1272
  568. tport.c:3492 tport_send_msg() tport_vsend returned 613
  569. send 613 bytes to udp/[87.127.251.183]:1272 at 14:18:07.076645:
  570.    ------------------------------------------------------------------------
  571.    SIP/2.0 200 OK
  572.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK2822826693;rport=1272;received=87.127.251.183
  573.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  574.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=pNp7j92cHrF4F
  575.    Call-ID: 2_2750365493@10.8.32.108
  576.    CSeq: 119 REGISTER
  577.    Contact: <sip:1001@87.127.251.183:1272>;expires=30
  578.    Date: Tue, 05 Sep 2017 14:18:07 GMT
  579.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  580.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  581.    Supported: timer, path, replaces
  582.    Content-Length: 0
  583.    
  584.    ------------------------------------------------------------------------
  585. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (119)
  586. nua_stack.c:529 nua_signal() nua(0x7f812c0106e0): sent signal r_respond
  587. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  588. nua_stack.c:569 nua_stack_signal() nua(0x7f812c0106e0): recv signal r_destroy
  589. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  590. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c01c6d0) called
  591. nua_stack.c:529 nua_signal() nua(0x7f812c0106e0): sent signal r_destroy
  592. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  593. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  594. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  595. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  596. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c0197c0 from (udp/195.74.100.112:5060) has 4 bytes, veclen = 1
  597. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): bad msg 0x7f812c0197c0 (4 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  598. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  599. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  600. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/5 term, 1/6 free
  601. nta.c:1296 agent_timer() nta: timer set next to 2711 ms
  602. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  603. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  604. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c017b90 from (udp/195.74.100.112:5060) has 846 bytes, veclen = 1
  605. recv 846 bytes from udp/[87.127.251.183]:1277 at 14:18:09.785101:
  606.    ------------------------------------------------------------------------
  607.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  608.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK3039063866
  609.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  610.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>
  611.    Call-ID: 2_4292396569@10.8.32.151
  612.    CSeq: 229 REGISTER
  613.    Contact: <sip:1000@10.8.32.151:5060>
  614.    Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="9adf1b08-8976-4bbd-817c-d3dce30ac1dc", uri="sip:fspbx1.evoip.enta.net:5060", response="896cf9be928fef1c453cbecaaaed948e", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000020
  615.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  616.    Max-Forwards: 70
  617.    User-Agent: Yealink SIP-T23G 44.80.0.137
  618.    Expires: 3600
  619.    Allow-Events: talk,hold,conference,refer,check-sync
  620.    Content-Length: 0
  621.    
  622.    ------------------------------------------------------------------------
  623. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c017b90 (846 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  624. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 229)
  625. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  626. nta.c:3085 agent_recv_request() nta: REGISTER (229) going to a default leg
  627. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  628. nua_stack.c:899 nh_create() nua: nh_create: entering
  629. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  630. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  631. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c0197c0) called
  632. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c020190, ...) called
  633. nua_stack.c:271 nua_stack_event() nua(0x7f812c0197c0): event i_register 100 Trying
  634. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  635. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  636. nua.c:879 nua_respond() nua: nua_respond: entering
  637. nua_stack.c:573 nua_stack_signal() nua(0x7f812c0197c0): recv signal r_respond 200 OK
  638. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  639. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c020190, ...) called
  640. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  641. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  642. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  643. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 612 bytes of 612 to udp/87.127.251.183:1277
  644. tport.c:3492 tport_send_msg() tport_vsend returned 612
  645. send 612 bytes to udp/[87.127.251.183]:1277 at 14:18:09.800361:
  646.    ------------------------------------------------------------------------
  647.    SIP/2.0 200 OK
  648.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK3039063866;received=87.127.251.183
  649.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  650.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=QyF0m4Kge15pB
  651.    Call-ID: 2_4292396569@10.8.32.151
  652.    CSeq: 229 REGISTER
  653.    Contact: <sip:1000@87.127.251.183:1277>;expires=30
  654.    Date: Tue, 05 Sep 2017 14:18:09 GMT
  655.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  656.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  657.    Supported: timer, path, replaces
  658.    Content-Length: 0
  659.    
  660.    ------------------------------------------------------------------------
  661. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (229)
  662. nua_stack.c:529 nua_signal() nua(0x7f812c0197c0): sent signal r_respond
  663. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  664. nua_stack.c:569 nua_stack_signal() nua(0x7f812c0197c0): recv signal r_destroy
  665. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  666. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c020190) called
  667. nua_stack.c:529 nua_signal() nua(0x7f812c0197c0): sent signal r_destroy
  668. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  669. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  670. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  671. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  672. auth_digest.c:348 auth_digest_response() auth_response: 692f4d6290267e9166d17712d16e2b30 = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb21600015ae65d051487785d822c9e76a5fbdb307e8b:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  673. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  674. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  675. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  676. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  677. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  678. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  679. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  680. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  681. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  682. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  683. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  684. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  685. tport.c:3492 tport_send_msg() tport_vsend returned 874
  686. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:10.009051:
  687.    ------------------------------------------------------------------------
  688.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  689.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK6m13jv1rD9tSD
  690.    Max-Forwards: 70
  691.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  692.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  693.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  694.    CSeq: 111974228 REGISTER
  695.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  696.    Expires: 3600
  697.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  698.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  699.    Supported: timer, path, replaces
  700.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb21600015ae65d051487785d822c9e76a5fbdb307e8b", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="692f4d6290267e9166d17712d16e2b30"
  701.    Content-Length: 0
  702.    
  703.    ------------------------------------------------------------------------
  704. nta.c:8310 outgoing_send() nta: sent REGISTER (111974228) to udp/195.74.100.80:5060/sip
  705. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f81180854c0 for udp/195.74.100.112:5080 (already 1)
  706. nta.c:1350 set_timeout() nta: timer set to 32000 ms
  707. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  708. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  709. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  710. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118042100 from (udp/195.74.100.112:5080) has 537 bytes, veclen = 1
  711. recv 537 bytes from udp/[195.74.100.80]:5060 at 14:18:10.018926:
  712.    ------------------------------------------------------------------------
  713.    SIP/2.0 401 Unauthorized
  714.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bK6m13jv1rD9tSD
  715.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  716.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.c45e
  717.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  718.    CSeq: 111974228 REGISTER
  719.    WWW-Authenticate: Digest realm="EN33510464.voip-portal.co.uk", nonce="59aeb23100015b0b3d886c2d1d8d590b7fea74c428d50eb6", stale=true
  720.    Server: Entanet SIP Proxy V8.24
  721.    Content-Length: 0
  722.    
  723.    ------------------------------------------------------------------------
  724. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118042100 (537 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  725. nta.c:3299 agent_recv_response() nta: received 401 Unauthorized for REGISTER (111974228)
  726. nta.c:3366 agent_recv_response() nta: 401 Unauthorized is going to a transaction
  727. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 10.013 ms
  728. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f81180854c0 by 0x7f81180f1130 with 0x7f8118042100
  729. auth_digest.c:105 auth_digest_challenge_get() auth_digest_challenge_get(): got 3
  730. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  731. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  732. auth_digest.c:348 auth_digest_response() auth_response: 48a53bf9f50d0fd1ab6486abd47d6a1c = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb23100015b0b3d886c2d1d8d590b7fea74c428d50eb6:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  733. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  734. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  735. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  736. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  737. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  738. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  739. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  740. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  741. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  742. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  743. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  744. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  745. tport.c:3492 tport_send_msg() tport_vsend returned 874
  746. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:10.019189:
  747.    ------------------------------------------------------------------------
  748.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  749.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK7XtvmQjvajHcS
  750.    Max-Forwards: 70
  751.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  752.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  753.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  754.    CSeq: 111974229 REGISTER
  755.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  756.    Expires: 3600
  757.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  758.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  759.    Supported: timer, path, replaces
  760.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb23100015b0b3d886c2d1d8d590b7fea74c428d50eb6", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="48a53bf9f50d0fd1ab6486abd47d6a1c"
  761.    Content-Length: 0
  762.    
  763.    ------------------------------------------------------------------------
  764. nta.c:8310 outgoing_send() nta: sent REGISTER (111974229) to udp/195.74.100.80:5060/sip
  765. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f81180416f0 for udp/195.74.100.112:5080 (already 1)
  766. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 100 Request Authorized by Cache
  767. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  768. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  769. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  770. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  771. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  772. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118070990 from (udp/195.74.100.112:5080) has 481 bytes, veclen = 1
  773. recv 481 bytes from udp/[195.74.100.80]:5060 at 14:18:10.032294:
  774.    ------------------------------------------------------------------------
  775.    SIP/2.0 200 OK
  776.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bK7XtvmQjvajHcS
  777.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  778.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.9d5c
  779.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  780.    CSeq: 111974229 REGISTER
  781.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>;q=0;expires=60
  782.    Server: Entanet SIP Proxy V8.24
  783.    Content-Length: 0
  784.    
  785.    ------------------------------------------------------------------------
  786. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118070990 (481 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  787. nta.c:3299 agent_recv_response() nta: received 200 OK for REGISTER (111974229)
  788. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  789. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 13.196 ms
  790. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f81180416f0 by 0x7f8118065de0 with 0x7f8118070990
  791. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh register after 17 seconds (in [15..45])
  792. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 200 OK
  793. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  794. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  795. 2017-09-05 14:18:10.006225 [DEBUG] sofia_reg.c:2435 Changing expire time to 60 by request of proxy sip:EN33510464.voip-portal.co.uk
  796. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  797. nta.c:1296 agent_timer() nta: timer set next to 4010 ms
  798. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  799. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  800. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f81180664c0 from (udp/195.74.100.112:5080) has 1511 bytes, veclen = 1
  801. recv 1511 bytes from udp/[195.74.100.80]:5060 at 14:18:11.410425:
  802.    ------------------------------------------------------------------------
  803.    SIP/2.0 200 OK
  804.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bK5B8aH1gNg046H
  805.    Record-Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  806.    Record-Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  807.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  808.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  809.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  810.    CSeq: 111974474 INVITE
  811.    Contact: <sip:03331019574@195.74.100.81:5080;transport=tcp>
  812.    User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit
  813.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  814.    Supported: timer, path, replaces
  815.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  816.    Content-Type: application/sdp
  817.    Content-Disposition: session
  818.    Content-Length: 222
  819.    X-FS-Display-Name: 443331019574
  820.    X-FS-Display-Number: sip:443331019574@EN33510464.voip-portal.co.uk
  821.    X-FS-Support: update_display,send_info
  822.    Remote-Party-ID: "443331019574" <sip:443331019574@EN33510464.voip-portal.co.uk>;party=calling;privacy=off;screen=no
  823.    
  824.    v=0
  825.    o=FreeSWITCH 1504601255 1504601256 IN IP4 195.74.100.81
  826.    s=FreeSWITCH
  827.    c=IN IP4 195.74.100.81
  828.    t=0 0
  829.    m=audio 19836 RTP/AVP 9 101
  830.    a=rtpmap:9 G722/8000
  831.    a=rtpmap:101 telephone-event/8000
  832.    a=fmtp:101 0-16
  833.    a=ptime:20
  834.    ------------------------------------------------------------------------
  835. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f81180664c0 (1511 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  836. nta.c:3299 agent_recv_response() nta: received 200 OK for INVITE (111974474)
  837. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  838. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808fb60 by 0x7f8118080680 with 0x7f81180664c0
  839. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f8118084a90, (nil), 0x7f8118087b89, 222) called
  840. soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f8118084a90) called
  841. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f8118084a90, soa_process_answer): called
  842. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f811803df50, 0x7f8118082f70, ""): called
  843. soa_static.c:1304 offer_answer_step() soa_static(0x7f8118084a90, soa_process_answer): upgrade codecs with remote description
  844. soa_static.c:1446 offer_answer_step() soa_static(0x7f8118084a90, soa_process_answer): storing local description
  845. soa.c:1730 soa_activate() soa_activate(static::0x7f8118084a90, (nil)) called
  846. nua_session.c:988 nua_session_client_response() nua(0x7f8128007c00): INVITE: processed SDP answer in 200 OK
  847. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event r_invite 200 OK
  848. nua_session.c:4139 signal_call_state_change() nua(0x7f8128007c00): call state changed: proceeding -> completing, received answer
  849. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f8118084a90, [0x7f813165d608], [0x7f813165d610], [(nil)]) called
  850. soa.c:616 soa_get_params() soa_get_params(static::0x7f8118084a90, ...) called
  851. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_state 200 OK
  852. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  853. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  854. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  855. 2017-09-05 14:18:11.406226 [INFO] sofia.c:1348 sofia/external/03331019574 Update Callee ID to "443331019574" <sip:443331019574@EN33510464.voip-portal.co.uk>
  856. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  857. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  858. 2017-09-05 14:18:11.406226 [DEBUG] sofia.c:7283 Channel sofia/external/03331019574 entering state [completing][200]
  859. 2017-09-05 14:18:11.406226 [DEBUG] sofia.c:7293 Remote SDP:
  860. v=0
  861. o=FreeSWITCH 1504601255 1504601256 IN IP4 195.74.100.81
  862. s=FreeSWITCH
  863. c=IN IP4 195.74.100.81
  864. t=0 0
  865. m=audio 19836 RTP/AVP 9 101
  866. a=rtpmap:9 G722/8000
  867. a=rtpmap:101 telephone-event/8000
  868. a=fmtp:101 0-16
  869. a=ptime:20
  870.  
  871. nua.c:639 nua_ack() nua: nua_ack: entering
  872. nua_stack.c:569 nua_stack_signal() nua(0x7f8128007c00): recv signal r_ack
  873. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  874. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  875. soa.c:1730 soa_activate() soa_activate(static::0x7f8118084a90, (nil)) called
  876. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  877. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  878. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  879. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  880. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 624 bytes of 624 to udp/195.74.100.80:5060
  881. tport.c:3492 tport_send_msg() tport_vsend returned 624
  882. send 624 bytes to udp/[195.74.100.80]:5060 at 14:18:11.413200:
  883.    ------------------------------------------------------------------------
  884.    ACK sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  885.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK86KNpj3Z7t7ym
  886.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  887.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  888.    Max-Forwards: 70
  889.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  890.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  891.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  892.    CSeq: 111974474 ACK
  893.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  894.    Content-Length: 0
  895.    
  896.    ------------------------------------------------------------------------
  897. nta.c:8310 outgoing_send() nta: sent ACK (111974474) to */195.74.100.80:5060
  898. nua_session.c:4139 signal_call_state_change() nua(0x7f8128007c00): call state changed: completing -> ready
  899. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_state 200 ACK sent
  900. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_active 200 Call active
  901. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  902. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  903. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_ack
  904. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  905. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  906. 2017-09-05 14:18:11.406226 [DEBUG] sofia.c:7283 Channel sofia/external/03331019574 entering state [ready][200]
  907. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  908. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  909. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  910. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  911. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  912. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:3430 Set Codec sofia/external/03331019574 G722/8000 20 ms 160 samples 64000 bits 1 channels
  913. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_codec.c:111 sofia/external/03331019574 Original read codec set to G722:9
  914. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  915. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5432 sofia/external/03331019574 Set 2833 dtmf send payload to 101 recv payload to 101
  916. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8149 AUDIO RTP [sofia/external/03331019574] 195.74.100.112 port 28872 -> 195.74.100.81 port 19836 codec: 9 ms: 20
  917. 2017-09-05 14:18:11.406226 [DEBUG] switch_rtp.c:4164 Starting timer [soft] 160 bytes per 20ms
  918. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8453 sofia/external/03331019574 Set 2833 dtmf send payload to 101
  919. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8460 sofia/external/03331019574 Set 2833 dtmf receive payload to 101
  920. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8483 sofia/external/03331019574 Set rtp dtmf delay to 40
  921. 2017-09-05 14:18:11.406226 [NOTICE] sofia.c:8419 Channel [sofia/external/03331019574] has been answered
  922. 2017-09-05 14:18:11.406226 [DEBUG] switch_channel.c:3781 (sofia/external/03331019574) Callstate Change RINGING -> ACTIVE
  923. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  924. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  925. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  926. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  927. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  928. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  929. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  930. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  931. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  932. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  933. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  934. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  935. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  936. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  937. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  938. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  939. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  940. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  941. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  942. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:3430 Set Codec sofia/internal/1000@fspbx1.evoip.enta.net:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels
  943. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Original read codec set to G722:9
  944. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  945. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:5432 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  946. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8149 AUDIO RTP [sofia/internal/1000@fspbx1.evoip.enta.net:5060] 195.74.100.112 port 21592 -> 10.8.32.151 port 11930 codec: 9 ms: 20
  947. 2017-09-05 14:18:11.406226 [DEBUG] switch_rtp.c:4164 Starting timer [soft] 160 bytes per 20ms
  948. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8453 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Set 2833 dtmf send payload to 101
  949. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8460 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Set 2833 dtmf receive payload to 101
  950. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8483 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Set rtp dtmf delay to 40
  951. 2017-09-05 14:18:11.406226 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@fspbx1.evoip.enta.net:5060!
  952. 2017-09-05 14:18:11.406226 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Callstate Change RINGING -> EARLY
  953. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_media.c:8132 Audio params are unchanged for sofia/internal/1000@fspbx1.evoip.enta.net:5060.
  954. 2017-09-05 14:18:11.406226 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1000@fspbx1.evoip.enta.net:5060:
  955. v=0
  956. o=FreeSWITCH 1504599499 1504599500 IN IP4 195.74.100.112
  957. s=FreeSWITCH
  958. c=IN IP4 195.74.100.112
  959. t=0 0
  960. m=audio 21592 RTP/AVP 9 101
  961. a=rtpmap:9 G722/8000
  962. a=rtpmap:101 telephone-event/8000
  963. a=fmtp:101 0-16
  964. a=ptime:20
  965. a=sendrecv
  966.  
  967. nua.c:879 nua_respond() nua: nua_respond: entering
  968. nua_stack.c:573 nua_stack_signal() nua(0x7f812c014200): recv signal r_respond 200 OK
  969. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  970. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  971. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f812c0281e0, (nil), 0x7f811c05b968, -1) called
  972. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f812c0281e0, (nil), 0x7f811c05b968, -1) called
  973. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  974. soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f812c0281e0) called
  975. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f812c0281e0, soa_generate_answer): called
  976. soa_static.c:1189 offer_answer_step() soa_static(0x7f812c0281e0, soa_generate_answer): generating local description
  977. soa_static.c:1230 offer_answer_step() soa_static(0x7f812c0281e0, soa_generate_answer): upgrade with remote description
  978. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f8131119ab0, 0x7f812c029350, ""): called
  979. soa_static.c:1446 offer_answer_step() soa_static(0x7f812c0281e0, soa_generate_answer): storing local description
  980. soa.c:1730 soa_activate() soa_activate(static::0x7f812c0281e0, (nil)) called
  981. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f812c0281e0, [(nil)], [0x7f813111bc38], [0x7f813111bc34]) called
  982. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  983. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  984. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  985. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 1186 bytes of 1186 to udp/87.127.251.183:1277
  986. tport.c:3492 tport_send_msg() tport_vsend returned 1186
  987. send 1186 bytes to udp/[87.127.251.183]:1277 at 14:18:11.427777:
  988.    ------------------------------------------------------------------------
  989.    SIP/2.0 200 OK
  990.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK4245134600;received=87.127.251.183
  991.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  992.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  993.    Call-ID: 2_1100593423@10.8.32.151
  994.    CSeq: 2 INVITE
  995.    Contact: <sip:03331019574@195.74.100.112:5060;transport=udp>
  996.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  997.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  998.    Supported: timer, path, replaces
  999.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  1000.    Session-Expires: 120;refresher=uas
  1001.    Content-Type: application/sdp
  1002.    Content-Disposition: session
  1003.    Content-Length: 224
  1004.    Remote-Party-ID: "443331019574" <sip:443331019574@fspbx1.evoip.enta.net>;party=calling;privacy=off;screen=no
  1005.    
  1006.    v=0
  1007.    o=FreeSWITCH 1504599499 1504599500 IN IP4 195.74.100.112
  1008.    s=FreeSWITCH
  1009.    c=IN IP4 195.74.100.112
  1010.    t=0 0
  1011.    m=audio 21592 RTP/AVP 9 101
  1012.    a=rtpmap:9 G722/8000
  1013.    a=rtpmap:101 telephone-event/8000
  1014.    a=fmtp:101 0-16
  1015.    a=ptime:20
  1016.    ------------------------------------------------------------------------
  1017. nta.c:6797 incoming_reply() nta: sent 200 OK for INVITE (2)
  1018. nua_session.c:4139 signal_call_state_change() nua(0x7f812c014200): call state changed: early -> completed, sent answer
  1019. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f812c0281e0, [0x7f813111bce8], [0x7f813111bcf0], [(nil)]) called
  1020. soa.c:616 soa_get_params() soa_get_params(static::0x7f812c0281e0, ...) called
  1021. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 200 OK
  1022. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1023. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_respond
  1024. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1025. 2017-09-05 14:18:11.406226 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [completed][200]
  1026. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1027. 2017-09-05 14:18:11.406226 [NOTICE] switch_ivr_originate.c:3662 Channel [sofia/internal/1000@fspbx1.evoip.enta.net:5060] has been answered
  1028. 2017-09-05 14:18:11.406226 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Callstate Change EARLY -> ACTIVE
  1029. 2017-09-05 14:18:11.406226 [DEBUG] switch_ivr_originate.c:3720 Originate Resulted in Success: [sofia/external/03331019574]
  1030. 2017-09-05 14:18:11.406226 [DEBUG] switch_ivr_bridge.c:1744 (sofia/external/03331019574) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  1031. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 8)
  1032. 2017-09-05 14:18:11.406226 [DEBUG] switch_core_state_machine.c:653 (sofia/external/03331019574) State EXCHANGE_MEDIA
  1033. 2017-09-05 14:18:11.406226 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
  1034. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1035. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1036. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c02ba00 from (udp/195.74.100.112:5060) has 705 bytes, veclen = 1
  1037. recv 705 bytes from udp/[87.127.251.183]:1277 at 14:18:11.448749:
  1038.    ------------------------------------------------------------------------
  1039.    ACK sip:03331019574@195.74.100.112:5060;transport=udp SIP/2.0
  1040.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK2643518755
  1041.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  1042.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  1043.    Call-ID: 2_1100593423@10.8.32.151
  1044.    CSeq: 2 ACK
  1045.    Contact: <sip:1000@10.8.32.151:5060>
  1046.    Proxy-Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="21e292a6-2542-4628-ae3f-2b3b4bcdee63", uri="sip:03331019574@fspbx1.evoip.enta.net:5060", response="5c8c1d3c1e93369dd6e29c7481d3e6fe", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
  1047.    Max-Forwards: 70
  1048.    User-Agent: Yealink SIP-T23G 44.80.0.137
  1049.    Content-Length: 0
  1050.    
  1051.    ------------------------------------------------------------------------
  1052. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c02ba00 (705 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1053. nta.c:2880 agent_recv_request() nta: received ACK sip:03331019574@195.74.100.112:5060;transport=udp SIP/2.0 (CSeq 2)
  1054. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  1055. nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2)
  1056. nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering
  1057. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f812c0281e0) called
  1058. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_ack 200 OK
  1059. nua_session.c:4139 signal_call_state_change() nua(0x7f812c014200): call state changed: completed -> ready
  1060. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 200 OK
  1061. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_active 200 Call active
  1062. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh session after 57 seconds (in [55..65])
  1063. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1064. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1065. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1066. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  1067. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  1068. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118088800 from (udp/195.74.100.112:5080) has 875 bytes, veclen = 1
  1069. recv 875 bytes from udp/[195.74.100.80]:5060 at 14:18:11.449867:
  1070.    ------------------------------------------------------------------------
  1071.    INFO sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet SIP/2.0
  1072.    Via: SIP/2.0/UDP 195.74.100.80:5060;branch=z9hG4bK0969.21fc5961.0;i=c35
  1073.    Via: SIP/2.0/TCP 195.74.100.81:5080;rport=33158;received=195.74.100.81;branch=z9hG4bKFc5e9tK7gQK0p
  1074.    Max-Forwards: 69
  1075.    From: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1076.    To: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1077.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1078.    CSeq: 111974481 INFO
  1079.    Contact: <sip:03331019574@195.74.100.81:5080;transport=tcp>
  1080.    User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit
  1081.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  1082.    Supported: timer, path, replaces
  1083.    Content-Type: message/update_display
  1084.    Content-Length: 0
  1085.    X-FS-Display-Name: 443331019574
  1086.    X-FS-Display-Number: 443331019574
  1087.    
  1088.    ------------------------------------------------------------------------
  1089. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118088800 (875 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  1090. nta.c:2880 agent_recv_request() nta: received INFO sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet SIP/2.0 (CSeq 111974481)
  1091. nta.c:3248 agent_aliases() nta: canonizing sip:gw+entanet@195.74.100.112:5080 with contact
  1092. nta.c:3060 agent_recv_request() nta: INFO (111974481) going to existing leg
  1093. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1094. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_info 100 Trying
  1095. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1096. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1097. nua.c:879 nua_respond() nua: nua_respond: entering
  1098. nua_stack.c:573 nua_stack_signal() nua(0x7f8128007c00): recv signal r_respond 200 OK
  1099. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1100. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  1101. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = UDP/195.74.100.80:5060
  1102. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1103. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name UDP/195.74.100.80:5060
  1104. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 612 bytes of 612 to udp/195.74.100.80:5060
  1105. tport.c:3492 tport_send_msg() tport_vsend returned 612
  1106. send 612 bytes to udp/[195.74.100.80]:5060 at 14:18:11.454996:
  1107.    ------------------------------------------------------------------------
  1108.    SIP/2.0 200 OK
  1109.    Via: SIP/2.0/UDP 195.74.100.80:5060;branch=z9hG4bK0969.21fc5961.0;i=c35
  1110.    Via: SIP/2.0/TCP 195.74.100.81:5080;rport=33158;received=195.74.100.81;branch=z9hG4bKFc5e9tK7gQK0p
  1111.    From: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1112.    To: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1113.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1114.    CSeq: 111974481 INFO
  1115.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1116.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1117.    Supported: timer, path, replaces
  1118.    Content-Length: 0
  1119.    
  1120.    ------------------------------------------------------------------------
  1121. nta.c:6797 incoming_reply() nta: sent 200 OK for INFO (111974481)
  1122. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_respond
  1123. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1124. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1125. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1126. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1127. 2017-09-05 14:18:11.446215 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [ready][200]
  1128. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1129. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1130. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1131. nua.c:798 nua_info() nua: nua_info: entering
  1132. nua_stack.c:569 nua_stack_signal() nua(0x7f8128007c00): recv signal r_info
  1133. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1134. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  1135. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  1136. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1137. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1138. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1139. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1140. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1141. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:11.474910:
  1142.    ------------------------------------------------------------------------
  1143.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1144.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1145.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1146.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1147.    Max-Forwards: 70
  1148.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1149.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1150.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1151.    CSeq: 111974475 INFO
  1152.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1153.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1154.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1155.    Supported: timer, path, replaces
  1156.    Content-Type: message/update_display
  1157.    Content-Length: 0
  1158.    X-FS-Display-Name: Extension 1000
  1159.    X-FS-Display-Number: 441156870140
  1160.    
  1161.    ------------------------------------------------------------------------
  1162. nta.c:8310 outgoing_send() nta: sent INFO (111974475) to */195.74.100.80:5060
  1163. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1164. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  1165. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_info
  1166. nua.c:810 nua_update() nua: nua_update: entering
  1167. nua_stack.c:569 nua_stack_signal() nua(0x7f812c014200): recv signal r_update
  1168. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1169. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  1170. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f812c0281e0) called
  1171. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f812c0281e0, 0) called
  1172. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f812c0281e0, soa_generate_offer): called
  1173. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f812c029c40, (nil), ""): called
  1174. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f812c0281e0, [(nil)], [0x7f813111bc48], [0x7f813111bc44]) called
  1175. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  1176. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = udp/87.127.251.183:1277
  1177. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  1178. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name udp/87.127.251.183:1277
  1179. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 1013 bytes of 1013 to udp/87.127.251.183:1277
  1180. tport.c:3492 tport_send_msg() tport_vsend returned 1013
  1181. send 1013 bytes to udp/[87.127.251.183]:1277 at 14:18:11.484486:
  1182.    ------------------------------------------------------------------------
  1183.    UPDATE sip:1000@10.8.32.151:5060 SIP/2.0
  1184.    Via: SIP/2.0/UDP 195.74.100.112;rport;branch=z9hG4bKpX7Nt1rXFZBQD
  1185.    Max-Forwards: 70
  1186.    From: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  1187.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  1188.    Call-ID: 2_1100593423@10.8.32.151
  1189.    CSeq: 111974481 UPDATE
  1190.    Contact: <sip:03331019574@195.74.100.112:5060;transport=udp>
  1191.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1192.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  1193.    Supported: timer, path, replaces
  1194.    Session-Expires: 120;refresher=uac
  1195.    Min-SE: 120
  1196.    Content-Type: application/sdp
  1197.    Content-Disposition: session
  1198.    Content-Length: 224
  1199.    P-Asserted-Identity: "443331019574" <sip:443331019574@195.74.100.112>
  1200.    
  1201.    v=0
  1202.    o=FreeSWITCH 1504599499 1504599500 IN IP4 195.74.100.112
  1203.    s=FreeSWITCH
  1204.    c=IN IP4 195.74.100.112
  1205.    t=0 0
  1206.    m=audio 21592 RTP/AVP 9 101
  1207.    a=rtpmap:9 G722/8000
  1208.    a=rtpmap:101 telephone-event/8000
  1209.    a=fmtp:101 0-16
  1210.    a=ptime:20
  1211.    ------------------------------------------------------------------------
  1212. nta.c:8310 outgoing_send() nta: sent UPDATE (111974481) to udp/87.127.251.183:1277
  1213. tport.c:4160 tport_pend() tport_pend(0x7f812c0045a0): pending 0x7f812c02bd10 for udp/195.74.100.112:5060 (already 0)
  1214. nua_session.c:4145 signal_call_state_change() nua(0x7f812c014200): ready call updated: calling sent offer
  1215. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f812c0281e0, [0x7f813111bc28], [0x7f813111bc30], [(nil)]) called
  1216. nua_stack.c:269 nua_stack_event() nua(0x7f812c014200): event i_state UPDATE sent
  1217. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1218. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_update
  1219. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1220. 2017-09-05 14:18:11.466214 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [calling][0]
  1221. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1222. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1223. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1224. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c02a390 from (udp/195.74.100.112:5060) has 625 bytes, veclen = 1
  1225. recv 625 bytes from udp/[87.127.251.183]:1277 at 14:18:11.510858:
  1226.    ------------------------------------------------------------------------
  1227.    SIP/2.0 200 OK
  1228.    Via: SIP/2.0/UDP 195.74.100.112;rport=5060;branch=z9hG4bKpX7Nt1rXFZBQD
  1229.    From: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  1230.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  1231.    Call-ID: 2_1100593423@10.8.32.151
  1232.    CSeq: 111974481 UPDATE
  1233.    Contact: <sip:1000@10.8.32.151:5060>
  1234.    Content-Type: application/sdp
  1235.    User-Agent: Yealink SIP-T23G 44.80.0.137
  1236.    Content-Length: 209
  1237.    
  1238.    v=0
  1239.    o=- 20111 20112 IN IP4 10.8.32.151
  1240.    s=SDP data
  1241.    c=IN IP4 10.8.32.151
  1242.    t=0 0
  1243.    m=audio 11930 RTP/AVP 9 101
  1244.    a=rtpmap:9 G722/8000
  1245.    a=ptime:20
  1246.    a=rtpmap:101 telephone-event/8000
  1247.    a=fmtp:101 0-15
  1248.    a=sendrecv
  1249.    ------------------------------------------------------------------------
  1250. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c02a390 (625 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1251. nta.c:3299 agent_recv_response() nta: received 200 OK for UPDATE (111974481)
  1252. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  1253. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 26.475 ms
  1254. tport.c:4222 tport_release() tport_release(0x7f812c0045a0): 0x7f812c02bd10 by 0x7f812c020d80 with 0x7f812c02a390
  1255. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh session after 57 seconds (in [55..65])
  1256. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f812c0281e0, (nil), 0x7f812c02e750, 209) called
  1257. soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f812c0281e0) called
  1258. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f812c0281e0, soa_process_answer): called
  1259. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f812c029c40, 0x7f812c02d890, ""): called
  1260. soa_static.c:1304 offer_answer_step() soa_static(0x7f812c0281e0, soa_process_answer): upgrade codecs with remote description
  1261. soa.c:1730 soa_activate() soa_activate(static::0x7f812c0281e0, (nil)) called
  1262. nua_session.c:988 nua_session_client_response() nua(0x7f812c014200): UPDATE: processed SDP answer in 200 OK
  1263. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event r_update 200 OK
  1264. nua_session.c:4145 signal_call_state_change() nua(0x7f812c014200): ready call updated: ready received answer
  1265. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f812c0281e0, [0x7f813111b6f8], [0x7f813111b700], [(nil)]) called
  1266. soa.c:616 soa_get_params() soa_get_params(static::0x7f812c0281e0, ...) called
  1267. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 200 OK
  1268. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_active 200 Call active
  1269. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1270. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1271. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1272. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1273. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1274. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1275. 2017-09-05 14:18:11.506225 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 entering state [ready][200]
  1276. 2017-09-05 14:18:11.506225 [DEBUG] sofia.c:7293 Remote SDP:
  1277. v=0
  1278. o=- 20111 20112 IN IP4 10.8.32.151
  1279. s=SDP data
  1280. c=IN IP4 10.8.32.151
  1281. t=0 0
  1282. m=audio 11930 RTP/AVP 9 101
  1283. a=rtpmap:9 G722/8000
  1284. a=rtpmap:101 telephone-event/8000
  1285. a=fmtp:101 0-15
  1286. a=ptime:20
  1287.  
  1288. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  1289. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  1290. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  1291. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  1292. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  1293. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  1294. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:5432 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  1295. 2017-09-05 14:18:11.506225 [DEBUG] sofia.c:8262 Processing updated SDP
  1296. 2017-09-05 14:18:11.506225 [DEBUG] switch_core_media.c:8132 Audio params are unchanged for sofia/internal/1000@fspbx1.evoip.enta.net:5060.
  1297. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1298. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1299. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1300. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  1301. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  1302. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/6 free
  1303. nta.c:1296 agent_timer() nta: timer set next to 4666 ms
  1304. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1305. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1306. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1307. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1308. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1309. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1310. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1311. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:12.475186:
  1312.    ------------------------------------------------------------------------
  1313.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1314.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1315.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1316.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1317.    Max-Forwards: 70
  1318.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1319.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1320.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1321.    CSeq: 111974475 INFO
  1322.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1323.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1324.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1325.    Supported: timer, path, replaces
  1326.    Content-Type: message/update_display
  1327.    Content-Length: 0
  1328.    X-FS-Display-Name: Extension 1000
  1329.    X-FS-Display-Number: 441156870140
  1330.    
  1331.    ------------------------------------------------------------------------
  1332. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1333. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1334. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/3 term, 0/5 free
  1335. nta.c:1296 agent_timer() nta: timer set next to 2000 ms
  1336. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1337. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1338. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1339. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1340. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1341. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1342. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1343. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:14.478182:
  1344.    ------------------------------------------------------------------------
  1345.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1346.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1347.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1348.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1349.    Max-Forwards: 70
  1350.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1351.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1352.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1353.    CSeq: 111974475 INFO
  1354.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1355.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1356.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1357.    Supported: timer, path, replaces
  1358.    Content-Type: message/update_display
  1359.    Content-Length: 0
  1360.    X-FS-Display-Name: Extension 1000
  1361.    X-FS-Display-Number: 441156870140
  1362.    
  1363.    ------------------------------------------------------------------------
  1364. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1365. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1366. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/3 term, 0/5 free
  1367. nta.c:1296 agent_timer() nta: timer set next to 543 ms
  1368. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate REGISTER (111974228)
  1369. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  1370. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/2 tout, 1/3 term, 1/5 free
  1371. nta.c:1296 agent_timer() nta: timer set next to 13 ms
  1372. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate REGISTER (111974229)
  1373. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  1374. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/2 tout, 1/2 term, 1/4 free
  1375. nta.c:1296 agent_timer() nta: timer set next to 3446 ms
  1376. nta.c:7140 _nta_incoming_timer() nta: timer I fired, terminate 200 response
  1377. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  1378. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/5 term, 1/5 free
  1379. nta.c:1296 agent_timer() nta: timer set next to 62 ms
  1380. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate UPDATE (111974481)
  1381. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813111bd40)
  1382. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
  1383. nta.c:1296 agent_timer() nta: timer set next to 7564 ms
  1384. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1385. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1386. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c00d040 from (udp/195.74.100.112:5060) has 712 bytes, veclen = 1
  1387. recv 712 bytes from udp/[87.127.251.183]:1277 at 14:18:18.451073:
  1388.    ------------------------------------------------------------------------
  1389.    BYE sip:03331019574@195.74.100.112:5060;transport=udp SIP/2.0
  1390.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK2284330756
  1391.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  1392.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  1393.    Call-ID: 2_1100593423@10.8.32.151
  1394.    CSeq: 3 BYE
  1395.    Contact: <sip:1000@10.8.32.151:5060>
  1396.    Proxy-Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="21e292a6-2542-4628-ae3f-2b3b4bcdee63", uri="sip:03331019574@195.74.100.112:5060;transport=udp", response="fa0524a63033ac491b78e4372a25ccd6", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000002
  1397.    Max-Forwards: 70
  1398.    User-Agent: Yealink SIP-T23G 44.80.0.137
  1399.    Content-Length: 0
  1400.    
  1401.    ------------------------------------------------------------------------
  1402. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c00d040 (712 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1403. nta.c:2880 agent_recv_request() nta: received BYE sip:03331019574@195.74.100.112:5060;transport=udp SIP/2.0 (CSeq 3)
  1404. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  1405. nta.c:3248 agent_aliases() nta: canonizing sip:03331019574@195.74.100.112:5060 with contact
  1406. nta.c:3060 agent_recv_request() nta: BYE (3) going to existing leg
  1407. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1408. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_bye 100 Trying
  1409. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1410. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1411. 2017-09-05 14:18:18.446227 [NOTICE] sofia.c:1079 Hangup sofia/internal/1000@fspbx1.evoip.enta.net:5060 [CS_EXECUTE] [NORMAL_CLEARING]
  1412. nua.c:879 nua_respond() nua: nua_respond: entering
  1413. nua_stack.c:573 nua_stack_signal() nua(0x7f812c014200): recv signal r_respond 200 OK
  1414. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1415. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0281e0, ...) called
  1416. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  1417. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  1418. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  1419. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 517 bytes of 517 to udp/87.127.251.183:1277
  1420. tport.c:3492 tport_send_msg() tport_vsend returned 517
  1421. send 517 bytes to udp/[87.127.251.183]:1277 at 14:18:18.466642:
  1422.    ------------------------------------------------------------------------
  1423.    SIP/2.0 200 OK
  1424.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK2284330756;received=87.127.251.183
  1425.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=1118572399
  1426.    To: <sip:03331019574@fspbx1.evoip.enta.net:5060>;tag=NcXeHej9KFSHm
  1427.    Call-ID: 2_1100593423@10.8.32.151
  1428.    CSeq: 3 BYE
  1429.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1430.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  1431.    Supported: timer, path, replaces
  1432.    Content-Length: 0
  1433.    
  1434.    ------------------------------------------------------------------------
  1435. nta.c:6797 incoming_reply() nta: sent 200 OK for BYE (3)
  1436. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f812c014200): removing session usage
  1437. nua_session.c:4139 signal_call_state_change() nua(0x7f812c014200): call state changed: ready -> terminated
  1438. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_state 200 Session Terminated
  1439. nua_stack.c:271 nua_stack_event() nua(0x7f812c014200): event i_terminated 200 Session Terminated
  1440. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c0281e0) called
  1441. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f812c0234c0)
  1442. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1443. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1444. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_respond
  1445. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  1446. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1447. nua_stack.c:569 nua_stack_signal() nua(0x7f812c014200): recv signal r_destroy
  1448. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  1449. nua_stack.c:529 nua_signal() nua(0x7f812c014200): sent signal r_destroy
  1450. 2017-09-05 14:18:18.446227 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1000@fspbx1.evoip.enta.net:5060]
  1451. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1452. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1453. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1454. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1455. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1456. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1457. 2017-09-05 14:18:18.446227 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/external/03331019574]
  1458. 2017-09-05 14:18:18.446227 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/external/03331019574 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  1459. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:653 (sofia/external/03331019574) State EXCHANGE_MEDIA going to sleep
  1460. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_HANGUP (Cur 2 Tot 8)
  1461. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:850 (sofia/external/03331019574) Callstate Change ACTIVE -> HANGUP
  1462. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:852 (sofia/external/03331019574) State HANGUP
  1463. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:443 sofia/external/03331019574 Overriding SIP cause 480 with 200 from the other leg
  1464. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:449 Channel sofia/external/03331019574 hanging up, cause: NORMAL_CLEARING
  1465. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/external/03331019574
  1466. nua.c:645 nua_bye() nua: nua_bye: entering
  1467. nua_stack.c:569 nua_stack_signal() nua(0x7f8128007c00): recv signal r_bye
  1468. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_bye
  1469. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:60 sofia/external/03331019574 Standard HANGUP, cause: NORMAL_CLEARING
  1470. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:852 (sofia/external/03331019574) State HANGUP going to sleep
  1471. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:619 (sofia/external/03331019574) State Change CS_HANGUP -> CS_REPORTING
  1472. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:584 (sofia/external/03331019574) Running State Change CS_REPORTING (Cur 2 Tot 8)
  1473. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:938 (sofia/external/03331019574) State REPORTING
  1474. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:174 sofia/external/03331019574 Standard REPORTING, cause: NORMAL_CLEARING
  1475. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:938 (sofia/external/03331019574) State REPORTING going to sleep
  1476. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:610 (sofia/external/03331019574) State Change CS_REPORTING -> CS_DESTROY
  1477. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_session.c:1713 Session 8 (sofia/external/03331019574) Locked, Waiting on external entities
  1478. 2017-09-05 14:18:18.446227 [DEBUG] switch_ivr_bridge.c:1846 sofia/internal/1000@fspbx1.evoip.enta.net:5060 skip receive message [TRANSFER] (channel is hungup already)
  1479. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_session.c:2885 sofia/internal/1000@fspbx1.evoip.enta.net:5060 skip receive message [PHONE_EVENT] (channel is hungup already)
  1480. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State EXECUTE going to sleep
  1481. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_HANGUP (Cur 2 Tot 8)
  1482. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Callstate Change ACTIVE -> HANGUP
  1483. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State HANGUP
  1484. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 hanging up, cause: NORMAL_CLEARING
  1485. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard HANGUP, cause: NORMAL_CLEARING
  1486. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State HANGUP going to sleep
  1487. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State Change CS_HANGUP -> CS_REPORTING
  1488. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1489. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1490. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1491. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1492. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1493. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1494. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1495. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:18.479508:
  1496.    ------------------------------------------------------------------------
  1497.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1498.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1499.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1500.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1501.    Max-Forwards: 70
  1502.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1503.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1504.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1505.    CSeq: 111974475 INFO
  1506.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1507.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1508.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1509.    Supported: timer, path, replaces
  1510.    Content-Type: message/update_display
  1511.    Content-Length: 0
  1512.    X-FS-Display-Name: Extension 1000
  1513.    X-FS-Display-Number: 441156870140
  1514.    
  1515.    ------------------------------------------------------------------------
  1516. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1517. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1518. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  1519. nta.c:1296 agent_timer() nta: timer set next to 4001 ms
  1520. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_REPORTING (Cur 2 Tot 8)
  1521. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State REPORTING
  1522. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard REPORTING, cause: NORMAL_CLEARING
  1523. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State REPORTING going to sleep
  1524. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State Change CS_REPORTING -> CS_DESTROY
  1525. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_session.c:1713 Session 7 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Locked, Waiting on external entities
  1526. 2017-09-05 14:18:18.446227 [NOTICE] switch_core_session.c:1731 Session 7 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Ended
  1527. 2017-09-05 14:18:18.446227 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@fspbx1.evoip.enta.net:5060 [CS_DESTROY]
  1528. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) Running State Change CS_DESTROY (Cur 1 Tot 8)
  1529. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State DESTROY
  1530. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:354 sofia/internal/1000@fspbx1.evoip.enta.net:5060 SOFIA DESTROY
  1531. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@fspbx1.evoip.enta.net:5060 Standard DESTROY
  1532. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@fspbx1.evoip.enta.net:5060) State DESTROY going to sleep
  1533. 2017-09-05 14:18:18.446227 [NOTICE] switch_core_session.c:1731 Session 8 (sofia/external/03331019574) Ended
  1534. 2017-09-05 14:18:18.446227 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/03331019574 [CS_DESTROY]
  1535. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:741 (sofia/external/03331019574) Running State Change CS_DESTROY (Cur 0 Tot 8)
  1536. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:751 (sofia/external/03331019574) State DESTROY
  1537. 2017-09-05 14:18:18.446227 [DEBUG] mod_sofia.c:354 sofia/external/03331019574 SOFIA DESTROY
  1538. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:181 sofia/external/03331019574 Standard DESTROY
  1539. 2017-09-05 14:18:18.446227 [DEBUG] switch_core_state_machine.c:751 (sofia/external/03331019574) State DESTROY going to sleep
  1540. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1541. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1542. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c014120 from (udp/195.74.100.112:5060) has 844 bytes, veclen = 1
  1543. recv 844 bytes from udp/[87.127.251.183]:1272 at 14:18:22.071898:
  1544.    ------------------------------------------------------------------------
  1545.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  1546.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK1193402102;rport
  1547.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  1548.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>
  1549.    Call-ID: 2_2750365493@10.8.32.108
  1550.    CSeq: 120 REGISTER
  1551.    Contact: <sip:1001@10.8.32.108:5060>
  1552.    Authorization: Digest username="1001", realm="fspbx1.evoip.enta.net", nonce="c7cb569d-64b5-4376-be1f-14c4d91114db", uri="sip:fspbx1.evoip.enta.net:5060", response="9a970e39e6013e4c083f1e9b95b0fed1", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000040
  1553.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  1554.    Max-Forwards: 70
  1555.    User-Agent: Yealink SIP-T23G 44.81.0.70
  1556.    Expires: 60
  1557.    Allow-Events: talk,hold,conference,refer,check-sync
  1558.    Content-Length: 0
  1559.    
  1560.    ------------------------------------------------------------------------
  1561. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c014120 (844 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1562. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 120)
  1563. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  1564. nta.c:3085 agent_recv_request() nta: REGISTER (120) going to a default leg
  1565. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1566. nua_stack.c:899 nh_create() nua: nh_create: entering
  1567. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  1568. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1569. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c028600) called
  1570. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c018150, ...) called
  1571. nua_stack.c:271 nua_stack_event() nua(0x7f812c028600): event i_register 100 Trying
  1572. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1573. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1574. nua.c:879 nua_respond() nua: nua_respond: entering
  1575. nua_stack.c:573 nua_stack_signal() nua(0x7f812c028600): recv signal r_respond 200 OK
  1576. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1577. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c018150, ...) called
  1578. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1272
  1579. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1272
  1580. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1272
  1581. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 613 bytes of 613 to udp/87.127.251.183:1272
  1582. tport.c:3492 tport_send_msg() tport_vsend returned 613
  1583. send 613 bytes to udp/[87.127.251.183]:1272 at 14:18:22.076159:
  1584.    ------------------------------------------------------------------------
  1585.    SIP/2.0 200 OK
  1586.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK1193402102;rport=1272;received=87.127.251.183
  1587.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  1588.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=r78rpZ4KBav9p
  1589.    Call-ID: 2_2750365493@10.8.32.108
  1590.    CSeq: 120 REGISTER
  1591.    Contact: <sip:1001@87.127.251.183:1272>;expires=30
  1592.    Date: Tue, 05 Sep 2017 14:18:22 GMT
  1593.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1594.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  1595.    Supported: timer, path, replaces
  1596.    Content-Length: 0
  1597.    
  1598.    ------------------------------------------------------------------------
  1599. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (120)
  1600. nua_stack.c:529 nua_signal() nua(0x7f812c028600): sent signal r_respond
  1601. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1602. nua_stack.c:569 nua_stack_signal() nua(0x7f812c028600): recv signal r_destroy
  1603. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  1604. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c018150) called
  1605. nua_stack.c:529 nua_signal() nua(0x7f812c028600): sent signal r_destroy
  1606. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1607. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1608. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1609. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1610. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1611. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1612. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1613. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1614. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1615. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:22.480610:
  1616.    ------------------------------------------------------------------------
  1617.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1618.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1619.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1620.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1621.    Max-Forwards: 70
  1622.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1623.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1624.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1625.    CSeq: 111974475 INFO
  1626.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1627.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1628.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1629.    Supported: timer, path, replaces
  1630.    Content-Type: message/update_display
  1631.    Content-Length: 0
  1632.    X-FS-Display-Name: Extension 1000
  1633.    X-FS-Display-Number: 441156870140
  1634.    
  1635.    ------------------------------------------------------------------------
  1636. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1637. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1638. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  1639. nta.c:1296 agent_timer() nta: timer set next to 4001 ms
  1640. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  1641. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  1642. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/6 free
  1643. nta.c:1296 agent_timer() nta: timer set next to 2710 ms
  1644. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1645. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1646. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c00edb0 from (udp/195.74.100.112:5060) has 846 bytes, veclen = 1
  1647. recv 846 bytes from udp/[87.127.251.183]:1277 at 14:18:24.766719:
  1648.    ------------------------------------------------------------------------
  1649.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  1650.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK3781942151
  1651.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  1652.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>
  1653.    Call-ID: 2_4292396569@10.8.32.151
  1654.    CSeq: 230 REGISTER
  1655.    Contact: <sip:1000@10.8.32.151:5060>
  1656.    Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="9adf1b08-8976-4bbd-817c-d3dce30ac1dc", uri="sip:fspbx1.evoip.enta.net:5060", response="451cf1a4135347fa74fae5cfbb9fcd3a", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000021
  1657.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  1658.    Max-Forwards: 70
  1659.    User-Agent: Yealink SIP-T23G 44.80.0.137
  1660.    Expires: 3600
  1661.    Allow-Events: talk,hold,conference,refer,check-sync
  1662.    Content-Length: 0
  1663.    
  1664.    ------------------------------------------------------------------------
  1665. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c00edb0 (846 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1666. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 230)
  1667. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  1668. nta.c:3085 agent_recv_request() nta: REGISTER (230) going to a default leg
  1669. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1670. nua_stack.c:899 nh_create() nua: nh_create: entering
  1671. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  1672. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1673. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c020690) called
  1674. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c027a00, ...) called
  1675. nua_stack.c:271 nua_stack_event() nua(0x7f812c020690): event i_register 100 Trying
  1676. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1677. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1678. nua.c:879 nua_respond() nua: nua_respond: entering
  1679. nua_stack.c:573 nua_stack_signal() nua(0x7f812c020690): recv signal r_respond 200 OK
  1680. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1681. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c027a00, ...) called
  1682. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  1683. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  1684. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  1685. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 612 bytes of 612 to udp/87.127.251.183:1277
  1686. tport.c:3492 tport_send_msg() tport_vsend returned 612
  1687. send 612 bytes to udp/[87.127.251.183]:1277 at 14:18:24.770396:
  1688.    ------------------------------------------------------------------------
  1689.    SIP/2.0 200 OK
  1690.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK3781942151;received=87.127.251.183
  1691.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  1692.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=Sg2HrtNQ8jjvj
  1693.    Call-ID: 2_4292396569@10.8.32.151
  1694.    CSeq: 230 REGISTER
  1695.    Contact: <sip:1000@87.127.251.183:1277>;expires=30
  1696.    Date: Tue, 05 Sep 2017 14:18:24 GMT
  1697.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1698.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  1699.    Supported: timer, path, replaces
  1700.    Content-Length: 0
  1701.    
  1702.    ------------------------------------------------------------------------
  1703. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (230)
  1704. nua_stack.c:529 nua_signal() nua(0x7f812c020690): sent signal r_respond
  1705. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1706. nua_stack.c:569 nua_stack_signal() nua(0x7f812c020690): recv signal r_destroy
  1707. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  1708. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c027a00) called
  1709. nua_stack.c:529 nua_signal() nua(0x7f812c020690): sent signal r_destroy
  1710. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1711. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  1712. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1713. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1714. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1715. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1716. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1717. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1718. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1719. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:26.481660:
  1720.    ------------------------------------------------------------------------
  1721.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1722.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1723.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1724.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1725.    Max-Forwards: 70
  1726.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1727.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1728.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1729.    CSeq: 111974475 INFO
  1730.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1731.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1732.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1733.    Supported: timer, path, replaces
  1734.    Content-Type: message/update_display
  1735.    Content-Length: 0
  1736.    X-FS-Display-Name: Extension 1000
  1737.    X-FS-Display-Number: 441156870140
  1738.    
  1739.    ------------------------------------------------------------------------
  1740. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1741. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1742. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  1743. nta.c:1296 agent_timer() nta: timer set next to 4001 ms
  1744. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  1745. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  1746. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/6 free
  1747. nta.c:1296 agent_timer() nta: timer set next to 12290 ms
  1748. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  1749. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  1750. auth_digest.c:348 auth_digest_response() auth_response: 48a53bf9f50d0fd1ab6486abd47d6a1c = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb23100015b0b3d886c2d1d8d590b7fea74c428d50eb6:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  1751. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  1752. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  1753. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  1754. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  1755. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  1756. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  1757. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  1758. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  1759. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  1760. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1761. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  1762. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  1763. tport.c:3492 tport_send_msg() tport_vsend returned 874
  1764. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:27.020394:
  1765.    ------------------------------------------------------------------------
  1766.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  1767.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bKaS66S8461cm4B
  1768.    Max-Forwards: 70
  1769.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  1770.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  1771.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  1772.    CSeq: 111974230 REGISTER
  1773.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1774.    Expires: 3600
  1775.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1776.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1777.    Supported: timer, path, replaces
  1778.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb23100015b0b3d886c2d1d8d590b7fea74c428d50eb6", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="48a53bf9f50d0fd1ab6486abd47d6a1c"
  1779.    Content-Length: 0
  1780.    
  1781.    ------------------------------------------------------------------------
  1782. nta.c:8310 outgoing_send() nta: sent REGISTER (111974230) to udp/195.74.100.80:5060/sip
  1783. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f8118070990 for udp/195.74.100.112:5080 (already 1)
  1784. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  1785. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  1786. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  1787. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f81180854c0 from (udp/195.74.100.112:5080) has 537 bytes, veclen = 1
  1788. recv 537 bytes from udp/[195.74.100.80]:5060 at 14:18:27.029934:
  1789.    ------------------------------------------------------------------------
  1790.    SIP/2.0 401 Unauthorized
  1791.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bKaS66S8461cm4B
  1792.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  1793.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.dd82
  1794.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  1795.    CSeq: 111974230 REGISTER
  1796.    WWW-Authenticate: Digest realm="EN33510464.voip-portal.co.uk", nonce="59aeb24200015b29b17b71d128a36a1a209d9aafd8adada9", stale=true
  1797.    Server: Entanet SIP Proxy V8.24
  1798.    Content-Length: 0
  1799.    
  1800.    ------------------------------------------------------------------------
  1801. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f81180854c0 (537 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  1802. nta.c:3299 agent_recv_response() nta: received 401 Unauthorized for REGISTER (111974230)
  1803. nta.c:3366 agent_recv_response() nta: 401 Unauthorized is going to a transaction
  1804. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 9.653 ms
  1805. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f8118070990 by 0x7f81180897d0 with 0x7f81180854c0
  1806. auth_digest.c:105 auth_digest_challenge_get() auth_digest_challenge_get(): got 3
  1807. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  1808. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  1809. auth_digest.c:348 auth_digest_response() auth_response: da8af6400d62d434f6c40e1d001884b0 = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb24200015b29b17b71d128a36a1a209d9aafd8adada9:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  1810. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  1811. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  1812. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  1813. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  1814. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  1815. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  1816. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  1817. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  1818. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  1819. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1820. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  1821. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  1822. tport.c:3492 tport_send_msg() tport_vsend returned 874
  1823. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:27.030132:
  1824.    ------------------------------------------------------------------------
  1825.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  1826.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bKB2ZZU3NaZNaQQ
  1827.    Max-Forwards: 70
  1828.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  1829.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  1830.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  1831.    CSeq: 111974231 REGISTER
  1832.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1833.    Expires: 3600
  1834.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1835.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1836.    Supported: timer, path, replaces
  1837.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb24200015b29b17b71d128a36a1a209d9aafd8adada9", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="da8af6400d62d434f6c40e1d001884b0"
  1838.    Content-Length: 0
  1839.    
  1840.    ------------------------------------------------------------------------
  1841. nta.c:8310 outgoing_send() nta: sent REGISTER (111974231) to udp/195.74.100.80:5060/sip
  1842. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f81180415b0 for udp/195.74.100.112:5080 (already 1)
  1843. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 100 Request Authorized by Cache
  1844. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1845. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1846. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1847. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  1848. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  1849. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118092540 from (udp/195.74.100.112:5080) has 481 bytes, veclen = 1
  1850. recv 481 bytes from udp/[195.74.100.80]:5060 at 14:18:27.042697:
  1851.    ------------------------------------------------------------------------
  1852.    SIP/2.0 200 OK
  1853.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bKB2ZZU3NaZNaQQ
  1854.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  1855.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.b0a5
  1856.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  1857.    CSeq: 111974231 REGISTER
  1858.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>;q=0;expires=60
  1859.    Server: Entanet SIP Proxy V8.24
  1860.    Content-Length: 0
  1861.    
  1862.    ------------------------------------------------------------------------
  1863. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118092540 (481 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  1864. nta.c:3299 agent_recv_response() nta: received 200 OK for REGISTER (111974231)
  1865. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  1866. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 12.657 ms
  1867. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f81180415b0 by 0x7f81180711c0 with 0x7f8118092540
  1868. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh register after 17 seconds (in [15..45])
  1869. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 200 OK
  1870. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1871. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1872. 2017-09-05 14:18:27.006226 [DEBUG] sofia_reg.c:2435 Changing expire time to 60 by request of proxy sip:EN33510464.voip-portal.co.uk
  1873. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1874. nta.c:1296 agent_timer() nta: timer set next to 2461 ms
  1875. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1876. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1877. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c021f50 from (udp/195.74.100.112:5060) has 4 bytes, veclen = 1
  1878. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): bad msg 0x7f812c021f50 (4 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1879. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1880. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1881. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1882. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1883. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1884. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1885. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1886. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:30.484788:
  1887.    ------------------------------------------------------------------------
  1888.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1889.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1890.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1891.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1892.    Max-Forwards: 70
  1893.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1894.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1895.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1896.    CSeq: 111974475 INFO
  1897.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1898.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1899.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1900.    Supported: timer, path, replaces
  1901.    Content-Type: message/update_display
  1902.    Content-Length: 0
  1903.    X-FS-Display-Name: Extension 1000
  1904.    X-FS-Display-Number: 441156870140
  1905.    
  1906.    ------------------------------------------------------------------------
  1907. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1908. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1909. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/3 term, 0/5 free
  1910. nta.c:1296 agent_timer() nta: timer set next to 1548 ms
  1911. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate REGISTER (111974230)
  1912. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  1913. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/2 tout, 1/3 term, 1/5 free
  1914. nta.c:1296 agent_timer() nta: timer set next to 13 ms
  1915. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate REGISTER (111974231)
  1916. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  1917. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/2 tout, 1/2 term, 1/4 free
  1918. nta.c:1296 agent_timer() nta: timer set next to 2442 ms
  1919. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  1920. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  1921. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  1922. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  1923. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  1924. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  1925. tport.c:3492 tport_send_msg() tport_vsend returned 916
  1926. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:34.485111:
  1927.    ------------------------------------------------------------------------
  1928.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  1929.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  1930.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1931.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  1932.    Max-Forwards: 70
  1933.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  1934.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  1935.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  1936.    CSeq: 111974475 INFO
  1937.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  1938.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  1939.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  1940.    Supported: timer, path, replaces
  1941.    Content-Type: message/update_display
  1942.    Content-Length: 0
  1943.    X-FS-Display-Name: Extension 1000
  1944.    X-FS-Display-Number: 441156870140
  1945.    
  1946.    ------------------------------------------------------------------------
  1947. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  1948. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  1949. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  1950. nta.c:1296 agent_timer() nta: timer set next to 4000 ms
  1951. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  1952. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  1953. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c019250 from (udp/195.74.100.112:5060) has 844 bytes, veclen = 1
  1954. recv 844 bytes from udp/[87.127.251.183]:1272 at 14:18:37.066839:
  1955.    ------------------------------------------------------------------------
  1956.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  1957.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK3443894051;rport
  1958.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  1959.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>
  1960.    Call-ID: 2_2750365493@10.8.32.108
  1961.    CSeq: 121 REGISTER
  1962.    Contact: <sip:1001@10.8.32.108:5060>
  1963.    Authorization: Digest username="1001", realm="fspbx1.evoip.enta.net", nonce="c7cb569d-64b5-4376-be1f-14c4d91114db", uri="sip:fspbx1.evoip.enta.net:5060", response="d57b95a12dec41a911f87b6ab44b5cf9", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000041
  1964.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  1965.    Max-Forwards: 70
  1966.    User-Agent: Yealink SIP-T23G 44.81.0.70
  1967.    Expires: 60
  1968.    Allow-Events: talk,hold,conference,refer,check-sync
  1969.    Content-Length: 0
  1970.    
  1971.    ------------------------------------------------------------------------
  1972. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c019250 (844 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  1973. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 121)
  1974. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  1975. nta.c:3085 agent_recv_request() nta: REGISTER (121) going to a default leg
  1976. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  1977. nua_stack.c:899 nh_create() nua: nh_create: entering
  1978. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  1979. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1980. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c00f160) called
  1981. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c027a00, ...) called
  1982. nua_stack.c:271 nua_stack_event() nua(0x7f812c00f160): event i_register 100 Trying
  1983. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  1984. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  1985. nua.c:879 nua_respond() nua: nua_respond: entering
  1986. nua_stack.c:573 nua_stack_signal() nua(0x7f812c00f160): recv signal r_respond 200 OK
  1987. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  1988. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c027a00, ...) called
  1989. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1272
  1990. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1272
  1991. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1272
  1992. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 613 bytes of 613 to udp/87.127.251.183:1272
  1993. tport.c:3492 tport_send_msg() tport_vsend returned 613
  1994. send 613 bytes to udp/[87.127.251.183]:1272 at 14:18:37.071187:
  1995.    ------------------------------------------------------------------------
  1996.    SIP/2.0 200 OK
  1997.    Via: SIP/2.0/UDP 10.8.32.108:5060;branch=z9hG4bK3443894051;rport=1272;received=87.127.251.183
  1998.    From: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=4288287416
  1999.    To: "1001" <sip:1001@fspbx1.evoip.enta.net:5060>;tag=tSUatN6t5U8ee
  2000.    Call-ID: 2_2750365493@10.8.32.108
  2001.    CSeq: 121 REGISTER
  2002.    Contact: <sip:1001@87.127.251.183:1272>;expires=30
  2003.    Date: Tue, 05 Sep 2017 14:18:37 GMT
  2004.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2005.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  2006.    Supported: timer, path, replaces
  2007.    Content-Length: 0
  2008.    
  2009.    ------------------------------------------------------------------------
  2010. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (121)
  2011. nua_stack.c:529 nua_signal() nua(0x7f812c00f160): sent signal r_respond
  2012. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  2013. nua_stack.c:569 nua_stack_signal() nua(0x7f812c00f160): recv signal r_destroy
  2014. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  2015. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c027a00) called
  2016. nua_stack.c:529 nua_signal() nua(0x7f812c00f160): sent signal r_destroy
  2017. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2018. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  2019. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  2020. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  2021. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  2022. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  2023. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  2024. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  2025. tport.c:3492 tport_send_msg() tport_vsend returned 916
  2026. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:38.485132:
  2027.    ------------------------------------------------------------------------
  2028.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  2029.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  2030.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2031.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2032.    Max-Forwards: 70
  2033.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  2034.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  2035.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  2036.    CSeq: 111974475 INFO
  2037.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  2038.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2039.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  2040.    Supported: timer, path, replaces
  2041.    Content-Type: message/update_display
  2042.    Content-Length: 0
  2043.    X-FS-Display-Name: Extension 1000
  2044.    X-FS-Display-Number: 441156870140
  2045.    
  2046.    ------------------------------------------------------------------------
  2047. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  2048. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  2049. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  2050. nta.c:1296 agent_timer() nta: timer set next to 4000 ms
  2051. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  2052. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  2053. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c01c080 from (udp/195.74.100.112:5060) has 4 bytes, veclen = 1
  2054. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): bad msg 0x7f812c01c080 (4 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  2055. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  2056. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  2057. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/6 free
  2058. nta.c:1296 agent_timer() nta: timer set next to 2723 ms
  2059. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f812c0045a0): events IN
  2060. tport.c:2864 tport_recv_event() tport_recv_event(0x7f812c0045a0)
  2061. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f812c0045a0) msg 0x7f812c027d80 from (udp/195.74.100.112:5060) has 846 bytes, veclen = 1
  2062. recv 846 bytes from udp/[87.127.251.183]:1277 at 14:18:39.778241:
  2063.    ------------------------------------------------------------------------
  2064.    REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0
  2065.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport;branch=z9hG4bK1478111329
  2066.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  2067.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>
  2068.    Call-ID: 2_4292396569@10.8.32.151
  2069.    CSeq: 231 REGISTER
  2070.    Contact: <sip:1000@10.8.32.151:5060>
  2071.    Authorization: Digest username="1000", realm="fspbx1.evoip.enta.net", nonce="9adf1b08-8976-4bbd-817c-d3dce30ac1dc", uri="sip:fspbx1.evoip.enta.net:5060", response="a406a91718c4c9729b05fe664fe8eddb", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000022
  2072.    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
  2073.    Max-Forwards: 70
  2074.    User-Agent: Yealink SIP-T23G 44.80.0.137
  2075.    Expires: 3600
  2076.    Allow-Events: talk,hold,conference,refer,check-sync
  2077.    Content-Length: 0
  2078.    
  2079.    ------------------------------------------------------------------------
  2080. tport.c:3023 tport_deliver() tport_deliver(0x7f812c0045a0): msg 0x7f812c027d80 (846 bytes) from udp/87.127.251.183:5060/sip next=(nil)
  2081. nta.c:2880 agent_recv_request() nta: received REGISTER sip:fspbx1.evoip.enta.net:5060 SIP/2.0 (CSeq 231)
  2082. nta.c:3174 agent_check_request_via() nta: Via check: received=87.127.251.183
  2083. nta.c:3085 agent_recv_request() nta: REGISTER (231) going to a default leg
  2084. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  2085. nua_stack.c:899 nh_create() nua: nh_create: entering
  2086. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  2087. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  2088. soa.c:280 soa_clone() soa_clone(static::0x7f812c001b10, 0x7f812c001310, 0x7f812c010e20) called
  2089. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0200e0, ...) called
  2090. nua_stack.c:271 nua_stack_event() nua(0x7f812c010e20): event i_register 100 Trying
  2091. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2092. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2093. nua.c:879 nua_respond() nua: nua_respond: entering
  2094. nua_stack.c:573 nua_stack_signal() nua(0x7f812c010e20): recv signal r_respond 200 OK
  2095. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  2096. soa.c:403 soa_set_params() soa_set_params(static::0x7f812c0200e0, ...) called
  2097. tport.c:3257 tport_tsend() tport_tsend(0x7f812c0045a0) tpn = UDP/87.127.251.183:1277
  2098. tport.c:4046 tport_resolve() tport_resolve addrinfo = 87.127.251.183:1277
  2099. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f812c0045a0): not found by name UDP/87.127.251.183:1277
  2100. tport.c:3594 tport_vsend() tport_vsend(0x7f812c0045a0): 612 bytes of 612 to udp/87.127.251.183:1277
  2101. tport.c:3492 tport_send_msg() tport_vsend returned 612
  2102. send 612 bytes to udp/[87.127.251.183]:1277 at 14:18:39.781639:
  2103.    ------------------------------------------------------------------------
  2104.    SIP/2.0 200 OK
  2105.    Via: SIP/2.0/UDP 10.8.32.151:5060;rport=1277;branch=z9hG4bK1478111329;received=87.127.251.183
  2106.    From: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=964408845
  2107.    To: "1000" <sip:1000@fspbx1.evoip.enta.net:5060>;tag=U2m3UgQy24y1S
  2108.    Call-ID: 2_4292396569@10.8.32.151
  2109.    CSeq: 231 REGISTER
  2110.    Contact: <sip:1000@87.127.251.183:1277>;expires=30
  2111.    Date: Tue, 05 Sep 2017 14:18:39 GMT
  2112.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2113.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  2114.    Supported: timer, path, replaces
  2115.    Content-Length: 0
  2116.    
  2117.    ------------------------------------------------------------------------
  2118. nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (231)
  2119. nua_stack.c:529 nua_signal() nua(0x7f812c010e20): sent signal r_respond
  2120. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  2121. nua_stack.c:569 nua_stack_signal() nua(0x7f812c010e20): recv signal r_destroy
  2122. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  2123. soa.c:356 soa_destroy() soa_destroy(static::0x7f812c0200e0) called
  2124. nua_stack.c:529 nua_signal() nua(0x7f812c010e20): sent signal r_destroy
  2125. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2126. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  2127. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  2128. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813111bc60)
  2129. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/6 free
  2130. nta.c:1296 agent_timer() nta: timer set next to 8667 ms
  2131. nta.c:8899 _nta_outgoing_timer() nta: timer E fired, retransmit INFO (111974475)
  2132. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  2133. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  2134. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  2135. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  2136. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 916 bytes of 916 to udp/195.74.100.80:5060
  2137. tport.c:3492 tport_send_msg() tport_vsend returned 916
  2138. send 916 bytes to udp/[195.74.100.80]:5060 at 14:18:42.485140:
  2139.    ------------------------------------------------------------------------
  2140.    INFO sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  2141.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bK9FDerDm343XHg
  2142.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2143.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2144.    Max-Forwards: 70
  2145.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  2146.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  2147.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  2148.    CSeq: 111974475 INFO
  2149.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  2150.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2151.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  2152.    Supported: timer, path, replaces
  2153.    Content-Type: message/update_display
  2154.    Content-Length: 0
  2155.    X-FS-Display-Name: Extension 1000
  2156.    X-FS-Display-Number: 441156870140
  2157.    
  2158.    ------------------------------------------------------------------------
  2159. nta.c:8310 outgoing_send() nta: resent INFO (111974475) to */195.74.100.80:5060
  2160. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811808d0a0 for udp/195.74.100.112:5080 (already 0)
  2161. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 1/1 resent, 0/2 tout, 0/1 term, 0/3 free
  2162. nta.c:1296 agent_timer() nta: timer set next to 926 ms
  2163. nta.c:9107 outgoing_timer_dk() nta: timer D fired, terminate INVITE (111974474)
  2164. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  2165. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/2 tout, 1/1 term, 1/3 free
  2166. nta.c:1296 agent_timer() nta: timer set next to 2 ms
  2167. nta.c:8988 outgoing_timer_bf() nta: timer F fired, terminating ACK (111974474)
  2168. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  2169. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 1/2 tout, 0/0 term, 1/2 free
  2170. nta.c:1296 agent_timer() nta: timer set next to 42 ms
  2171. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  2172. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f813165dc60)
  2173. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
  2174. nta.c:1296 agent_timer() nta: timer set next to 20 ms
  2175. nta.c:8988 outgoing_timer_bf() nta: timer F fired, timeout INFO (111974475)
  2176. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811808d0a0 by 0x7f811808de20 with (nil)
  2177. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event r_info 408 Request Timeout
  2178. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  2179. soa.c:403 soa_set_params() soa_set_params(static::0x7f8118084a90, ...) called
  2180. soa.c:1784 soa_terminate() soa_terminate(static::0x7f8118084a90) called
  2181. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f8118084a90) called
  2182. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  2183. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = */195.74.100.80:5060
  2184. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  2185. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name */195.74.100.80:5060
  2186. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 781 bytes of 781 to udp/195.74.100.80:5060
  2187. tport.c:3492 tport_send_msg() tport_vsend returned 781
  2188. send 781 bytes to udp/[195.74.100.80]:5060 at 14:18:43.475866:
  2189.    ------------------------------------------------------------------------
  2190.    BYE sip:03331019574@195.74.100.81:5080;transport=tcp SIP/2.0
  2191.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bKcBSrXy6Dvy09j
  2192.    Route: <sip:195.74.100.80;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2193.    Route: <sip:195.74.100.80;transport=tcp;r2=on;lr;ftag=tFge5351jXBeH;did=127.6a916db3>
  2194.    Max-Forwards: 70
  2195.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  2196.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  2197.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  2198.    CSeq: 111974476 BYE
  2199.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2200.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  2201.    Supported: timer, path, replaces
  2202.    Reason: Q.850;cause=16;text="NORMAL_CLEARING"
  2203.    Content-Length: 0
  2204.    
  2205.    ------------------------------------------------------------------------
  2206. nta.c:8310 outgoing_send() nta: sent BYE (111974476) to */195.74.100.80:5060
  2207. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f8118085e20 for udp/195.74.100.112:5080 (already 0)
  2208. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 1/1 tout, 0/0 term, 0/1 free
  2209. nta.c:1296 agent_timer() nta: timer set next to 1000 ms
  2210. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2211. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2212. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2213. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  2214. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  2215. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118086ee0 from (udp/195.74.100.112:5080) has 559 bytes, veclen = 1
  2216. recv 559 bytes from udp/[195.74.100.80]:5060 at 14:18:43.509061:
  2217.    ------------------------------------------------------------------------
  2218.    SIP/2.0 200 OK
  2219.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bKcBSrXy6Dvy09j
  2220.    From: "Extension 1000" <sip:sip@EN33510464.voip-portal.co.uk>;tag=tFge5351jXBeH
  2221.    To: <sip:03331019574@EN33510464.voip-portal.co.uk>;tag=8F1FZ09KpjvNF
  2222.    Call-ID: db9ef20b-0ce7-1236-79a5-fa163e3b5224
  2223.    CSeq: 111974476 BYE
  2224.    User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit
  2225.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  2226.    Supported: timer, path, replaces
  2227.    Content-Length: 0
  2228.    
  2229.    ------------------------------------------------------------------------
  2230. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118086ee0 (559 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  2231. nta.c:3299 agent_recv_response() nta: received 200 OK for BYE (111974476)
  2232. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  2233. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 33.364 ms
  2234. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f8118085e20 by 0x7f8118080680 with 0x7f8118086ee0
  2235. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event r_bye 200 OK
  2236. nua_session.c:4139 signal_call_state_change() nua(0x7f8128007c00): call state changed: terminating -> terminated
  2237. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_state 200 to BYE
  2238. nua_stack.c:271 nua_stack_event() nua(0x7f8128007c00): event i_terminated 200 to BYE
  2239. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f8128007c00): removing session usage
  2240. soa.c:356 soa_destroy() soa_destroy(static::0x7f8118084a90) called
  2241. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f8118084980)
  2242. nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f8128007c00
  2243. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2244. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2245. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2246. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2247. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2248. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2249. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2250. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  2251. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2252. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2253. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  2254. nua_stack.c:569 nua_stack_signal() nua(0x7f8128007c00): recv signal r_destroy
  2255. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  2256. nua_stack.c:529 nua_signal() nua(0x7f8128007c00): sent signal r_destroy
  2257. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  2258. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  2259. auth_digest.c:348 auth_digest_response() auth_response: da8af6400d62d434f6c40e1d001884b0 = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb24200015b29b17b71d128a36a1a209d9aafd8adada9:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  2260. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  2261. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  2262. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV
  2263. sres.c:968 sres_query() sres_query(0x7f8118037e00, 0x7f81180807e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk") called
  2264. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f8118084610) called
  2265. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f8118084610) id=62404 SRV _sip._udp.EN33510464.voip-portal.co.uk (to [195.74.100.89]:53)
  2266. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8118037e00, 53) called
  2267. sres.c:3781 sres_create_record() ANSWER RR received _sip._udp.EN33510464.voip-portal.co.uk. CNAME IN 60 rdlen=10
  2268. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. SOA IN 24 rdlen=46
  2269. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8118037e00, 0x7f8118084610) id=62404 (from [195.74.100.89]:53)
  2270. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "sipgate.voip-portal.co.uk.") called
  2271. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811808ffc0) called
  2272. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811808ffc0) id=62405 SRV sipgate.voip-portal.co.uk. (to [195.74.100.89]:53)
  2273. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8118037e00, 53) called
  2274. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. SOA IN 24 rdlen=46
  2275. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8118037e00, 0x7f811808ffc0) id=62405 (from [195.74.100.89]:53)
  2276. sres.c:2987 sres_query_report_error() sres(q=0x7f811808ffc0): reporting error RECORD_ERR for SRV sipgate.voip-portal.co.uk.
  2277. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  2278. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A
  2279. sres.c:968 sres_query() sres_query(0x7f8118037e00, 0x7f81180807e0, A, "EN33510464.voip-portal.co.uk") called
  2280. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803b610) called
  2281. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8118037e00, 0x7f811803b610) id=62406 A EN33510464.voip-portal.co.uk (to [195.74.100.89]:53)
  2282. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8118037e00, 53) called
  2283. sres.c:3781 sres_create_record() ANSWER RR received EN33510464.voip-portal.co.uk. CNAME IN 60 rdlen=10
  2284. sres.c:3781 sres_create_record() ANSWER RR received sipgate.voip-portal.co.uk. A IN 50 rdlen=4
  2285. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. NS IN 50 rdlen=14
  2286. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. NS IN 50 rdlen=6
  2287. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. NS IN 50 rdlen=5
  2288. sres.c:3781 sres_create_record() AUTHORITY RR received voip-portal.co.uk. NS IN 50 rdlen=6
  2289. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8118037e00, 0x7f811803b610) id=62406 (from [195.74.100.89]:53)
  2290. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "sipgate.voip-portal.co.uk.") called
  2291. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "sipgate.voip-portal.co.uk.") returned 1 entries
  2292. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  2293. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  2294. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  2295. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  2296. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  2297. tport.c:3492 tport_send_msg() tport_vsend returned 874
  2298. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:44.048157:
  2299.    ------------------------------------------------------------------------
  2300.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  2301.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bKDmjHZSQHS7pve
  2302.    Max-Forwards: 70
  2303.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  2304.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  2305.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  2306.    CSeq: 111974232 REGISTER
  2307.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  2308.    Expires: 3600
  2309.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2310.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  2311.    Supported: timer, path, replaces
  2312.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb24200015b29b17b71d128a36a1a209d9aafd8adada9", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="da8af6400d62d434f6c40e1d001884b0"
  2313.    Content-Length: 0
  2314.    
  2315.    ------------------------------------------------------------------------
  2316. nta.c:8310 outgoing_send() nta: sent REGISTER (111974232) to udp/195.74.100.80:5060/sip
  2317. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811803df50 for udp/195.74.100.112:5080 (already 0)
  2318. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  2319. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  2320. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f8118080200 from (udp/195.74.100.112:5080) has 537 bytes, veclen = 1
  2321. recv 537 bytes from udp/[195.74.100.80]:5060 at 14:18:44.056466:
  2322.    ------------------------------------------------------------------------
  2323.    SIP/2.0 401 Unauthorized
  2324.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bKDmjHZSQHS7pve
  2325.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  2326.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.a69e
  2327.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  2328.    CSeq: 111974232 REGISTER
  2329.    WWW-Authenticate: Digest realm="EN33510464.voip-portal.co.uk", nonce="59aeb25300015b3fd4d042892626cc270097244c4f408f21", stale=true
  2330.    Server: Entanet SIP Proxy V8.24
  2331.    Content-Length: 0
  2332.    
  2333.    ------------------------------------------------------------------------
  2334. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f8118080200 (537 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  2335. nta.c:3299 agent_recv_response() nta: received 401 Unauthorized for REGISTER (111974232)
  2336. nta.c:3366 agent_recv_response() nta: 401 Unauthorized is going to a transaction
  2337. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 8.412 ms
  2338. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811803df50 by 0x7f81180807e0 with 0x7f8118080200
  2339. auth_digest.c:105 auth_digest_challenge_get() auth_digest_challenge_get(): got 3
  2340. auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(sip:EN33510464.voip-portal.co.uk:c776fa8e8152b37e) = 3d06e695d593a7eac66b7bf7d73ab105
  2341. auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:EN33510464.voip-portal.co.uk;transport=udp)
  2342. auth_digest.c:348 auth_digest_response() auth_response: 1ddc4f38f975e0ffb1c9cf1f4e5fdcbd = MD5(3d06e695d593a7eac66b7bf7d73ab105:59aeb25300015b3fd4d042892626cc270097244c4f408f21:e74b8fa4c49b2545abc7114a4258522e) (qop=NONE)
  2343. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  2344. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") called
  2345. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, SRV, "_sip._udp.EN33510464.voip-portal.co.uk.") returned 1 entries
  2346. nta.c:10604 outgoing_query_srv() nta: for "EN33510464.voip-portal.co.uk" query "_sip._udp.EN33510464.voip-portal.co.uk" SRV (cached)
  2347. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") called
  2348. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f81180262e0, A, "EN33510464.voip-portal.co.uk.") returned 1 entries
  2349. nta.c:10809 outgoing_query_a() nta: for "EN33510464.voip-portal.co.uk" query "EN33510464.voip-portal.co.uk" A (cached)
  2350. nta.c:10862 outgoing_answer_a() nta: sipgate.voip-portal.co.uk. IN A 195.74.100.80
  2351. tport.c:3257 tport_tsend() tport_tsend(0x7f81180397c0) tpn = udp/195.74.100.80:5060/sip
  2352. tport.c:4046 tport_resolve() tport_resolve addrinfo = 195.74.100.80:5060
  2353. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f81180397c0): not found by name udp/195.74.100.80:5060/sip
  2354. tport.c:3594 tport_vsend() tport_vsend(0x7f81180397c0): 874 bytes of 874 to udp/195.74.100.80:5060
  2355. tport.c:3492 tport_send_msg() tport_vsend returned 874
  2356. send 874 bytes to udp/[195.74.100.80]:5060 at 14:18:44.056602:
  2357.    ------------------------------------------------------------------------
  2358.    REGISTER sip:EN33510464.voip-portal.co.uk;transport=udp SIP/2.0
  2359.    Via: SIP/2.0/UDP 195.74.100.112:5080;rport;branch=z9hG4bKeXBa1m8mpgDFa
  2360.    Max-Forwards: 70
  2361.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  2362.    To: <sip:sip@EN33510464.voip-portal.co.uk>
  2363.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  2364.    CSeq: 111974233 REGISTER
  2365.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>
  2366.    Expires: 3600
  2367.    User-Agent: FreeSWITCH-mod_sofia/1.9.0-556-68fc3b5~64bit
  2368.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  2369.    Supported: timer, path, replaces
  2370.    Authorization: Digest username="sip", realm="EN33510464.voip-portal.co.uk", nonce="59aeb25300015b3fd4d042892626cc270097244c4f408f21", algorithm=MD5, uri="sip:EN33510464.voip-portal.co.uk;transport=udp", response="1ddc4f38f975e0ffb1c9cf1f4e5fdcbd"
  2371.    Content-Length: 0
  2372.    
  2373.    ------------------------------------------------------------------------
  2374. nta.c:8310 outgoing_send() nta: sent REGISTER (111974233) to udp/195.74.100.80:5060/sip
  2375. tport.c:4160 tport_pend() tport_pend(0x7f81180397c0): pending 0x7f811803e7b0 for udp/195.74.100.112:5080 (already 0)
  2376. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 100 Request Authorized by Cache
  2377. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2378. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2379. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2380. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f81180397c0): events IN
  2381. tport.c:2864 tport_recv_event() tport_recv_event(0x7f81180397c0)
  2382. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f81180397c0) msg 0x7f81180877d0 from (udp/195.74.100.112:5080) has 481 bytes, veclen = 1
  2383. recv 481 bytes from udp/[195.74.100.80]:5060 at 14:18:44.069049:
  2384.    ------------------------------------------------------------------------
  2385.    SIP/2.0 200 OK
  2386.    Via: SIP/2.0/UDP 195.74.100.112:5080;received=195.74.100.112;rport=5080;branch=z9hG4bKeXBa1m8mpgDFa
  2387.    From: <sip:sip@EN33510464.voip-portal.co.uk>;tag=KgZ0r6F96yFBg
  2388.    To: <sip:sip@EN33510464.voip-portal.co.uk>;tag=a5e8f5e9ef62e93eca305ef64f43c9c0.cfcf
  2389.    Call-ID: 50be4af2-ef74-4936-b532-330a3a739cd9
  2390.    CSeq: 111974233 REGISTER
  2391.    Contact: <sip:gw+entanet@195.74.100.112:5080;transport=udp;gw=entanet>;q=0;expires=60
  2392.    Server: Entanet SIP Proxy V8.24
  2393.    Content-Length: 0
  2394.    
  2395.    ------------------------------------------------------------------------
  2396. tport.c:3023 tport_deliver() tport_deliver(0x7f81180397c0): msg 0x7f81180877d0 (481 bytes) from udp/195.74.100.80:5080/sip next=(nil)
  2397. nta.c:3299 agent_recv_response() nta: received 200 OK for REGISTER (111974233)
  2398. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
  2399. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 12.504 ms
  2400. tport.c:4222 tport_release() tport_release(0x7f81180397c0): 0x7f811803e7b0 by 0x7f8118065830 with 0x7f81180877d0
  2401. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh register after 40 seconds (in [15..45])
  2402. nua_stack.c:271 nua_stack_event() nua(0x7f812005c5d0): event r_register 200 OK
  2403. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  2404. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2405. 2017-09-05 14:18:44.066244 [DEBUG] sofia_reg.c:2435 Changing expire time to 60 by request of proxy sip:EN33510464.voip-portal.co.uk
  2406. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  2407. nta.c:1296 agent_timer() nta: timer set next to 4000 ms
  2408. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate INFO (111974475)
  2409. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  2410. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/4 term, 1/4 free
  2411. nta.c:1296 agent_timer() nta: timer set next to 33 ms
  2412. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate BYE (111974476)
  2413. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f813165dd40)
  2414. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/3 free
  2415. nta.c:1296 agent_timer() nta: timer set next to 548 ms
  2416.