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.