From Bipin, 8 Years ago, written in FreeSWITCH.
- view diff
Embed
  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:pass) = 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":       "pass",
  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.