From danilo, 1 Year ago, written in Plain Text.
- view diff
Embed
  1. root@voz:~# fs_cli -pqX9cSmjaIycY74SFdF2p | grep dbb.voz.brvoz.net
  2. 2023-05-31 22:15:16.081396 98.53% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [10200@dbb.voz.brvoz.net] from ip 189.41.77.66
  3. 2023-05-31 22:15:17.181394 98.50% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [10200@dbb.voz.brvoz.net] from ip 189.41.77.66
  4. 2023-05-31 22:15:26.681401 98.47% [NOTICE] switch_channel.c:1123 New Channel sofia/default/10200@dbb.voz.brvoz.net [7489e69b-7579-4203-a12d-1a8a042b29f7]
  5. 2023-05-31 22:15:26.681401 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_NEW (Cur 3 Tot 26356)
  6. 2023-05-31 22:15:26.681401 98.47% [INFO] sofia.c:10462 sofia/default/10200@dbb.voz.brvoz.net receiving invite from 189.41.77.66:50894 version: 1.10.7 -release 64bit call-id: a107edf2e1fc47dd98357cb017d65c69
  7. 2023-05-31 22:15:26.681401 98.47% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [3438233779@dbb.voz.brvoz.net] from ip 189.41.77.66
  8. 2023-05-31 22:15:26.681401 98.47% [DEBUG] switch_core_state_machine.c:600 (sofia/default/10200@dbb.voz.brvoz.net) State NEW
  9. 2023-05-31 22:15:26.701399 98.47% [INFO] sofia.c:10462 sofia/default/10200@dbb.voz.brvoz.net receiving invite from 189.41.77.66:50894 version: 1.10.7 -release 64bit call-id: a107edf2e1fc47dd98357cb017d65c69
  10. 2023-05-31 22:15:26.701399 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  11. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/10200@dbb.voz.brvoz.net PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  12. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_codec.c:111 sofia/default/10200@dbb.voz.brvoz.net Original read codec set to PCMA:8
  13. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  14. 2023-05-31 22:15:26.701399 98.47% [DEBUG] sofia.c:7933 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_NEW -> CS_INIT
  15. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_INIT (Cur 3 Tot 26356)
  16. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/10200@dbb.voz.brvoz.net) State INIT
  17. 2023-05-31 22:15:26.701399 98.47% [DEBUG] mod_sofia.c:97 sofia/default/10200@dbb.voz.brvoz.net SOFIA INIT
  18. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:40 sofia/default/10200@dbb.voz.brvoz.net Standard INIT
  19. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:48 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_INIT -> CS_ROUTING
  20. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/10200@dbb.voz.brvoz.net) State INIT going to sleep
  21. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_ROUTING (Cur 3 Tot 26356)
  22. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_channel.c:2380 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change DOWN -> RINGING
  23. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/10200@dbb.voz.brvoz.net) State ROUTING
  24. 2023-05-31 22:15:26.701399 98.47% [DEBUG] mod_sofia.c:158 sofia/default/10200@dbb.voz.brvoz.net SOFIA ROUTING
  25. 2023-05-31 22:15:26.701399 98.47% [DEBUG] switch_core_state_machine.c:230 sofia/default/10200@dbb.voz.brvoz.net Standard ROUTING
  26. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation,sip_devices.codec as sip_codec FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="3438233779"  AND domains.domain="dbb.voz.brvoz.net" limit 1
  27. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation,sip_devices.codec as sip_codec FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="3438233779"  AND domains.domain="dbb.voz.brvoz.net" limit 1
  28. Dialplan: sofia/default/10200@dbb.voz.brvoz.net parsing [default->3438233779] continue=false
  29. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Regex (PASS) [3438233779] destination_number(3438233779) =~ /3438233779/ break=on-false
  30. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_destination_number=3438233779)
  31. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(bridge_pre_execute_bleg_app=sched_hangup)
  32. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  33. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(notify_flag=0)
  34. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(notify_credit_limit=5.00000)
  35. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(type=0)
  36. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_account=38)
  37. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_rate=0.09000)
  38. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_minimum=0.00000)
  39. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_increment=30)
  40. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action nibblebill(heartbeat 30)
  41. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(callstart=2023-05-31 22:15:26)
  42. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(hangup_after_bridge=true)
  43. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(continue_on_fail=TRUE)
  44. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(account_id=38)
  45. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(parent_id=0)
  46. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(entity_id=0)
  47. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(call_processed=internal)
  48. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(call_direction=outbound)
  49. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(accountname=default)
  50. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(origination_rates=ID:72|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.09000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38)
  51. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(original_caller_id_name=10200)
  52. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(original_caller_id_number=10200)
  53. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action limit(db 4616261204 user_4616261204 30 )
  54. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action limit(hash CPS_4616261204 CPS_user_4616261204 30/1 )
  55. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(is_recording=1)
  56. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(media_bug_answer_req=true)
  57. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(RECORD_STEREO=true)
  58. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(record_sample_rate=8000)
  59. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(execute_on_answer=record_session $${recordings_dir}/${uuid}.wav)
  60. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_name=10200)
  61. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_number=10200)
  62. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(calltype=STANDARD)
  63. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(termination_rates=ID:71|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02400|INC:6|INITIALBLOCK:30|TRUNK:1|PROVIDER:5)
  64. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(trunk_id=1)
  65. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(provider_id=5)
  66. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(rate_flag=0)
  67. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(daily_call_credit_limit=0.00000)
  68. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(monthly_call_credit_limit=0.00000)
  69. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(daily_call_used_limit=0.00000)
  70. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(monthly_call_used_limit=0.00000)
  71. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(quality_trunk_seq=1)
  72. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(force_trunk_flag=72)
  73. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_data=trunk_id=1)
  74. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(intcall=0)
  75. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_number=11953259484)
  76. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_id=3438233779)
  77. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_data=x|||DANILO LOCAL(4616261204)|||^343.* // Brasil Fixo // 0.09000 |||Fixo // ^343.* // Brasil Fixo // 0.02400 // trunk_id=1|||STD|||189.41.77.66)
  78. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/DAT_ITX/553438233779)
  79. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/IPCorpTDM/553438233779)
  80. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/IDT/553438233779)
  81. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_core_state_machine.c:281 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_ROUTING -> CS_EXECUTE
  82. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/10200@dbb.voz.brvoz.net) State ROUTING going to sleep
  83. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_EXECUTE (Cur 3 Tot 26356)
  84. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/10200@dbb.voz.brvoz.net) State EXECUTE
  85. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_sofia.c:213 sofia/default/10200@dbb.voz.brvoz.net SOFIA EXECUTE
  86. 2023-05-31 22:15:26.721401 98.47% [DEBUG] switch_core_state_machine.c:323 sofia/default/10200@dbb.voz.brvoz.net Standard EXECUTE
  87. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_destination_number=3438233779)
  88. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_destination_number]=[3438233779]
  89. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(bridge_pre_execute_bleg_app=sched_hangup)
  90. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [bridge_pre_execute_bleg_app]=[sched_hangup]
  91. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  92. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
  93. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(notify_flag=0)
  94. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [notify_flag]=[0]
  95. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(notify_credit_limit=5.00000)
  96. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [notify_credit_limit]=[5.00000]
  97. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(type=0)
  98. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [type]=[0]
  99. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_account=38)
  100. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_account]=[38]
  101. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_rate=0.09000)
  102. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_rate]=[0.09000]
  103. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_minimum=0.00000)
  104. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_minimum]=[0.00000]
  105. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_increment=30)
  106. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_increment]=[30]
  107. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net nibblebill(heartbeat 30)
  108. 2023-05-31 22:15:26.721401 98.47% [WARNING] switch_core_session.c:1693 sofia/default/10200@dbb.voz.brvoz.net using scheduler due to bypass media or media is not established.
  109. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(callstart=2023-05-31 22:15:26)
  110. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [callstart]=[2023-05-31 22:15:26]
  111. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(hangup_after_bridge=true)
  112. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [hangup_after_bridge]=[true]
  113. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(continue_on_fail=TRUE)
  114. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [continue_on_fail]=[TRUE]
  115. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(account_id=38)
  116. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [account_id]=[38]
  117. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(parent_id=0)
  118. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [parent_id]=[0]
  119. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(entity_id=0)
  120. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [entity_id]=[0]
  121. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(call_processed=internal)
  122. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [call_processed]=[internal]
  123. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(call_direction=outbound)
  124. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [call_direction]=[outbound]
  125. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(accountname=default)
  126. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [accountname]=[default]
  127. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(origination_rates=ID:72|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.09000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38)
  128. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [origination_rates]=[ID:72|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.09000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38]
  129. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(original_caller_id_name=10200)
  130. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [original_caller_id_name]=[10200]
  131. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(original_caller_id_number=10200)
  132. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [original_caller_id_number]=[10200]
  133. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net limit(db 4616261204 user_4616261204 30 )
  134. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net limit(hash CPS_4616261204 CPS_user_4616261204 30/1 )
  135. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(is_recording=1)
  136. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(media_bug_answer_req=true)
  137. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(RECORD_STEREO=true)
  138. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(record_sample_rate=8000)
  139. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(execute_on_answer=record_session /var/www/html/astpp/playlist/example/media/recordings/7489e69b-7579-4203-a12d-1a8a042b29f7.wav)
  140. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_name=10200)
  141. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_name]=[10200]
  142. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_number=10200)
  143. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_number]=[10200]
  144. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(calltype=STANDARD)
  145. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [calltype]=[STANDARD]
  146. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(termination_rates=ID:71|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02400|INC:6|INITIALBLOCK:30|TRUNK:1|PROVIDER:5)
  147. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [termination_rates]=[ID:71|CODE:^343.*|DESTINATION:Brasil Fixo|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02400|INC:6|INITIALBLOCK:30|TRUNK:1|PROVIDER:5]
  148. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(trunk_id=1)
  149. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [trunk_id]=[1]
  150. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(provider_id=5)
  151. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [provider_id]=[5]
  152. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(rate_flag=0)
  153. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [rate_flag]=[0]
  154. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(daily_call_credit_limit=0.00000)
  155. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [daily_call_credit_limit]=[0.00000]
  156. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(monthly_call_credit_limit=0.00000)
  157. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [monthly_call_credit_limit]=[0.00000]
  158. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(daily_call_used_limit=0.00000)
  159. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [daily_call_used_limit]=[0.00000]
  160. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(monthly_call_used_limit=0.00000)
  161. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [monthly_call_used_limit]=[0.00000]
  162. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(quality_trunk_seq=1)
  163. 2023-05-31 22:15:26.721401 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [quality_trunk_seq]=[1]
  164. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(force_trunk_flag=72)
  165. 2023-05-31 22:15:26.741400 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [force_trunk_flag]=[72]
  166. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_data=trunk_id=1)
  167. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(intcall=0)
  168. 2023-05-31 22:15:26.741400 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [intcall]=[0]
  169. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_number=11953259484)
  170. 2023-05-31 22:15:26.741400 98.47% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_number]=[11953259484]
  171. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_id=3438233779)
  172. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_data=x|||DANILO LOCAL(4616261204)|||^343.* // Brasil Fixo // 0.09000 |||Fixo // ^343.* // Brasil Fixo // 0.02400 // trunk_id=1|||STD|||189.41.77.66)
  173. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/DAT_ITX/553438233779)
  174. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [is_recording]=[1] to event
  175. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
  176. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
  177. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [record_sample_rate]=[8000] to event
  178. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [execute_on_answer]=[record_session /var/www/html/astpp/playlist/example/media/recordings/7489e69b-7579-4203-a12d-1a8a042b29f7.wav] to event
  179. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_data]=[x|||DANILO LOCAL(4616261204)|||^343.* // Brasil Fixo // 0.09000 |||Fixo // ^343.* // Brasil Fixo // 0.02400 // trunk_id=1|||STD|||189.41.77.66] to event
  180. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_id]=[3438233779] to event
  181. 2023-05-31 22:15:26.741400 98.47% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_data]=[x|||DANILO LOCAL(4616261204)|||^343.* // Brasil Fixo // 0.09000 |||Fixo // ^343.* // Brasil Fixo // 0.02400 // trunk_id=1|||STD|||189.41.77.66] to event
  182. 2023-05-31 22:15:27.921396 98.33% [NOTICE] mod_sofia.c:2515 Ring-Ready sofia/default/10200@dbb.voz.brvoz.net!
  183. 2023-05-31 22:15:27.921396 98.33% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [early][180]
  184. 2023-05-31 22:15:27.921396 98.33% [NOTICE] switch_ivr_originate.c:565 Ring Ready sofia/default/10200@dbb.voz.brvoz.net!
  185. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/10200@dbb.voz.brvoz.net] 10.0.0.4 port 30460 -> 189.41.77.66 port 4000 codec: 8 ms: 20
  186. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_core_media.c:9089 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101
  187. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_core_media.c:9096 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf receive payload to 101
  188. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_core_media.c:9119 sofia/default/10200@dbb.voz.brvoz.net Set rtp dtmf delay to 40
  189. 2023-05-31 22:15:29.241398 98.27% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/10200@dbb.voz.brvoz.net:
  190. 2023-05-31 22:15:29.241398 98.27% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/default/10200@dbb.voz.brvoz.net] has been answered
  191. 2023-05-31 22:15:29.241398 98.27% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  192. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net record_session(/var/www/html/astpp/playlist/example/media/recordings/7489e69b-7579-4203-a12d-1a8a042b29f7.wav)
  193. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/default/10200@dbb.voz.brvoz.net
  194. 2023-05-31 22:15:29.241398 98.27% [DEBUG] switch_channel.c:3950 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change RINGING -> ACTIVE
  195. 2023-05-31 22:15:29.261398 98.27% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  196. 2023-05-31 22:15:38.761399 98.97% [NOTICE] switch_channel.c:1123 New Channel sofia/default/10200@dbb.voz.brvoz.net [6d9b837f-799b-4086-8bf7-1d82fc08d626]
  197. 2023-05-31 22:15:38.761399 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_NEW (Cur 3 Tot 26360)
  198. 2023-05-31 22:15:38.761399 98.97% [INFO] sofia.c:10462 sofia/default/10200@dbb.voz.brvoz.net receiving invite from 189.41.77.66:50894 version: 1.10.7 -release 64bit call-id: 9451973fffd2415fadf986ac8c89f43d
  199. 2023-05-31 22:15:38.761399 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [34999423533@dbb.voz.brvoz.net] from ip 189.41.77.66
  200. 2023-05-31 22:15:38.761399 98.97% [DEBUG] switch_core_state_machine.c:600 (sofia/default/10200@dbb.voz.brvoz.net) State NEW
  201. 2023-05-31 22:15:38.781398 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  202. 2023-05-31 22:15:38.781398 98.97% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  203. 2023-05-31 22:15:38.781398 98.97% [INFO] sofia.c:10462 sofia/default/10200@dbb.voz.brvoz.net receiving invite from 189.41.77.66:50894 version: 1.10.7 -release 64bit call-id: 9451973fffd2415fadf986ac8c89f43d
  204. 2023-05-31 22:15:38.801402 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  205. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/10200@dbb.voz.brvoz.net PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  206. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_codec.c:111 sofia/default/10200@dbb.voz.brvoz.net Original read codec set to PCMA:8
  207. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  208. 2023-05-31 22:15:38.801402 98.97% [DEBUG] sofia.c:7933 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_NEW -> CS_INIT
  209. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_INIT (Cur 3 Tot 26360)
  210. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/10200@dbb.voz.brvoz.net) State INIT
  211. 2023-05-31 22:15:38.801402 98.97% [DEBUG] mod_sofia.c:97 sofia/default/10200@dbb.voz.brvoz.net SOFIA INIT
  212. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:40 sofia/default/10200@dbb.voz.brvoz.net Standard INIT
  213. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:48 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_INIT -> CS_ROUTING
  214. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/10200@dbb.voz.brvoz.net) State INIT going to sleep
  215. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_ROUTING (Cur 3 Tot 26360)
  216. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_channel.c:2380 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change DOWN -> RINGING
  217. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/10200@dbb.voz.brvoz.net) State ROUTING
  218. 2023-05-31 22:15:38.801402 98.97% [DEBUG] mod_sofia.c:158 sofia/default/10200@dbb.voz.brvoz.net SOFIA ROUTING
  219. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_core_state_machine.c:230 sofia/default/10200@dbb.voz.brvoz.net Standard ROUTING
  220. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation,sip_devices.codec as sip_codec FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="34999423533"  AND domains.domain="dbb.voz.brvoz.net" limit 1
  221. 2023-05-31 22:15:38.801402 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation,sip_devices.codec as sip_codec FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="34999423533"  AND domains.domain="dbb.voz.brvoz.net" limit 1
  222. Dialplan: sofia/default/10200@dbb.voz.brvoz.net parsing [default->34999423533] continue=false
  223. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Regex (PASS) [34999423533] destination_number(34999423533) =~ /34999423533/ break=on-false
  224. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_destination_number=34999423533)
  225. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(bridge_pre_execute_bleg_app=sched_hangup)
  226. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  227. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(notify_flag=0)
  228. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(notify_credit_limit=5.00000)
  229. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(type=0)
  230. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_account=38)
  231. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_rate=0.28000)
  232. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_minimum=0.00000)
  233. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(nibble_increment=30)
  234. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action nibblebill(heartbeat 30)
  235. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(callstart=2023-05-31 22:15:38)
  236. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(hangup_after_bridge=true)
  237. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(continue_on_fail=TRUE)
  238. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(account_id=38)
  239. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(parent_id=0)
  240. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(entity_id=0)
  241. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(call_processed=internal)
  242. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(call_direction=outbound)
  243. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(accountname=default)
  244. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(origination_rates=ID:288|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.28000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38)
  245. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(original_caller_id_name=10200)
  246. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(original_caller_id_number=10200)
  247. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action limit(db 4616261204 user_4616261204 30 )
  248. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action limit(hash CPS_4616261204 CPS_user_4616261204 30/1 )
  249. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(is_recording=1)
  250. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(media_bug_answer_req=true)
  251. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(RECORD_STEREO=true)
  252. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(record_sample_rate=8000)
  253. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(execute_on_answer=record_session $${recordings_dir}/${uuid}.wav)
  254. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_name=10200)
  255. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_number=10200)
  256. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(calltype=STANDARD)
  257. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(termination_rates=ID:287|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.05500|INC:6|INITIALBLOCK:30|TRUNK:3|PROVIDER:5)
  258. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(trunk_id=3)
  259. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(provider_id=5)
  260. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(rate_flag=0)
  261. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(daily_call_credit_limit=0.00000)
  262. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(monthly_call_credit_limit=0.00000)
  263. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(daily_call_used_limit=0.00000)
  264. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(monthly_call_used_limit=0.00000)
  265. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(quality_trunk_seq=3)
  266. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(force_trunk_flag=288)
  267. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_data=trunk_id=3)
  268. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(intcall=0)
  269. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action set(effective_caller_id_number=11953259484)
  270. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_id=34999423533)
  271. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action export(presence_data=x|||DANILO LOCAL(4616261204)|||^349.* // Brasil Movel // 0.28000 |||Celular // ^349.* // Brasil Movel // 0.05500 // trunk_id=3|||STD|||189.41.77.66)
  272. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/DATIDmovel/5534999423533)
  273. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/IPCorpITX/5534999423533)
  274. Dialplan: sofia/default/10200@dbb.voz.brvoz.net Action bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/IDT/5534999423533)
  275. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_core_state_machine.c:281 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_ROUTING -> CS_EXECUTE
  276. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/10200@dbb.voz.brvoz.net) State ROUTING going to sleep
  277. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_EXECUTE (Cur 3 Tot 26360)
  278. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_core_state_machine.c:647 (sofia/default/10200@dbb.voz.brvoz.net) State EXECUTE
  279. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_sofia.c:213 sofia/default/10200@dbb.voz.brvoz.net SOFIA EXECUTE
  280. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_core_state_machine.c:323 sofia/default/10200@dbb.voz.brvoz.net Standard EXECUTE
  281. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_destination_number=34999423533)
  282. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_destination_number]=[34999423533]
  283. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(bridge_pre_execute_bleg_app=sched_hangup)
  284. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [bridge_pre_execute_bleg_app]=[sched_hangup]
  285. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  286. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
  287. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(notify_flag=0)
  288. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [notify_flag]=[0]
  289. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(notify_credit_limit=5.00000)
  290. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [notify_credit_limit]=[5.00000]
  291. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(type=0)
  292. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [type]=[0]
  293. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_account=38)
  294. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_account]=[38]
  295. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_rate=0.28000)
  296. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_rate]=[0.28000]
  297. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_minimum=0.00000)
  298. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_minimum]=[0.00000]
  299. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(nibble_increment=30)
  300. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [nibble_increment]=[30]
  301. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net nibblebill(heartbeat 30)
  302. 2023-05-31 22:15:38.821407 98.97% [WARNING] switch_core_session.c:1693 sofia/default/10200@dbb.voz.brvoz.net using scheduler due to bypass media or media is not established.
  303. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(callstart=2023-05-31 22:15:38)
  304. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [callstart]=[2023-05-31 22:15:38]
  305. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(hangup_after_bridge=true)
  306. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [hangup_after_bridge]=[true]
  307. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(continue_on_fail=TRUE)
  308. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [continue_on_fail]=[TRUE]
  309. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(account_id=38)
  310. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [account_id]=[38]
  311. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(parent_id=0)
  312. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [parent_id]=[0]
  313. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(entity_id=0)
  314. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [entity_id]=[0]
  315. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(call_processed=internal)
  316. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [call_processed]=[internal]
  317. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(call_direction=outbound)
  318. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [call_direction]=[outbound]
  319. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(accountname=default)
  320. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [accountname]=[default]
  321. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(origination_rates=ID:288|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.28000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38)
  322. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [origination_rates]=[ID:288|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.28000|INC:6|INITIALBLOCK:30|RATEGROUP:1|MARKUP:0|CI:28|ACCID:38]
  323. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(original_caller_id_name=10200)
  324. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [original_caller_id_name]=[10200]
  325. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(original_caller_id_number=10200)
  326. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [original_caller_id_number]=[10200]
  327. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net limit(db 4616261204 user_4616261204 30 )
  328. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net limit(hash CPS_4616261204 CPS_user_4616261204 30/1 )
  329. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(is_recording=1)
  330. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(media_bug_answer_req=true)
  331. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(RECORD_STEREO=true)
  332. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(record_sample_rate=8000)
  333. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(execute_on_answer=record_session /var/www/html/astpp/playlist/example/media/recordings/6d9b837f-799b-4086-8bf7-1d82fc08d626.wav)
  334. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_name=10200)
  335. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_name]=[10200]
  336. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_number=10200)
  337. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_number]=[10200]
  338. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(calltype=STANDARD)
  339. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [calltype]=[STANDARD]
  340. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(termination_rates=ID:287|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.05500|INC:6|INITIALBLOCK:30|TRUNK:3|PROVIDER:5)
  341. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [termination_rates]=[ID:287|CODE:^349.*|DESTINATION:Brasil Movel|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.05500|INC:6|INITIALBLOCK:30|TRUNK:3|PROVIDER:5]
  342. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(trunk_id=3)
  343. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [trunk_id]=[3]
  344. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(provider_id=5)
  345. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [provider_id]=[5]
  346. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(rate_flag=0)
  347. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [rate_flag]=[0]
  348. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(daily_call_credit_limit=0.00000)
  349. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [daily_call_credit_limit]=[0.00000]
  350. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(monthly_call_credit_limit=0.00000)
  351. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [monthly_call_credit_limit]=[0.00000]
  352. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(daily_call_used_limit=0.00000)
  353. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [daily_call_used_limit]=[0.00000]
  354. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(monthly_call_used_limit=0.00000)
  355. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [monthly_call_used_limit]=[0.00000]
  356. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(quality_trunk_seq=3)
  357. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [quality_trunk_seq]=[3]
  358. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(force_trunk_flag=288)
  359. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [force_trunk_flag]=[288]
  360. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_data=trunk_id=3)
  361. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(intcall=0)
  362. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [intcall]=[0]
  363. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net set(effective_caller_id_number=11953259484)
  364. 2023-05-31 22:15:38.821407 98.97% [DEBUG] mod_dptools.c:1685 SET sofia/default/10200@dbb.voz.brvoz.net [effective_caller_id_number]=[11953259484]
  365. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_id=34999423533)
  366. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net export(presence_data=x|||DANILO LOCAL(4616261204)|||^349.* // Brasil Movel // 0.28000 |||Celular // ^349.* // Brasil Movel // 0.05500 // trunk_id=3|||STD|||189.41.77.66)
  367. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net bridge({sip_cid_type=none}[leg_timeout=30,absolute_codec_string=^^:PCMA:PCMU]sofia/gateway/DATIDmovel/5534999423533)
  368. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [is_recording]=[1] to event
  369. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
  370. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
  371. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [record_sample_rate]=[8000] to event
  372. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [execute_on_answer]=[record_session /var/www/html/astpp/playlist/example/media/recordings/6d9b837f-799b-4086-8bf7-1d82fc08d626.wav] to event
  373. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_data]=[x|||DANILO LOCAL(4616261204)|||^349.* // Brasil Movel // 0.28000 |||Celular // ^349.* // Brasil Movel // 0.05500 // trunk_id=3|||STD|||189.41.77.66] to event
  374. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_id]=[34999423533] to event
  375. 2023-05-31 22:15:38.821407 98.97% [DEBUG] switch_channel.c:1269 sofia/default/10200@dbb.voz.brvoz.net EXPORTING[export_vars] [presence_data]=[x|||DANILO LOCAL(4616261204)|||^349.* // Brasil Movel // 0.28000 |||Celular // ^349.* // Brasil Movel // 0.05500 // trunk_id=3|||STD|||189.41.77.66] to event
  376. 2023-05-31 22:15:39.021396 98.87% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  377. 2023-05-31 22:15:39.021396 98.87% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  378. 2023-05-31 22:15:39.041399 98.87% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  379. 2023-05-31 22:15:39.041399 98.87% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  380. 2023-05-31 22:15:39.381397 98.87% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/10200@dbb.voz.brvoz.net] 10.0.0.4 port 24378 -> 189.41.77.66 port 4002 codec: 8 ms: 20
  381. 2023-05-31 22:15:39.381397 98.87% [DEBUG] switch_core_media.c:9089 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101
  382. 2023-05-31 22:15:39.381397 98.87% [DEBUG] switch_core_media.c:9096 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf receive payload to 101
  383. 2023-05-31 22:15:39.381397 98.87% [DEBUG] switch_core_media.c:9119 sofia/default/10200@dbb.voz.brvoz.net Set rtp dtmf delay to 40
  384. 2023-05-31 22:15:39.381397 98.87% [NOTICE] mod_sofia.c:2613 Pre-Answer sofia/default/10200@dbb.voz.brvoz.net!
  385. 2023-05-31 22:15:39.381397 98.87% [DEBUG] switch_channel.c:3622 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change RINGING -> EARLY
  386. 2023-05-31 22:15:39.381397 98.87% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [early][183]
  387. 2023-05-31 22:15:46.081394 98.47% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  388. 2023-05-31 22:15:46.081394 98.47% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/10200@dbb.voz.brvoz.net:
  389. 2023-05-31 22:15:46.081394 98.47% [NOTICE] switch_ivr_bridge.c:731 Channel [sofia/default/10200@dbb.voz.brvoz.net] has been answered
  390. 2023-05-31 22:15:46.081394 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  391. EXECUTE [depth=0] sofia/default/10200@dbb.voz.brvoz.net record_session(/var/www/html/astpp/playlist/example/media/recordings/6d9b837f-799b-4086-8bf7-1d82fc08d626.wav)
  392. 2023-05-31 22:15:46.101397 98.47% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/default/10200@dbb.voz.brvoz.net
  393. 2023-05-31 22:15:46.101397 98.47% [DEBUG] switch_channel.c:3950 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change EARLY -> ACTIVE
  394. 2023-05-31 22:15:46.101397 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  395. 2023-05-31 22:15:52.421401 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  396. 2023-05-31 22:15:52.421401 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  397. 2023-05-31 22:15:52.421401 98.47% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  398. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  399. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  400. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  401. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  402. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  403. 2023-05-31 22:15:52.681398 98.47% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  404. 2023-05-31 22:15:52.681398 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  405. 2023-05-31 22:15:52.701399 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  406. 2023-05-31 22:15:52.701399 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  407. 2023-05-31 22:15:52.701399 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  408. 2023-05-31 22:15:59.121396 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  409. 2023-05-31 22:15:59.121396 98.43% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  410. 2023-05-31 22:15:59.121396 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  411. 2023-05-31 22:15:59.361397 98.43% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  412. 2023-05-31 22:15:59.361397 98.43% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  413. 2023-05-31 22:15:59.381396 98.43% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  414. 2023-05-31 22:15:59.381396 98.43% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  415. 2023-05-31 22:15:59.381396 98.43% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  416. 2023-05-31 22:15:59.381396 98.43% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  417. 2023-05-31 22:15:59.381396 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  418. 2023-05-31 22:15:59.381396 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  419. 2023-05-31 22:15:59.381396 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  420. 2023-05-31 22:15:59.401401 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  421. 2023-05-31 22:16:08.601405 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  422. 2023-05-31 22:16:08.601405 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  423. 2023-05-31 22:16:08.601405 97.57% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  424. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  425. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  426. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  427. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  428. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  429. 2023-05-31 22:16:08.861396 97.57% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  430. 2023-05-31 22:16:08.861396 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  431. 2023-05-31 22:16:08.881410 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  432. 2023-05-31 22:16:08.881410 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  433. 2023-05-31 22:16:08.881410 97.57% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  434. 2023-05-31 22:16:14.901399 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  435. 2023-05-31 22:16:14.921399 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  436. 2023-05-31 22:16:14.921399 97.80% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  437. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  438. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  439. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  440. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  441. 2023-05-31 22:16:15.161396 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  442. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  443. 2023-05-31 22:16:15.161396 97.80% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  444. 2023-05-31 22:16:15.181403 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  445. 2023-05-31 22:16:15.181403 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  446. 2023-05-31 22:16:15.201399 97.80% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  447. 2023-05-31 22:16:19.681398 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  448. 2023-05-31 22:16:19.681398 97.67% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  449. 2023-05-31 22:16:19.701397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  450. 2023-05-31 22:16:19.941397 97.67% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  451. 2023-05-31 22:16:19.941397 97.67% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  452. 2023-05-31 22:16:19.961397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  453. 2023-05-31 22:16:19.961397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  454. 2023-05-31 22:16:19.961397 97.67% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  455. 2023-05-31 22:16:19.961397 97.67% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  456. 2023-05-31 22:16:19.961397 97.67% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  457. 2023-05-31 22:16:19.961397 97.67% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  458. 2023-05-31 22:16:19.961397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  459. 2023-05-31 22:16:19.981400 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  460. 2023-05-31 22:16:23.341397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  461. 2023-05-31 22:16:23.341397 97.67% [DEBUG] switch_channel.c:1975 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HELD
  462. 2023-05-31 22:16:23.341397 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [received][100]
  463. 2023-05-31 22:16:23.581396 97.67% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  464. 2023-05-31 22:16:23.581396 97.67% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  465. 2023-05-31 22:16:23.601395 97.67% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  466. 2023-05-31 22:16:23.601395 97.67% [DEBUG] switch_core_media.c:5973 sofia/default/10200@dbb.voz.brvoz.net Set 2833 dtmf send payload to 101 recv payload to 101
  467. 2023-05-31 22:16:23.601395 97.67% [DEBUG] switch_core_media.c:8759 Audio params are unchanged for sofia/default/10200@dbb.voz.brvoz.net.
  468. 2023-05-31 22:16:23.601395 97.67% [DEBUG] switch_core_io.c:941 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> ACTIVE
  469. 2023-05-31 22:16:23.601395 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  470. 2023-05-31 22:16:23.601395 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [completed][200]
  471. 2023-05-31 22:16:23.601395 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  472. 2023-05-31 22:16:23.621398 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/10200@dbb.voz.brvoz.net entering state [ready][200]
  473. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/10200@dbb.voz.brvoz.net]
  474. 2023-05-31 22:16:28.301398 97.80% [NOTICE] switch_ivr_bridge.c:1944 Hangup sofia/default/10200@dbb.voz.brvoz.net [CS_EXECUTE] [NORMAL_CLEARING]
  475. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_session.c:2983 sofia/default/10200@dbb.voz.brvoz.net skip receive message [PHONE_EVENT] (channel is hungup already)
  476. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:647 (sofia/default/10200@dbb.voz.brvoz.net) State EXECUTE going to sleep
  477. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_HANGUP (Cur 5 Tot 26375)
  478. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_media_bug.c:1328 Removing BUG from sofia/default/10200@dbb.voz.brvoz.net
  479. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:844 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change ACTIVE -> HANGUP
  480. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10200@dbb.voz.brvoz.net) State HANGUP
  481. 2023-05-31 22:16:28.301398 97.80% [DEBUG] mod_sofia.c:462 sofia/default/10200@dbb.voz.brvoz.net Overriding SIP cause 480 with 200 from the other leg
  482. 2023-05-31 22:16:28.301398 97.80% [DEBUG] mod_sofia.c:468 Channel sofia/default/10200@dbb.voz.brvoz.net hanging up, cause: NORMAL_CLEARING
  483. 2023-05-31 22:16:28.301398 97.80% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/10200@dbb.voz.brvoz.net
  484. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:59 sofia/default/10200@dbb.voz.brvoz.net Standard HANGUP, cause: NORMAL_CLEARING
  485. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10200@dbb.voz.brvoz.net) State HANGUP going to sleep
  486. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:616 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_HANGUP -> CS_REPORTING
  487. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_REPORTING (Cur 5 Tot 26375)
  488. 2023-05-31 22:16:28.301398 97.80% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10200@dbb.voz.brvoz.net) State REPORTING
  489. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:168 sofia/default/10200@dbb.voz.brvoz.net Standard REPORTING, cause: NORMAL_CLEARING
  490. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10200@dbb.voz.brvoz.net) State REPORTING going to sleep
  491. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:607 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_REPORTING -> CS_DESTROY
  492. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_session.c:1753 Session 26360 (sofia/default/10200@dbb.voz.brvoz.net) Locked, Waiting on external entities
  493. 2023-05-31 22:16:28.321411 97.80% [NOTICE] switch_core_session.c:1771 Session 26360 (sofia/default/10200@dbb.voz.brvoz.net) Ended
  494. 2023-05-31 22:16:28.321411 97.80% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/10200@dbb.voz.brvoz.net [CS_DESTROY]
  495. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:735 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_DESTROY (Cur 4 Tot 26375)
  496. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10200@dbb.voz.brvoz.net) State DESTROY
  497. 2023-05-31 22:16:28.321411 97.80% [DEBUG] mod_sofia.c:379 sofia/default/10200@dbb.voz.brvoz.net SOFIA DESTROY
  498. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:175 sofia/default/10200@dbb.voz.brvoz.net Standard DESTROY
  499. 2023-05-31 22:16:28.321411 97.80% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10200@dbb.voz.brvoz.net) State DESTROY going to sleep
  500. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/10200@dbb.voz.brvoz.net]
  501. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_channel.c:2160 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change HELD -> UNHELD
  502. 2023-05-31 22:16:29.581400 97.77% [NOTICE] switch_ivr_bridge.c:1944 Hangup sofia/default/10200@dbb.voz.brvoz.net [CS_EXECUTE] [NORMAL_CLEARING]
  503. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_session.c:2983 sofia/default/10200@dbb.voz.brvoz.net skip receive message [PHONE_EVENT] (channel is hungup already)
  504. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:647 (sofia/default/10200@dbb.voz.brvoz.net) State EXECUTE going to sleep
  505. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_HANGUP (Cur 3 Tot 26375)
  506. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_media_bug.c:1328 Removing BUG from sofia/default/10200@dbb.voz.brvoz.net
  507. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:844 (sofia/default/10200@dbb.voz.brvoz.net) Callstate Change UNHELD -> HANGUP
  508. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10200@dbb.voz.brvoz.net) State HANGUP
  509. 2023-05-31 22:16:29.581400 97.77% [DEBUG] mod_sofia.c:462 sofia/default/10200@dbb.voz.brvoz.net Overriding SIP cause 480 with 200 from the other leg
  510. 2023-05-31 22:16:29.581400 97.77% [DEBUG] mod_sofia.c:468 Channel sofia/default/10200@dbb.voz.brvoz.net hanging up, cause: NORMAL_CLEARING
  511. 2023-05-31 22:16:29.581400 97.77% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/10200@dbb.voz.brvoz.net
  512. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:59 sofia/default/10200@dbb.voz.brvoz.net Standard HANGUP, cause: NORMAL_CLEARING
  513. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10200@dbb.voz.brvoz.net) State HANGUP going to sleep
  514. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:616 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_HANGUP -> CS_REPORTING
  515. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_REPORTING (Cur 3 Tot 26375)
  516. 2023-05-31 22:16:29.581400 97.77% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10200@dbb.voz.brvoz.net) State REPORTING
  517. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:168 sofia/default/10200@dbb.voz.brvoz.net Standard REPORTING, cause: NORMAL_CLEARING
  518. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10200@dbb.voz.brvoz.net) State REPORTING going to sleep
  519. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:607 (sofia/default/10200@dbb.voz.brvoz.net) State Change CS_REPORTING -> CS_DESTROY
  520. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_session.c:1753 Session 26356 (sofia/default/10200@dbb.voz.brvoz.net) Locked, Waiting on external entities
  521. 2023-05-31 22:16:29.601399 97.77% [NOTICE] switch_core_session.c:1771 Session 26356 (sofia/default/10200@dbb.voz.brvoz.net) Ended
  522. 2023-05-31 22:16:29.601399 97.77% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/10200@dbb.voz.brvoz.net [CS_DESTROY]
  523. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:735 (sofia/default/10200@dbb.voz.brvoz.net) Running State Change CS_DESTROY (Cur 2 Tot 26375)
  524. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10200@dbb.voz.brvoz.net) State DESTROY
  525. 2023-05-31 22:16:29.601399 97.77% [DEBUG] mod_sofia.c:379 sofia/default/10200@dbb.voz.brvoz.net SOFIA DESTROY
  526. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:175 sofia/default/10200@dbb.voz.brvoz.net Standard DESTROY
  527. 2023-05-31 22:16:29.601399 97.77% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10200@dbb.voz.brvoz.net) State DESTROY going to sleep
  528.