From Eru Michael, 2 Years ago, written in FreeSWITCH.
- go back
Embed
Viewing differences between and Inbound call coming to fs server but does not last
  1. +OK log level 7 [7]
  2. 2022-04-22 10:27:24.577453 [WARNING] switch_core_state_machine.c:687 b714f266-d654-4cfc-af4c-cd1d2448514e sofia/internal/17@156.0.249.118 Abandoned
  3. 2022-04-22 10:27:24.577453 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/17@156.0.249.118 [CS_NEW] [WRONG_CALL_STATE]
  4. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/17@156.0.249.118) Running State Change CS_HANGUP (Cur 2 Tot 14683)
  5. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/17@156.0.249.118) Callstate Change DOWN -> HANGUP
  6. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/17@156.0.249.118) State HANGUP
  7. 2022-04-22 10:27:24.577453 [DEBUG] mod_sofia.c:438 Channel sofia/internal/17@156.0.249.118 hanging up, cause: WRONG_CALL_STATE
  8. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:60 sofia/internal/17@156.0.249.118 Standard HANGUP, cause: WRONG_CALL_STATE
  9. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/17@156.0.249.118) State HANGUP going to sleep
  10. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/17@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  11. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/17@156.0.249.118) Running State Change CS_REPORTING (Cur 2 Tot 14683)
  12. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/17@156.0.249.118) State REPORTING
  13. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:174 sofia/internal/17@156.0.249.118 Standard REPORTING, cause: WRONG_CALL_STATE
  14. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/17@156.0.249.118) State REPORTING going to sleep
  15. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/17@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  16. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_session.c:1665 Session 14676 (sofia/internal/17@156.0.249.118) Locked, Waiting on external entities
  17. 2022-04-22 10:27:24.577453 [NOTICE] switch_core_session.c:1683 Session 14676 (sofia/internal/17@156.0.249.118) Ended
  18. 2022-04-22 10:27:24.577453 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/17@156.0.249.118 [CS_DESTROY]
  19. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/17@156.0.249.118) Running State Change CS_DESTROY (Cur 1 Tot 14683)
  20. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/17@156.0.249.118) State DESTROY
  21. 2022-04-22 10:27:24.577453 [DEBUG] mod_sofia.c:343 sofia/internal/17@156.0.249.118 SOFIA DESTROY
  22. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:181 sofia/internal/17@156.0.249.118 Standard DESTROY
  23. 2022-04-22 10:27:24.577453 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/17@156.0.249.118) State DESTROY going to sleep
  24. 2022-04-22 10:27:25.737467 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/08176416480@37.9.63.182:5060 [f79acedd-70a7-4303-a9ab-ef0a3fed635b]
  25. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_NEW (Cur 2 Tot 14684)
  26. 2022-04-22 10:27:25.737467 [DEBUG] sofia.c:9873 sofia/internal/08176416480@37.9.63.182:5060 receiving invite from 37.9.63.182:5060 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  27. 2022-04-22 10:27:25.737467 [DEBUG] sofia.c:9989 IP 37.9.63.182 Approved by acl "domains[]". Access Granted.
  28. 2022-04-22 10:27:25.737467 [DEBUG] sofia.c:7084 Channel sofia/internal/08176416480@37.9.63.182:5060 entering state [received][100]
  29. 2022-04-22 10:27:25.737467 [DEBUG] sofia.c:7094 Remote SDP:
  30. v=0
  31. o=- 221063692 221063677 IN IP4 37.9.63.182
  32. s=VoipSIP
  33. c=IN IP4 37.9.63.182
  34. t=0 0
  35. m=audio 7618 RTP/AVP 18
  36. a=rtpmap:18 G729/8000/1
  37. a=fmtp:18 annexb=no
  38.  
  39. 2022-04-22 10:27:25.737467 [DEBUG] sofia.c:7486 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_NEW -> CS_INIT
  40. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/08176416480@37.9.63.182:5060) State NEW
  41. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_INIT (Cur 2 Tot 14684)
  42. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/08176416480@37.9.63.182:5060) State INIT
  43. 2022-04-22 10:27:25.737467 [DEBUG] mod_sofia.c:90 sofia/internal/08176416480@37.9.63.182:5060 SOFIA INIT
  44. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:40 sofia/internal/08176416480@37.9.63.182:5060 Standard INIT
  45. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_INIT -> CS_ROUTING
  46. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/08176416480@37.9.63.182:5060) State INIT going to sleep
  47. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_ROUTING (Cur 2 Tot 14684)
  48. 2022-04-22 10:27:25.737467 [DEBUG] switch_channel.c:2249 (sofia/internal/08176416480@37.9.63.182:5060) Callstate Change DOWN -> RINGING
  49. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/08176416480@37.9.63.182:5060) State ROUTING
  50. 2022-04-22 10:27:25.737467 [DEBUG] mod_sofia.c:143 sofia/internal/08176416480@37.9.63.182:5060 SOFIA ROUTING
  51. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:236 sofia/internal/08176416480@37.9.63.182:5060 Standard ROUTING
  52. 2022-04-22 10:27:25.737467 [INFO] mod_dialplan_xml.c:637 Processing 08176416480 <08176416480>->23418888325 in context public
  53. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->unloop] continue=false
  54. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  55. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  56. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->outside_call] continue=true
  57. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Absolute Condition [outside_call]
  58. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(outside_call=true)
  59. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  60. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->call_debug] continue=true
  61. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  62. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->public_extensions] continue=false
  63. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [public_extensions] destination_number(23418888325) =~ /^(10[01][0-9])$/ break=on-false
  64. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->public_did] continue=false
  65. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [public_did] destination_number(23418888325) =~ /^(5551212)$/ break=on-false
  66. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [public->mydid] continue=false
  67. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (PASS) [mydid] destination_number(23418888325) =~ /^(23418888325)$/ break=on-false
  68. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(domain_name=156.0.249.118)
  69. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action transfer(1002 XML default)
  70. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_ROUTING -> CS_EXECUTE
  71. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/08176416480@37.9.63.182:5060) State ROUTING going to sleep
  72. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_EXECUTE (Cur 2 Tot 14684)
  73. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/08176416480@37.9.63.182:5060) State EXECUTE
  74. 2022-04-22 10:27:25.737467 [DEBUG] mod_sofia.c:198 sofia/internal/08176416480@37.9.63.182:5060 SOFIA EXECUTE
  75. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:328 sofia/internal/08176416480@37.9.63.182:5060 Standard EXECUTE
  76. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(outside_call=true)
  77. 2022-04-22 10:27:25.737467 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [outside_call]=[true]
  78. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 export(RFC2822_DATE=Fri, 22 Apr 2022 10:27:25 +0100)
  79. 2022-04-22 10:27:25.737467 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100]
  80. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(domain_name=156.0.249.118)
  81. 2022-04-22 10:27:25.737467 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [domain_name]=[156.0.249.118]
  82. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 transfer(1002 XML default)
  83. 2022-04-22 10:27:25.737467 [DEBUG] switch_ivr.c:2165 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_EXECUTE -> CS_ROUTING
  84. 2022-04-22 10:27:25.737467 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/08176416480@37.9.63.182:5060 to XML[1002@default]
  85. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/08176416480@37.9.63.182:5060) State EXECUTE going to sleep
  86. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_ROUTING (Cur 2 Tot 14684)
  87. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/08176416480@37.9.63.182:5060) State ROUTING
  88. 2022-04-22 10:27:25.737467 [DEBUG] mod_sofia.c:143 sofia/internal/08176416480@37.9.63.182:5060 SOFIA ROUTING
  89. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:236 sofia/internal/08176416480@37.9.63.182:5060 Standard ROUTING
  90. 2022-04-22 10:27:25.737467 [INFO] mod_dialplan_xml.c:637 Processing 08176416480 <08176416480>->1002 in context default
  91. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->nativetalk] continue=false
  92. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [nativetalk] destination_number(1002) =~ /^(/d{11)$/ break=on-false
  93. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->unloop] continue=false
  94. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  95. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  96. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->tod_example] continue=true
  97. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Date/Time Match (PASS) [tod_example] break=on-false
  98. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(open=true)
  99. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->holiday_example] continue=true
  100. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  101. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->global-intercept] continue=false
  102. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false
  103. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->group-intercept] continue=false
  104. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false
  105. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->intercept-ext] continue=false
  106. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false
  107. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->redial] continue=false
  108. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false
  109. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->global] continue=true
  110. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  111. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [global] ${default_password}(012345) =~ /^1234$/ break=never
  112. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 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
  113. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  114. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  115. o=- 221063692 221063677 IN IP4 37.9.63.182
  116. s=VoipSIP
  117. c=IN IP4 37.9.63.182
  118. t=0 0
  119. m=audio 7618 RTP/AVP 18
  120. a=rtpmap:18 G729/8000/1
  121. a=fmtp:18 annexb=no
  122. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  123. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Absolute Condition [global]
  124. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  125. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  126. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  127. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  128. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->snom-demo-2] continue=false
  129. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false
  130. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->snom-demo-1] continue=false
  131. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false
  132. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->eavesdrop] continue=false
  133. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  134. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->eavesdrop] continue=false
  135. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false
  136. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->call_return] continue=false
  137. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false
  138. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->del-group] continue=false
  139. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false
  140. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->add-group] continue=false
  141. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false
  142. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->call-group-simo] continue=false
  143. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false
  144. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->call-group-order] continue=false
  145. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false
  146. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->extension-intercom] continue=false
  147. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false
  148. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 parsing [default->Local_Extension] continue=false
  149. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[0-9]|1[1-9][0-9]|[2-9][0-9]{2}|10[01][0-9])$/ break=on-false
  150. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action export(dialed_extension=1002)
  151. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bind_meta_app(1 b s execute_extension::dx XML features)
  152. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  153. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bind_meta_app(3 b s execute_extension::cf XML features)
  154. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  155. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(ringback=${us-ring})
  156. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(transfer_ringback=local_stream://moh)
  157. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(call_timeout=30)
  158. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(hangup_after_bridge=true)
  159. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(continue_on_fail=true)
  160. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  161. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  162. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  163. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  164. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  165. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  166. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bridge(user/${dialed_extension}@${domain_name})
  167. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action answer()
  168. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action sleep(1000)
  169. Dialplan: sofia/internal/08176416480@37.9.63.182:5060 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  170. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_ROUTING -> CS_EXECUTE
  171. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/08176416480@37.9.63.182:5060) State ROUTING going to sleep
  172. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_EXECUTE (Cur 2 Tot 14684)
  173. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/08176416480@37.9.63.182:5060) State EXECUTE
  174. 2022-04-22 10:27:25.737467 [DEBUG] mod_sofia.c:198 sofia/internal/08176416480@37.9.63.182:5060 SOFIA EXECUTE
  175. 2022-04-22 10:27:25.737467 [DEBUG] switch_core_state_machine.c:328 sofia/internal/08176416480@37.9.63.182:5060 Standard EXECUTE
  176. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(open=true)
  177. 2022-04-22 10:27:25.737467 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [open]=[true]
  178. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-spymap/08176416480/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  179. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial/08176416480/1002)
  180. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial/global/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  181. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 export(RFC2822_DATE=Fri, 22 Apr 2022 10:27:25 +0100)
  182. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100]
  183. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 export(dialed_extension=1002)
  184. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1002]
  185. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 bind_meta_app(1 b s execute_extension::dx XML features)
  186. 2022-04-22 10:27:25.757373 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *1 execute_extension::dx XML features
  187. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/08176416480.2022-04-22-10-27-25.wav)
  188. 2022-04-22 10:27:25.757373 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/08176416480.2022-04-22-10-27-25.wav
  189. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 bind_meta_app(3 b s execute_extension::cf XML features)
  190. 2022-04-22 10:27:25.757373 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *3 execute_extension::cf XML features
  191. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  192. 2022-04-22 10:27:25.757373 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *4 execute_extension::att_xfer XML features
  193. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(ringback=%(2000,4000,440,480))
  194. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [ringback]=[%(2000,4000,440,480)]
  195. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(transfer_ringback=local_stream://moh)
  196. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [transfer_ringback]=[local_stream://moh]
  197. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(call_timeout=30)
  198. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [call_timeout]=[30]
  199. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(hangup_after_bridge=true)
  200. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [hangup_after_bridge]=[true]
  201. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(continue_on_fail=true)
  202. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [continue_on_fail]=[true]
  203. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-call_return/1002/08176416480)
  204. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial_ext/1002/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  205. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 set(called_party_callgroup=techsupport)
  206. 2022-04-22 10:27:25.757373 [DEBUG] mod_dptools.c:1548 SET sofia/internal/08176416480@37.9.63.182:5060 [called_party_callgroup]=[techsupport]
  207. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial_ext/techsupport/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  208. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial_ext/global/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  209. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 hash(insert/156.0.249.118-last_dial/techsupport/f79acedd-70a7-4303-a9ab-ef0a3fed635b)
  210. EXECUTE sofia/internal/08176416480@37.9.63.182:5060 bridge(user/1002@156.0.249.118)
  211. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100] to event
  212. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100] to event
  213. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
  214. 2022-04-22 10:27:25.757373 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  215. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100] to event
  216. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:25 +0100] to event
  217. 2022-04-22 10:27:25.757373 [DEBUG] switch_channel.c:1250 sofia/internal/08176416480@37.9.63.182:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
  218. 2022-04-22 10:27:25.757373 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  219. 2022-04-22 10:27:25.757373 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@41.204.224.210:5060 [9d8f8d44-d5de-4b30-b2a7-f0a0886df5f8]
  220. 2022-04-22 10:27:25.757373 [DEBUG] mod_sofia.c:4819 (sofia/internal/1002@41.204.224.210:5060) State Change CS_NEW -> CS_INIT
  221. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_INIT (Cur 3 Tot 14685)
  222. 2022-04-22 10:27:25.757373 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  223. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@41.204.224.210:5060) State INIT
  224. 2022-04-22 10:27:25.757373 [DEBUG] mod_sofia.c:90 sofia/internal/1002@41.204.224.210:5060 SOFIA INIT
  225. 2022-04-22 10:27:25.757373 [DEBUG] sofia_glue.c:1295 sofia/internal/1002@41.204.224.210:5060 sending invite version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  226. Local SDP:
  227. v=0
  228. o=FreeSWITCH 1650587957 1650587958 IN IP4 156.0.249.118
  229. s=FreeSWITCH
  230. c=IN IP4 156.0.249.118
  231. t=0 0
  232. m=audio 31688 RTP/AVP 9 0 8 101
  233. a=rtpmap:9 G722/8000
  234. a=rtpmap:0 PCMU/8000
  235. a=rtpmap:8 PCMA/8000
  236. a=rtpmap:101 telephone-event/8000
  237. a=fmtp:101 0-16
  238. a=ptime:20
  239. a=sendrecv
  240. m=video 17190 RTP/AVP 102
  241. b=AS:1024
  242. a=rtpmap:102 VP8/90000
  243. a=rtcp-fb:102 ccm fir
  244. a=rtcp-fb:102 ccm tmmbr
  245. a=rtcp-fb:102 nack
  246. a=rtcp-fb:102 nack pli
  247.  
  248. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@41.204.224.210:5060 Standard INIT
  249. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@41.204.224.210:5060) State Change CS_INIT -> CS_ROUTING
  250. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@41.204.224.210:5060) State INIT going to sleep
  251. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_ROUTING (Cur 3 Tot 14685)
  252. 2022-04-22 10:27:25.757373 [DEBUG] sofia.c:7084 Channel sofia/internal/1002@41.204.224.210:5060 entering state [calling][0]
  253. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@41.204.224.210:5060) State ROUTING
  254. 2022-04-22 10:27:25.757373 [DEBUG] mod_sofia.c:143 sofia/internal/1002@41.204.224.210:5060 SOFIA ROUTING
  255. 2022-04-22 10:27:25.757373 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1002@41.204.224.210:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  256. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@41.204.224.210:5060) State ROUTING going to sleep
  257. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 14685)
  258. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@41.204.224.210:5060) State CONSUME_MEDIA
  259. 2022-04-22 10:27:25.757373 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@41.204.224.210:5060) State CONSUME_MEDIA going to sleep
  260. 2022-04-22 10:27:26.097407 [DEBUG] sofia.c:7084 Channel sofia/internal/1002@41.204.224.210:5060 entering state [proceeding][180]
  261. 2022-04-22 10:27:26.097407 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/1002@41.204.224.210:5060!
  262. 2022-04-22 10:27:26.097407 [DEBUG] switch_channel.c:3346 (sofia/internal/1002@41.204.224.210:5060) Callstate Change DOWN -> RINGING
  263. 2022-04-22 10:27:26.117386 [INFO] switch_ivr_originate.c:1215 Sending early media
  264. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  265. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  266. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  267. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_media.c:4738 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  268. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_media.c:4767 sofia/internal/08176416480@37.9.63.182:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  269. 2022-04-22 10:27:26.117386 [ERR] mod_sofia.c:2343 CODEC NEGOTIATION ERROR.  SDP:
  270. v=0
  271. o=- 221063692 221063677 IN IP4 37.9.63.182
  272. s=VoipSIP
  273. c=IN IP4 37.9.63.182
  274. t=0 0
  275. m=audio 7618 RTP/AVP 18
  276. a=rtpmap:18 G729/8000/1
  277. a=fmtp:18 annexb=no
  278.  
  279. 2022-04-22 10:27:26.117386 [NOTICE] switch_channel.c:3515 Hangup sofia/internal/08176416480@37.9.63.182:5060 [CS_EXECUTE] [INCOMPATIBLE_DESTINATION]
  280. 2022-04-22 10:27:26.117386 [DEBUG] switch_ivr_originate.c:1216 sofia/internal/08176416480@37.9.63.182:5060 Media Establishment Failed.
  281. 2022-04-22 10:27:26.117386 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
  282. 2022-04-22 10:27:26.117386 [NOTICE] switch_ivr_originate.c:3938 Hangup sofia/internal/1002@41.204.224.210:5060 [CS_CONSUME_MEDIA] [USER_NOT_REGISTERED]
  283. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_HANGUP (Cur 3 Tot 14685)
  284. 2022-04-22 10:27:26.117386 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
  285. 2022-04-22 10:27:26.117386 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
  286. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1002@41.204.224.210:5060) Callstate Change RINGING -> HANGUP
  287. 2022-04-22 10:27:26.117386 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: USER_NOT_REGISTERED
  288. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_session.c:2815 sofia/internal/08176416480@37.9.63.182:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  289. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/08176416480@37.9.63.182:5060) State EXECUTE going to sleep
  290. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_HANGUP (Cur 3 Tot 14685)
  291. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@41.204.224.210:5060) State HANGUP
  292. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/08176416480@37.9.63.182:5060) Callstate Change RINGING -> HANGUP
  293. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1002@41.204.224.210:5060 hanging up, cause: USER_NOT_REGISTERED
  294. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/08176416480@37.9.63.182:5060) State HANGUP
  295. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:438 Channel sofia/internal/08176416480@37.9.63.182:5060 hanging up, cause: INCOMPATIBLE_DESTINATION
  296. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/1002@41.204.224.210:5060
  297. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1002@41.204.224.210:5060 Standard HANGUP, cause: USER_NOT_REGISTERED
  298. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@41.204.224.210:5060) State HANGUP going to sleep
  299. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1002@41.204.224.210:5060) State Change CS_HANGUP -> CS_REPORTING
  300. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_REPORTING (Cur 3 Tot 14685)
  301. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@41.204.224.210:5060) State REPORTING
  302. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1002@41.204.224.210:5060 Standard REPORTING, cause: USER_NOT_REGISTERED
  303. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@41.204.224.210:5060) State REPORTING going to sleep
  304. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1002@41.204.224.210:5060) State Change CS_REPORTING -> CS_DESTROY
  305. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_session.c:1665 Session 14685 (sofia/internal/1002@41.204.224.210:5060) Locked, Waiting on external entities
  306. 2022-04-22 10:27:26.117386 [NOTICE] switch_core_session.c:1683 Session 14685 (sofia/internal/1002@41.204.224.210:5060) Ended
  307. 2022-04-22 10:27:26.117386 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1002@41.204.224.210:5060 [CS_DESTROY]
  308. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1002@41.204.224.210:5060) Running State Change CS_DESTROY (Cur 2 Tot 14685)
  309. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 488
  310. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@41.204.224.210:5060) State DESTROY
  311. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:343 sofia/internal/1002@41.204.224.210:5060 SOFIA DESTROY
  312. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1002@41.204.224.210:5060 Standard DESTROY
  313. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@41.204.224.210:5060) State DESTROY going to sleep
  314. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:60 sofia/internal/08176416480@37.9.63.182:5060 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
  315. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/08176416480@37.9.63.182:5060) State HANGUP going to sleep
  316. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_HANGUP -> CS_REPORTING
  317. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_REPORTING (Cur 2 Tot 14685)
  318. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/08176416480@37.9.63.182:5060) State REPORTING
  319. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:174 sofia/internal/08176416480@37.9.63.182:5060 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
  320. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/08176416480@37.9.63.182:5060) State REPORTING going to sleep
  321. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/08176416480@37.9.63.182:5060) State Change CS_REPORTING -> CS_DESTROY
  322. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_session.c:1665 Session 14684 (sofia/internal/08176416480@37.9.63.182:5060) Locked, Waiting on external entities
  323. 2022-04-22 10:27:26.117386 [NOTICE] switch_core_session.c:1683 Session 14684 (sofia/internal/08176416480@37.9.63.182:5060) Ended
  324. 2022-04-22 10:27:26.117386 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/08176416480@37.9.63.182:5060 [CS_DESTROY]
  325. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/08176416480@37.9.63.182:5060) Running State Change CS_DESTROY (Cur 1 Tot 14685)
  326. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/08176416480@37.9.63.182:5060) State DESTROY
  327. 2022-04-22 10:27:26.117386 [DEBUG] mod_sofia.c:343 sofia/internal/08176416480@37.9.63.182:5060 SOFIA DESTROY
  328. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:181 sofia/internal/08176416480@37.9.63.182:5060 Standard DESTROY
  329. 2022-04-22 10:27:26.117386 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/08176416480@37.9.63.182:5060) State DESTROY going to sleep
  330. 2022-04-22 10:27:26.677391 [WARNING] switch_core_state_machine.c:687 d97b5d8b-18ce-4d1f-8dca-aac956a3a128 sofia/internal/10001@156.0.249.118 Abandoned
  331. 2022-04-22 10:27:26.677391 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/10001@156.0.249.118 [CS_NEW] [WRONG_CALL_STATE]
  332. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10001@156.0.249.118) Running State Change CS_HANGUP (Cur 1 Tot 14685)
  333. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/10001@156.0.249.118) Callstate Change DOWN -> HANGUP
  334. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/10001@156.0.249.118) State HANGUP
  335. 2022-04-22 10:27:26.677391 [DEBUG] mod_sofia.c:438 Channel sofia/internal/10001@156.0.249.118 hanging up, cause: WRONG_CALL_STATE
  336. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:60 sofia/internal/10001@156.0.249.118 Standard HANGUP, cause: WRONG_CALL_STATE
  337. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/10001@156.0.249.118) State HANGUP going to sleep
  338. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/10001@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  339. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10001@156.0.249.118) Running State Change CS_REPORTING (Cur 1 Tot 14685)
  340. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/10001@156.0.249.118) State REPORTING
  341. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:174 sofia/internal/10001@156.0.249.118 Standard REPORTING, cause: WRONG_CALL_STATE
  342. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/10001@156.0.249.118) State REPORTING going to sleep
  343. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/10001@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  344. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_session.c:1665 Session 14679 (sofia/internal/10001@156.0.249.118) Locked, Waiting on external entities
  345. 2022-04-22 10:27:26.677391 [NOTICE] switch_core_session.c:1683 Session 14679 (sofia/internal/10001@156.0.249.118) Ended
  346. 2022-04-22 10:27:26.677391 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/10001@156.0.249.118 [CS_DESTROY]
  347. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/10001@156.0.249.118) Running State Change CS_DESTROY (Cur 0 Tot 14685)
  348. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/10001@156.0.249.118) State DESTROY
  349. 2022-04-22 10:27:26.677391 [DEBUG] mod_sofia.c:343 sofia/internal/10001@156.0.249.118 SOFIA DESTROY
  350. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:181 sofia/internal/10001@156.0.249.118 Standard DESTROY
  351. 2022-04-22 10:27:26.677391 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/10001@156.0.249.118) State DESTROY going to sleep
  352. 2022-04-22 10:27:27.277382 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@156.0.249.118 [a25b8ee0-7e54-4213-a05a-75014319fada]
  353. 2022-04-22 10:27:27.277382 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_NEW (Cur 1 Tot 14686)
  354. 2022-04-22 10:27:27.277382 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:63874 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  355. 2022-04-22 10:27:27.277382 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  356. 2022-04-22 10:27:27.277382 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@156.0.249.118) State NEW
  357. 2022-04-22 10:27:27.277382 [DEBUG] sofia.c:2334 detaching session a25b8ee0-7e54-4213-a05a-75014319fada
  358. 2022-04-22 10:27:27.577389 [DEBUG] sofia.c:2442 Re-attaching to session a25b8ee0-7e54-4213-a05a-75014319fada
  359. 2022-04-22 10:27:27.577389 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:63874 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  360. 2022-04-22 10:27:27.577389 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  361. 2022-04-22 10:27:27.577389 [NOTICE] sofia.c:2332 Hangup sofia/internal/1000@156.0.249.118 [CS_NEW] [CALL_REJECTED]
  362. 2022-04-22 10:27:27.597387 [DEBUG] sofia.c:1453 Channel is already hungup.
  363. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_HANGUP (Cur 1 Tot 14686)
  364. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@156.0.249.118) Callstate Change DOWN -> HANGUP
  365. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP
  366. 2022-04-22 10:27:27.597387 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1000@156.0.249.118 hanging up, cause: CALL_REJECTED
  367. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@156.0.249.118 Standard HANGUP, cause: CALL_REJECTED
  368. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP going to sleep
  369. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  370. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_REPORTING (Cur 1 Tot 14686)
  371. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING
  372. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@156.0.249.118 Standard REPORTING, cause: CALL_REJECTED
  373. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING going to sleep
  374. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  375. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_session.c:1665 Session 14686 (sofia/internal/1000@156.0.249.118) Locked, Waiting on external entities
  376. 2022-04-22 10:27:27.597387 [NOTICE] switch_core_session.c:1683 Session 14686 (sofia/internal/1000@156.0.249.118) Ended
  377. 2022-04-22 10:27:27.597387 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1000@156.0.249.118 [CS_DESTROY]
  378. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@156.0.249.118) Running State Change CS_DESTROY (Cur 0 Tot 14686)
  379. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY
  380. 2022-04-22 10:27:27.597387 [DEBUG] mod_sofia.c:343 sofia/internal/1000@156.0.249.118 SOFIA DESTROY
  381. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@156.0.249.118 Standard DESTROY
  382. 2022-04-22 10:27:27.597387 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY going to sleep
  383. 2022-04-22 10:27:27.717404 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1000@156.0.249.118 [4722a4b7-f0ee-4c58-af52-e37028ee65c6]
  384. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_NEW (Cur 1 Tot 14687)
  385. 2022-04-22 10:27:27.717404 [DEBUG] sofia.c:9873 sofia/external/1000@156.0.249.118 receiving invite from 103.213.247.230:64128 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  386. 2022-04-22 10:27:27.717404 [DEBUG] sofia.c:7084 Channel sofia/external/1000@156.0.249.118 entering state [received][100]
  387. 2022-04-22 10:27:27.717404 [DEBUG] sofia.c:7094 Remote SDP:
  388. v=0
  389. o=- 329918574 329919044 IN IP4 0.0.0.0
  390. s=sipcall
  391. c=IN IP4 0.0.0.0
  392. t=0 0
  393. m=audio 7628 RTP/AVP 100 6 0 8 3 18 5 101
  394. a=rtpmap:100 speex/16000
  395. a=rtpmap:101 telephone-event/8000
  396. a=fmtp:101 0-11
  397. a=alt:1 1 : DF50DC48 0000006A 0.0.0.0 7628
  398.  
  399. 2022-04-22 10:27:27.717404 [DEBUG] sofia.c:7486 (sofia/external/1000@156.0.249.118) State Change CS_NEW -> CS_INIT
  400. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:603 (sofia/external/1000@156.0.249.118) State NEW
  401. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_INIT (Cur 1 Tot 14687)
  402. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@156.0.249.118) State INIT
  403. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:90 sofia/external/1000@156.0.249.118 SOFIA INIT
  404. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:40 sofia/external/1000@156.0.249.118 Standard INIT
  405. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1000@156.0.249.118) State Change CS_INIT -> CS_ROUTING
  406. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@156.0.249.118) State INIT going to sleep
  407. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_ROUTING (Cur 1 Tot 14687)
  408. 2022-04-22 10:27:27.717404 [DEBUG] switch_channel.c:2249 (sofia/external/1000@156.0.249.118) Callstate Change DOWN -> RINGING
  409. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@156.0.249.118) State ROUTING
  410. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:143 sofia/external/1000@156.0.249.118 SOFIA ROUTING
  411. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:236 sofia/external/1000@156.0.249.118 Standard ROUTING
  412. 2022-04-22 10:27:27.717404 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->51815054790850 in context public
  413. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->unloop] continue=false
  414. Dialplan: sofia/external/1000@156.0.249.118 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  415. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  416. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->outside_call] continue=true
  417. Dialplan: sofia/external/1000@156.0.249.118 Absolute Condition [outside_call]
  418. Dialplan: sofia/external/1000@156.0.249.118 Action set(outside_call=true)
  419. Dialplan: sofia/external/1000@156.0.249.118 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  420. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->call_debug] continue=true
  421. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  422. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->public_extensions] continue=false
  423. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [public_extensions] destination_number(51815054790850) =~ /^(10[01][0-9])$/ break=on-false
  424. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->public_did] continue=false
  425. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [public_did] destination_number(51815054790850) =~ /^(5551212)$/ break=on-false
  426. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->mydid] continue=false
  427. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [mydid] destination_number(51815054790850) =~ /^(23418888325)$/ break=on-false
  428. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:286 (sofia/external/1000@156.0.249.118) State Change CS_ROUTING -> CS_EXECUTE
  429. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@156.0.249.118) State ROUTING going to sleep
  430. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_EXECUTE (Cur 1 Tot 14687)
  431. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@156.0.249.118) State EXECUTE
  432. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:198 sofia/external/1000@156.0.249.118 SOFIA EXECUTE
  433. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:328 sofia/external/1000@156.0.249.118 Standard EXECUTE
  434. EXECUTE sofia/external/1000@156.0.249.118 set(outside_call=true)
  435. 2022-04-22 10:27:27.717404 [DEBUG] mod_dptools.c:1548 SET sofia/external/1000@156.0.249.118 [outside_call]=[true]
  436. EXECUTE sofia/external/1000@156.0.249.118 export(RFC2822_DATE=Fri, 22 Apr 2022 10:27:27 +0100)
  437. 2022-04-22 10:27:27.717404 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:27 +0100]
  438. 2022-04-22 10:27:27.717404 [NOTICE] switch_core_state_machine.c:385 sofia/external/1000@156.0.249.118 has executed the last dialplan instruction, hanging up.
  439. 2022-04-22 10:27:27.717404 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/1000@156.0.249.118 [CS_EXECUTE] [NORMAL_CLEARING]
  440. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@156.0.249.118) State EXECUTE going to sleep
  441. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_HANGUP (Cur 1 Tot 14687)
  442. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1000@156.0.249.118) Callstate Change RINGING -> HANGUP
  443. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@156.0.249.118) State HANGUP
  444. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:438 Channel sofia/external/1000@156.0.249.118 hanging up, cause: NORMAL_CLEARING
  445. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
  446. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:60 sofia/external/1000@156.0.249.118 Standard HANGUP, cause: NORMAL_CLEARING
  447. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@156.0.249.118) State HANGUP going to sleep
  448. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1000@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  449. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_REPORTING (Cur 1 Tot 14687)
  450. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@156.0.249.118) State REPORTING
  451. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:174 sofia/external/1000@156.0.249.118 Standard REPORTING, cause: NORMAL_CLEARING
  452. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@156.0.249.118) State REPORTING going to sleep
  453. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1000@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  454. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_session.c:1665 Session 14687 (sofia/external/1000@156.0.249.118) Locked, Waiting on external entities
  455. 2022-04-22 10:27:27.717404 [NOTICE] switch_core_session.c:1683 Session 14687 (sofia/external/1000@156.0.249.118) Ended
  456. 2022-04-22 10:27:27.717404 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1000@156.0.249.118 [CS_DESTROY]
  457. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1000@156.0.249.118) Running State Change CS_DESTROY (Cur 0 Tot 14687)
  458. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@156.0.249.118) State DESTROY
  459. 2022-04-22 10:27:27.717404 [DEBUG] mod_sofia.c:343 sofia/external/1000@156.0.249.118 SOFIA DESTROY
  460. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:181 sofia/external/1000@156.0.249.118 Standard DESTROY
  461. 2022-04-22 10:27:27.717404 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@156.0.249.118) State DESTROY going to sleep
  462. 2022-04-22 10:27:27.937411 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/6001@156.0.249.118 [cb1a2fab-955d-4875-9846-98c8ade21817]
  463. 2022-04-22 10:27:27.937411 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/6001@156.0.249.118) Running State Change CS_NEW (Cur 1 Tot 14688)
  464. 2022-04-22 10:27:27.937411 [DEBUG] sofia.c:9873 sofia/internal/6001@156.0.249.118 receiving invite from 45.93.16.40:49229 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  465. 2022-04-22 10:27:27.937411 [DEBUG] sofia.c:10044 IP 45.93.16.40 Rejected by acl "domains". Falling back to Digest auth.
  466. 2022-04-22 10:27:27.937411 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/6001@156.0.249.118) State NEW
  467. 2022-04-22 10:27:27.937411 [DEBUG] sofia.c:2334 detaching session cb1a2fab-955d-4875-9846-98c8ade21817
  468. 2022-04-22 10:27:29.057408 [WARNING] sofia_reg.c:2906 Can't find user [3001@156.0.249.118] from 20.31.130.193
  469. You must define a domain called '156.0.249.118' in your directory and add a user with the id="3001" attribute
  470. and you must configure your device to use the proper domain in it's authentication credentials.
  471. 2022-04-22 10:27:31.917389 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@156.0.249.118 [c4c99391-152e-4d8e-a946-98e0935f59e6]
  472. 2022-04-22 10:27:31.917389 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_NEW (Cur 2 Tot 14689)
  473. 2022-04-22 10:27:31.917389 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:60468 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  474. 2022-04-22 10:27:31.917389 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  475. 2022-04-22 10:27:31.917389 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@156.0.249.118) State NEW
  476. 2022-04-22 10:27:31.917389 [DEBUG] sofia.c:2334 detaching session c4c99391-152e-4d8e-a946-98e0935f59e6
  477. 2022-04-22 10:27:31.977382 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/0000000@156.0.249.118 [5669f982-632d-4255-9904-c5997a62d199]
  478. 2022-04-22 10:27:31.977382 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/0000000@156.0.249.118) Running State Change CS_NEW (Cur 3 Tot 14690)
  479. 2022-04-22 10:27:31.977382 [DEBUG] sofia.c:9873 sofia/internal/0000000@156.0.249.118 receiving invite from 20.224.243.51:64248 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  480. 2022-04-22 10:27:31.977382 [DEBUG] sofia.c:10044 IP 20.224.243.51 Rejected by acl "domains". Falling back to Digest auth.
  481. 2022-04-22 10:27:31.977382 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/0000000@156.0.249.118) State NEW
  482. 2022-04-22 10:27:31.977382 [DEBUG] sofia.c:2334 detaching session 5669f982-632d-4255-9904-c5997a62d199
  483. 2022-04-22 10:27:32.217394 [DEBUG] sofia.c:2442 Re-attaching to session c4c99391-152e-4d8e-a946-98e0935f59e6
  484. 2022-04-22 10:27:32.237384 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/10001@156.0.249.118 [1e994eed-0140-4a9e-9c4c-f64adce4b293]
  485. 2022-04-22 10:27:32.237384 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10001@156.0.249.118) Running State Change CS_NEW (Cur 4 Tot 14691)
  486. 2022-04-22 10:27:32.237384 [DEBUG] sofia.c:9873 sofia/internal/10001@156.0.249.118 receiving invite from 45.93.16.41:60246 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  487. 2022-04-22 10:27:32.237384 [DEBUG] sofia.c:10044 IP 45.93.16.41 Rejected by acl "domains". Falling back to Digest auth.
  488. 2022-04-22 10:27:32.237384 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/10001@156.0.249.118) State NEW
  489. 2022-04-22 10:27:32.237384 [DEBUG] sofia.c:2334 detaching session 1e994eed-0140-4a9e-9c4c-f64adce4b293
  490. 2022-04-22 10:27:32.237384 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:60468 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  491. 2022-04-22 10:27:32.237384 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  492. 2022-04-22 10:27:32.237384 [NOTICE] sofia.c:2332 Hangup sofia/internal/1000@156.0.249.118 [CS_NEW] [CALL_REJECTED]
  493. 2022-04-22 10:27:32.257382 [DEBUG] sofia.c:1453 Channel is already hungup.
  494. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_HANGUP (Cur 4 Tot 14691)
  495. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@156.0.249.118) Callstate Change DOWN -> HANGUP
  496. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP
  497. 2022-04-22 10:27:32.257382 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1000@156.0.249.118 hanging up, cause: CALL_REJECTED
  498. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@156.0.249.118 Standard HANGUP, cause: CALL_REJECTED
  499. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP going to sleep
  500. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  501. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_REPORTING (Cur 4 Tot 14691)
  502. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING
  503. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@156.0.249.118 Standard REPORTING, cause: CALL_REJECTED
  504. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING going to sleep
  505. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  506. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_session.c:1665 Session 14689 (sofia/internal/1000@156.0.249.118) Locked, Waiting on external entities
  507. 2022-04-22 10:27:32.257382 [NOTICE] switch_core_session.c:1683 Session 14689 (sofia/internal/1000@156.0.249.118) Ended
  508. 2022-04-22 10:27:32.257382 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1000@156.0.249.118 [CS_DESTROY]
  509. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@156.0.249.118) Running State Change CS_DESTROY (Cur 3 Tot 14691)
  510. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY
  511. 2022-04-22 10:27:32.257382 [DEBUG] mod_sofia.c:343 sofia/internal/1000@156.0.249.118 SOFIA DESTROY
  512. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@156.0.249.118 Standard DESTROY
  513. 2022-04-22 10:27:32.257382 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY going to sleep
  514. 2022-04-22 10:27:33.677382 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1000@156.0.249.118 [39a72c82-970f-4e4a-8a7b-82311f781d21]
  515. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_NEW (Cur 4 Tot 14692)
  516. 2022-04-22 10:27:33.677382 [DEBUG] sofia.c:9873 sofia/external/1000@156.0.249.118 receiving invite from 103.213.247.230:60976 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  517. 2022-04-22 10:27:33.677382 [DEBUG] sofia.c:7084 Channel sofia/external/1000@156.0.249.118 entering state [received][100]
  518. 2022-04-22 10:27:33.677382 [DEBUG] sofia.c:7094 Remote SDP:
  519. v=0
  520. o=- 329918574 329919044 IN IP4 0.0.0.0
  521. s=sipcall
  522. c=IN IP4 0.0.0.0
  523. t=0 0
  524. m=audio 7628 RTP/AVP 100 6 0 8 3 18 5 101
  525. a=rtpmap:100 speex/16000
  526. a=rtpmap:101 telephone-event/8000
  527. a=fmtp:101 0-11
  528. a=alt:1 1 : DF50DC48 0000006A 0.0.0.0 7628
  529.  
  530. 2022-04-22 10:27:33.677382 [DEBUG] sofia.c:7486 (sofia/external/1000@156.0.249.118) State Change CS_NEW -> CS_INIT
  531. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:603 (sofia/external/1000@156.0.249.118) State NEW
  532. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_INIT (Cur 4 Tot 14692)
  533. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@156.0.249.118) State INIT
  534. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:90 sofia/external/1000@156.0.249.118 SOFIA INIT
  535. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:40 sofia/external/1000@156.0.249.118 Standard INIT
  536. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1000@156.0.249.118) State Change CS_INIT -> CS_ROUTING
  537. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@156.0.249.118) State INIT going to sleep
  538. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_ROUTING (Cur 4 Tot 14692)
  539. 2022-04-22 10:27:33.677382 [DEBUG] switch_channel.c:2249 (sofia/external/1000@156.0.249.118) Callstate Change DOWN -> RINGING
  540. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@156.0.249.118) State ROUTING
  541. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:143 sofia/external/1000@156.0.249.118 SOFIA ROUTING
  542. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:236 sofia/external/1000@156.0.249.118 Standard ROUTING
  543. 2022-04-22 10:27:33.677382 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->52815054790850 in context public
  544. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->unloop] continue=false
  545. Dialplan: sofia/external/1000@156.0.249.118 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  546. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  547. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->outside_call] continue=true
  548. Dialplan: sofia/external/1000@156.0.249.118 Absolute Condition [outside_call]
  549. Dialplan: sofia/external/1000@156.0.249.118 Action set(outside_call=true)
  550. Dialplan: sofia/external/1000@156.0.249.118 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  551. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->call_debug] continue=true
  552. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  553. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->public_extensions] continue=false
  554. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [public_extensions] destination_number(52815054790850) =~ /^(10[01][0-9])$/ break=on-false
  555. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->public_did] continue=false
  556. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [public_did] destination_number(52815054790850) =~ /^(5551212)$/ break=on-false
  557. Dialplan: sofia/external/1000@156.0.249.118 parsing [public->mydid] continue=false
  558. Dialplan: sofia/external/1000@156.0.249.118 Regex (FAIL) [mydid] destination_number(52815054790850) =~ /^(23418888325)$/ break=on-false
  559. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:286 (sofia/external/1000@156.0.249.118) State Change CS_ROUTING -> CS_EXECUTE
  560. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@156.0.249.118) State ROUTING going to sleep
  561. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_EXECUTE (Cur 4 Tot 14692)
  562. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@156.0.249.118) State EXECUTE
  563. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:198 sofia/external/1000@156.0.249.118 SOFIA EXECUTE
  564. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:328 sofia/external/1000@156.0.249.118 Standard EXECUTE
  565. EXECUTE sofia/external/1000@156.0.249.118 set(outside_call=true)
  566. 2022-04-22 10:27:33.677382 [DEBUG] mod_dptools.c:1548 SET sofia/external/1000@156.0.249.118 [outside_call]=[true]
  567. EXECUTE sofia/external/1000@156.0.249.118 export(RFC2822_DATE=Fri, 22 Apr 2022 10:27:33 +0100)
  568. 2022-04-22 10:27:33.677382 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 22 Apr 2022 10:27:33 +0100]
  569. 2022-04-22 10:27:33.677382 [NOTICE] switch_core_state_machine.c:385 sofia/external/1000@156.0.249.118 has executed the last dialplan instruction, hanging up.
  570. 2022-04-22 10:27:33.677382 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/1000@156.0.249.118 [CS_EXECUTE] [NORMAL_CLEARING]
  571. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@156.0.249.118) State EXECUTE going to sleep
  572. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_HANGUP (Cur 4 Tot 14692)
  573. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1000@156.0.249.118) Callstate Change RINGING -> HANGUP
  574. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@156.0.249.118) State HANGUP
  575. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:438 Channel sofia/external/1000@156.0.249.118 hanging up, cause: NORMAL_CLEARING
  576. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
  577. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:60 sofia/external/1000@156.0.249.118 Standard HANGUP, cause: NORMAL_CLEARING
  578. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@156.0.249.118) State HANGUP going to sleep
  579. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1000@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  580. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@156.0.249.118) Running State Change CS_REPORTING (Cur 4 Tot 14692)
  581. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@156.0.249.118) State REPORTING
  582. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:174 sofia/external/1000@156.0.249.118 Standard REPORTING, cause: NORMAL_CLEARING
  583. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@156.0.249.118) State REPORTING going to sleep
  584. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1000@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  585. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_session.c:1665 Session 14692 (sofia/external/1000@156.0.249.118) Locked, Waiting on external entities
  586. 2022-04-22 10:27:33.677382 [NOTICE] switch_core_session.c:1683 Session 14692 (sofia/external/1000@156.0.249.118) Ended
  587. 2022-04-22 10:27:33.677382 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1000@156.0.249.118 [CS_DESTROY]
  588. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1000@156.0.249.118) Running State Change CS_DESTROY (Cur 3 Tot 14692)
  589. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@156.0.249.118) State DESTROY
  590. 2022-04-22 10:27:33.677382 [DEBUG] mod_sofia.c:343 sofia/external/1000@156.0.249.118 SOFIA DESTROY
  591. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:181 sofia/external/1000@156.0.249.118 Standard DESTROY
  592. 2022-04-22 10:27:33.677382 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@156.0.249.118) State DESTROY going to sleep
  593. 2022-04-22 10:27:37.377406 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@156.0.249.118 [3fdb0e42-b48e-45bb-9c40-bf27838319ab]
  594. 2022-04-22 10:27:37.377406 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_NEW (Cur 4 Tot 14693)
  595. 2022-04-22 10:27:37.377406 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:62219 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  596. 2022-04-22 10:27:37.377406 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  597. 2022-04-22 10:27:37.377406 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@156.0.249.118) State NEW
  598. 2022-04-22 10:27:37.377406 [DEBUG] sofia.c:2334 detaching session 3fdb0e42-b48e-45bb-9c40-bf27838319ab
  599. 2022-04-22 10:27:37.737383 [DEBUG] sofia.c:2442 Re-attaching to session 3fdb0e42-b48e-45bb-9c40-bf27838319ab
  600. 2022-04-22 10:27:37.737383 [DEBUG] sofia.c:9873 sofia/internal/1000@156.0.249.118 receiving invite from 103.213.247.230:62219 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 64bit
  601. 2022-04-22 10:27:37.737383 [DEBUG] sofia.c:10044 IP 103.213.247.230 Rejected by acl "domains". Falling back to Digest auth.
  602. 2022-04-22 10:27:37.737383 [NOTICE] sofia.c:2332 Hangup sofia/internal/1000@156.0.249.118 [CS_NEW] [CALL_REJECTED]
  603. 2022-04-22 10:27:37.757390 [DEBUG] sofia.c:1453 Channel is already hungup.
  604. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_HANGUP (Cur 4 Tot 14693)
  605. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@156.0.249.118) Callstate Change DOWN -> HANGUP
  606. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP
  607. 2022-04-22 10:27:37.757390 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1000@156.0.249.118 hanging up, cause: CALL_REJECTED
  608. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@156.0.249.118 Standard HANGUP, cause: CALL_REJECTED
  609. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@156.0.249.118) State HANGUP going to sleep
  610. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@156.0.249.118) State Change CS_HANGUP -> CS_REPORTING
  611. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@156.0.249.118) Running State Change CS_REPORTING (Cur 4 Tot 14693)
  612. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING
  613. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@156.0.249.118 Standard REPORTING, cause: CALL_REJECTED
  614. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@156.0.249.118) State REPORTING going to sleep
  615. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@156.0.249.118) State Change CS_REPORTING -> CS_DESTROY
  616. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_session.c:1665 Session 14693 (sofia/internal/1000@156.0.249.118) Locked, Waiting on external entities
  617. 2022-04-22 10:27:37.757390 [NOTICE] switch_core_session.c:1683 Session 14693 (sofia/internal/1000@156.0.249.118) Ended
  618. 2022-04-22 10:27:37.757390 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1000@156.0.249.118 [CS_DESTROY]
  619. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@156.0.249.118) Running State Change CS_DESTROY (Cur 3 Tot 14693)
  620. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY
  621. 2022-04-22 10:27:37.757390 [DEBUG] mod_sofia.c:343 sofia/internal/1000@156.0.249.118 SOFIA DESTROY
  622. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@156.0.249.118 Standard DESTROY
  623. 2022-04-22 10:27:37.757390 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@156.0.249.118) State DESTROY going to sleep
  624.