SOLVED ring group not ringing

Status
Not open for further replies.
T

Tobias.F

New Member
Aug 2, 2020
20
2
3
Hello,

My ring group is not working. What is the best way to debug this?

When I put my extensions (00, 10, 20) in the dial plan, I can call these from external and internal. All is working as expected. The same extensions I put in a ring group (50) with strategy "simultaneous". None of the extension is reacting when I use the extension of the ring group in the dial plan or when I try to call the extension of the ring group directly.

When setting up the ring group I followed the manual. I assume any miss-configuration, but I do not know how to debug this.

ring plan.png
 
T

Tobias.F

New Member
Aug 2, 2020
20
2
3
wouam31 said:
and if you put enterprise instead of simultaneous

View attachment 4195
Click to expand...
No, still not working.

This is what I see in the log. Nothing hat helps me for debugging I found.

edit: corrected log

Code: 
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/xxxxxxxxxxx@fritz.box [7e8a2d40-a022-4338-9c52-051a2441f3d4]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_NEW (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [INFO] sofia.c:10459 sofia/internal/xxxxxxxxxxx@fritz.box receiving invite from 192.168.178.1:5060 version: 1.10.11 -release 64bit call-id: 13A1E5E3C677B63E@192.168.178.1
2024-06-25 21:38:46.914695 98.63% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 192.168.178.1:0.
2024-06-25 21:38:46.914695 98.63% [DEBUG] sofia.c:10582 IP 192.168.178.1 Approved by acl "providers[]". Access Granted.
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] sofia.c:7493 Channel sofia/internal/xxxxxxxxxxx@fritz.box entering state [received][100]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] sofia.c:7503 Remote SDP:
7e8a2d40-a022-4338-9c52-051a2441f3d4 v=0
7e8a2d40-a022-4338-9c52-051a2441f3d4 o=user 10713944 10713944 IN IP4 192.168.178.1
7e8a2d40-a022-4338-9c52-051a2441f3d4 s=call
7e8a2d40-a022-4338-9c52-051a2441f3d4 c=IN IP4 192.168.178.1
7e8a2d40-a022-4338-9c52-051a2441f3d4 t=0 0
7e8a2d40-a022-4338-9c52-051a2441f3d4 m=audio 7080 RTP/AVP 9 8 0 120 121 101
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtpmap:120 PCMA/16000
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtpmap:121 PCMU/16000
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtpmap:101 telephone-event/8000
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=fmtp:101 0-15
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtcp:7081
7e8a2d40-a022-4338-9c52-051a2441f3d4
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] sofia.c:7906 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_NEW -> CS_INIT
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/xxxxxxxxxxx@fritz.box) State NEW
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_INIT (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/xxxxxxxxxxx@fritz.box) State INIT
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] mod_sofia.c:97 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA INIT
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:40 sofia/internal/xxxxxxxxxxx@fritz.box Standard INIT
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_INIT -> CS_ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/xxxxxxxxxxx@fritz.box) State INIT going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_ROUTING (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_channel.c:2399 (sofia/internal/xxxxxxxxxxx@fritz.box) Callstate Change DOWN -> RINGING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/xxxxxxxxxxx@fritz.box) State ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] mod_sofia.c:158 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [DEBUG] switch_core_state_machine.c:230 sofia/internal/xxxxxxxxxxx@fritz.box Standard ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.914695 98.63% [INFO] mod_dialplan_xml.c:639 Processing xxxxxxxxxxx <xxxxxxxxxxx>->xxxxxxxxx90 in context public
2024-06-25 21:38:46.954601 98.63% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:public
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [public->caller-details] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [caller-details] () =~ // break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action export(call_direction=inbound) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box export(call_direction=inbound)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[inbound]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(caller_destination=${sip_to_user}) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(caller_destination=gw+8ef99aff-b459-41e7-bfa6-999c4affbe30)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [caller_destination]=[gw+8ef99aff-b459-41e7-bfa6-999c4affbe30]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(caller_id_name=${caller_id_name}) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(caller_id_name=xxxxxxxxxxx)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [caller_id_name]=[xxxxxxxxxxx]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(caller_id_number=${caller_id_number})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [public->xxxxxxxxx44] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [xxxxxxxxx44] destination_number(xxxxxxxxx90) =~ /^(xxxxxxxxx44)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [public->xxxxxxxxx39] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [xxxxxxxxx39] destination_number(xxxxxxxxx90) =~ /^(xxxxxxxxx39)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [public->xxxxxxxxx13] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [xxxxxxxxx13] destination_number(xxxxxxxxx90) =~ /^(xxxxxxxxx13)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [public->xxxxxxxxx90] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [xxxxxxxxx90] destination_number(xxxxxxxxx90) =~ /^(xxxxxxxxx90)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action export(call_direction=inbound) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box export(call_direction=inbound)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[inbound]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(domain_uuid=2843aa99-c211-4913-9651-736902e4638c) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(domain_uuid=2843aa99-c211-4913-9651-736902e4638c)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [domain_uuid]=[2843aa99-c211-4913-9651-736902e4638c]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(domain_name=sip.xxxxxxxxxxx.de) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(domain_name=sip.xxxxxxxxxxx.de)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [domain_name]=[sip.xxxxxxxxxxx.de]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action transfer(50 XML sip.xxxxxxxxxxx.de)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_ROUTING -> CS_EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/xxxxxxxxxxx@fritz.box) State ROUTING going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_EXECUTE (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/xxxxxxxxxxx@fritz.box) State EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_sofia.c:213 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:323 sofia/internal/xxxxxxxxxxx@fritz.box Standard EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(caller_id_number=xxxxxxxxxxx)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [caller_id_number]=[xxxxxxxxxxx]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box transfer(50 XML sip.xxxxxxxxxxx.de)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_ivr.c:2296 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_EXECUTE -> CS_ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [NOTICE] switch_ivr.c:2303 Transfer sofia/internal/xxxxxxxxxxx@fritz.box to XML[50@sip.xxxxxxxxxxx.de]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/xxxxxxxxxxx@fritz.box) State EXECUTE going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_ROUTING (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/xxxxxxxxxxx@fritz.box) State ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_sofia.c:149 Call appears to be already acknowledged
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] mod_sofia.c:158 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [DEBUG] switch_core_state_machine.c:230 sofia/internal/xxxxxxxxxxx@fritz.box Standard ROUTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.954601 98.63% [INFO] mod_dialplan_xml.c:639 Processing xxxxxxxxxxx <xxxxxxxxxxx>->50 in context sip.xxxxxxxxxxx.de
2024-06-25 21:38:46.954601 98.63% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:sip.xxxxxxxxxxx.de
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->user_exists] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [user_exists] () =~ // break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(user_exists=false)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [user_exists]=[false]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(from_user_exists=false)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [from_user_exists]=[false]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->caller-details] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [caller-details] ${caller_destination}(gw+8ef99aff-b459-41e7-bfa6-999c4affbe30) =~ /^$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->global-variables] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [global-variables] () =~ // break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(timezone=Europe/Berlin) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(timezone=Europe/Berlin)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [timezone]=[Europe/Berlin]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->domain-variables] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [domain-variables] () =~ // break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action export(origination_callee_id_name=${caller_destination})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(operator=1000) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(operator=1000)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [operator]=[1000]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->call_direction-outbound] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [call_direction-outbound] ${user_exists}(false) =~ /false/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [call_direction-outbound] ${call_direction}(inbound) =~ /^$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->clear_sip_auto_answer] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->is_loopback] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->call-direction] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [call-direction] ${call_direction}(inbound) =~ /^$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->call_block] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [call_block] ${call_direction}(inbound) =~ /^(inbound|outbound)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action lua(app.lua call_block)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->user_record] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->rtp_has_crypto] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [rtp_has_crypto] ${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=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->redial] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [redial] destination_number(50) =~ /^(redial|\*870)$/ break=on-true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [redial] () =~ // break=never
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->speed_dial] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [speed_dial] destination_number(50) =~ /^\*0(.*)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->default_caller_id] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [default_caller_id] ${call_direction}(inbound) =~ /outbound/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->user_hold_music] continue=true
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box parsing [sip.xxxxxxxxxxx.de->Fritzbox-xxxxxxxxx37.49490049019d] continue=false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [Fritzbox-xxxxxxxxx37.49490049019d] ${user_exists}(false) =~ /false/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Regex (PASS) [Fritzbox-xxxxxxxxx37.49490049019d] destination_number(50) =~ /^((|49|\+49|0049|0)[1-9]\d*)$/ break=on-false
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action export(call_direction=outbound) INLINE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box export(call_direction=outbound)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action unset(call_timeout)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(hangup_after_bridge=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(effective_caller_id_name=${outbound_caller_id_name})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(effective_caller_id_number=${outbound_caller_id_number})
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(inherit_codec=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(ignore_display_updates=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(callee_id_number=50)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
7e8a2d40-a022-4338-9c52-051a2441f3d4 Dialplan: sofia/internal/xxxxxxxxxxx@fritz.box Action bridge(sofia/gateway/41f3cb9a-73e0-4b25-8ca4-688b708859fe/50)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_ROUTING -> CS_EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/xxxxxxxxxxx@fritz.box) State ROUTING going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_EXECUTE (Cur 1 Tot 12)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/xxxxxxxxxxx@fritz.box) State EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_sofia.c:213 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_core_state_machine.c:323 sofia/internal/xxxxxxxxxxx@fritz.box Standard EXECUTE
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(RFC2822_DATE=Tue, 25 Jun 2024 21:38:46 +0200)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [RFC2822_DATE]=[Tue, 25 Jun 2024 21:38:46 +0200]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box export(origination_callee_id_name=gw+8ef99aff-b459-41e7-bfa6-999c4affbe30)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[gw+8ef99aff-b459-41e7-bfa6-999c4affbe30]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box lua(app.lua call_block)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] switch_cpp.cpp:1210 sofia/internal/xxxxxxxxxxx@fritz.box destroy/unlink session from object
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box hash(insert/sip.xxxxxxxxxxx.de-last_dial/xxxxxxxxxxx/50)
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box unset(call_timeout)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(hangup_after_bridge=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [hangup_after_bridge]=[true]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(effective_caller_id_name=)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [effective_caller_id_name]=[UNDEF]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(effective_caller_id_number=)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [effective_caller_id_number]=[UNDEF]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(inherit_codec=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [inherit_codec]=[true]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(ignore_display_updates=true)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [ignore_display_updates]=[true]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(callee_id_number=50)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [callee_id_number]=[50]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.974599 98.63% [DEBUG] mod_dptools.c:1671 SET sofia/internal/xxxxxxxxxxx@fritz.box [continue_on_fail]=[1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]
7e8a2d40-a022-4338-9c52-051a2441f3d4 EXECUTE [depth=0] sofia/internal/xxxxxxxxxxx@fritz.box bridge(sofia/gateway/41f3cb9a-73e0-4b25-8ca4-688b708859fe/50)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_channel.c:1288 sofia/internal/xxxxxxxxxxx@fritz.box EXPORTING[export_vars] [call_direction]=[outbound] to event
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_channel.c:1288 sofia/internal/xxxxxxxxxxx@fritz.box EXPORTING[export_vars] [call_direction]=[outbound] to event
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_channel.c:1288 sofia/internal/xxxxxxxxxxx@fritz.box EXPORTING[export_vars] [call_direction]=[outbound] to event
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_channel.c:1288 sofia/internal/xxxxxxxxxxx@fritz.box EXPORTING[export_vars] [origination_callee_id_name]=[gw+8ef99aff-b459-41e7-bfa6-999c4affbe30] to event
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_ivr_originate.c:2301 Parsing global variables
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/50 [674ac9c1-52dc-457b-8cc6-266e8a964e09]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] mod_sofia.c:5110 (sofia/internal/50) State Change CS_NEW -> CS_INIT
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_INIT (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/50) State INIT
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] mod_sofia.c:97 sofia/internal/50 SOFIA INIT
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [INFO] sofia_glue.c:1659 sofia/internal/50 sending invite call-id: (null)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] sofia_glue.c:1662 sofia/internal/50 sending invite version: 1.10.11 -release 64bit
674ac9c1-52dc-457b-8cc6-266e8a964e09 Local SDP:
674ac9c1-52dc-457b-8cc6-266e8a964e09 v=0
674ac9c1-52dc-457b-8cc6-266e8a964e09 o=FreeSWITCH 1719321958 1719321959 IN IP4 192.168.10.40
674ac9c1-52dc-457b-8cc6-266e8a964e09 s=FreeSWITCH
674ac9c1-52dc-457b-8cc6-266e8a964e09 c=IN IP4 192.168.10.40
674ac9c1-52dc-457b-8cc6-266e8a964e09 t=0 0
674ac9c1-52dc-457b-8cc6-266e8a964e09 m=audio 22368 RTP/AVP 9 8 0 102 101 13 103 104
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:9 G722/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:8 PCMA/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:0 PCMU/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:102 opus/48000/2
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:101 telephone-event/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=fmtp:101 0-15
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:103 telephone-event/48000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=fmtp:103 0-15
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:13 CN/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:104 CN/48000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=ptime:20
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=sendrecv
674ac9c1-52dc-457b-8cc6-266e8a964e09
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:40 sofia/internal/50 Standard INIT
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/50) State Change CS_INIT -> CS_ROUTING
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/50) State INIT going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_ROUTING (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] sofia.c:7493 Channel sofia/internal/50 entering state [calling][0]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/50) State ROUTING
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] mod_sofia.c:158 sofia/internal/50 SOFIA ROUTING
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_ivr_originate.c:67 (sofia/internal/50) State Change CS_ROUTING -> CS_CONSUME_MEDIA
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/50) State ROUTING going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/50) State CONSUME_MEDIA
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/50) State CONSUME_MEDIA going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:46.994589 98.63% [DEBUG] sofia.c:7493 Channel sofia/internal/50 entering state [calling][0]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] sofia.c:7493 Channel sofia/internal/50 entering state [proceeding][183]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] sofia.c:7503 Remote SDP:
674ac9c1-52dc-457b-8cc6-266e8a964e09 v=0
674ac9c1-52dc-457b-8cc6-266e8a964e09 o=user 4706186 4706186 IN IP4 192.168.178.1
674ac9c1-52dc-457b-8cc6-266e8a964e09 s=FreeSWITCH
674ac9c1-52dc-457b-8cc6-266e8a964e09 c=IN IP4 192.168.178.1
674ac9c1-52dc-457b-8cc6-266e8a964e09 t=0 0
674ac9c1-52dc-457b-8cc6-266e8a964e09 m=audio 7078 RTP/AVP 9 8 0 101
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:9 G722/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:8 PCMA/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:0 PCMU/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtpmap:101 telephone-event/8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=fmtp:101 0-15
674ac9c1-52dc-457b-8cc6-266e8a964e09 a=rtcp:7079
674ac9c1-52dc-457b-8cc6-266e8a964e09
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [NOTICE] sofia.c:7506 Pre-Answer sofia/internal/50!
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_channel.c:3585 (sofia/internal/50) Callstate Change DOWN -> EARLY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:3731 Set Codec sofia/internal/50 G722/8000 20 ms 160 samples 64000 bits 1 channels
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_codec.c:111 sofia/internal/50 Original read codec set to G722:9
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:5856 sofia/internal/50 Set 2833 dtmf send payload to 101 recv payload to 101
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:8660 AUDIO RTP [sofia/internal/50] 192.168.10.40 port 22368 -> 192.168.178.1 port 7078 codec: 9 ms: 20
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_rtp.c:4563 Starting timer [soft] 160 bytes per 20ms
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:8881 Activating RTCP PORT 7079
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_rtp.c:4895 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 7079
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_rtp.c:2689 Setting RTCP remote addr to 192.168.178.1:7079 2
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:8973 sofia/internal/50 Set 2833 dtmf send payload to 101
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:8980 sofia/internal/50 Set 2833 dtmf receive payload to 101
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.014607 98.63% [DEBUG] switch_core_media.c:9003 sofia/internal/50 Set rtp dtmf delay to 40
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_ivr_originate.c:455 Setting codec string on sofia/internal/xxxxxxxxxxx@fritz.box to G722@8000h@20i
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [INFO] switch_ivr_originate.c:3862 Sending early media
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:120:16000:20:0:1]/[G722:9:8000:20:64000:1]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:121:16000:20:0:1]/[G722:9:8000:20:64000:1]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:3731 Set Codec sofia/internal/xxxxxxxxxxx@fritz.box G722/8000 20 ms 160 samples 64000 bits 1 channels
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_codec.c:111 sofia/internal/xxxxxxxxxxx@fritz.box Original read codec set to G722:9
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:5856 sofia/internal/xxxxxxxxxxx@fritz.box Set 2833 dtmf send payload to 101 recv payload to 101
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:8660 AUDIO RTP [sofia/internal/xxxxxxxxxxx@fritz.box] 192.168.10.40 port 31384 -> 192.168.178.1 port 7080 codec: 9 ms: 20
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_rtp.c:4563 Starting timer [soft] 160 bytes per 20ms
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:8881 Activating RTCP PORT 7081
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_rtp.c:4895 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 7081
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_rtp.c:2689 Setting RTCP remote addr to 192.168.178.1:7081 2
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:8973 sofia/internal/xxxxxxxxxxx@fritz.box Set 2833 dtmf send payload to 101
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:8980 sofia/internal/xxxxxxxxxxx@fritz.box Set 2833 dtmf receive payload to 101
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:9003 sofia/internal/xxxxxxxxxxx@fritz.box Set rtp dtmf delay to 40
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/xxxxxxxxxxx@fritz.box!
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_channel.c:3585 (sofia/internal/xxxxxxxxxxx@fritz.box) Callstate Change RINGING -> EARLY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_media.c:8642 Audio params are unchanged for sofia/internal/xxxxxxxxxxx@fritz.box.
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] mod_sofia.c:2607 Ring SDP:
7e8a2d40-a022-4338-9c52-051a2441f3d4 v=0
7e8a2d40-a022-4338-9c52-051a2441f3d4 o=FreeSWITCH 1719312943 1719312944 IN IP4 192.168.10.40
7e8a2d40-a022-4338-9c52-051a2441f3d4 s=FreeSWITCH
7e8a2d40-a022-4338-9c52-051a2441f3d4 c=IN IP4 192.168.10.40
7e8a2d40-a022-4338-9c52-051a2441f3d4 t=0 0
7e8a2d40-a022-4338-9c52-051a2441f3d4 m=audio 31384 RTP/AVP 9 101
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtpmap:9 G722/8000
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtpmap:101 telephone-event/8000
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=fmtp:101 0-15
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=ptime:20
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=sendrecv
7e8a2d40-a022-4338-9c52-051a2441f3d4 a=rtcp:31385 IN IP4 192.168.10.40
7e8a2d40-a022-4338-9c52-051a2441f3d4
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_ivr_originate.c:3913 Originate Resulted in Success: [sofia/internal/50] Peer UUID: 674ac9c1-52dc-457b-8cc6-266e8a964e09
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:38:47.034596 98.63% [DEBUG] sofia.c:7493 Channel sofia/internal/xxxxxxxxxxx@fritz.box entering state [early][183]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_ivr_bridge.c:1791 (sofia/internal/50) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_core_state_machine.c:650 (sofia/internal/50) State EXCHANGE_MEDIA
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.034596 98.63% [DEBUG] mod_sofia.c:672 SOFIA EXCHANGE_MEDIA
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.034596 98.63% [DEBUG] switch_rtp.c:1930 rtcp_stats_init: audio ssrc[1089053329] base_seq[1]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:47.074629 98.63% [DEBUG] switch_rtp.c:7695 Correct audio ip/port confirmed.
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:38:49.514694 98.13% [DEBUG] switch_rtp.c:7125 Correct audio RTCP ip/port confirmed.
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] sofia.c:7493 Channel sofia/internal/50 entering state [terminated][486]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [NOTICE] sofia.c:8735 Hangup sofia/internal/50 [CS_EXCHANGE_MEDIA] [USER_BUSY]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_ivr_bridge.c:825 sofia/internal/50 ending bridge by request from read function
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/internal/50]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:650 (sofia/internal/50) State EXCHANGE_MEDIA going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_HANGUP (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/50) Callstate Change EARLY -> HANGUP
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/50) State HANGUP
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] mod_sofia.c:469 Channel sofia/internal/50 hanging up, cause: USER_BUSY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:59 sofia/internal/50 Standard HANGUP, cause: USER_BUSY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/50) State HANGUP going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/50) State Change CS_HANGUP -> CS_REPORTING
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/50) Running State Change CS_REPORTING (Cur 2 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/50) State REPORTING
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:168 sofia/internal/50 Standard REPORTING, cause: USER_BUSY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/50) State REPORTING going to sleep
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/50) State Change CS_REPORTING -> CS_DESTROY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.954626 98.13% [DEBUG] switch_core_session.c:1744 Session 13 (sofia/internal/50) Locked, Waiting on external entities
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/internal/xxxxxxxxxxx@fritz.box]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [NOTICE] switch_channel.c:5012 Hangup sofia/internal/xxxxxxxxxxx@fritz.box [CS_EXECUTE] [USER_BUSY]
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [NOTICE] switch_core_session.c:1762 Session 13 (sofia/internal/50) Ended
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/50 [CS_DESTROY]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_session.c:2979 sofia/internal/xxxxxxxxxxx@fritz.box skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/xxxxxxxxxxx@fritz.box) State EXECUTE going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_HANGUP (Cur 1 Tot 13)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/xxxxxxxxxxx@fritz.box) Callstate Change EARLY -> HANGUP
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/xxxxxxxxxxx@fritz.box) State HANGUP
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] mod_sofia.c:463 sofia/internal/xxxxxxxxxxx@fritz.box Overriding SIP cause 486 with 486 from the other leg
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] mod_sofia.c:469 Channel sofia/internal/xxxxxxxxxxx@fritz.box hanging up, cause: USER_BUSY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/50) Running State Change CS_DESTROY (Cur 1 Tot 13)
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/50) State DESTROY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [DEBUG] mod_sofia.c:380 sofia/internal/50 SOFIA DESTROY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:175 sofia/internal/50 Standard DESTROY
674ac9c1-52dc-457b-8cc6-266e8a964e09 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/50) State DESTROY going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] mod_sofia.c:614 Responding to INVITE with: 486
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:59 sofia/internal/xxxxxxxxxxx@fritz.box Standard HANGUP, cause: USER_BUSY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/xxxxxxxxxxx@fritz.box) State HANGUP going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_HANGUP -> CS_REPORTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_REPORTING (Cur 1 Tot 13)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/xxxxxxxxxxx@fritz.box) State REPORTING
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:168 sofia/internal/xxxxxxxxxxx@fritz.box Standard REPORTING, cause: USER_BUSY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/xxxxxxxxxxx@fritz.box) State REPORTING going to sleep
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/xxxxxxxxxxx@fritz.box) State Change CS_REPORTING -> CS_DESTROY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_session.c:1744 Session 12 (sofia/internal/xxxxxxxxxxx@fritz.box) Locked, Waiting on external entities
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [NOTICE] switch_core_session.c:1762 Session 12 (sofia/internal/xxxxxxxxxxx@fritz.box) Ended
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/xxxxxxxxxxx@fritz.box [CS_DESTROY]
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/xxxxxxxxxxx@fritz.box) Running State Change CS_DESTROY (Cur 0 Tot 13)
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/xxxxxxxxxxx@fritz.box) State DESTROY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] mod_sofia.c:380 sofia/internal/xxxxxxxxxxx@fritz.box SOFIA DESTROY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:175 sofia/internal/xxxxxxxxxxx@fritz.box Standard DESTROY
7e8a2d40-a022-4338-9c52-051a2441f3d4 2024-06-25 21:39:48.974632 98.13% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/xxxxxxxxxxx@fritz.box) State DESTROY going to sleep
 
