From Edgy Kitten, 6 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x13196a0): events IN
  2. tport.c:2864 tport_recv_event() tport_recv_event(0x13196a0)
  3. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x13196a0) msg 0x14c3d90 from (udp/192.168.1.118:5060) has 4 bytes, veclen = 1
  4. tport.c:3023 tport_deliver() tport_deliver(0x13196a0): bad msg 0x14c3d90 (4 bytes) from udp/192.168.1.156:5060/sip next=(nil)
  5. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  6. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  7. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x14c3d90 from (tcp/192.168.1.33:54582) has 995 bytes, veclen = 1
  8. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x14c3d90 (995 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  9. nta.c:2880 agent_recv_request() nta: received PUBLISH sip:1000@192.168.1.118;transport=TCP SIP/2.0 (CSeq 202)
  10. nta.c:3248 agent_aliases() nta: canonizing sip:1000@192.168.1.118 with contact
  11. nta.c:3085 agent_recv_request() nta: PUBLISH (202) going to a default leg
  12. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  13. nua_stack.c:899 nh_create() nua: nh_create: entering
  14. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  15. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  16. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x11149b0) called
  17. soa.c:403 soa_set_params() soa_set_params(static::0x1319210, ...) called
  18. nua_stack.c:271 nua_stack_event() nua(0x11149b0): event i_publish 100 Trying
  19. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  20. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  21. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  22. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x11fa5b0 from (tcp/192.168.1.33:54582) has 1988 bytes, veclen = 1
  23. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x11fa5b0 (995 bytes) from tcp/192.168.1.33:54582/sip next=0x1126c70
  24. nta.c:2880 agent_recv_request() nta: received PUBLISH sip:1001@192.168.1.118;transport=TCP SIP/2.0 (CSeq 202)
  25. nta.c:3248 agent_aliases() nta: canonizing sip:1001@192.168.1.118 with contact
  26. nta.c:3085 agent_recv_request() nta: PUBLISH (202) going to a default leg
  27. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  28. nua_stack.c:899 nh_create() nua: nh_create: entering
  29. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  30. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  31. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x12085a0) called
  32. soa.c:403 soa_set_params() soa_set_params(static::0x120ec60, ...) called
  33. nua_stack.c:271 nua_stack_event() nua(0x12085a0): event i_publish 100 Trying
  34. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x1126c70 (993 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  35. nta.c:2880 agent_recv_request() nta: received PUBLISH sip:1003@192.168.1.118;transport=TCP SIP/2.0 (CSeq 6)
  36. nta.c:3248 agent_aliases() nta: canonizing sip:1003@192.168.1.118 with contact
  37. nta.c:3085 agent_recv_request() nta: PUBLISH (6) going to a default leg
  38. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  39. nua_stack.c:899 nh_create() nua: nh_create: entering
  40. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  41. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  42. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x121a720) called
  43. soa.c:403 soa_set_params() soa_set_params(static::0x127c110, ...) called
  44. nua_stack.c:271 nua_stack_event() nua(0x121a720): event i_publish 100 Trying
  45. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  46. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  47. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  48. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  49. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  50. nua.c:879 nua_respond() nua: nua_respond: entering
  51. nua_stack.c:573 nua_stack_signal() nua(0x11149b0): recv signal r_respond 200 OK
  52. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  53. soa.c:403 soa_set_params() soa_set_params(static::0x1319210, ...) called
  54. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  55. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 758 bytes of 758 to tcp/192.168.1.33:54582
  56. tport.c:3492 tport_send_msg() tport_vsend returned 758
  57. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  58. nta.c:6791 incoming_reply() nta: sent 200 OK for PUBLISH (202)
  59. nta.c:5744 incoming_free() nta: incoming_free(0x1100e20)
  60. nua_stack.c:529 nua_signal() nua(0x11149b0): sent signal r_respond
  61. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  62. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  63. nua_stack.c:569 nua_stack_signal() nua(0x11149b0): recv signal r_destroy
  64. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  65. soa.c:356 soa_destroy() soa_destroy(static::0x1319210) called
  66. nua_stack.c:529 nua_signal() nua(0x11149b0): sent signal r_destroy
  67. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  68. nua.c:879 nua_respond() nua: nua_respond: entering
  69. nua_stack.c:573 nua_stack_signal() nua(0x12085a0): recv signal r_respond 200 OK
  70. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  71. soa.c:403 soa_set_params() soa_set_params(static::0x120ec60, ...) called
  72. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  73. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 758 bytes of 758 to tcp/192.168.1.33:54582
  74. tport.c:3492 tport_send_msg() tport_vsend returned 758
  75. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  76. nta.c:6791 incoming_reply() nta: sent 200 OK for PUBLISH (202)
  77. nta.c:5744 incoming_free() nta: incoming_free(0x1206d50)
  78. nua_stack.c:529 nua_signal() nua(0x12085a0): sent signal r_respond
  79. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  80. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  81. nua_stack.c:569 nua_stack_signal() nua(0x12085a0): recv signal r_destroy
  82. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  83. soa.c:356 soa_destroy() soa_destroy(static::0x120ec60) called
  84. nua_stack.c:529 nua_signal() nua(0x12085a0): sent signal r_destroy
  85. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  86. nua.c:879 nua_respond() nua: nua_respond: entering
  87. nua_stack.c:573 nua_stack_signal() nua(0x121a720): recv signal r_respond 200 OK
  88. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  89. soa.c:403 soa_set_params() soa_set_params(static::0x127c110, ...) called
  90. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  91. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 756 bytes of 756 to tcp/192.168.1.33:54582
  92. tport.c:3492 tport_send_msg() tport_vsend returned 756
  93. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  94. nta.c:6791 incoming_reply() nta: sent 200 OK for PUBLISH (6)
  95. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  96. nta.c:5744 incoming_free() nta: incoming_free(0x127c7a0)
  97. nua_stack.c:529 nua_signal() nua(0x121a720): sent signal r_respond
  98. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  99. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  100. nua_stack.c:569 nua_stack_signal() nua(0x121a720): recv signal r_destroy
  101. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  102. soa.c:356 soa_destroy() soa_destroy(static::0x127c110) called
  103. nua_stack.c:529 nua_signal() nua(0x121a720): sent signal r_destroy
  104. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  105. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  106. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x10f5750 from (tcp/192.168.1.33:54582) has 907 bytes, veclen = 1
  107. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x10f5750 (907 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  108. nta.c:2880 agent_recv_request() nta: received INVITE sip:3000@192.168.1.118;transport=TCP SIP/2.0 (CSeq 1)
  109. nta.c:3248 agent_aliases() nta: canonizing sip:3000@192.168.1.118 with contact
  110. nta.c:3085 agent_recv_request() nta: INVITE (1) going to a default leg
  111. nta.c:1350 set_timeout() nta: timer set to 2000 ms
  112. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  113. nua_stack.c:899 nh_create() nua: nh_create: entering
  114. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  115. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  116. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x1534270) called
  117. soa.c:403 soa_set_params() soa_set_params(static::0x12127e0, ...) called
  118. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x1114b70)
  119. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x12127e0) called
  120. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x12127e0, (nil), 0x1532ec8, 243) called
  121. nua_dialog.c:338 nua_dialog_usage_add() nua(0x1534270): adding session usage
  122. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  123. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 362 bytes of 362 to tcp/192.168.1.33:54582
  124. tport.c:3492 tport_send_msg() tport_vsend returned 362
  125. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  126. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (1)
  127. nua_stack.c:271 nua_stack_event() nua(0x1534270): event i_invite 100 Trying
  128. nua_session.c:4139 signal_call_state_change() nua(0x1534270): call state changed: init -> received, received offer
  129. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x12127e0, [0x7f86c53328c8], [0x7f86c53328d0], [(nil)]) called
  130. nua_stack.c:271 nua_stack_event() nua(0x1534270): event i_state 100 Trying
  131. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  132. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  133. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  134. 2017-10-12 20:27:01.165465 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.1.118 [f785cb04-a3ee-43e4-9415-e43e7e606990]
  135. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  136. 2017-10-12 20:27:01.165465 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.118) Running State Change CS_NEW (Cur 1 Tot 85)
  137. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  138. 2017-10-12 20:27:01.165465 [DEBUG] sofia.c:9837 sofia/internal/1000@192.168.1.118 receiving invite from 192.168.1.33:54582 version: 1.6.18  64bit
  139. 2017-10-12 20:27:01.165465 [DEBUG] sofia.c:10008 IP 192.168.1.33 Rejected by acl "domains". Falling back to Digest auth.
  140. nua.c:879 nua_respond() nua: nua_respond: entering
  141. nua_stack.c:573 nua_stack_signal() nua(0x1534270): recv signal r_respond 407 Proxy Authentication Required
  142. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  143. soa.c:403 soa_set_params() soa_set_params(static::0x12127e0, ...) called
  144. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  145. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x12127e0) called
  146. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  147. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 866 bytes of 866 to tcp/192.168.1.33:54582
  148. tport.c:3492 tport_send_msg() tport_vsend returned 866
  149. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  150. nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (1)
  151. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x1534270): removing session usage
  152. nua_session.c:4139 signal_call_state_change() nua(0x1534270): call state changed: received -> terminated
  153. nua_stack.c:271 nua_stack_event() nua(0x1534270): event i_state 407 Proxy Authentication Required
  154. nua_stack.c:271 nua_stack_event() nua(0x1534270): event i_terminated 407 Proxy Authentication Required
  155. soa.c:356 soa_destroy() soa_destroy(static::0x12127e0) called
  156. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x1114b70)
  157. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  158. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  159. 2017-10-12 20:27:01.165465 [DEBUG] sofia.c:2334 detaching session f785cb04-a3ee-43e4-9415-e43e7e606990
  160. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  161. nua_stack.c:529 nua_signal() nua(0x1534270): sent signal r_destroy
  162. nua_stack.c:569 nua_stack_signal() nua(0x1534270): recv signal r_destroy
  163. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  164. nua_stack.c:529 nua_signal() nua(0x1534270): sent signal r_respond
  165. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  166. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  167. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  168. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  169. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  170. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  171. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  172. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  173. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  174. 2017-10-12 20:27:01.165465 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@192.168.1.118) State NEW
  175. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  176. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  177. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x162cff0 from (tcp/192.168.1.33:54582) has 366 bytes, veclen = 1
  178. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x162cff0 (366 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  179. nta.c:2880 agent_recv_request() nta: received ACK sip:3000@192.168.1.118;transport=TCP SIP/2.0 (CSeq 1)
  180. nta.c:3019 agent_recv_request() nta: ACK (1) is going to INVITE (1)
  181. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  182. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  183. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  184. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x162cff0 from (tcp/192.168.1.33:54582) has 1183 bytes, veclen = 1
  185. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x162cff0 (1183 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  186. nta.c:2880 agent_recv_request() nta: received INVITE sip:3000@192.168.1.118;transport=TCP SIP/2.0 (CSeq 2)
  187. nta.c:3248 agent_aliases() nta: canonizing sip:3000@192.168.1.118 with contact
  188. nta.c:3085 agent_recv_request() nta: INVITE (2) going to a default leg
  189. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  190. nua_stack.c:899 nh_create() nua: nh_create: entering
  191. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  192. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  193. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x120ea30) called
  194. soa.c:403 soa_set_params() soa_set_params(static::0x1534190, ...) called
  195. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x12110e0)
  196. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x1534190) called
  197. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x1534190, (nil), 0x114377c, 243) called
  198. nua_dialog.c:338 nua_dialog_usage_add() nua(0x120ea30): adding session usage
  199. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  200. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 362 bytes of 362 to tcp/192.168.1.33:54582
  201. tport.c:3492 tport_send_msg() tport_vsend returned 362
  202. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  203. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (2)
  204. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_invite 100 Trying
  205. nua_session.c:4139 signal_call_state_change() nua(0x120ea30): call state changed: init -> received, received offer
  206. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x1534190, [0x7f86c53328c8], [0x7f86c53328d0], [(nil)]) called
  207. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_state 100 Trying
  208. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  209. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  210. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  211. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:2442 Re-attaching to session f785cb04-a3ee-43e4-9415-e43e7e606990
  212. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  213. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  214. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:9837 sofia/internal/1000@192.168.1.118 receiving invite from 192.168.1.33:54582 version: 1.6.18  64bit
  215. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:10008 IP 192.168.1.33 Rejected by acl "domains". Falling back to Digest auth.
  216. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  217. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  218. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:7048 Channel sofia/internal/1000@192.168.1.118 entering state [received][100]
  219. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:7058 Remote SDP:
  220. v=0
  221. o=Z 0 0 IN IP4 117.247.91.162
  222. s=Z
  223. c=IN IP4 117.247.91.162
  224. t=0 0
  225. m=audio 8000 RTP/AVP 3 110 8 0 98 101
  226. a=rtpmap:110 speex/8000
  227. a=rtpmap:98 iLBC/8000
  228. a=fmtp:98 mode=20
  229. a=rtpmap:101 telephone-event/8000
  230. a=fmtp:101 0-15
  231.  
  232. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:7450 (sofia/internal/1000@192.168.1.118) State Change CS_NEW -> CS_INIT
  233. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  234. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.118) Running State Change CS_INIT (Cur 1 Tot 85)
  235. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.118) State INIT
  236. 2017-10-12 20:27:01.205456 [DEBUG] mod_sofia.c:90 sofia/internal/1000@192.168.1.118 SOFIA INIT
  237. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.118 Standard INIT
  238. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.118) State Change CS_INIT -> CS_ROUTING
  239. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.118) State INIT going to sleep
  240. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.118) Running State Change CS_ROUTING (Cur 1 Tot 85)
  241. 2017-10-12 20:27:01.205456 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@192.168.1.118) Callstate Change DOWN -> RINGING
  242. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.118) State ROUTING
  243. 2017-10-12 20:27:01.205456 [DEBUG] mod_sofia.c:143 sofia/internal/1000@192.168.1.118 SOFIA ROUTING
  244. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@192.168.1.118 Standard ROUTING
  245. 2017-10-12 20:27:01.205456 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->3000 in context default
  246. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->unloop] continue=false
  247. Dialplan: sofia/internal/1000@192.168.1.118 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  248. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  249. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->tod_example] continue=true
  250. Dialplan: sofia/internal/1000@192.168.1.118 Date/TimeMatch (FAIL) [tod_example] break=on-false
  251. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->holiday_example] continue=true
  252. Dialplan: sofia/internal/1000@192.168.1.118 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  253. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->global-intercept] continue=false
  254. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [global-intercept] destination_number(3000) =~ /^886$/ break=on-false
  255. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->group-intercept] continue=false
  256. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [group-intercept] destination_number(3000) =~ /^\*8$/ break=on-false
  257. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->intercept-ext] continue=false
  258. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [intercept-ext] destination_number(3000) =~ /^\*\*(\d+)$/ break=on-false
  259. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->redial] continue=false
  260. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [redial] destination_number(3000) =~ /^(redial|870)$/ break=on-false
  261. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->global] continue=true
  262. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  263. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never
  264. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  265. Dialplan: sofia/internal/1000@192.168.1.118 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  266. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  267. o=Z 0 0 IN IP4 117.247.91.162
  268. s=Z
  269. c=IN IP4 117.247.91.162
  270. t=0 0
  271. m=audio 8000 RTP/AVP 3 110 8 0 98 101
  272. a=rtpmap:110 speex/8000
  273. a=rtpmap:98 iLBC/8000
  274. a=fmtp:98 mode=20
  275. a=rtpmap:101 telephone-event/8000
  276. a=fmtp:101 0-15
  277. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  278. Dialplan: sofia/internal/1000@192.168.1.118 Absolute Condition [global]
  279. Dialplan: sofia/internal/1000@192.168.1.118 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  280. Dialplan: sofia/internal/1000@192.168.1.118 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  281. Dialplan: sofia/internal/1000@192.168.1.118 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  282. Dialplan: sofia/internal/1000@192.168.1.118 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  283. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->snom-demo-2] continue=false
  284. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [snom-demo-2] destination_number(3000) =~ /^9001$/ break=on-false
  285. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->snom-demo-1] continue=false
  286. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [snom-demo-1] destination_number(3000) =~ /^9000$/ break=on-false
  287. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->eavesdrop] continue=false
  288. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [eavesdrop] destination_number(3000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  289. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->eavesdrop] continue=false
  290. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [eavesdrop] destination_number(3000) =~ /^779$/ break=on-false
  291. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->call_return] continue=false
  292. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [call_return] destination_number(3000) =~ /^\*69$|^869$|^lcr$/ break=on-false
  293. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->del-group] continue=false
  294. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [del-group] destination_number(3000) =~ /^80(\d{2})$/ break=on-false
  295. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->add-group] continue=false
  296. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [add-group] destination_number(3000) =~ /^81(\d{2})$/ break=on-false
  297. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->call-group-simo] continue=false
  298. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [call-group-simo] destination_number(3000) =~ /^82(\d{2})$/ break=on-false
  299. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->call-group-order] continue=false
  300. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [call-group-order] destination_number(3000) =~ /^83(\d{2})$/ break=on-false
  301. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->extension-intercom] continue=false
  302. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [extension-intercom] destination_number(3000) =~ /^8(10[01][0-9])$/ break=on-false
  303. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->Local_Extension] continue=false
  304. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [Local_Extension] destination_number(3000) =~ /^(10[01][0-9])$/ break=on-false
  305. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->Local_Extension_Skinny] continue=false
  306. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [Local_Extension_Skinny] destination_number(3000) =~ /^(11[01][0-9])$/ break=on-false
  307. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->group_dial_sales] continue=false
  308. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [group_dial_sales] destination_number(3000) =~ /^2000$/ break=on-false
  309. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->group_dial_support] continue=false
  310. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [group_dial_support] destination_number(3000) =~ /^2001$/ break=on-false
  311. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->group_dial_billing] continue=false
  312. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [group_dial_billing] destination_number(3000) =~ /^2002$/ break=on-false
  313. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->operator] continue=false
  314. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [operator] destination_number(3000) =~ /^(operator|0)$/ break=on-false
  315. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->vmain] continue=false
  316. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [vmain] destination_number(3000) =~ /^vmain$|^4000$|^\*98$/ break=on-false
  317. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->sip_uri] continue=false
  318. Dialplan: sofia/internal/1000@192.168.1.118 Regex (FAIL) [sip_uri] destination_number(3000) =~ /^sip:(.*)$/ break=on-false
  319. Dialplan: sofia/internal/1000@192.168.1.118 parsing [default->nb_conferences] continue=false
  320. Dialplan: sofia/internal/1000@192.168.1.118 Regex (PASS) [nb_conferences] destination_number(3000) =~ /^(30\d{2})$/ break=on-false
  321. Dialplan: sofia/internal/1000@192.168.1.118 Action answer()
  322. Dialplan: sofia/internal/1000@192.168.1.118 Action conference(3000-${domain_name}@default)
  323. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@192.168.1.118) State Change CS_ROUTING -> CS_EXECUTE
  324. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.118) State ROUTING going to sleep
  325. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.118) Running State Change CS_EXECUTE (Cur 1 Tot 85)
  326. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@192.168.1.118) State EXECUTE
  327. 2017-10-12 20:27:01.205456 [DEBUG] mod_sofia.c:198 sofia/internal/1000@192.168.1.118 SOFIA EXECUTE
  328. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@192.168.1.118 Standard EXECUTE
  329. EXECUTE sofia/internal/1000@192.168.1.118 hash(insert/192.168.1.118-spymap/1000/f785cb04-a3ee-43e4-9415-e43e7e606990)
  330. EXECUTE sofia/internal/1000@192.168.1.118 hash(insert/192.168.1.118-last_dial/1000/3000)
  331. EXECUTE sofia/internal/1000@192.168.1.118 hash(insert/192.168.1.118-last_dial/global/f785cb04-a3ee-43e4-9415-e43e7e606990)
  332. EXECUTE sofia/internal/1000@192.168.1.118 export(RFC2822_DATE=Thu, 12 Oct 2017 20:27:01 +0530)
  333. 2017-10-12 20:27:01.205456 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 12 Oct 2017 20:27:01 +0530]
  334. EXECUTE sofia/internal/1000@192.168.1.118 answer()
  335. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  336. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  337. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  338. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [speex:110:8000:20:0:1]/[G722:9:8000:20:64000:1]
  339. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  340. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  341. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  342. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  343. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  344. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  345. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  346. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  347. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  348. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  349. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [iLBC:98:8000:30:0:1]/[G722:9:8000:20:64000:1]
  350. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  351. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  352. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
  353. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:3057 Set Codec sofia/internal/1000@192.168.1.118 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  354. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.1.118 Original read codec set to PCMA:8
  355. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
  356. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:4763 sofia/internal/1000@192.168.1.118 Set 2833 dtmf send payload to 101 recv payload to 101
  357. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/internal/1000@192.168.1.118] 192.168.1.118 port 17278 -> 117.247.91.162 port 8000 codec: 8 ms: 20
  358. 2017-10-12 20:27:01.205456 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
  359. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:7175 sofia/internal/1000@192.168.1.118 Set 2833 dtmf send payload to 101
  360. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:7182 sofia/internal/1000@192.168.1.118 Set 2833 dtmf receive payload to 101
  361. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:7205 sofia/internal/1000@192.168.1.118 Set rtp dtmf delay to 40
  362. 2017-10-12 20:27:01.205456 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@192.168.1.118!
  363. 2017-10-12 20:27:01.205456 [DEBUG] switch_channel.c:3474 (sofia/internal/1000@192.168.1.118) Callstate Change RINGING -> EARLY
  364. 2017-10-12 20:27:01.205456 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/internal/1000@192.168.1.118.
  365. 2017-10-12 20:27:01.205456 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1000@192.168.1.118:
  366. v=0
  367. o=FreeSWITCH 1507802943 1507802944 IN IP4 192.168.1.118
  368. s=FreeSWITCH
  369. c=IN IP4 192.168.1.118
  370. t=0 0
  371. m=audio 17278 RTP/AVP 8 101
  372. a=rtpmap:8 PCMA/8000
  373. a=rtpmap:101 telephone-event/8000
  374. a=fmtp:101 0-16
  375. a=ptime:20
  376. a=sendrecv
  377.  
  378. nua.c:879 nua_respond() nua: nua_respond: entering
  379. nua_stack.c:573 nua_stack_signal() nua(0x120ea30): recv signal r_respond 200 OK
  380. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  381. soa.c:403 soa_set_params() soa_set_params(static::0x1534190, ...) called
  382. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x1534190, (nil), 0x1651902, -1) called
  383. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x1534190, (nil), 0x1651902, -1) called
  384. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  385. soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x1534190) called
  386. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x1534190, soa_generate_answer): called
  387. soa_static.c:1189 offer_answer_step() soa_static(0x1534190, soa_generate_answer): generating local description
  388. soa_static.c:1230 offer_answer_step() soa_static(0x1534190, soa_generate_answer): upgrade with remote description
  389. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f86c5330b00, 0x112c3f0, ""): called
  390. soa_static.c:1446 offer_answer_step() soa_static(0x1534190, soa_generate_answer): storing local description
  391. soa.c:1730 soa_activate() soa_activate(static::0x1534190, (nil)) called
  392. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1534190, [(nil)], [0x7f86c5332c38], [0x7f86c5332c34]) called
  393. tport.c:3257 tport_tsend() tport_tsend(0x1289300) tpn = TCP/192.168.1.33:54582
  394. tport.c:3594 tport_vsend() tport_vsend(0x1289300): 1141 bytes of 1141 to tcp/192.168.1.33:54582
  395. tport.c:3492 tport_send_msg() tport_vsend returned 1141
  396. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  397. nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (2)
  398. nta.c:1348 set_timeout() nta: timer shortened to 500 ms
  399. nua_session.c:4139 signal_call_state_change() nua(0x120ea30): call state changed: received -> completed, sent answer
  400. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1534190, [0x7f86c5332ce8], [0x7f86c5332cf0], [(nil)]) called
  401. soa.c:616 soa_get_params() soa_get_params(static::0x1534190, ...) called
  402. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_state 200 OK
  403. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  404. nua_stack.c:529 nua_signal() nua(0x120ea30): sent signal r_respond
  405. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  406. 2017-10-12 20:27:01.205456 [DEBUG] sofia.c:7048 Channel sofia/internal/1000@192.168.1.118 entering state [completed][200]
  407. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  408. 2017-10-12 20:27:01.205456 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/1000@192.168.1.118] has been answered
  409. 2017-10-12 20:27:01.225455 [DEBUG] switch_channel.c:3773 (sofia/internal/1000@192.168.1.118) Callstate Change EARLY -> ACTIVE
  410. EXECUTE sofia/internal/1000@192.168.1.118 conference(3000-192.168.1.118@default)
  411. 2017-10-12 20:27:01.225455 [DEBUG] mod_conference.c:3065 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie
  412. 2017-10-12 20:27:01.225455 [DEBUG] conference_member.c:1690 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  413. 2017-10-12 20:27:01.225455 [DEBUG] conference_member.c:1737 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  414. 2017-10-12 20:27:01.225455 [DEBUG] switch_core_codec.c:223 sofia/internal/1000@192.168.1.118 Push codec L16:100
  415. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '0' to 'mute'
  416. 2017-10-12 20:27:01.245468 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
  417. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f86c783eb40 data: 0x10083f8
  418. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '*' to 'deaf mute'
  419. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f86c783eb40 data: 0x1008428
  420. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '9' to 'energy up'
  421. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f86c783eb40 data: 0x1008458
  422. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '8' to 'energy equ'
  423. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f86c783eb40 data: 0x1008488
  424. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '7' to 'energy dn'
  425. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f86c783eb40 data: 0x10084b8
  426. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '3' to 'vol talk up'
  427. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f86c783eb40 data: 0x10084e8
  428. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '2' to 'vol talk zero'
  429. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f86c783eb40 data: 0x1008518
  430. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '1' to 'vol talk dn'
  431. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f86c783eb40 data: 0x1008548
  432. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '6' to 'vol listen up'
  433. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f86c783eb40 data: 0x1008578
  434. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '5' to 'vol listen zero'
  435. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f86c783eb40 data: 0x10085a8
  436. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '4' to 'vol listen dn'
  437. 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f86c783eb40 data: 0x10085d8
  438. 2017-10-12 20:27:01.245468 [DEBUG] conference_member.c:128 sofia/internal/1000@192.168.1.118 binding '#' to 'execute_application'
  439. span style="color: goldenrod; font-weight: bold;"> 2017-10-12 20:27:01.245468 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f86c783eb40 data: 0x1008608
  440. span style="color: goldenrod; font-weight: bold;"> 2017-10-12 20:27:01.245468 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20  samples: 160 from codec PCMA
  441. 2017-10-12 20:27:01.245468 [DEBUG] mod_conference.c:220 Setup timer success interval: 20  samples: 160
  442. tport.c:2773 tport_wakeup() tport_wakeup(0x1289300): events IN
  443. tport.c:2864 tport_recv_event() tport_recv_event(0x1289300)
  444. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1289300) msg 0x11026d0 from (tcp/192.168.1.33:54582) has 735 bytes, veclen = 1
  445. tport.c:3023 tport_deliver() tport_deliver(0x1289300): msg 0x11026d0 (735 bytes) from tcp/192.168.1.33:54582/sip next=(nil)
  446. nta.c:2880 agent_recv_request() nta: received ACK sip:3000@192.168.1.118:5060;transport=tcp SIP/2.0 (CSeq 2)
  447. nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2)
  448. nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering
  449. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x1534190) called
  450. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_ack 200 OK
  451. nua_session.c:4139 signal_call_state_change() nua(0x120ea30): call state changed: completed -> ready
  452. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_state 200 OK
  453. nua_stack.c:271 nua_stack_event() nua(0x120ea30): event i_active 200 Call active
  454. nta.c:5744 incoming_free() nta: incoming_free(0x10f5b00)
  455. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  456. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  457. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  458. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  459. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  460. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  461. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  462. 2017-10-12 20:27:01.265457 [DEBUG] sofia.c:7048 Channel sofia/internal/1000@192.168.1.118 entering state [ready][200]
  463. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  464. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  465. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  466. 2017-10-12 20:27:01.505461 [INFO] switch_rtp.c:7214 Auto Changing audio port from 117.247.91.162:8000 to 192.168.1.33:8000
  467. tport.c:2296 tport_set_secondary_timer() tport(0x1289300): reset timer
  468. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f86c5332c60)
  469. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 0/0 term, 1/1 free
  470. nta.c:1289 agent_timer() nta: timer not set
  471. 2017-10-12 20:27:04.005458 [DEBUG] mod_local_stream.c:871 Opening Stream [moh/8000] 8000hz
  472. freeswitch@freeswitch>
  473. freeswitch@freeswitch>
  474. freeswitch@freeswitch>
  475. freeswitch@freeswitch>
  476. freeswitch@freeswitch>
  477. freeswitch@freeswitch>
  478. freeswitch@freeswitch>
  479. freeswitch@freeswitch>
  480. freeswitch@freeswitch>
  481. freeswitch@freeswitch>
  482. freeswitch@freeswitch>
  483. freeswitch@freeswitch>
  484. freeswitch@freeswitch>
  485. freeswitch@freeswitch>
  486. freeswitch@freeswitch>
  487. freeswitch@freeswitch>
  488. freeswitch@freeswitch>
  489. freeswitch@freeswitch>
  490. freeswitch@freeswitch>
  491. freeswitch@freeswitch>
  492. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x13196a0): events IN
  493. tport.c:2864 tport_recv_event() tport_recv_event(0x13196a0)
  494. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x13196a0) msg 0x11c46a0 from (udp/192.168.1.118:5060) has 853 bytes, veclen = 1
  495. tport.c:3023 tport_deliver() tport_deliver(0x13196a0): msg 0x11c46a0 (853 bytes) from udp/192.168.1.156:5060/sip next=(nil)
  496. nta.c:2880 agent_recv_request() nta: received INVITE sip:3000@192.168.1.118:5060 SIP/2.0 (CSeq 1)
  497. nta.c:3248 agent_aliases() nta: canonizing sip:3000@192.168.1.118:5060 with contact
  498. nta.c:3085 agent_recv_request() nta: INVITE (1) going to a default leg
  499. nta.c:1350 set_timeout() nta: timer set to 200 ms
  500. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  501. nua_stack.c:899 nh_create() nua: nh_create: entering
  502. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  503. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  504. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x12099d0) called
  505. soa.c:403 soa_set_params() soa_set_params(static::0x123cfc0, ...) called
  506. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x1289530)
  507. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x123cfc0) called
  508. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x123cfc0, (nil), 0x1102920, 261) called
  509. nua_dialog.c:338 nua_dialog_usage_add() nua(0x12099d0): adding session usage
  510. tport.c:3257 tport_tsend() tport_tsend(0x13196a0) tpn = UDP/192.168.1.156:5062
  511. tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.1.156:5062
  512. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x13196a0): not found by name UDP/192.168.1.156:5062
  513. tport.c:3594 tport_vsend() tport_vsend(0x13196a0): 285 bytes of 285 to udp/192.168.1.156:5062
  514. tport.c:3492 tport_send_msg() tport_vsend returned 285
  515. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (1)
  516. nua_stack.c:271 nua_stack_event() nua(0x12099d0): event i_invite 100 Trying
  517. nua_session.c:4139 signal_call_state_change() nua(0x12099d0): call state changed: init -> received, received offer
  518. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x123cfc0, [0x7f86c53328c8], [0x7f86c53328d0], [(nil)]) called
  519. nua_stack.c:271 nua_stack_event() nua(0x12099d0): event i_state 100 Trying
  520. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  521. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  522. 2017-10-12 20:27:11.485457 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@192.168.1.118 [9626d8bb-97d1-4b43-b588-0ec2a561bedc]
  523. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  524. 2017-10-12 20:27:11.485457 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@192.168.1.118) Running State Change CS_NEW (Cur 2 Tot 86)
  525. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  526. 2017-10-12 20:27:11.485457 [DEBUG] sofia.c:9837 sofia/internal/1002@192.168.1.118 receiving invite from 192.168.1.156:5062 version: 1.6.18  64bit
  527. 2017-10-12 20:27:11.485457 [DEBUG] sofia.c:10008 IP 192.168.1.156 Rejected by acl "domains". Falling back to Digest auth.
  528. nua.c:879 nua_respond() nua: nua_respond: entering
  529. nua_stack.c:573 nua_stack_signal() nua(0x12099d0): recv signal r_respond 407 Proxy Authentication Required
  530. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  531. soa.c:403 soa_set_params() soa_set_params(static::0x123cfc0, ...) called
  532. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  533. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x123cfc0) called
  534. tport.c:3257 tport_tsend() tport_tsend(0x13196a0) tpn = UDP/192.168.1.156:5062
  535. tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.1.156:5062
  536. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x13196a0): not found by name UDP/192.168.1.156:5062
  537. tport.c:3594 tport_vsend() tport_vsend(0x13196a0): 789 bytes of 789 to udp/192.168.1.156:5062
  538. tport.c:3492 tport_send_msg() tport_vsend returned 789
  539. nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (1)
  540. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x12099d0): removing session usage
  541. nua_session.c:4139 signal_call_state_change() nua(0x12099d0): call state changed: received -> terminated
  542. nua_stack.c:271 nua_stack_event() nua(0x12099d0): event i_state 407 Proxy Authentication Required
  543. nua_stack.c:271 nua_stack_event() nua(0x12099d0): event i_terminated 407 Proxy Authentication Required
  544. soa.c:356 soa_destroy() soa_destroy(static::0x123cfc0) called
  545. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x1289530)
  546. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  547. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  548. 2017-10-12 20:27:11.485457 [DEBUG] sofia.c:2334 detaching session 9626d8bb-97d1-4b43-b588-0ec2a561bedc
  549. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  550. nua_stack.c:529 nua_signal() nua(0x12099d0): sent signal r_destroy
  551. nua_stack.c:569 nua_stack_signal() nua(0x12099d0): recv signal r_destroy
  552. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  553. nua_stack.c:529 nua_signal() nua(0x12099d0): sent signal r_respond
  554. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  555. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  556. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  557. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  558. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  559. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  560. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  561. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  562. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  563. 2017-10-12 20:27:11.485457 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1002@192.168.1.118) State NEW
  564. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x13196a0): events IN
  565. tport.c:2864 tport_recv_event() tport_recv_event(0x13196a0)
  566. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x13196a0) msg 0x1397050 from (udp/192.168.1.118:5060) has 274 bytes, veclen = 1
  567. tport.c:3023 tport_deliver() tport_deliver(0x13196a0): msg 0x1397050 (274 bytes) from udp/192.168.1.156:5060/sip next=(nil)
  568. nta.c:2880 agent_recv_request() nta: received ACK sip:3000@192.168.1.118:5060 SIP/2.0 (CSeq 1)
  569. nta.c:3019 agent_recv_request() nta: ACK (1) is going to INVITE (1)
  570. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x13196a0): events IN
  571. tport.c:2864 tport_recv_event() tport_recv_event(0x13196a0)
  572. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x13196a0) msg 0x1397050 from (udp/192.168.1.118:5060) has 1104 bytes, veclen = 1
  573. tport.c:3023 tport_deliver() tport_deliver(0x13196a0): msg 0x1397050 (1104 bytes) from udp/192.168.1.156:5060/sip next=(nil)
  574. nta.c:2880 agent_recv_request() nta: received INVITE sip:3000@192.168.1.118:5060 SIP/2.0 (CSeq 2)
  575. nta.c:3248 agent_aliases() nta: canonizing sip:3000@192.168.1.118:5060 with contact
  576. nta.c:3085 agent_recv_request() nta: INVITE (2) going to a default leg
  577. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  578. nua_stack.c:899 nh_create() nua: nh_create: entering
  579. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  580. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  581. soa.c:280 soa_clone() soa_clone(static::0x120fea0, 0x11f8990, 0x1315880) called
  582. soa.c:403 soa_set_params() soa_set_params(static::0x123cfc0, ...) called
  583. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x1212830)
  584. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x123cfc0) called
  585. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x123cfc0, (nil), 0x10f5b0b, 261) called
  586. nua_dialog.c:338 nua_dialog_usage_add() nua(0x1315880): adding session usage
  587. tport.c:3257 tport_tsend() tport_tsend(0x13196a0) tpn = UDP/192.168.1.156:5062
  588. tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.1.156:5062
  589. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x13196a0): not found by name UDP/192.168.1.156:5062
  590. tport.c:3594 tport_vsend() tport_vsend(0x13196a0): 285 bytes of 285 to udp/192.168.1.156:5062
  591. tport.c:3492 tport_send_msg() tport_vsend returned 285
  592. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (2)
  593. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_invite 100 Trying
  594. nua_session.c:4139 signal_call_state_change() nua(0x1315880): call state changed: init -> received, received offer
  595. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x123cfc0, [0x7f86c53328c8], [0x7f86c53328d0], [(nil)]) called
  596. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_state 100 Trying
  597. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  598. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  599. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:2442 Re-attaching to session 9626d8bb-97d1-4b43-b588-0ec2a561bedc
  600. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  601. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  602. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:9837 sofia/internal/1002@192.168.1.118 receiving invite from 192.168.1.156:5062 version: 1.6.18  64bit
  603. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:10008 IP 192.168.1.156 Rejected by acl "domains". Falling back to Digest auth.
  604. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  605. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  606. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@192.168.1.118 entering state [received][100]
  607. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:7058 Remote SDP:
  608. v=0
  609. o=- 20020 20020 IN IP4 192.168.1.156
  610. s=SDP data
  611. c=IN IP4 192.168.1.156
  612. t=0 0
  613. m=audio 11798 RTP/AVP 0 4 8 101
  614. a=rtpmap:0 PCMU/8000
  615. a=rtpmap:4 G723/8000
  616. a=rtpmap:8 PCMA/8000
  617. a=rtpmap:101 telephone-event/8000
  618. a=fmtp:101 0-15
  619. a=ptime:20
  620.  
  621. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:7450 (sofia/internal/1002@192.168.1.118) State Change CS_NEW -> CS_INIT
  622. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  623. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@192.168.1.118) Running State Change CS_INIT (Cur 2 Tot 86)
  624. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@192.168.1.118) State INIT
  625. 2017-10-12 20:27:11.645458 [DEBUG] mod_sofia.c:90 sofia/internal/1002@192.168.1.118 SOFIA INIT
  626. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@192.168.1.118 Standard INIT
  627. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@192.168.1.118) State Change CS_INIT -> CS_ROUTING
  628. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@192.168.1.118) State INIT going to sleep
  629. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@192.168.1.118) Running State Change CS_ROUTING (Cur 2 Tot 86)
  630. 2017-10-12 20:27:11.645458 [DEBUG] switch_channel.c:2249 (sofia/internal/1002@192.168.1.118) Callstate Change DOWN -> RINGING
  631. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@192.168.1.118) State ROUTING
  632. 2017-10-12 20:27:11.645458 [DEBUG] mod_sofia.c:143 sofia/internal/1002@192.168.1.118 SOFIA ROUTING
  633. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1002@192.168.1.118 Standard ROUTING
  634. 2017-10-12 20:27:11.645458 [INFO] mod_dialplan_xml.c:637 Processing mayur <1002>->3000 in context default
  635. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->unloop] continue=false
  636. Dialplan: sofia/internal/1002@192.168.1.118 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  637. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  638. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->tod_example] continue=true
  639. Dialplan: sofia/internal/1002@192.168.1.118 Date/TimeMatch (FAIL) [tod_example] break=on-false
  640. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->holiday_example] continue=true
  641. Dialplan: sofia/internal/1002@192.168.1.118 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  642. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->global-intercept] continue=false
  643. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [global-intercept] destination_number(3000) =~ /^886$/ break=on-false
  644. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->group-intercept] continue=false
  645. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [group-intercept] destination_number(3000) =~ /^\*8$/ break=on-false
  646. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->intercept-ext] continue=false
  647. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [intercept-ext] destination_number(3000) =~ /^\*\*(\d+)$/ break=on-false
  648. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->redial] continue=false
  649. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [redial] destination_number(3000) =~ /^(redial|870)$/ break=on-false
  650. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->global] continue=true
  651. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  652. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never
  653. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  654. Dialplan: sofia/internal/1002@192.168.1.118 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  655. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  656. o=- 20020 20020 IN IP4 192.168.1.156
  657. s=SDP data
  658. c=IN IP4 192.168.1.156
  659. t=0 0
  660. m=audio 11798 RTP/AVP 0 4 8 101
  661. a=rtpmap:0 PCMU/8000
  662. a=rtpmap:4 G723/8000
  663. a=rtpmap:8 PCMA/8000
  664. a=rtpmap:101 telephone-event/8000
  665. a=fmtp:101 0-15
  666. a=ptime:20
  667. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  668. Dialplan: sofia/internal/1002@192.168.1.118 Absolute Condition [global]
  669. Dialplan: sofia/internal/1002@192.168.1.118 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  670. Dialplan: sofia/internal/1002@192.168.1.118 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  671. Dialplan: sofia/internal/1002@192.168.1.118 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  672. Dialplan: sofia/internal/1002@192.168.1.118 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  673. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->snom-demo-2] continue=false
  674. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [snom-demo-2] destination_number(3000) =~ /^9001$/ break=on-false
  675. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->snom-demo-1] continue=false
  676. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [snom-demo-1] destination_number(3000) =~ /^9000$/ break=on-false
  677. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->eavesdrop] continue=false
  678. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [eavesdrop] destination_number(3000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  679. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->eavesdrop] continue=false
  680. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [eavesdrop] destination_number(3000) =~ /^779$/ break=on-false
  681. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->call_return] continue=false
  682. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [call_return] destination_number(3000) =~ /^\*69$|^869$|^lcr$/ break=on-false
  683. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->del-group] continue=false
  684. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [del-group] destination_number(3000) =~ /^80(\d{2})$/ break=on-false
  685. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->add-group] continue=false
  686. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [add-group] destination_number(3000) =~ /^81(\d{2})$/ break=on-false
  687. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->call-group-simo] continue=false
  688. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [call-group-simo] destination_number(3000) =~ /^82(\d{2})$/ break=on-false
  689. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->call-group-order] continue=false
  690. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [call-group-order] destination_number(3000) =~ /^83(\d{2})$/ break=on-false
  691. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->extension-intercom] continue=false
  692. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [extension-intercom] destination_number(3000) =~ /^8(10[01][0-9])$/ break=on-false
  693. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->Local_Extension] continue=false
  694. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [Local_Extension] destination_number(3000) =~ /^(10[01][0-9])$/ break=on-false
  695. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->Local_Extension_Skinny] continue=false
  696. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [Local_Extension_Skinny] destination_number(3000) =~ /^(11[01][0-9])$/ break=on-false
  697. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->group_dial_sales] continue=false
  698. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [group_dial_sales] destination_number(3000) =~ /^2000$/ break=on-false
  699. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->group_dial_support] continue=false
  700. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [group_dial_support] destination_number(3000) =~ /^2001$/ break=on-false
  701. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->group_dial_billing] continue=false
  702. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [group_dial_billing] destination_number(3000) =~ /^2002$/ break=on-false
  703. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->operator] continue=false
  704. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [operator] destination_number(3000) =~ /^(operator|0)$/ break=on-false
  705. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->vmain] continue=false
  706. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [vmain] destination_number(3000) =~ /^vmain$|^4000$|^\*98$/ break=on-false
  707. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->sip_uri] continue=false
  708. Dialplan: sofia/internal/1002@192.168.1.118 Regex (FAIL) [sip_uri] destination_number(3000) =~ /^sip:(.*)$/ break=on-false
  709. Dialplan: sofia/internal/1002@192.168.1.118 parsing [default->nb_conferences] continue=false
  710. Dialplan: sofia/internal/1002@192.168.1.118 Regex (PASS) [nb_conferences] destination_number(3000) =~ /^(30\d{2})$/ break=on-false
  711. Dialplan: sofia/internal/1002@192.168.1.118 Action answer()
  712. Dialplan: sofia/internal/1002@192.168.1.118 Action conference(3000-${domain_name}@default)
  713. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1002@192.168.1.118) State Change CS_ROUTING -> CS_EXECUTE
  714. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@192.168.1.118) State ROUTING going to sleep
  715. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@192.168.1.118) Running State Change CS_EXECUTE (Cur 2 Tot 86)
  716. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1002@192.168.1.118) State EXECUTE
  717. 2017-10-12 20:27:11.645458 [DEBUG] mod_sofia.c:198 sofia/internal/1002@192.168.1.118 SOFIA EXECUTE
  718. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1002@192.168.1.118 Standard EXECUTE
  719. EXECUTE sofia/internal/1002@192.168.1.118 hash(insert/192.168.1.118-spymap/1002/9626d8bb-97d1-4b43-b588-0ec2a561bedc)
  720. EXECUTE sofia/internal/1002@192.168.1.118 hash(insert/192.168.1.118-last_dial/1002/3000)
  721. EXECUTE sofia/internal/1002@192.168.1.118 hash(insert/192.168.1.118-last_dial/global/9626d8bb-97d1-4b43-b588-0ec2a561bedc)
  722. EXECUTE sofia/internal/1002@192.168.1.118 export(RFC2822_DATE=Thu, 12 Oct 2017 20:27:11 +0530)
  723. 2017-10-12 20:27:11.645458 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 12 Oct 2017 20:27:11 +0530]
  724. EXECUTE sofia/internal/1002@192.168.1.118 answer()
  725. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  726. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  727. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  728. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  729. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1]
  730. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
  731. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
  732. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  733. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  734. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  735. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  736. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
  737. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:3057 Set Codec sofia/internal/1002@192.168.1.118 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  738. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@192.168.1.118 Original read codec set to PCMU:0
  739. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
  740. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:4763 sofia/internal/1002@192.168.1.118 Set 2833 dtmf send payload to 101 recv payload to 101
  741. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/internal/1002@192.168.1.118] 192.168.1.118 port 32036 -> 192.168.1.156 port 11798 codec: 0 ms: 20
  742. 2017-10-12 20:27:11.645458 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
  743. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:7175 sofia/internal/1002@192.168.1.118 Set 2833 dtmf send payload to 101
  744. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:7182 sofia/internal/1002@192.168.1.118 Set 2833 dtmf receive payload to 101
  745. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:7205 sofia/internal/1002@192.168.1.118 Set rtp dtmf delay to 40
  746. 2017-10-12 20:27:11.645458 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1002@192.168.1.118!
  747. 2017-10-12 20:27:11.645458 [DEBUG] switch_channel.c:3474 (sofia/internal/1002@192.168.1.118) Callstate Change RINGING -> EARLY
  748. 2017-10-12 20:27:11.645458 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/internal/1002@192.168.1.118.
  749. 2017-10-12 20:27:11.645458 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1002@192.168.1.118:
  750. v=0
  751. o=FreeSWITCH 1507788195 1507788196 IN IP4 192.168.1.118
  752. s=FreeSWITCH
  753. c=IN IP4 192.168.1.118
  754. t=0 0
  755. m=audio 32036 RTP/AVP 0 101
  756. a=rtpmap:0 PCMU/8000
  757. a=rtpmap:101 telephone-event/8000
  758. a=fmtp:101 0-16
  759. a=ptime:20
  760. a=sendrecv
  761.  
  762. nua.c:879 nua_respond() nua: nua_respond: entering
  763. nua_stack.c:573 nua_stack_signal() nua(0x1315880): recv signal r_respond 200 OK
  764. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  765. soa.c:403 soa_set_params() soa_set_params(static::0x123cfc0, ...) called
  766. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x123cfc0, (nil), 0x1650352, -1) called
  767. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x123cfc0, (nil), 0x1650352, -1) called
  768. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  769. soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x123cfc0) called
  770. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x123cfc0, soa_generate_answer): called
  771. soa_static.c:1189 offer_answer_step() soa_static(0x123cfc0, soa_generate_answer): generating local description
  772. soa_static.c:1230 offer_answer_step() soa_static(0x123cfc0, soa_generate_answer): upgrade with remote description
  773. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f86c5330b00, 0x1538c30, ""): called
  774. soa_static.c:1446 offer_answer_step() soa_static(0x123cfc0, soa_generate_answer): storing local description
  775. soa.c:1730 soa_activate() soa_activate(static::0x123cfc0, (nil)) called
  776. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x123cfc0, [(nil)], [0x7f86c5332c38], [0x7f86c5332c34]) called
  777. tport.c:3257 tport_tsend() tport_tsend(0x13196a0) tpn = UDP/192.168.1.156:5062
  778. tport.c:4046 tport_resolve() tport_resolve addrinfo = 192.168.1.156:5062
  779. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x13196a0): not found by name UDP/192.168.1.156:5062
  780. tport.c:3594 tport_vsend() tport_vsend(0x13196a0): 1064 bytes of 1064 to udp/192.168.1.156:5062
  781. tport.c:3492 tport_send_msg() tport_vsend returned 1064
  782. nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (2)
  783. nua_session.c:4139 signal_call_state_change() nua(0x1315880): call state changed: received -> completed, sent answer
  784. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x123cfc0, [0x7f86c5332ce8], [0x7f86c5332cf0], [(nil)]) called
  785. soa.c:616 soa_get_params() soa_get_params(static::0x123cfc0, ...) called
  786. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_state 200 OK
  787. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  788. nua_stack.c:529 nua_signal() nua(0x1315880): sent signal r_respond
  789. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  790. 2017-10-12 20:27:11.645458 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@192.168.1.118 entering state [completed][200]
  791. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  792. 2017-10-12 20:27:11.645458 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/1002@192.168.1.118] has been answered
  793. 2017-10-12 20:27:11.665452 [DEBUG] switch_channel.c:3773 (sofia/internal/1002@192.168.1.118) Callstate Change EARLY -> ACTIVE
  794. EXECUTE sofia/internal/1002@192.168.1.118 conference(3000-192.168.1.118@default)
  795. 2017-10-12 20:27:11.665452 [DEBUG] conference_member.c:1690 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  796. 2017-10-12 20:27:11.665452 [DEBUG] conference_member.c:1737 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  797. 2017-10-12 20:27:11.665452 [DEBUG] switch_core_codec.c:223 sofia/internal/1002@192.168.1.118 Push codec L16:100
  798. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '0' to 'mute'
  799. 2017-10-12 20:27:11.685455 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
  800. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f86c783eb40 data: 0x1688c98
  801. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '*' to 'deaf mute'
  802. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f86c783eb40 data: 0x1688cc8
  803. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '9' to 'energy up'
  804. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f86c783eb40 data: 0x1688cf8
  805. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '8' to 'energy equ'
  806. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f86c783eb40 data: 0x1688d28
  807. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '7' to 'energy dn'
  808. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f86c783eb40 data: 0x1688d58
  809. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '3' to 'vol talk up'
  810. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f86c783eb40 data: 0x1688d88
  811. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '2' to 'vol talk zero'
  812. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f86c783eb40 data: 0x1688db8
  813. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '1' to 'vol talk dn'
  814. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f86c783eb40 data: 0x1688de8
  815. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '6' to 'vol listen up'
  816. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f86c783eb40 data: 0x1688e18
  817. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '5' to 'vol listen zero'
  818. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f86c783eb40 data: 0x1688e48
  819. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '4' to 'vol listen dn'
  820. 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f86c783eb40 data: 0x1688e78
  821. 2017-10-12 20:27:11.685455 [DEBUG] conference_member.c:128 sofia/internal/1002@192.168.1.118 binding '#' to 'execute_application'
  822. span style="color: goldenrod; font-weight: bold;"> 2017-10-12 20:27:11.685455 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f86c783eb40 data: 0x1688ea8
  823. span style="color: goldenrod; font-weight: bold;"> 2017-10-12 20:27:11.685455 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20  samples: 160 from codec PCMU
  824. nta.c:1296 agent_timer() nta: timer set next to 475 ms
  825. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x13196a0): events IN
  826. tport.c:2864 tport_recv_event() tport_recv_event(0x13196a0)
  827. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x13196a0) msg 0x11433d0 from (udp/192.168.1.118:5060) has 639 bytes, veclen = 1
  828. tport.c:3023 tport_deliver() tport_deliver(0x13196a0): msg 0x11433d0 (639 bytes) from udp/192.168.1.156:5060/sip next=(nil)
  829. nta.c:2880 agent_recv_request() nta: received ACK sip:3000@192.168.1.118:5060;transport=udp SIP/2.0 (CSeq 2)
  830. nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2)
  831. nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering
  832. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x123cfc0) called
  833. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_ack 200 OK
  834. nua_session.c:4139 signal_call_state_change() nua(0x1315880): call state changed: completed -> ready
  835. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_state 200 OK
  836. nua_stack.c:271 nua_stack_event() nua(0x1315880): event i_active 200 Call active
  837. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  838. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  839. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  840. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  841. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  842. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  843. 2017-10-12 20:27:11.905454 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@192.168.1.118 entering state [ready][200]
  844. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  845. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  846. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  847. 2017-10-12 20:27:12.025456 [DEBUG] switch_rtp.c:7254 Correct audio ip/port confirmed.
  848. nta.c:1296 agent_timer() nta: timer set next to 4405 ms
  849. nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response
  850. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f86c5332c60)
  851. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
  852. nta.c:1296 agent_timer() nta: timer set next to 330 ms
  853. nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response
  854. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f86c5332c60)
  855. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
  856. nta.c:1289 agent_timer() nta: timer not set
  857.