1. .=======================================================.
2. |            _____ ____     ____ _     ___              |
3. |           |  ___/ ___|   / ___| |   |_ _|             |
4. |           | |_  \___ \  | |   | |    | |              |
5. |           |  _|  ___) | | |___| |___ | |              |
6. |           |_|   |____/   \____|_____|___|             |
7. |                                                       |
8. .=======================================================.
9. | Anthony Minessale II, Ken Rice,                       |
10. | Michael Jerris, Travis Cross                          |
11. | FreeSWITCH (http://www.freeswitch.org)                |
12. | Paypal Donations Appreciated: paypal@freeswitch.org   |
13. | Brought to you by ClueCon http://www.cluecon.com/     |
14. .=======================================================.
15.  
16. .=======================================================================================================.
17. |    ____ _             ____                                                                            |
18. |   / ___| |_   _  ___ / ___|___  _ __                                                                  |
19. |  | |   | | | | |/ _ \ |   / _ \| '_ \                                                                 |
20. |  | |___| | |_| |  __/ |__| (_) | | | |                                                                |
21. |   \____|_|\__,_|\___|\____\___/|_| |_|                                                                |
22. |                                                                                                       |
23. |   _____    _            _                          ____             __                                |
24. |  |_   _|__| | ___ _ __ | |__   ___  _ __  _   _   / ___|___  _ __  / _| ___ _ __ ___ _ __   ___ ___   |
25. |    | |/ _ \ |/ _ \ '_ \| '_ \ / _ \| '_ \| | | | | |   / _ \| '_ \| |_ / _ \ '__/ _ \ '_ \ / __/ _ \  |
26. |    | |  __/ |  __/ |_) | | | | (_) | | | | |_| | | |__| (_) | | | |  _|  __/ | |  __/ | | | (_|  __/  |
27. |    |_|\___|_|\___| .__/|_| |_|\___/|_| |_|\__, |  \____\___/|_| |_|_|  \___|_|  \___|_| |_|\___\___|  |
28. |                  |_|                      |___/                                                       |
29. |   _____                           _                         _                                         |
30. |  | ____|_   _____ _ __ _   _     / \  _   _  __ _ _   _ ___| |_                                       |
31. |  |  _| \ \ / / _ \ '__| | | |   / _ \| | | |/ _` | | | / __| __|                                      |
32. |  | |___ \ V /  __/ |  | |_| |  / ___ \ |_| | (_| | |_| \__ \ |_                                       |
33. |  |_____| \_/ \___|_|   \__, | /_/   \_\__,_|\__, |\__,_|___/\__|                                      |
34. |                        |___/                |___/                                                     |
35. |                                       ____ _             ____                                         |
36. |  __      ____      ____      __      / ___| |_   _  ___ / ___|___  _ __         ___ ___  _ __ ___     |
37. |  \ \ /\ / /\ \ /\ / /\ \ /\ / /     | |   | | | | |/ _ \ |   / _ \| '_ \       / __/ _ \| '_ ` _ \    |
38. |   \ V  V /  \ V  V /  \ V  V /   _  | |___| | |_| |  __/ |__| (_) | | | |  _  | (_| (_) | | | | | |   |
39. |    \_/\_/    \_/\_/    \_/\_/   (_)  \____|_|\__,_|\___|\____\___/|_| |_| (_)  \___\___/|_| |_| |_|   |
40. |                                                                                                       |
41. .=======================================================================================================.
42.  
43. Type /help <enter> to see a list of commands
44.  
45.  
46.  
47. +OK log level  [7]
48. freeswitch@DESKTOP-5PS5MGH> sofia global siptrace on
49. +OK Global siptrace on
50. freeswitch@DESKTOP-5PS5MGH> send 478 bytes to udp/[10.10.0.1]:5060 at 06:15:16.563655:
51.    ------------------------------------------------------------------------
52.    OPTIONS sip:10.10.0.1;transport=udp SIP/2.0
53.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKFy5FtgeU9p6ym
54.    Max-Forwards: 70
55.    From: <sip:10.10.0.1>;tag=eNBDmKNj04tQD
56.    To: <sip:10.10.0.1>
57.    Call-ID: a7460ca0-d4ad-1234-3fbf-c5acbca4426b
58.    CSeq: 94809576 OPTIONS
59.    User-Agent: Talkycom
60.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
61.    Supported: timer, path, replaces
62.    Allow-Events: talk, hold, conference, refer
63.    Content-Length: 0
64.  
65.    ------------------------------------------------------------------------
66. recv 363 bytes from udp/[10.10.0.1]:5060 at 06:15:16.774740:
67.    ------------------------------------------------------------------------
68.    SIP/2.0 200 OK
69.    CSeq: 94809576 OPTIONS
70.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKFy5FtgeU9p6ym
71.    From: <sip:10.10.0.1>;tag=eNBDmKNj04tQD
72.    Call-ID: a7460ca0-d4ad-1234-3fbf-c5acbca4426b
73.    To: <sip:10.10.0.1>;tag=1015203708634984
74.   Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, INFO, NOTIFY, MESSAGE, SUBSCRIBE, REFER, PUBLISH
75.    Content-Length: 0
76.  
77.    ------------------------------------------------------------------------
78. sofia loglevel all 9
79. Sofia log level for component [all] has been set to [9]
80. freeswitch@DESKTOP-5PS5MGH> ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (94809576)
81. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
82. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
83. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
84. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BED38): sent signal r_options
85. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BED38): recv signal r_options
86. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:280 soa_clone() soa_clone(static::01356098, 01A28248, 004BED38) called
87. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031FDFA8, ...) called
88. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031FDFA8, ...) called
89. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
90. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADC2D0) tpn = udp/10.10.0.1:5060
91. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.10.0.1:5060
92. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADC2D0): not found by name udp/10.10.0.1:5060
93. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADC2D0): 478 bytes of 478 to udp/10.10.0.1:5060
94. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 478
95. send 478 bytes to udp/[10.10.0.1]:5060 at 06:15:36.622599:
96.    ------------------------------------------------------------------------
97.    OPTIONS sip:10.10.0.1;transport=udp SIP/2.0
98.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKg7y8UBZy6ZvHg
99.    Max-Forwards: 70
100.    From: <sip:10.10.0.1>;tag=Fy45Ne6NXDHaS
101.    To: <sip:10.10.0.1>
102.    Call-ID: b33acd11-d4ad-1234-3fbf-c5acbca4426b
103.    CSeq: 94809577 OPTIONS
104.    User-Agent: Talkycom
105.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
106.    Supported: timer, path, replaces
107.    Allow-Events: talk, hold, conference, refer
108.    Content-Length: 0
109.  
110.    ------------------------------------------------------------------------
111. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent OPTIONS (94809577) to udp/10.10.0.1:5060
112. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADC2D0): pending 01AC5BA0 for udp/192.168.0.11:5070 (already 0)
113. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
114. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
115. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADC2D0): events IN
116. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADC2D0)
117. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADC2D0) msg 01AC63C0 from (udp/192.168.0.11:5070) has 363 bytes, veclen = 1
118. recv 363 bytes from udp/[10.10.0.1]:5060 at 06:15:36.833615:
119.    ------------------------------------------------------------------------
120.    SIP/2.0 200 OK
121.    CSeq: 94809577 OPTIONS
122.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKg7y8UBZy6ZvHg
123.    From: <sip:10.10.0.1>;tag=Fy45Ne6NXDHaS
124.    Call-ID: b33acd11-d4ad-1234-3fbf-c5acbca4426b
125.    To: <sip:10.10.0.1>;tag=1015403708655046
126.   Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, INFO, NOTIFY, MESSAGE, SUBSCRIBE, REFER, PUBLISH
127.    Content-Length: 0
128.  
129.    ------------------------------------------------------------------------
130. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADC2D0): msg 01AC63C0 (363 bytes) from udp/10.10.0.1:5070/sip next=00000000
131. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (94809577)
132. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
133. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 211.514 ms
134. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADC2D0): 01AC5BA0 by 0320FB30 with 01AC63C0
135. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BED38): event r_options 200 OK
136. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BED38): sent signal r_destroy
137. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BED38): recv signal r_destroy
138. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(00000000)
139. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:356 soa_destroy() soa_destroy(static::031FDFA8) called
140. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1296 agent_timer() nta: timer set next to 4211 ms
141. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (94809577)
142. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
143. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
144. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
145. ..\..\sofia-sip\libsofia-sip-ua\iptsec\auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(trillion:voipswitch:927bipin) = 6888b7aa95211dd720e4b32a7ddc889f
146. ..\..\sofia-sip\libsofia-sip-ua\iptsec\auth_digest.c:318 auth_digest_response() A2 = MD5(REGISTER:sip:10.10.0.1;transport=udp)
147. ..\..\sofia-sip\libsofia-sip-ua\iptsec\auth_digest.c:348 auth_digest_response() auth_response: fe86c5435bb3269ee393fbdbcc3f7658 = MD5(6888b7aa95211dd720e4b32a7ddc889f:dd0c601506e92dd8-04101021708142031431:328af1b33ea82019418600699dc55bbc) (qop=NONE)
148. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
149. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADC2D0) tpn = udp/10.10.0.1:5060/sip
150. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.10.0.1:5060
151. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADC2D0): not found by name udp/10.10.0.1:5060/sip
152. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADC2D0): 745 bytes of 745 to udp/10.10.0.1:5060
153. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 745
154. send 745 bytes to udp/[10.10.0.1]:5060 at 06:15:47.376265:
155.    ------------------------------------------------------------------------
156.    REGISTER sip:10.10.0.1;transport=udp SIP/2.0
157.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKHgr1X6F238j4B
158.    Max-Forwards: 70
159.    From: <sip:trillion@10.10.0.1>;tag=BtZ2e22789QZa
160.    To: <sip:trillion@10.10.0.1>
161.    Call-ID: e19865b4-3630-438a-9220-29c8e03e1603
162.    CSeq: 94809566 REGISTER
163.    Contact: <sip:trillion@192.168.0.11:5070;transport=udp;gw=bipin>
164.    Expires: 3600
165.    User-Agent: Talkycom
166.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
167.    Supported: timer, path, replaces
168.    Proxy-Authorization: Digest username="trillion", realm="voipswitch", nonce="dd0c601506e92dd8-04101021708142031431", algorithm=MD5, uri="sip:10.10.0.1;transport=udp", response="fe86c5435bb3269ee393fbdbcc3f7658"
169.    Content-Length: 0
170.  
171.    ------------------------------------------------------------------------
172. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent REGISTER (94809566) to udp/10.10.0.1:5060/sip
173. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADC2D0): pending 01AC67D0 for udp/192.168.0.11:5070 (already 0)
174. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
175. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
176. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
177. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
178. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 01AC6DE8 from (udp/192.168.0.11:5060) has 4 bytes, veclen = 1
179. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): bad msg 01AC6DE8 (4 bytes) from udp/192.168.0.11:5060/sip next=00000000
180. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADC2D0): events IN
181. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADC2D0)
182. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADC2D0) msg 01AC6DE8 from (udp/192.168.0.11:5070) has 372 bytes, veclen = 1
183. recv 372 bytes from udp/[10.10.0.1]:5060 at 06:15:47.587536:
184.    ------------------------------------------------------------------------
185.    SIP/2.0 200 OK
186.    CSeq: 94809566 REGISTER
187.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKHgr1X6F238j4B
188.    From: <sip:trillion@10.10.0.1>;tag=BtZ2e22789QZa
189.    Call-ID: e19865b4-3630-438a-9220-29c8e03e1603
190.    To: <sip:trillion@10.10.0.1>;tag=1015503708665796
191.    Contact: <sip:trillion@192.168.0.11:5070;transport=udp;gw=bipin>;expires=120
192.    Expires: 120
193.    Content-Length: 0
194.  
195.    ------------------------------------------------------------------------
196. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADC2D0): msg 01AC6DE8 (372 bytes) from udp/10.10.0.1:5070/sip next=00000000
197. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for REGISTER (94809566)
198. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
199. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 211.271 ms
200. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADC2D0): 01AC67D0 by 0320EFF0 with 01AC6DE8
201. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh register after 78 seconds (in [60..90])
202. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE838): event r_register 200 OK
203. 2016-08-04 10:15:47.580534 [DEBUG] sofia_reg.c:2429 Changing expire time to 120 by request of proxy sip:10.10.0.1
204. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1296 agent_timer() nta: timer set next to 4210 ms
205. 2016-08-04 10:15:48.780227 [INFO] mod_verto.c:4025 192.168.0.11:61745 Client Connect.
206. 2016-08-04 10:15:48.780227 [INFO] mod_verto.c:1978 192.168.0.11:61745 Starting client thread.
207. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
208.         "jsonrpc":      "2.0",
209.         "method":       "login",
210.         "params":       {
211.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
212.         },
213.         "id":   2
214. }]
215. 2016-08-04 10:15:48.840255 [INFO] mod_verto.c:1267 192.168.0.11:61745 re-connecting session de02989a-0170-a830-e80e-b052c07e81f5
216. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
217.         "jsonrpc":      "2.0",
218.         "id":   2,
219.        "error":        {
220.                 "code": -32000,
221.                 "message":      "Authentication Required"
222.         }
223. }]
224. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
225.         "jsonrpc":      "2.0",
226.         "method":       "login",
227.         "params":       {
228.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
229.         },
230.         "id":   1
231. }]
232. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
233.         "jsonrpc":      "2.0",
234.         "id":   1,
235.        "error":        {
236.                 "code": -32000,
237.                 "message":      "Authentication Required"
238.         }
239. }]
240. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
241.         "jsonrpc":      "2.0",
242.         "method":       "login",
243.         "params":       {
244.                 "login":        "trillionss@xbipin.com",
245.                 "passwd":       "927bipin",
246.                 "loginParams":  {
247.                 },
248.                 "userVariables":        {
249.                 },
250.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
251.         },
252.         "id":   3
253. }]
254. 2016-08-04 10:15:48.840255 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
255.         "jsonrpc":      "2.0",
256.         "id":   3,
257.         "result":       {
258.                 "message":      "logged in",
259.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
260.         }
261. }]
262. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate REGISTER (94809566)
263. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
264. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
265. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
266. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BF198): sent signal r_options
267. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BF198): recv signal r_options
268. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:280 soa_clone() soa_clone(static::01356098, 01A28248, 004BF198) called
269. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
270. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
271. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
272. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADC2D0) tpn = udp/10.10.0.1:5060
273. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.10.0.1:5060
274. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADC2D0): not found by name udp/10.10.0.1:5060
275. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADC2D0): 478 bytes of 478 to udp/10.10.0.1:5060
276. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 478
277. send 478 bytes to udp/[10.10.0.1]:5060 at 06:15:56.677936:
278.    ------------------------------------------------------------------------
279.    OPTIONS sip:10.10.0.1;transport=udp SIP/2.0
280.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKjSHtZ1050H9pQ
281.    Max-Forwards: 70
282.    From: <sip:10.10.0.1>;tag=g7XyQ9pStp7vm
283.    To: <sip:10.10.0.1>
284.    Call-ID: bf2f27e0-d4ad-1234-3fbf-c5acbca4426b
285.    CSeq: 94809578 OPTIONS
286.    User-Agent: Talkycom
287.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
288.    Supported: timer, path, replaces
289.    Allow-Events: talk, hold, conference, refer
290.    Content-Length: 0
291.  
292.    ------------------------------------------------------------------------
293. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent OPTIONS (94809578) to udp/10.10.0.1:5060
294. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADC2D0): pending 01AC5998 for udp/192.168.0.11:5070 (already 0)
295. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
296. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
297. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADC2D0): events IN
298. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADC2D0)
299. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADC2D0) msg 01AC6DE8 from (udp/192.168.0.11:5070) has 363 bytes, veclen = 1
300. recv 363 bytes from udp/[10.10.0.1]:5060 at 06:15:56.889370:
301.    ------------------------------------------------------------------------
302.    SIP/2.0 200 OK
303.    CSeq: 94809578 OPTIONS
304.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKjSHtZ1050H9pQ
305.    From: <sip:10.10.0.1>;tag=g7XyQ9pStp7vm
306.    Call-ID: bf2f27e0-d4ad-1234-3fbf-c5acbca4426b
307.    To: <sip:10.10.0.1>;tag=1016003708675109
308.   Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, INFO, NOTIFY, MESSAGE, SUBSCRIBE, REFER, PUBLISH
309.    Content-Length: 0
310.  
311.    ------------------------------------------------------------------------
312. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADC2D0): msg 01AC6DE8 (363 bytes) from udp/10.10.0.1:5070/sip next=00000000
313. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (94809578)
314. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
315. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 211.934 ms
316. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADC2D0): 01AC5998 by 0320FBF0 with 01AC6DE8
317. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BF198): event r_options 200 OK
318. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BF198): sent signal r_destroy
319. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BF198): recv signal r_destroy
320. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(00000000)
321. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:356 soa_destroy() soa_destroy(static::031DA1C8) called
322. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1296 agent_timer() nta: timer set next to 4212 ms
323. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (94809578)
324. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
325. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
326. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
327. 2016-08-04 10:16:08.140291 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
328.         "jsonrpc":      "2.0",
329.         "method":       "verto.invite",
330.         "params":       {
331.                 "sdp":  "v=0\r\no=- 8720450899619411369 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio\r\na=msid-semantic: WMS xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI\r\nm=audio 61266 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126\r\nc=IN IP4 86.99.124.187\r\na=rtcp:61269 IN IP4 86.99.124.187\r\na=candidate:2591490071 1 udp 2122255103 2001::5ef5:79fd:10e3:1539:3f57:fff4 61264 typ host generation 0 network-id 2\r\na=candidate:2237255773 1 udp 2122194687 169.254.101.10 61265 typ host generation 0 network-id 3\r\na=candidate:3988902457 1 udp 2122129151 192.168.0.11 61266 typ host generation 0 network-id 1\r\na=candidate:2591490071 2 udp 2122255102 2001::5ef5:79fd:10e3:1539:3f57:fff4 61267 typ host generation 0 network-id 2\r\na=candidate:2237255773 2 udp 2122194686 169.254.101.10 61268 typ host generation 0 network-id 3\r\na=candidate:3988902457 2 udp 2122129150 192.168.0.11 61269 typ host generation 0 network-id 1\r\na=candidate:3572825319 1 tcp 1518275327 2001::5ef5:79fd:10e3:1539:3f57:fff4 9 typ host tcptype active generation 0 network-id 2\r\na=candidate:3420073133 1 tcp 1518214911 169.254.101.10 9 typ host tcptype active generation 0 network-id 3\r\na=candidate:2739023561 1 tcp 1518149375 192.168.0.11 9 typ host tcptype active generation 0 network-id 1\r\na=candidate:3572825319 2 tcp 1518275326 2001::5ef5:79fd:10e3:1539:3f57:fff4 9 typ host tcptype active generation 0 network-id 2\r\na=candidate:3420073133 2 tcp 1518214910 169.254.101.10 9 typ host tcptype active generation 0 network-id 3\r\na=candidate:2739023561 2 tcp 1518149374 192.168.0.11 9 typ host tcptype active generation 0 network-id 1\r\na=candidate:466725869 1 udp 1685921535 86.99.124.187 61266 typ srflx raddr 192.168.0.11 rport 61266 generation 0 network-id 1\r\na=candidate:466725869 2 udp 1685921534 86.99.124.187 61269 typ srflx raddr 192.168.0.11 rport 61269 generation 0 network-id 1\r\na=ice-ufrag:LW6dMsmqXjYwpHWI\r\na=ice-pwd:o2hkpfEAJqcZyIDhe6fa1Ppp\r\na=fingerprint:sha-256 04:87:66:8E:11:58:93:07:3C:CA:C4:17:BB:E7:71:BF:C3:A8:FA:DD:B5:9E:77:4B:85:50:03:A7:1A:2A:20:A9\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=rtcp-fb:111 transport-cc\r\na=fmtp:111 minptime=10;useinbandfec=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:126 telephone-event/8000\r\na=maxptime:60\r\na=ssrc:3803537473 cname:3TSma3p3nz57SdiF\r\na=ssrc:3803537473 msid:xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI 4c307149-c5b4-422f-81aa-f94d86c33461\r\na=ssrc:3803537473 mslabel:xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI\r\na=ssrc:3803537473 label:4c307149-c5b4-422f-81aa-f94d86c33461\r\n",
332.                 "dialogParams": {
333.                         "useVideo":     false,
334.                         "useStereo":    false,
335.                         "screenShare":  false,
336.                         "useCamera":    "none",
337.                         "useMic":       "0cf03192275f0100c7e90f472d6e42d1abf3f4ac2b86080e5f1b8c1ff2147f2e",
338.                         "useSpeak":     "default",
339.                         "tag":  "webcam",
340.                         "localTag":     null,
341.                         "login":        "trillionss@xbipin.com",
342.                         "videoParams":  {
343.                                 "minWidth":     320,
344.                                 "minHeight":    180,
345.                                 "maxWidth":     320,
346.                                 "maxHeight":    180,
347.                                 "minFrameRate": 15
348.                         },
349.                         "destination_number":   "2002",
350.                         "caller_id_name":       "1234",
351.                         "caller_id_number":     "",
352.                         "outgoingBandwidth":    90354,
353.                         "incomingBandwidth":    192000,
354.                         "dedEnc":       false,
355.                         "mirrorInput":  false,
356.                         "userVariables":        {
357.                                 "email":        "",
358.                                 "avatar":       "http://gravatar.com/avatar/d41d8cd98f00b204e9800998ecf8427e.png?s=600"
359.                         },
360.                         "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
361.                         "remote_caller_id_name":        "Outbound Call",
362.                         "remote_caller_id_number":      "2002"
363.                 },
364.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
365.         },
366.         "id":   4
367. }]
368. 2016-08-04 10:16:08.140291 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
369. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_session.c:613 N/A set UUID=8e34ba61-e7b9-930e-4de0-2292db2c3009
370. 2016-08-04 10:16:08.140291 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/2002 [8e34ba61-e7b9-930e-4de0-2292db2c3009]
371. 2016-08-04 10:16:08.140291 [DEBUG] mod_verto.c:3579 Remote SDP verto.rtc/2002:
372. v=0
373. o=- 8720450899619411369 2 IN IP4 127.0.0.1
374. s=-
375. t=0 0
376. a=group:BUNDLE audio
377. a=msid-semantic: WMS xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI
378. m=audio 61266 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
379. c=IN IP4 86.99.124.187
380. a=rtcp:61269 IN IP4 86.99.124.187
381. a=candidate:2591490071 1 udp 2122255103 2001::5ef5:79fd:10e3:1539:3f57:fff4 61264 typ host generation 0 network-id 2
382. a=candidate:2237255773 1 udp 2122194687 169.254.101.10 61265 typ host generation 0 network-id 3
383. a=candidate:3988902457 1 udp 2122129151 192.168.0.11 61266 typ host generation 0 network-id 1
384. a=candidate:2591490071 2 udp 2122255102 2001::5ef5:79fd:10e3:1539:3f57:fff4 61267 typ host generation 0 network-id 2
385. a=candidate:2237255773 2 udp 2122194686 169.254.101.10 61268 typ host generation 0 network-id 3
386. a=candidate:3988902457 2 udp 2122129150 192.168.0.11 61269 typ host generation 0 network-id 1
387. a=candidate:3572825319 1 tcp 1518275327 2001::5ef5:79fd:10e3:1539:3f57:fff4 9 typ host tcptype active generation 0 network-id 2
388. a=candidate:3420073133 1 tcp 1518214911 169.254.101.10 9 typ host tcptype active generation 0 network-id 3
389. a=candidate:2739023561 1 tcp 1518149375 192.168.0.11 9 typ host tcptype active generation 0 network-id 1
390. a=candidate:3572825319 2 tcp 1518275326 2001::5ef5:79fd:10e3:1539:3f57:fff4 9 typ host tcptype active generation 0 network-id 2
391. a=candidate:3420073133 2 tcp 1518214910 169.254.101.10 9 typ host tcptype active generation 0 network-id 3
392. a=candidate:2739023561 2 tcp 1518149374 192.168.0.11 9 typ host tcptype active generation 0 network-id 1
393. a=candidate:466725869 1 udp 1685921535 86.99.124.187 61266 typ srflx raddr 192.168.0.11 rport 61266 generation 0 network-id 1
394. a=candidate:466725869 2 udp 1685921534 86.99.124.187 61269 typ srflx raddr 192.168.0.11 rport 61269 generation 0 network-id 1
395. a=ice-ufrag:LW6dMsmqXjYwpHWI
396. a=ice-pwd:o2hkpfEAJqcZyIDhe6fa1Ppp
397. a=fingerprint:sha-256 04:87:66:8E:11:58:93:07:3C:CA:C4:17:BB:E7:71:BF:C3:A8:FA:DD:B5:9E:77:4B:85:50:03:A7:1A:2A:20:A9
398. a=setup:actpass
399. a=mid:audio
400. a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
401. a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
402. a=sendrecv
403. a=rtcp-mux
404. a=rtpmap:111 opus/48000/2
405. a=rtcp-fb:111 transport-cc
406. a=fmtp:111 minptime=10;useinbandfec=1
407. a=rtpmap:103 ISAC/16000
408. a=rtpmap:104 ISAC/32000
409. a=rtpmap:9 G722/8000
410. a=rtpmap:0 PCMU/8000
411. a=rtpmap:8 PCMA/8000
412. a=rtpmap:106 CN/32000
413. a=rtpmap:105 CN/16000
414. a=rtpmap:13 CN/8000
415. a=rtpmap:126 telephone-event/8000
416. a=maxptime:60
417. a=ssrc:3803537473 cname:3TSma3p3nz57SdiF
418. a=ssrc:3803537473 msid:xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI 4c307149-c5b4-422f-81aa-f94d86c33461
419. a=ssrc:3803537473 mslabel:xFbaghzziZW71YHWb2FL3HPrs19MftwTBaxI
420. a=ssrc:3803537473 label:4c307149-c5b4-422f-81aa-f94d86c33461
421.  
422. 2016-08-04 10:16:08.140291 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
423.         "jsonrpc":      "2.0",
424.         "id":   4,
425.         "result":       {
426.                 "message":      "CALL CREATED",
427.                 "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
428.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
429.         }
430. }]
431. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:543 (verto.rtc/2002) Running State Change CS_INIT
432. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:586 (verto.rtc/2002) State INIT
433. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:40 verto.rtc/2002 Standard INIT
434. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/2002) State Change CS_INIT -> CS_ROUTING
435. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:586 (verto.rtc/2002) State INIT going to sleep
436. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:543 (verto.rtc/2002) Running State Change CS_ROUTING
437. 2016-08-04 10:16:08.140291 [DEBUG] switch_channel.c:2249 (verto.rtc/2002) Callstate Change DOWN -> RINGING
438. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:602 (verto.rtc/2002) State ROUTING
439. 2016-08-04 10:16:08.140291 [DEBUG] mod_rtc.c:89 verto.rtc/2002 RTC ROUTING
440. 2016-08-04 10:16:08.140291 [DEBUG] switch_core_state_machine.c:236 verto.rtc/2002 Standard ROUTING
441. 2016-08-04 10:16:08.140291 [INFO] mod_dialplan_xml.c:637 Processing 1234 <0000000000>->2002 in context lanusersdialout
442. Dialplan: verto.rtc/2002 parsing [lanusersdialout->call_xlite] continue=false
443. Dialplan: verto.rtc/2002 Regex (PASS) [call_xlite] destination_number(2002) =~ /^2002$/ break=on-false
444. Dialplan: verto.rtc/2002 Action bridge(user/trillions@${domain_name})
445. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:286 (verto.rtc/2002) State Change CS_ROUTING -> CS_EXECUTE
446. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:602 (verto.rtc/2002) State ROUTING going to sleep
447. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:543 (verto.rtc/2002) Running State Change CS_EXECUTE
448. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:609 (verto.rtc/2002) State EXECUTE
449. 2016-08-04 10:16:08.160735 [DEBUG] mod_rtc.c:120 verto.rtc/2002 RTC EXECUTE
450. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:328 verto.rtc/2002 Standard EXECUTE
451. EXECUTE verto.rtc/2002 bridge(user/trillions@192.168.0.11)
452. 2016-08-04 10:16:08.160735 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
453. 2016-08-04 10:16:08.160735 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
454. 2016-08-04 10:16:08.160735 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/trillions@192.168.0.11:9040 [8319a985-5a8b-44c1-be11-d805def20700]
455. 2016-08-04 10:16:08.160735 [DEBUG] mod_sofia.c:4754 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_NEW -> CS_INIT
456. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_INIT
457. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/trillions@192.168.0.11:9040) State INIT
458. 2016-08-04 10:16:08.160735 [DEBUG] mod_sofia.c:90 sofia/internal/trillions@192.168.0.11:9040 SOFIA INIT
459. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1032 pass
460. 2016-08-04 10:16:08.160735 [DEBUG] sofia_glue.c:1249 sofia/internal/trillions@192.168.0.11:9040 sending invite version: 1.7.0 git 18f1d56 2016-07-24 04:35:30Z 32bit
461. Local SDP:
462. v=0
463. o=Talkycom 1470290336 1470290337 IN IP4 192.168.0.11
464. s=Talkycom
465. c=IN IP4 192.168.0.11
466. t=0 0
467. m=audio 1032 RTP/AVP 102 9 0 8 103 101
468. a=rtpmap:102 opus/48000/2
469. a=fmtp:102 useinbandfec=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; ptime=20; minptime=10; maxptime=40; stereo=1
470. a=rtpmap:9 G722/8000
471. a=rtpmap:0 PCMU/8000
472. a=rtpmap:8 PCMA/8000
473. a=rtpmap:103 telephone-event/48000
474. a=fmtp:103 0-16
475. a=rtpmap:101 telephone-event/8000
476. a=fmtp:101 0-16
477. a=silenceSupp:off - - - -
478. a=ptime:20
479. a=sendrecv
480.  
481. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BE978): sent signal r_invite
482. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:40 sofia/internal/trillions@192.168.0.11:9040 Standard INIT
483. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BE978): recv signal r_invite
484. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_INIT -> CS_ROUTING
485. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:280 soa_clone() soa_clone(static::013563E0, 01A28888, 004BE978) called
486. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
487. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/trillions@192.168.0.11:9040) State INIT going to sleep
488. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
489. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::031DA1C8, 00000000, 03213B94, -1) called
490. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::031DA1C8, 00000000, 03213B94, -1) called
491. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_dialog.c:338 nua_dialog_usage_add() nua(004BE978): adding session usage
492. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(03140940)
493. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::031DA1C8) called
494. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1426 soa_generate_offer() soa_generate_offer(static::031DA1C8, 0) called
495. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(031DA1C8, soa_generate_offer): called
496. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1187 offer_answer_step() soa_static(031DA1C8, soa_generate_offer): generating local description
497. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1215 offer_answer_step() soa_static(031DA1C8, soa_generate_offer): upgrade with local description
498. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0298F510, 00000000, ""): called
499. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_ROUTING
500. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1444 offer_answer_step() soa_static(031DA1C8, soa_generate_offer): storing local description
501. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::031DA1C8, [00000000], [0298F588], [0298F598]) called
502. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
503. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADB7A8) tpn = */192.168.0.11:9040
504. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.0.11:9040
505. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/trillions@192.168.0.11:9040) State ROUTING
506. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADB7A8): not found by name */192.168.0.11:9040
507. 2016-08-04 10:16:08.160735 [DEBUG] mod_sofia.c:143 sofia/internal/trillions@192.168.0.11:9040 SOFIA ROUTING
508. 2016-08-04 10:16:08.160735 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_ROUTING -> CS_CONSUME_MEDIA
509. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/trillions@192.168.0.11:9040) State ROUTING going to sleep
510. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADB7A8): 1480 bytes of 1480 to udp/192.168.0.11:9040
511. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 1480
512. send 1480 bytes to udp/[192.168.0.11]:9040 at 06:16:08.166240:
513.    ------------------------------------------------------------------------
514.    INVITE sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22 SIP/2.0
515.    Via: SIP/2.0/UDP 192.168.0.11;rport;branch=z9hG4bKK52tjpNXK5cyj
516.    Max-Forwards: 70
517.    From: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
518.    To: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>
519.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
520.    CSeq: 94809620 INVITE
521.    Contact: <sip:mod_sofia@192.168.0.11:5060>
522.    User-Agent: Talkycom
523.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
524.    Supported: timer, path, replaces
525.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
526.    Content-Type: application/sdp
527.    Content-Disposition: session
528.   Content-Length: 5272016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_CONSUME_MEDIA
529.  
530.    X-FS-Support: update_display,send_info
531.    Remote-Party-ID: "1234" <sip:0000000000@192.168.0.11>;party=calling;screen=yes;privacy=off
532.  
533.    v=0
534.    o=Talkycom 1470290336 1470290337 IN IP4 192.168.0.11
535.    s=Talkycom
536.    c=IN IP4 192.168.0.11
537.    t=0 0
538.    m=audio 1032 RTP/AVP 102 9 0 8 103 101
539.    a=rtpmap:102 opus/48000/2
540.    a=fmtp:102 useinbandfec=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; ptime=20; minptime=10; maxptime=40; stereo=1
541.    a=rtpmap:9 G722/8000
542.    a=rtpmap:0 PCMU/8000
543.    a=rtpmap:8 PCMA/8000
544.    a=rtpmap:103 telephone-event/48000
545.    a=fmtp:103 0-16
546. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/trillions@192.168.0.11:9040) State CONSUME_MEDIA
547.    a=rtpmap:101 telephone-event/8000
548. 2016-08-04 10:16:08.160735 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/trillions@192.168.0.11:9040) State CONSUME_MEDIA going to sleep
549.    a=fmtp:101 0-16
550.    a=silenceSupp:off - - - -
551.    a=ptime:20
552.    ------------------------------------------------------------------------
553. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent INVITE (94809620) to */192.168.0.11:9040
554. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADB7A8): pending 01AC71F8 for udp/192.168.0.11:5060 (already 0)
555. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
556. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
557. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:4139 signal_call_state_change() nua(004BE978): call state changed: init -> calling, sent offer
558. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::031DA1C8, [0298F5A4], [0298F5D4], [00000000]) called
559. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:269 nua_stack_event() nua(004BE978): event i_state INVITE sent
560. 2016-08-04 10:16:08.160735 [DEBUG] sofia.c:6937 Channel sofia/internal/trillions@192.168.0.11:9040 entering state [calling][0]
561. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
562. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
563. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 01AC7400 from (udp/192.168.0.11:5060) has 309 bytes, veclen = 1
564. recv 309 bytes from udp/[192.168.0.11]:9040 at 06:16:08.248731:
565.    ------------------------------------------------------------------------
566.    SIP/2.0 100 Trying
567.    Via: SIP/2.0/UDP 192.168.0.11;rport=5060;branch=z9hG4bKK52tjpNXK5cyj
568.    To: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>
569.    From: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
570.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
571.    CSeq: 94809620 INVITE
572.    Content-Length: 0
573.  
574.    ------------------------------------------------------------------------
575. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): msg 01AC7400 (309 bytes) from udp/192.168.0.11:5060/sip next=00000000
576. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (94809620)
577. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction
578. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 82.991 ms
579. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADB7A8): 01AC71F8 by 0320FB30 with 01AC7400 (preliminary)
580. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
581. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
582. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 01AC6FF0 from (udp/192.168.0.11:5060) has 453 bytes, veclen = 1
583. recv 453 bytes from udp/[192.168.0.11]:9040 at 06:16:08.358255:
584.    ------------------------------------------------------------------------
585.    SIP/2.0 180 Ringing
586.    Via: SIP/2.0/UDP 192.168.0.11;rport=5060;branch=z9hG4bKK52tjpNXK5cyj
587.    Contact: <sip:trillions@192.168.0.11:9040>
588.    To: "971559270058"<sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>;tag=76d89c38
589.    From: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
590.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
591.    CSeq: 94809620 INVITE
592.    User-Agent: X-Lite release 4.9.5 stamp 81136
593.    Allow-Events: talk, hold
594.    Content-Length: 0
595.  
596.    ------------------------------------------------------------------------
597. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): msg 01AC6FF0 (453 bytes) from udp/192.168.0.11:5060/sip next=00000000
598. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 180 Ringing for INVITE (94809620)
599. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 180 Ringing is going to a transaction
600. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADB7A8): 01AC71F8 by 0320FB30 with 01AC6FF0 (preliminary)
601. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event r_invite 180 Ringing
602. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:4139 signal_call_state_change() nua(004BE978): call state changed: calling -> proceeding
603. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_state 180 Ringing
604. 2016-08-04 10:16:08.340745 [DEBUG] sofia.c:6937 Channel sofia/internal/trillions@192.168.0.11:9040 entering state [proceeding][180]
605. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
606. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BF198): sent signal r_options
607. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BF198): recv signal r_options
608. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:280 soa_clone() soa_clone(static::01356098, 01A28248, 004BF198) called
609. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA510, ...) called
610. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA510, ...) called
611. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
612. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADC2D0) tpn = udp/10.10.0.1:5060
613. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.10.0.1:5060
614. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADC2D0): not found by name udp/10.10.0.1:5060
615. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADC2D0): 478 bytes of 478 to udp/10.10.0.1:5060
616. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 478
617. send 478 bytes to udp/[10.10.0.1]:5060 at 06:16:16.744301:
618.    ------------------------------------------------------------------------
619.    OPTIONS sip:10.10.0.1;transport=udp SIP/2.0
620.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKK2aK1vH9XtZ9j
621.    Max-Forwards: 70
622.    From: <sip:10.10.0.1>;tag=HgQQS47vQZXFg
623.    To: <sip:10.10.0.1>
624.    Call-ID: cb250a47-d4ad-1234-3fbf-c5acbca4426b
625.    CSeq: 94809579 OPTIONS
626.    User-Agent: Talkycom
627.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
628.    Supported: timer, path, replaces
629.    Allow-Events: talk, hold, conference, refer
630.    Content-Length: 0
631.  
632.    ------------------------------------------------------------------------
633. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent OPTIONS (94809579) to udp/10.10.0.1:5060
634. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADC2D0): pending 01AC63C0 for udp/192.168.0.11:5070 (already 0)
635. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
636. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
637. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADC2D0): events IN
638. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADC2D0)
639. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADC2D0) msg 01AC7400 from (udp/192.168.0.11:5070) has 363 bytes, veclen = 1
640. recv 363 bytes from udp/[10.10.0.1]:5060 at 06:16:16.955716:
641.    ------------------------------------------------------------------------
642.    SIP/2.0 200 OK
643.    CSeq: 94809579 OPTIONS
644.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKK2aK1vH9XtZ9j
645.    From: <sip:10.10.0.1>;tag=HgQQS47vQZXFg
646.    Call-ID: cb250a47-d4ad-1234-3fbf-c5acbca4426b
647.    To: <sip:10.10.0.1>;tag=1016203708695171
648.   Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, INFO, NOTIFY, MESSAGE, SUBSCRIBE, REFER, PUBLISH
649.    Content-Length: 0
650.  
651.    ------------------------------------------------------------------------
652. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADC2D0): msg 01AC7400 (363 bytes) from udp/10.10.0.1:5070/sip next=00000000
653. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (94809579)
654. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
655. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 211.947 ms
656. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADC2D0): 01AC63C0 by 0320FA70 with 01AC7400
657. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BF198): event r_options 200 OK
658. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BF198): sent signal r_destroy
659. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BF198): recv signal r_destroy
660. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(00000000)
661. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:356 soa_destroy() soa_destroy(static::031DA510) called
662. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
663. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
664. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 01AC67D0 from (udp/192.168.0.11:5060) has 4 bytes, veclen = 1
665. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): bad msg 01AC67D0 (4 bytes) from udp/192.168.0.11:5060/sip next=00000000
666. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1296 agent_timer() nta: timer set next to 4211 ms
667. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
668. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
669. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 01AC67D0 from (udp/192.168.0.11:5060) has 737 bytes, veclen = 1
670. recv 737 bytes from udp/[192.168.0.11]:9040 at 06:16:18.153174:
671.    ------------------------------------------------------------------------
672.    SIP/2.0 200 OK
673.    Via: SIP/2.0/UDP 192.168.0.11;rport=5060;branch=z9hG4bKK52tjpNXK5cyj
674.    Contact: <sip:trillions@192.168.0.11:9040>
675.    To: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>;tag=76d89c38
676.    From: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
677.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
678.    CSeq: 94809620 INVITE
679.   Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS
680.    Content-Type: application/sdp
681.    Supported: replaces
682.    User-Agent: X-Lite release 4.9.5 stamp 81136
683.    Content-Length: 201
684.  
685.    v=0
686.    o=- 735382566 3 IN IP4 192.168.0.11
687.    s=X-Lite release 4.9.5 stamp 81136
688.    c=IN IP4 192.168.0.11
689.    t=0 0
690.    m=audio 10044 RTP/AVP 0 101
691.    a=rtpmap:101 telephone-event/8000
692.    a=fmtp:101 0-15
693.    a=sendrecv
694.    ------------------------------------------------------------------------
695. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): msg 01AC67D0 (737 bytes) from udp/192.168.0.11:5060/sip next=00000000
696. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for INVITE (94809620)
697. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
698. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADB7A8): 01AC71F8 by 0320FB30 with 01AC67D0
699. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
700. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::031DA1C8, 00000000, 004BE2D0, 201) called
701. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1595 soa_process_answer() soa_process_answer(static::031DA1C8) called
702. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(031DA1C8, soa_process_answer): called
703. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(032B2F60, 033789E0, ""): called
704. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1302 offer_answer_step() soa_static(031DA1C8, soa_process_answer): upgrade codecs with remote description
705. ..\..\sofia-sip\libsofia-sip-ua\soa\soa_static.c:1444 offer_answer_step() soa_static(031DA1C8, soa_process_answer): storing local description
706. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1730 soa_activate() soa_activate(static::031DA1C8, (nil)) called
707. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:988 nua_session_client_response() nua(004BE978): INVITE: processed SDP answer in 200 OK
708. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event r_invite 200 OK
709. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:4139 signal_call_state_change() nua(004BE978): call state changed: proceeding -> completing, received answer
710. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::031DA1C8, [0298F3C8], [0298F3CC], [00000000]) called
711. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:616 soa_get_params() soa_get_params(static::031DA1C8, ...) called
712. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_state 200 OK
713. 2016-08-04 10:16:18.140679 [DEBUG] sofia.c:6937 Channel sofia/internal/trillions@192.168.0.11:9040 entering state [completing][200]
714. 2016-08-04 10:16:18.140679 [DEBUG] sofia.c:6947 Remote SDP:
715. v=0
716. o=- 735382566 3 IN IP4 192.168.0.11
717. s=X-Lite release 4.9.5 stamp 81136
718. c=IN IP4 192.168.0.11
719. t=0 0
720. m=audio 10044 RTP/AVP 0 101
721. a=rtpmap:101 telephone-event/8000
722. a=fmtp:101 0-15
723.  
724. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BE978): sent signal r_ack
725. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BE978): recv signal r_ack
726. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
727. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:1730 soa_activate() soa_activate(static::031DA1C8, (nil)) called
728. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
729. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADB7A8) tpn = */192.168.0.11:9040
730. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.0.11:9040
731. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADB7A8): not found by name */192.168.0.11:9040
732. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADB7A8): 401 bytes of 401 to udp/192.168.0.11:9040
733. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 401
734. send 401 bytes to udp/[192.168.0.11]:9040 at 06:16:18.157175:
735.    ------------------------------------------------------------------------
736.    ACK sip:trillions@192.168.0.11:9040 SIP/2.0
737.    Via: SIP/2.0/UDP 192.168.0.11;rport;branch=z9hG4bKmevKmH60ge3ge
738.    Max-Forwards: 70
739.    From: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
740.    To: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>;tag=76d89c38
741.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
742.    CSeq: 94809620 ACK
743.    Contact: <sip:mod_sofia@192.168.0.11:5060>
744.    Content-Length: 0
745.  
746.    ------------------------------------------------------------------------
747. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent ACK (94809620) to */192.168.0.11:9040
748. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:4139 signal_call_state_change() nua(004BE978): call state changed: completing -> ready
749. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_state 200 ACK sent
750. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_active 200 Call active
751. 2016-08-04 10:16:18.140679 [DEBUG] sofia.c:6937 Channel sofia/internal/trillions@192.168.0.11:9040 entering state [ready][200]
752. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
753. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
754. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
755. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4380 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
756. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
757. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4241 Set telephone-event payload to 101@8000
758. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:3032 Set Codec sofia/internal/trillions@192.168.0.11:9040 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
759. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_codec.c:111 sofia/internal/trillions@192.168.0.11:9040 Original read codec set to PCMU:0
760. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4594 Set telephone-event payload to 101@8000
761. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:4653 sofia/internal/trillions@192.168.0.11:9040 Set 2833 dtmf send payload to 101 recv payload to 101
762. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:6479 AUDIO RTP [sofia/internal/trillions@192.168.0.11:9040] 192.168.0.11 port 1032 -> 192.168.0.11 port 10044 codec: 0 ms: 20
763. 2016-08-04 10:16:18.140679 [DEBUG] switch_rtp.c:3833 Starting timer [soft] 160 bytes per 20ms
764. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:6778 sofia/internal/trillions@192.168.0.11:9040 Set 2833 dtmf send payload to 101
765. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:6785 sofia/internal/trillions@192.168.0.11:9040 Set 2833 dtmf receive payload to 101
766. 2016-08-04 10:16:18.140679 [DEBUG] switch_core_media.c:6808 sofia/internal/trillions@192.168.0.11:9040 Set rtp dtmf delay to 40
767. 2016-08-04 10:16:18.140679 [NOTICE] sofia.c:7968 Channel [sofia/internal/trillions@192.168.0.11:9040] has been answered
768. 2016-08-04 10:16:18.140679 [DEBUG] switch_channel.c:3770 (sofia/internal/trillions@192.168.0.11:9040) Callstate Change DOWN -> ACTIVE
769. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [opus:111:48000:60:0:1]/[opus:116:48000:20:0:1]
770. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4380 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
771. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [opus:111:48000:60:0:1]/[PCMU:0:8000:20:64000:1]
772. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [opus:111:48000:60:0:1]/[G729:18:8000:20:8000:1]
773. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [opus:111:48000:60:0:1]/[G723:4:8000:30:6300:1]
774. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
775. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
776. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G729:18:8000:20:8000:1]
777. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G723:4:8000:30:6300:1]
778. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]
779. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
780. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G729:18:8000:20:8000:1]
781. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G723:4:8000:30:6300:1]
782. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1]
783. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
784. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [G722:9:8000:60:64000:1]/[G729:18:8000:20:8000:1]
785. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [G722:9:8000:60:64000:1]/[G723:4:8000:30:6300:1]
786. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]
787. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
788. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4380 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
789. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G729:18:8000:20:8000:1]
790. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G723:4:8000:30:6300:1]
791. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]
792. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
793. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G729:18:8000:20:8000:1]
794. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G723:4:8000:30:6300:1]
795. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:106:32000:60:0:1]/[opus:116:48000:20:0:1]
796. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:106:32000:60:0:1]/[PCMU:0:8000:20:64000:1]
797. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:106:32000:60:0:1]/[G729:18:8000:20:8000:1]
798. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:106:32000:60:0:1]/[G723:4:8000:30:6300:1]
799. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]
800. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]
801. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:105:16000:60:0:1]/[G729:18:8000:20:8000:1]
802. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:105:16000:60:0:1]/[G723:4:8000:30:6300:1]
803. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]
804. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]
805. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:13:8000:60:0:1]/[G729:18:8000:20:8000:1]
806. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4325 Audio Codec Compare [CN:13:8000:60:0:1]/[G723:4:8000:30:6300:1]
807. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4241 Set telephone-event payload to 126@8000
808. 2016-08-04 10:16:18.160185 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
809. 2016-08-04 10:16:18.160185 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
810. 2016-08-04 10:16:18.160185 [DEBUG] mod_opus.c:554 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [20000bps]
811. 2016-08-04 10:16:18.160185 [DEBUG] mod_opus.c:571 Opus encoder: set audio bandwidth to [WIDEBAND] based on maxplaybackrate value found in SDP or local config [16000Hz]
812. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3032 Set Codec verto.rtc/2002 opus/48000 20 ms 960 samples 0 bits 1 channels
813. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_codec.c:111 verto.rtc/2002 Original read codec set to opus:116
814. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3430 Drop audio Candidate cid: 1 proto: udp type: host addr: 2001::5ef5:79fd:10e3:1539:3f57:fff4:61264 (no network path)
815. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 1 proto: udp type: host addr: 169.254.101.10:61265
816. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.0.11:61266
817. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3430 Drop audio Candidate cid: 2 proto: udp type: host addr: 2001::5ef5:79fd:10e3:1539:3f57:fff4:61267 (no network path)
818. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 2 proto: udp type: host addr: 169.254.101.10:61268
819. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.0.11:61269
820. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 1 proto: udp type: srflx addr: 86.99.124.187:61266
821. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3436 Save audio Candidate cid: 2 proto: udp type: srflx addr: 86.99.124.187:61269
822. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3478 Searching for rtp candidate.
823. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3483 Choose rtp candidate, index 2, 86.99.124.187:61266
824. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3261 verto.rtc/2002 choosing family v4
825. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3494 Choose same candidate, index 3, for rtcp based on rtcp-mux attribute 86.99.124.187:61266
826. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3539 setting remote audio ice addr to index 2 86.99.124.187:61266 based on candidate
827. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:3560 Setting remote rtcp audio addr to 86.99.124.187:61266 based on candidate
828. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:4653 verto.rtc/2002 Set 2833 dtmf send payload to 126 recv payload to 126
829. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 1030 pass
830. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:6479 AUDIO RTP [verto.rtc/2002] 192.168.0.11 port 1030 -> 86.99.124.187 port 61266 codec: 111 ms: 20
831. 2016-08-04 10:16:18.160185 [DEBUG] switch_rtp.c:3833 Starting timer [soft] 960 bytes per 20ms
832. 2016-08-04 10:16:18.160185 [INFO] switch_core_media.c:6654 Activating Audio ICE
833. 2016-08-04 10:16:18.160185 [NOTICE] switch_rtp.c:4325 Activating RTP audio ICE: LW6dMsmqXjYwpHWI:H2lTdOjkW8YbdVjh 86.99.124.187:61266
834. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:6697 Activating RTCP PORT 61266
835. 2016-08-04 10:16:18.160185 [DEBUG] switch_rtp.c:4222 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 61266
836. 2016-08-04 10:16:18.160185 [INFO] switch_core_media.c:6705 Skipping RTCP ICE (Same as RTP)
837. 2016-08-04 10:16:18.160185 [INFO] switch_rtp.c:3329 Activate RTP/RTCP audio DTLS client
838. 2016-08-04 10:16:18.160185 [INFO] switch_rtp.c:3460 Changing audio DTLS state from OFF to HANDSHAKE
839. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:1998 Setting Jitterbuffer to 20ms (1 frames) (50 max frames)
840. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:6778 verto.rtc/2002 Set 2833 dtmf send payload to 126
841. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:6785 verto.rtc/2002 Set 2833 dtmf receive payload to 126
842. 2016-08-04 10:16:18.160185 [DEBUG] mod_verto.c:2445 Local SDP verto.rtc/2002:
843. v=0
844. o=FreeSWITCH 1470290348 1470290349 IN IP4 192.168.0.11
845. s=FreeSWITCH
846. c=IN IP4 192.168.0.11
847. t=0 0
848. a=msid-semantic: WMS yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv
849. a=end-of-candidates
850. m=audio 1030 UDP/TLS/RTP/SAVPF 111 126
851. a=rtpmap:111 opus/48000/2
852. a=fmtp:111 useinbandfec=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=10
853. a=rtpmap:126 telephone-event/8000
854. a=silenceSupp:off - - - -
855. a=ptime:20
856. a=sendrecv
857. a=fingerprint:sha-256 6C:DF:81:17:9B:0C:B9:0A:A2:A3:9A:AC:FF:EB:B2:44:3B:7A:77:E5:A1:69:CD:0B:78:31:6A:28:FB:78:D0:C3
858. a=setup:active
859. a=rtcp-mux
860. a=rtcp:1030 IN IP4 192.168.0.11
861. a=ice-ufrag:H2lTdOjkW8YbdVjh
862. a=ice-pwd:sOi39omOLIOYyG0w41m74rgo
863. a=candidate:9609061325 1 udp 659136 192.168.0.11 1030 typ host generation 0
864. a=ssrc:1524143252 cname:GN2x7iGjaC01JSbO
865. a=ssrc:1524143252 msid:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv a0
866. a=ssrc:1524143252 mslabel:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv
867. a=ssrc:1524143252 label:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNva0
868.  
869. 2016-08-04 10:16:18.160185 [NOTICE] switch_ivr_originate.c:3549 Channel [verto.rtc/2002] has been answered
870. 2016-08-04 10:16:18.160185 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
871.         "jsonrpc":      "2.0",
872.         "id":   1,
873.         "method":       "verto.answer",
874.         "params":       {
875.                 "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
876.                 "sdp":  "v=0\r\no=FreeSWITCH 1470290348 1470290349 IN IP4 192.168.0.11\r\ns=FreeSWITCH\r\nc=IN IP4 192.168.0.11\r\nt=0 0\r\na=msid-semantic: WMS yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv\r\na=end-of-candidates\r\nm=audio 1030 UDP/TLS/RTP/SAVPF 111 126\r\na=rtpmap:111 opus/48000/2\r\na=fmtp:111 useinbandfec=1; maxaveragebitrate=20000; maxplaybackrate=16000; sprop-maxcapturerate=16000; minptime=10\r\na=rtpmap:126 telephone-event/8000\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\na=fingerprint:sha-256 6C:DF:81:17:9B:0C:B9:0A:A2:A3:9A:AC:FF:EB:B2:44:3B:7A:77:E5:A1:69:CD:0B:78:31:6A:28:FB:78:D0:C3\na=setup:active\r\na=rtcp-mux\r\na=rtcp:1030 IN IP4 192.168.0.11\r\na=ice-ufrag:H2lTdOjkW8YbdVjh\r\na=ice-pwd:sOi39omOLIOYyG0w41m74rgo\r\na=candidate:9609061325 1 udp 659136 192.168.0.11 1030 typ host generation 0\r\na=ssrc:1524143252 cname:GN2x7iGjaC01JSbO\r\na=ssrc:1524143252 msid:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv a0\r\na=ssrc:1524143252 mslabel:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNv\r\na=ssrc:1524143252 label:yKgnC3fH8eKgFNiTWdSVICvA7J3tIVNva0\r\n"
877.         }
878. }]
879. 2016-08-04 10:16:18.160185 [DEBUG] switch_channel.c:3770 (verto.rtc/2002) Callstate Change RINGING -> ACTIVE
880. 2016-08-04 10:16:18.160185 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/trillions@192.168.0.11:9040]
881. 2016-08-04 10:16:18.160185 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/trillions@192.168.0.11:9040]
882. 2016-08-04 10:16:18.160185 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
883.         "jsonrpc":      "2.0",
884.         "id":   1,
885.         "result":       {
886.                 "method":       "verto.answer"
887.         }
888. }]
889. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_media.c:9653 verto.rtc/2002 PAUSE Jitterbuffer
890. 2016-08-04 10:16:18.160185 [DEBUG] switch_ivr_bridge.c:1600 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
891. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_EXCHANGE_MEDIA
892. 2016-08-04 10:16:18.160185 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/trillions@192.168.0.11:9040) State EXCHANGE_MEDIA
893. 2016-08-04 10:16:18.160185 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
894. 2016-08-04 10:16:18.180826 [DEBUG] switch_rtp.c:6722 Correct audio ip/port confirmed.
895. 2016-08-04 10:16:18.180826 [NOTICE] switch_core_io.c:1202 Activating write resampler
896. 2016-08-04 10:16:18.180826 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
897.         "jsonrpc":      "2.0",
898.         "id":   2,
899.         "method":       "verto.display",
900.         "params":       {
901.                 "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
902.                 "display_name": "Outbound Call",
903.                 "display_number":       "trillions",
904.                 "caller_id_name":       "1234",
905.                 "caller_id_number":     "0000000000",
906.                 "callee_id_name":       "Outbound Call",
907.                 "callee_id_number":     "trillions",
908.                 "display_direction":    "inbound"
909.         }
910. }]
911. 2016-08-04 10:16:18.180826 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
912.         "jsonrpc":      "2.0",
913.         "id":   2,
914.         "result":       {
915.                 "method":       "verto.display"
916.         }
917. }]
918. 2016-08-04 10:16:18.540269 [NOTICE] switch_rtp.c:1258 Auto Changing audio stun/rtp/dtls port from 86.99.124.187:61266 to 192.168.0.11:61266
919. 2016-08-04 10:16:19.280734 [INFO] switch_rtp.c:3120 Changing audio DTLS state from HANDSHAKE to SETUP
920. 2016-08-04 10:16:19.300271 [INFO] switch_rtp.c:3029 audio Fingerprint Verified.
921. 2016-08-04 10:16:19.300271 [INFO] switch_rtp.c:3645 Activating Audio Secure RTP SEND
922. 2016-08-04 10:16:19.300271 [INFO] switch_rtp.c:3623 Activating Audio Secure RTP RECV
923. 2016-08-04 10:16:19.300271 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
924. 2016-08-04 10:16:19.300271 [INFO] switch_rtp.c:3069 Changing audio DTLS state from SETUP to READY
925. 2016-08-04 10:16:19.300271 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
926. 2016-08-04 10:16:19.360687 [NOTICE] switch_core_io.c:1202 Activating write resampler
927. 2016-08-04 10:16:19.380210 [DEBUG] switch_rtp.c:1847 rtcp_stats_init: audio ssrc[3803537473] base_seq[11906]
928. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADB7A8): events IN
929. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADB7A8)
930. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADB7A8) msg 034B92D8 from (udp/192.168.0.11:5060) has 454 bytes, veclen = 1
931. recv 454 bytes from udp/[192.168.0.11]:9040 at 06:16:20.980693:
932.    ------------------------------------------------------------------------
933.    BYE sip:mod_sofia@192.168.0.11:5060 SIP/2.0
934.    Via: SIP/2.0/UDP 192.168.0.11:9040;branch=z9hG4bK-524287-1---2b2da306c520eb5a
935.    Max-Forwards: 70
936.    Contact: <sip:trillions@192.168.0.11:9040>
937.    To: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
938.    From: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>;tag=76d89c38
939.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
940.    CSeq: 2 BYE
941.    User-Agent: X-Lite release 4.9.5 stamp 81136
942.    Content-Length: 0
943.  
944.    ------------------------------------------------------------------------
945. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADB7A8): msg 034B92D8 (454 bytes) from udp/192.168.0.11:5060/sip next=00000000
946. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2880 agent_recv_request() nta: received BYE sip:mod_sofia@192.168.0.11:5060 SIP/2.0 (CSeq 2)
947. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3248 agent_aliases() nta: canonizing sip:mod_sofia@192.168.0.11:5060 with contact
948. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3060 agent_recv_request() nta: BYE (2) going to existing leg
949. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_bye 100 Trying
950. 2016-08-04 10:16:21.001209 [DEBUG] switch_ivr_bridge.c:707 sofia/internal/trillions@192.168.0.11:9040 ending bridge by request from write function
951. 2016-08-04 10:16:21.001209 [DEBUG] switch_ivr_bridge.c:786 BRIDGE THREAD DONE [verto.rtc/2002]
952. 2016-08-04 10:16:21.001209 [NOTICE] sofia.c:988 Hangup sofia/internal/trillions@192.168.0.11:9040 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
953. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BE978): sent signal r_respond
954. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:573 nua_stack_signal() nua(004BE978): recv signal r_respond 200 OK
955. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::031DA1C8, ...) called
956. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BE978): sent signal r_destroy
957. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADB7A8) tpn = UDP/192.168.0.11:9040
958. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.0.11:9040
959. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADB7A8): not found by name UDP/192.168.0.11:9040
960. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADB7A8): 483 bytes of 483 to udp/192.168.0.11:9040
961. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 483
962. send 483 bytes to udp/[192.168.0.11]:9040 at 06:16:21.001710:
963.    ------------------------------------------------------------------------
964.    SIP/2.0 200 OK
965.    Via: SIP/2.0/UDP 192.168.0.11:9040;branch=z9hG4bK-524287-1---2b2da306c520eb5a
966.    From: <sip:trillions@192.168.0.11:9040;rinstance=1fc501a404528d22>;tag=76d89c38
967.    To: "1234" <sip:0000000000@192.168.0.11>;tag=QHm24p8jHSmBg
968.    Call-ID: c6080e3c-d4ad-1234-3fbf-c5acbca4426b
969.    CSeq: 2 BYE
970.    User-Agent: Talkycom
971.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
972.    Supported: timer, path, replaces
973.    Content-Length: 0
974.  
975.    ------------------------------------------------------------------------
976. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:6791 incoming_reply() nta: sent 200 OK for BYE (2)
977. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_dialog.c:397 nua_dialog_usage_remove_at() nua(004BE978): removing session usage
978. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_session.c:4139 signal_call_state_change() nua(004BE978): call state changed: ready -> terminated
979. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_state 200 Session Terminated
980. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BE978): event i_terminated 200 Session Terminated
981. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:356 soa_destroy() soa_destroy(static::031DA1C8) called
982. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(03140940)
983. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BE978): recv signal r_destroy
984. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(00000000)
985. 2016-08-04 10:16:21.001209 [DEBUG] switch_ivr_bridge.c:786 BRIDGE THREAD DONE [sofia/internal/trillions@192.168.0.11:9040]
986. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/trillions@192.168.0.11:9040) State EXCHANGE_MEDIA going to sleep
987. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_HANGUP
988. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/trillions@192.168.0.11:9040) Callstate Change ACTIVE -> HANGUP
989. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/trillions@192.168.0.11:9040) State HANGUP
990. 2016-08-04 10:16:21.001209 [DEBUG] mod_sofia.c:438 Channel sofia/internal/trillions@192.168.0.11:9040 hanging up, cause: NORMAL_CLEARING
991. 2016-08-04 10:16:21.001209 [DEBUG] switch_ivr_bridge.c:1698 sofia/internal/trillions@192.168.0.11:9040 skip receive message [UNBRIDGE] (channel is hungup already)
992. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_media.c:9721 verto.rtc/2002 RESUME Jitterbuffer
993. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_state_machine.c:385 verto.rtc/2002 has executed the last dialplan instruction, hanging up.
994. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_state_machine.c:387 Hangup verto.rtc/2002 [CS_EXECUTE] [NORMAL_CLEARING]
995. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:609 (verto.rtc/2002) State EXECUTE going to sleep
996. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:543 (verto.rtc/2002) Running State Change CS_HANGUP
997. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:60 sofia/internal/trillions@192.168.0.11:9040 Standard HANGUP, cause: NORMAL_CLEARING
998. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/trillions@192.168.0.11:9040) State HANGUP going to sleep
999. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_HANGUP -> CS_REPORTING
1000. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:809 (verto.rtc/2002) Callstate Change ACTIVE -> HANGUP
1001. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:811 (verto.rtc/2002) State HANGUP
1002. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_REPORTING
1003. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:60 verto.rtc/2002 Standard HANGUP, cause: NORMAL_CLEARING
1004. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:811 (verto.rtc/2002) State HANGUP going to sleep
1005. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:578 (verto.rtc/2002) State Change CS_HANGUP -> CS_REPORTING
1006. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/trillions@192.168.0.11:9040) State REPORTING
1007. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:174 sofia/internal/trillions@192.168.0.11:9040 Standard REPORTING, cause: NORMAL_CLEARING
1008. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/trillions@192.168.0.11:9040) State REPORTING going to sleep
1009. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:543 (verto.rtc/2002) Running State Change CS_REPORTING
1010. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:897 (verto.rtc/2002) State REPORTING
1011. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:174 verto.rtc/2002 Standard REPORTING, cause: NORMAL_CLEARING
1012. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:897 (verto.rtc/2002) State REPORTING going to sleep
1013. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/trillions@192.168.0.11:9040) State Change CS_REPORTING -> CS_DESTROY
1014. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_session.c:1647 Session 2 (sofia/internal/trillions@192.168.0.11:9040) Locked, Waiting on external entities
1015. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_session.c:1665 Session 2 (sofia/internal/trillions@192.168.0.11:9040) Ended
1016. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/trillions@192.168.0.11:9040 [CS_DESTROY]
1017. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:569 (verto.rtc/2002) State Change CS_REPORTING -> CS_DESTROY
1018. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_session.c:1647 Session 1 (verto.rtc/2002) Locked, Waiting on external entities
1019. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_session.c:1665 Session 1 (verto.rtc/2002) Ended
1020. 2016-08-04 10:16:21.001209 [NOTICE] switch_core_session.c:1669 Close Channel verto.rtc/2002 [CS_DESTROY]
1021. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/trillions@192.168.0.11:9040) Running State Change CS_DESTROY
1022. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/trillions@192.168.0.11:9040) State DESTROY
1023. 2016-08-04 10:16:21.001209 [DEBUG] mod_sofia.c:343 sofia/internal/trillions@192.168.0.11:9040 SOFIA DESTROY
1024. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:181 sofia/internal/trillions@192.168.0.11:9040 Standard DESTROY
1025. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/trillions@192.168.0.11:9040) State DESTROY going to sleep
1026. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:700 (verto.rtc/2002) Running State Change CS_DESTROY
1027. 2016-08-04 10:16:21.001209 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
1028.         "jsonrpc":      "2.0",
1029.         "id":   3,
1030.         "method":       "verto.bye",
1031.         "params":       {
1032.                 "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
1033.                 "causeCode":    16,
1034.                 "cause":        "NORMAL_CLEARING"
1035.         }
1036. }]
1037. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:710 (verto.rtc/2002) State DESTROY
1038. 2016-08-04 10:16:21.001209 [DEBUG] mod_rtc.c:132 verto.rtc/2002 RTC DESTROY
1039. 2016-08-04 10:16:21.001209 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[80] PLC[0] FEC[0]
1040. 2016-08-04 10:16:21.001209 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
1041. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:181 verto.rtc/2002 Standard DESTROY
1042. 2016-08-04 10:16:21.001209 [DEBUG] switch_core_state_machine.c:710 (verto.rtc/2002) State DESTROY going to sleep
1043. 2016-08-04 10:16:21.001209 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
1044.         "jsonrpc":      "2.0",
1045.         "method":       "verto.bye",
1046.         "params":       {
1047.                 "dialogParams": {
1048.                         "useVideo":     false,
1049.                         "useStereo":    false,
1050.                         "screenShare":  false,
1051.                         "useCamera":    "none",
1052.                         "useMic":       "0cf03192275f0100c7e90f472d6e42d1abf3f4ac2b86080e5f1b8c1ff2147f2e",
1053.                         "useSpeak":     "default",
1054.                         "tag":  "webcam",
1055.                         "localTag":     null,
1056.                         "login":        "trillionss@xbipin.com",
1057.                         "videoParams":  {
1058.                                 "minWidth":     320,
1059.                                 "minHeight":    180,
1060.                                 "maxWidth":     320,
1061.                                 "maxHeight":    180,
1062.                                 "minFrameRate": 15
1063.                         },
1064.                         "destination_number":   "2002",
1065.                         "caller_id_name":       "1234",
1066.                         "caller_id_number":     "",
1067.                         "outgoingBandwidth":    90354,
1068.                         "incomingBandwidth":    192000,
1069.                         "dedEnc":       false,
1070.                         "mirrorInput":  false,
1071.                         "userVariables":        {
1072.                                 "email":        "",
1073.                                 "avatar":       "http://gravatar.com/avatar/d41d8cd98f00b204e9800998ecf8427e.png?s=600"
1074.                         },
1075.                         "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
1076.                         "remote_caller_id_name":        "Outbound Call",
1077.                         "remote_caller_id_number":      "trillions"
1078.                 },
1079.                 "sessid":       "de02989a-0170-a830-e80e-b052c07e81f5"
1080.         },
1081.         "id":   5
1082. }]
1083. 2016-08-04 10:16:21.001209 [ALERT] mod_verto.c:604 WRITE 192.168.0.11:61745 [{
1084.         "jsonrpc":      "2.0",
1085.         "id":   5,
1086.        "error":        {
1087.                 "callID":       "8e34ba61-e7b9-930e-4de0-2292db2c3009",
1088.                 "message":      "CALL DOES NOT EXIST",
1089.                 "code": -32002
1090.         }
1091. }]
1092. 2016-08-04 10:16:21.040646 [ALERT] mod_verto.c:1370 READ 192.168.0.11:61745 [{
1093.         "jsonrpc":      "2.0",
1094.         "id":   3,
1095.         "result":       {
1096.                 "method":       "verto.bye"
1097.         }
1098. }]
1099. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (94809579)
1100. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
1101. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
1102. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
1103. 2016-08-04 10:16:27.800593 [DEBUG] mod_verto.c:1862 BAD READ -1000
1104. 2016-08-04 10:16:27.800593 [INFO] mod_verto.c:2005 192.168.0.11:61745 Ending client thread.
1105. 2016-08-04 10:16:27.800593 [INFO] mod_verto.c:2013 192.168.0.11:61745 Thread ended
1106. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BED38): sent signal r_options
1107. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BED38): recv signal r_options
1108. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:280 soa_clone() soa_clone(static::01356098, 01A28248, 004BED38) called
1109. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::033658E0, ...) called
1110. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:403 soa_set_params() soa_set_params(static::033658E0, ...) called
1111. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
1112. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3257 tport_tsend() tport_tsend(01ADC2D0) tpn = udp/10.10.0.1:5060
1113. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.10.0.1:5060
1114. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4680 tport_by_addrinfo() tport(01ADC2D0): not found by name udp/10.10.0.1:5060
1115. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3594 tport_vsend() tport_vsend(01ADC2D0): 478 bytes of 478 to udp/10.10.0.1:5060
1116. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3492 tport_send_msg() tport_vsend returned 478
1117. send 478 bytes to udp/[10.10.0.1]:5060 at 06:16:36.814118:
1118.    ------------------------------------------------------------------------
1119.    OPTIONS sip:10.10.0.1;transport=udp SIP/2.0
1120.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKmB4B3Q2cU3Nve
1121.    Max-Forwards: 70
1122.    From: <sip:10.10.0.1>;tag=jSggUZr0m8K2B
1123.    To: <sip:10.10.0.1>
1124.    Call-ID: d71b4c72-d4ad-1234-3fbf-c5acbca4426b
1125.    CSeq: 94809580 OPTIONS
1126.    User-Agent: Talkycom
1127.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
1128.    Supported: timer, path, replaces
1129.    Allow-Events: talk, hold, conference, refer
1130.    Content-Length: 0
1131.  
1132.    ------------------------------------------------------------------------
1133. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8304 outgoing_send() nta: sent OPTIONS (94809580) to udp/10.10.0.1:5060
1134. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4160 tport_pend() tport_pend(01ADC2D0): pending 034B9AF8 for udp/192.168.0.11:5070 (already 0)
1135. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1350 set_timeout() nta: timer set to 32000 ms
1136. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
1137. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(01ADC2D0): events IN
1138. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:2864 tport_recv_event() tport_recv_event(01ADC2D0)
1139. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3205 tport_recv_iovec() tport(01ADC2D0) msg 034B90D0 from (udp/192.168.0.11:5070) has 363 bytes, veclen = 1
1140. recv 363 bytes from udp/[10.10.0.1]:5060 at 06:16:37.024501:
1141.    ------------------------------------------------------------------------
1142.    SIP/2.0 200 OK
1143.    CSeq: 94809580 OPTIONS
1144.    Via: SIP/2.0/UDP 192.168.0.11:5070;rport;branch=z9hG4bKmB4B3Q2cU3Nve
1145.    From: <sip:10.10.0.1>;tag=jSggUZr0m8K2B
1146.    Call-ID: d71b4c72-d4ad-1234-3fbf-c5acbca4426b
1147.    To: <sip:10.10.0.1>;tag=1016403708715234
1148.   Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, INFO, NOTIFY, MESSAGE, SUBSCRIBE, REFER, PUBLISH
1149.    Content-Length: 0
1150.  
1151.    ------------------------------------------------------------------------
1152. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:3023 tport_deliver() tport(01ADC2D0): msg 034B90D0 (363 bytes) from udp/10.10.0.1:5070/sip next=00000000
1153. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (94809580)
1154. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
1155. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 211.383 ms
1156. ..\..\sofia-sip\libsofia-sip-ua\tport\tport.c:4222 tport_release() tport(01ADC2D0): 034B9AF8 by 0320F3B0 with 034B90D0
1157. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:271 nua_stack_event() nua(004BED38): event r_options 200 OK
1158. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:529 nua_signal() nua(004BED38): sent signal r_destroy
1159. ..\..\sofia-sip\libsofia-sip-ua\nua\nua_stack.c:569 nua_stack_signal() nua(004BED38): recv signal r_destroy
1160. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:4470 nta_leg_destroy() nta_leg_destroy(00000000)
1161. ..\..\sofia-sip\libsofia-sip-ua\soa\soa.c:356 soa_destroy() soa_destroy(static::033658E0) called
1162. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1296 agent_timer() nta: timer set next to 4211 ms
1163. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (94809580)
1164. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all(00000000, 00000000, 0284F874)
1165. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
1166. ..\..\sofia-sip\libsofia-sip-ua\nta\nta.c:1289 agent_timer() nta: timer not set
1167.