Last edited:
V

voipBull

Member
Dec 3, 2023
89
17
8
@Tobias.F why is your [call_direction = outbound]?? I think because of that, FusionPBX is trying to send the call out via your gateway. It's not even getting to the ring group dialplan. Post the full log of this call, starting from where the call hits your PBX from your carrier.
 
T

Tobias.F

New Member
Aug 2, 2020
20
2
3
voipBull said:
@Tobias.F why is your [call_direction = outbound]?? I think because of that, FusionPBX is trying to send the call out via your gateway. It's not even getting to the ring group dialplan. Post the full log of this call, starting from where the call hits your PBX from your carrier.
Click to expand...

The point regarding outbound in the log I cannot explain. To me it looks that in the settings all correctly is set on inbound.

I must have cropped the wrong log part of the log. I made a new test to better identify start and end in the log.
I updated the log in the previous post #5 .

50 it the extension of ring group
xxxxxxxxx90 is the number I am dialing from outside.
 
V

voipBull

Member
Dec 3, 2023
89
17
8
@Tobias.F It's your incorrect regex in your outbound dialplan, whichever one is this [Fritzbox-xxxxxxxxx37.49490049019d]. You have a PIPE / OR ("|") at the start of your regex that's basically matching everything. Instead of ^((|49|\+49|0049|0)[1-9]\d*)$, try to use ^((49|\+49|0049|0)[1-9]\d*)$
I'd even restrict it even further based on what prefix I want to match along with the number of digits in the string. Use https://regex101.com/ to test your regex's before you use them in your PBX.
 
  • Like
Reactions: Tobias.F
T

Tobias.F

New Member
Aug 2, 2020
20
2
3
Thank you for help.

I need to find some time to check in detail and do some testing.
But two thinks I do not yet understand:
- I have not set-up any "custom regex". All configured via web UI in the menu of Destinations and inbound routes.
- I is working when I change in the via UI from the extension from ring group to the extension of an single phone.
 
T

Tobias.F

New Member
Aug 2, 2020
20
2
3
voipBull said:
You have a PIPE / OR ("|") at the start of your regex that's basically matching everything. Instead of ^((|49|\+49|0049|0)[1-9]\d*)$, try to use ^((49|\+49|0049|0)[1-9]\d*)$
Click to expand...

Thank you. This solved my problem.

I did not expect this. The Regex is for outbound calls and I tested it before with a regex tool. I never came to the idea that this rule als will be relevant for inbound calls going to a ring group (extension 50).
 
Status
Not open for further replies.
Top Bottom