From len, 7 Years ago, written in Plain Text.
- go back
Embed
Viewing differences between and TLS
  1.  received INVITE sips:1002@sips2.lab.algosolutions.com:5061 SIP/2.0 (CSeq 26620)
  2. nta.c:3085 agent_recv_request() nta: INVITE (26620) going to a default leg
  3. nta.c:1350 set_timeout() nta: timer set to 2000 ms
  4. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  5. nua_stack.c:899 nh_create() nua: nh_create: entering
  6. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  7. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  8. soa.c:280 soa_clone() soa_clone(static::0x8c50360, 0x8c4c6a0, 0x8cca5a0) called
  9. soa.c:403 soa_set_params() soa_set_params(static::0x8ca1838, ...) called
  10. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x8ccb490)
  11. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x8ca1838) called
  12. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x8ca1838, (nil), 0x8ca10bb, 601) called
  13. nua_dialog.c:338 nua_dialog_usage_add() nua(0x8cca5a0): adding session usage
  14. tport.c:3257 tport_tsend() tport_tsend(0x8cca1c8) tpn = TLS/10.30.11.53:40452
  15. tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x8d610d0 0x8cc98d0 368 (368)
  16. tport.c:3492 tport_send_msg() tport_vsend returned 368
  17. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  18. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (26620)
  19. nua_session.c:4139 signal_call_state_change() nua(0x8cca5a0): call state changed: init -> received, received offer
  20. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x8ca1838, [0xb52d7dec], [0xb52d7df0], [(nil)]) called
  21. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  22. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  23. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  24. 2017-07-21 15:56:28.883729 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@sips2.lab.algosolutions.com:5061 [64611c78-7f79-4852-b5ad-1f48584efb01]
  25. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  26. 2017-07-21 15:56:28.883729 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) Running State Change CS_NEW (Cur 1 Tot 19)
  27. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  28. 2017-07-21 15:56:28.883729 [DEBUG] sofia.c:9837 sofia/internal/1001@sips2.lab.algosolutions.com:5061 receiving invite from 10.30.11.53:40452 version: 1.6.18 git db529ca 2017-06-30 17:38:19Z 32bit
  29. 2017-07-21 15:56:28.883729 [DEBUG] sofia.c:10008 IP 10.30.11.53 Rejected by acl "domains". Falling back to Digest auth.
  30. nua.c:879 nua_respond() nua: nua_respond: entering
  31. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  32. soa.c:403 soa_set_params() soa_set_params(static::0x8ca1838, ...) called
  33. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  34. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x8ca1838) called
  35. tport.c:3257 tport_tsend() tport_tsend(0x8cca1c8) tpn = TLS/10.30.11.53:40452
  36. tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x8d610d0 0x8ccef48 886 (886)
  37. tport.c:3492 tport_send_msg() tport_vsend returned 886
  38. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  39. nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (26620)
  40. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x8cca5a0): removing session usage
  41. nua_session.c:4139 signal_call_state_change() nua(0x8cca5a0): call state changed: received -> terminated
  42. soa.c:356 soa_destroy() soa_destroy(static::0x8ca1838) called
  43. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x8ccb490)
  44. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  45. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  46. 2017-07-21 15:56:28.883729 [DEBUG] sofia.c:2334 detaching session 64611c78-7f79-4852-b5ad-1f48584efb01
  47. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  48. nua_stack.c:529 nua_signal() nua(0x8cca5a0): sent signal r_destroy
  49. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  50. nua_stack.c:529 nua_signal() nua(0x8cca5a0): sent signal r_respond
  51. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  52. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  53. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  54. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  55. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  56. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  57. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  58. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  59. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  60. 2017-07-21 15:56:28.883729 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State NEW
  61. tport.c:2773 tport_wakeup() tport_wakeup(0x8cca1c8): events IN
  62. tport.c:2864 tport_recv_event() tport_recv_event(0x8cca1c8)
  63. tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x8cca1c8): tls_read() returned 386
  64. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x8cca1c8) msg 0x8ca1770 from (tls/10.30.11.53:40452) has 386 bytes, veclen = 1
  65. tport.c:3023 tport_deliver() tport_deliver(0x8cca1c8): msg 0x8ca1770 (386 bytes) from tls/10.30.11.53:40452/sips next=(nil)
  66. nta.c:2880 agent_recv_request() nta: received ACK sips:1002@sips2.lab.algosolutions.com:5061 SIP/2.0 (CSeq 26620)
  67. nta.c:3019 agent_recv_request() nta: ACK (26620) is going to INVITE (26620)
  68. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  69. tport.c:2773 tport_wakeup() tport_wakeup(0x8cca1c8): events IN
  70. tport.c:2864 tport_recv_event() tport_recv_event(0x8cca1c8)
  71. tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x8cca1c8): tls_read() returned 1341
  72. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x8cca1c8) msg 0x8ca1770 from (tls/10.30.11.53:40452) has 1341 bytes, veclen = 1
  73. tport.c:3023 tport_deliver() tport_deliver(0x8cca1c8): msg 0x8ca1770 (1341 bytes) from tls/10.30.11.53:40452/sips next=(nil)
  74. nta.c:2880 agent_recv_request() nta: received INVITE sips:1002@sips2.lab.algosolutions.com:5061 SIP/2.0 (CSeq 26621)
  75. nta.c:3085 agent_recv_request() nta: INVITE (26621) going to a default leg
  76. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  77. nua_stack.c:899 nh_create() nua: nh_create: entering
  78. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  79. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  80. soa.c:280 soa_clone() soa_clone(static::0x8c50360, 0x8c4c6a0, 0x8d98e00) called
  81. soa.c:403 soa_set_params() soa_set_params(static::0x8cd0248, ...) called
  82. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x8d643a8)
  83. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x8cd0248) called
  84. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x8cd0248, (nil), 0x8d98a14, 601) called
  85. nua_dialog.c:338 nua_dialog_usage_add() nua(0x8d98e00): adding session usage
  86. tport.c:3257 tport_tsend() tport_tsend(0x8cca1c8) tpn = TLS/10.30.11.53:40452
  87. tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x8d610d0 0x8cc98d0 368 (368)
  88. tport.c:3492 tport_send_msg() tport_vsend returned 368
  89. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  90. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (26621)
  91. nua_session.c:4139 signal_call_state_change() nua(0x8d98e00): call state changed: init -> received, received offer
  92. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x8cd0248, [0xb52d7dec], [0xb52d7df0], [(nil)]) called
  93. tport.c:2296 tport_set_secondary_timer() tport(0x8cca1c8): reset timer
  94. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  95. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  96. 2017-07-21 15:56:28.943857 [DEBUG] sofia.c:2442 Re-attaching to session 64611c78-7f79-4852-b5ad-1f48584efb01
  97. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  98. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  99. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:9837 sofia/internal/1001@sips2.lab.algosolutions.com:5061 receiving invite from 10.30.11.53:40452 version: 1.6.18 git db529ca 2017-06-30 17:38:19Z 32bit
  100. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:10008 IP 10.30.11.53 Rejected by acl "domains". Falling back to Digest auth.
  101. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  102. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  103. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@sips2.lab.algosolutions.com:5061 entering state [received][100]
  104. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:7058 Remote SDP:
  105. v=0
  106. o=- 1059576656 1397714575 IN IP4 10.30.11.53
  107. s=-
  108. c=IN IP4 10.30.11.53
  109. t=0 0
  110. m=audio 3000 RTP/SAVP 0 8 9 101
  111. a=rtpmap:0 PCMU/8000
  112. a=rtpmap:8 PCMA/8000
  113. a=rtpmap:9 G722/8000
  114. a=rtpmap:101 telephone-event/8000
  115. a=fmtp:101 0-15
  116. a=label:1
  117. a=rtcp-rsize
  118. a=ssrc:3843876445 cname:sips:1001@sips2.lab.algosolutions.com:5061
  119. a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:y6nj/mrfJAM2HVUP6zd06LitSWzDlo+Xy1FoQEKo
  120. a=ptime:20
  121. m=video 6000 RTP/AVP 110 111
  122. a=rtpmap:110 H264/90000
  123. a=fmtp:110 profile-level-id=42c00d
  124. a=rtpmap:111 H264/90000
  125. a=fmtp:111 profile-level-id=64001f
  126. a=sendonly
  127.  
  128. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:7436 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State Change CS_NEW -> CS_INIT
  129. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  130. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) Running State Change CS_INIT (Cur 1 Tot 19)
  131. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State INIT
  132. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:90 sofia/internal/1001@sips2.lab.algosolutions.com:5061 SOFIA INIT
  133. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@sips2.lab.algosolutions.com:5061 Standard INIT
  134. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State Change CS_INIT -> CS_ROUTING
  135. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State INIT going to sleep
  136. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) Running State Change CS_ROUTING (Cur 1 Tot 19)
  137. 2017-07-21 15:56:28.973694 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) Callstate Change DOWN -> RINGING
  138. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State ROUTING
  139. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:143 sofia/internal/1001@sips2.lab.algosolutions.com:5061 SOFIA ROUTING
  140. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@sips2.lab.algosolutions.com:5061 Standard ROUTING
  141. 2017-07-21 15:56:28.973694 [INFO] mod_dialplan_xml.c:637 Processing 1001 <1001>->1002 in context default
  142. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->unloop] continue=false
  143. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  144. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  145. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->tod_example] continue=true
  146. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Date/Time Match (PASS) [tod_example] break=on-false
  147. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(open=true)
  148. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->holiday_example] continue=true
  149. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  150. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->global-intercept] continue=false
  151. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false
  152. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->group-intercept] continue=false
  153. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false
  154. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->intercept-ext] continue=false
  155. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false
  156. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->redial] continue=false
  157. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false
  158. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->global] continue=true
  159. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  160. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [global] ${default_password}(0000) =~ /^1234$/ break=never
  161. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 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
  162. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [global] ${endpoint_disposition}(RECEIVED_NOMEDIA) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  163. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->snom-demo-2] continue=false
  164. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false
  165. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->snom-demo-1] continue=false
  166. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false
  167. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->eavesdrop] continue=false
  168. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  169. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->eavesdrop] continue=false
  170. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false
  171. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->call_return] continue=false
  172. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false
  173. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->del-group] continue=false
  174. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false
  175. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->add-group] continue=false
  176. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false
  177. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->call-group-simo] continue=false
  178. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false
  179. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->call-group-order] continue=false
  180. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false
  181. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->extension-intercom] continue=false
  182. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false
  183. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 parsing [default->Local_Extension] continue=false
  184. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false
  185. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action export(dialed_extension=1002)
  186. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bind_meta_app(1 b s execute_extension::dx XML features)
  187. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  188. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bind_meta_app(3 b s execute_extension::cf XML features)
  189. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  190. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(ringback=${us-ring})
  191. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(transfer_ringback=local_stream://moh)
  192. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(call_timeout=30)
  193. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(hangup_after_bridge=true)
  194. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(continue_on_fail=true)
  195. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  196. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  197. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  198. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  199. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  200. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  201. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bridge(user/${dialed_extension}@${domain_name})
  202. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action answer()
  203. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action sleep(1000)
  204. Dialplan: sofia/internal/1001@sips2.lab.algosolutions.com:5061 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  205. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State Change CS_ROUTING -> CS_EXECUTE
  206. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State ROUTING going to sleep
  207. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) Running State Change CS_EXECUTE (Cur 1 Tot 19)
  208. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@sips2.lab.algosolutions.com:5061) State EXECUTE
  209. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:198 sofia/internal/1001@sips2.lab.algosolutions.com:5061 SOFIA EXECUTE
  210. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@sips2.lab.algosolutions.com:5061 Standard EXECUTE
  211. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(open=true)
  212. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [open]=[true]
  213. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 export(dialed_extension=1002)
  214. 2017-07-21 15:56:28.973694 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1002]
  215. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 bind_meta_app(1 b s execute_extension::dx XML features)
  216. 2017-07-21 15:56:28.973694 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *1 execute_extension::dx XML features
  217. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1001.2017-07-21-15-56-28.wav)
  218. 2017-07-21 15:56:28.973694 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1001.2017-07-21-15-56-28.wav
  219. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 bind_meta_app(3 b s execute_extension::cf XML features)
  220. 2017-07-21 15:56:28.973694 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *3 execute_extension::cf XML features
  221. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  222. 2017-07-21 15:56:28.973694 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *4 execute_extension::att_xfer XML features
  223. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(ringback=%(2000,4000,440,480))
  224. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [ringback]=[%(2000,4000,440,480)]
  225. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(transfer_ringback=local_stream://moh)
  226. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [transfer_ringback]=[local_stream://moh]
  227. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(call_timeout=30)
  228. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [call_timeout]=[30]
  229. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(hangup_after_bridge=true)
  230. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [hangup_after_bridge]=[true]
  231. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(continue_on_fail=true)
  232. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [continue_on_fail]=[true]
  233. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 hash(insert/10.30.14.236-call_return/1002/1001)
  234. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 hash(insert/10.30.14.236-last_dial_ext/1002/64611c78-7f79-4852-b5ad-1f48584efb01)
  235. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 set(called_party_callgroup=techsupport)
  236. 2017-07-21 15:56:28.973694 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@sips2.lab.algosolutions.com:5061 [called_party_callgroup]=[techsupport]
  237. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 hash(insert/10.30.14.236-last_dial_ext/techsupport/64611c78-7f79-4852-b5ad-1f48584efb01)
  238. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 hash(insert/10.30.14.236-last_dial_ext/global/64611c78-7f79-4852-b5ad-1f48584efb01)
  239. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 hash(insert/10.30.14.236-last_dial/techsupport/64611c78-7f79-4852-b5ad-1f48584efb01)
  240. EXECUTE sofia/internal/1001@sips2.lab.algosolutions.com:5061 bridge(user/1002@10.30.14.236)
  241. 2017-07-21 15:56:28.973694 [DEBUG] switch_channel.c:1250 sofia/internal/1001@sips2.lab.algosolutions.com:5061 EXPORTING[export_vars] [dialed_extension]=[1002] to event
  242. 2017-07-21 15:56:28.973694 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  243. 2017-07-21 15:56:28.973694 [DEBUG] switch_channel.c:1250 sofia/internal/1001@sips2.lab.algosolutions.com:5061 EXPORTING[export_vars] [dialed_extension]=[1002] to event
  244. 2017-07-21 15:56:28.973694 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  245. 2017-07-21 15:56:28.973694 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@10.30.14.245:5061 [dd73a4d8-c79e-4c43-9d93-101861addc07]
  246. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:4819 (sofia/internal/1002@10.30.14.245:5061) State Change CS_NEW -> CS_INIT
  247. 2017-07-21 15:56:28.973694 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  248. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.30.14.245:5061) Running State Change CS_INIT (Cur 2 Tot 20)
  249. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@10.30.14.245:5061) State INIT
  250. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:90 sofia/internal/1002@10.30.14.245:5061 SOFIA INIT
  251. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  252. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  253. 2017-07-21 15:56:28.973694 [DEBUG] sofia_glue.c:1295 sofia/internal/1002@10.30.14.245:5061 sending invite version: 1.6.18 git db529ca 2017-06-30 17:38:19Z 32bit
  254. Local SDP:
  255. v=0
  256. o=- 1059576656 1397714575 IN IP4 10.30.11.53
  257. s=-
  258. c=IN IP4 10.30.11.53
  259. t=0 0
  260. m=audio 3000 RTP/SAVP 0 8 9 101
  261. a=rtpmap:0 PCMU/8000
  262. a=rtpmap:8 PCMA/8000
  263. a=rtpmap:9 G722/8000
  264. a=rtpmap:101 telephone-event/8000
  265. a=fmtp:101 0-15
  266. a=label:1
  267. a=rtcp-rsize
  268. a=ssrc:3843876445 cname:sips:1001@sips2.lab.algosolutions.com:5061
  269. a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:y6nj/mrfJAM2HVUP6zd06LitSWzDlo+Xy1FoQEKo
  270. a=ptime:20
  271. m=video 6000 RTP/AVP 110 111
  272. a=rtpmap:110 H264/90000
  273. a=fmtp:110 profile-level-id=42c00d
  274. a=rtpmap:111 H264/90000
  275. a=fmtp:111 profile-level-id=64001f
  276. a=sendonly
  277.  
  278. nua.c:633 nua_invite() nua: nua_invite: entering
  279. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
  280. soa.c:280 soa_clone() soa_clone(static::0x8c50360, 0x8c4c6a0, 0xb4426cb8) called
  281. soa.c:403 soa_set_params() soa_set_params(static::0x8ccec90, ...) called
  282. soa.c:403 soa_set_params() soa_set_params(static::0x8ccec90, ...) called
  283. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x8ccec90, (nil), 0xb5dc6213, -1) called
  284. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x8ccec90, (nil), 0xb5dc6213, -1) called
  285. nua_dialog.c:338 nua_dialog_usage_add() nua(0xb4426cb8): adding session usage
  286. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x8cca5f8)
  287. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x8ccec90) called
  288. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x8ccec90, 0) called
  289. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x8ccec90, soa_generate_offer): called
  290. soa_static.c:1189 offer_answer_step() soa_static(0x8ccec90, soa_generate_offer): generating local description
  291. soa_static.c:1217 offer_answer_step() soa_static(0x8ccec90, soa_generate_offer): upgrade with local description
  292. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0xb52d5f6c, (nil), ""): called
  293. soa_static.c:1446 offer_answer_step() soa_static(0x8ccec90, soa_generate_offer): storing local description
  294. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x8ccec90, [(nil)], [0xb52d8088], [0xb52d808c]) called
  295. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  296. tport.c:3257 tport_tsend() tport_tsend(0x8c52580) tpn = */10.30.14.245:5061
  297. tport.c:4046 tport_resolve() tport_resolve addrinfo = 10.30.14.245:5061
  298. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x8c52580): not found by name */10.30.14.245:5061
  299. tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x8c52580): new secondary tport 0x8d3cb08
  300. tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x8d3cb08): Setting TCP_KEEPIDLE to 30
  301. tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x8d3cb08): Setting TCP_KEEPINTVL to 30
  302. tport_type_tls.c:683 tport_tls_connect() tport_tls_connect(0x8d3cb08): connecting to tls/10.30.14.245:5061/sips
  303. tport.c:2296 tport_set_secondary_timer() tport(0x8d3cb08): reset timer
  304. tport.c:3782 tport_queue() tport_queue(0x8d3cb08): queueing 0x8bd4c38 for tls/10.30.14.245:5061
  305. nta.c:8304 outgoing_send() nta: sent INVITE (110002830) to */10.30.14.245:5061
  306. tport.c:4160 tport_pend() tport_pend(0x8d3cb08): pending 0x8bd4c38 for tls/10.30.14.245:5061 (already 0)
  307. nua_session.c:4139 signal_call_state_change() nua(0xb4426cb8): call state changed: init -> calling, sent offer
  308. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x8ccec90, [0xb52d8084], [0xb52d8088], [(nil)]) called
  309. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  310. nua_stack.c:529 nua_signal() nua(0xb4426cb8): sent signal r_invite
  311. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@10.30.14.245:5061 Standard INIT
  312. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@10.30.14.245:5061) State Change CS_INIT -> CS_ROUTING
  313. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@10.30.14.245:5061) State INIT going to sleep
  314. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.30.14.245:5061) Running State Change CS_ROUTING (Cur 2 Tot 20)
  315. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  316. tport_tls.c:955 tls_connect() tls_connect(0x8d3cb08): events CONNECTING
  317. 2017-07-21 15:56:28.973694 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@10.30.14.245:5061 entering state [calling][0]
  318. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  319. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@10.30.14.245:5061) State ROUTING
  320. 2017-07-21 15:56:28.973694 [DEBUG] mod_sofia.c:143 sofia/internal/1002@10.30.14.245:5061 SOFIA ROUTING
  321. 2017-07-21 15:56:28.973694 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1002@10.30.14.245:5061) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  322. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@10.30.14.245:5061) State ROUTING going to sleep
  323. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.30.14.245:5061) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 20)
  324. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@10.30.14.245:5061) State CONSUME_MEDIA
  325. 2017-07-21 15:56:28.973694 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@10.30.14.245:5061) State CONSUME_MEDIA going to sleep
  326. tport_tls.c:955 tls_connect() tls_connect(0x8d3cb08): events NEGOTIATING
  327. tport_tls.c:1044 tls_connect() tls_connect(0x8d3cb08): TLS setup failed (error:00000001:lib(0):func(0):reason(1))
  328. tport.c:2090 tport_close() tport_close(0x8d3cb08): tls/10.30.14.245:5061/sips
  329. tport.c:4222 tport_release() tport_release(0x8d3cb08): 0x8bd4c38 by 0x8d70e08 with (nil)
  330. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0xb52d8140)
  331. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 0/0 term, 1/2 free
  332. nta.c:1296 agent_timer() nta: timer set next to 30089 ms
  333.