Hi Folks!
I cannot seem to get outbound calling to work. I get a message that states, "The number you have dialed is not in service, please check the number and try again." I am not sure if this is coming from my carrier or FusionPBX at this point. Inbound works fine and I can also call another extension fine. Any help would be appreciated! Below are the logs from the one call. It seems like a lot going on here but I don't quite understand.
2025-01-12 23:43:04.879355 73.73% [WARNING] switch_core_db.c:92 SQLite is BUSY, sane=299 [select call_id,sip_user,sip_host,contact,status,rpid,expires,user_agent,server_user,server_host,profile_name from sip_registrations where force_ping=1 and hostname='pbx' and profile_name='internal' and orig_hostname='pbx' and ping_expires > 0 and ping_expires <= 1736743384]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/100@192.168.1.125 [9f17c7e6-5ec0-49dd-a73e-f238480673d3]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_NEW (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [INFO] sofia.c:10460 sofia/internal/100@192.168.1.125 receiving invite from 192.168.1.222:65371 version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit call-id: 9b637b68b4f140ea95422292164b12cf
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:10554 verifying acl "providers" for ip/port 192.168.1.222:0.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/100@192.168.1.125) State NEW
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:2419 detaching session 9f17c7e6-5ec0-49dd-a73e-f238480673d3
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:2532 Re-attaching to session 9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.919389 81.83% [INFO] sofia.c:10460 sofia/internal/100@192.168.1.125 receiving invite from 192.168.1.222:65371 version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit call-id: 9b637b68b4f140ea95422292164b12cf
2025-01-12 23:43:35.919389 81.83% [DEBUG] sofia.c:10554 verifying acl "providers" for ip/port 192.168.1.222:0.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [received][100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7503 Remote SDP:
9f17c7e6-5ec0-49dd-a73e-f238480673d3 v=0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 o=- 3945714217 3945714217 IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 s=pjmedia
9f17c7e6-5ec0-49dd-a73e-f238480673d3 b=AS:84
9f17c7e6-5ec0-49dd-a73e-f238480673d3 t=0 0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=X-nat:0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 m=audio 4132 RTP/AVP 8 0 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 c=IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 b=TIAS:64000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:8 PCMA/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:0 PCMU/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:101 telephone-event/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=fmtp:101 0-16
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtcp:4133 IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=ssrc:828844949 cname:3cc0532879dc702b
9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5436 Set telephone-event payload to 101@8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:3730 Set Codec sofia/internal/100@192.168.1.125 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_codec.c:132 sofia/internal/100@192.168.1.125 Original read codec set to PCMA:8
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5796 Set telephone-event payload to 101@8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5854 sofia/internal/100@192.168.1.125 Set 2833 dtmf send payload to 101 recv payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7927 (sofia/internal/100@192.168.1.125) State Change CS_NEW -> CS_INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_INIT (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/100@192.168.1.125) State INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] mod_sofia.c:97 sofia/internal/100@192.168.1.125 SOFIA INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:40 sofia/internal/100@192.168.1.125 Standard INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/100@192.168.1.125) State Change CS_INIT -> CS_ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/100@192.168.1.125) State INIT going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_ROUTING (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_channel.c:2399 (sofia/internal/100@192.168.1.125) Callstate Change DOWN -> RINGING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/100@192.168.1.125) State ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] mod_sofia.c:158 sofia/internal/100@192.168.1.125 SOFIA ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:230 sofia/internal/100@192.168.1.125 Standard ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [INFO] mod_dialplan_xml.c:639 Processing 100 <100>->18004444444 in context 192.168.1.125
2025-01-12 23:43:36.059359 81.83% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_exists] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_exists] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(user_exists=false)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.099374 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [user_exists]=[false]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(from_user_exists=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [from_user_exists]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->caller-details] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_destination=${destination_number}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_destination=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_destination]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_id_name=${caller_id_name}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_id_name=100)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_id_name]=[100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_id_number=${caller_id_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->global-variables] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [global-variables] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(timezone=America/New_York) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(timezone=America/New_York)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [timezone]=[America/New_York]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->domain-variables] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [domain-variables] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(origination_callee_id_name=${caller_destination})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(operator=1000) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(operator=1000)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [operator]=[1000]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->call_direction-outbound.11d] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] ${user_exists}(false) =~ /false/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] ${call_direction}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] destination_number(18004444444) =~ /^\+?(\d{11})$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(call_direction=outbound) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(call_direction=outbound)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->clear_sip_auto_answer] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->call-direction] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [call-direction] ${call_direction}(outbound) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_record] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(from_user_record=)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [from_user_record]=[UNDEF]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->rtp_has_crypto] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 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
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->redial] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [redial] destination_number(18004444444) =~ /^(redial|\*870)$/ break=on-true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [redial] () =~ // break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->speed_dial] continue=false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [speed_dial] destination_number(18004444444) =~ /^\*0(.*)$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_hold_music] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->default_caller_id] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${emergency_caller_id_name}(Jason Parks) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${emergency_caller_id_number}(7573871818) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${outbound_caller_id_name}(Jason Parks) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(7573871818) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->default_hold_music] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_hold_music] ${hold_music}(local_stream://default) =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->Momentum.11d] continue=false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [Momentum.11d] ${user_exists}(false) =~ /false/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [Momentum.11d] destination_number(18004444444) =~ /^\+?(\d{11})$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(call_direction=outbound) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(call_direction=outbound)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action unset(call_timeout)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(hangup_after_bridge=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(effective_caller_id_name=${outbound_caller_id_name})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(effective_caller_id_number=${outbound_caller_id_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(inherit_codec=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(ignore_display_updates=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(callee_id_number=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 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)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action bridge(sofia/gateway/cb343a45-d82f-4f21-a1b0-105f14768075/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/100@192.168.1.125) State Change CS_ROUTING -> CS_EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/100@192.168.1.125) State ROUTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_EXECUTE (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/100@192.168.1.125) State EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_sofia.c:213 sofia/internal/100@192.168.1.125 SOFIA EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:323 sofia/internal/100@192.168.1.125 Standard EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_id_number=100)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_id_number]=[100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(RFC2822_DATE=Sun, 12 Jan 2025 23:43:36 -0500)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [RFC2822_DATE]=[Sun, 12 Jan 2025 23:43:36 -0500]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(origination_callee_id_name=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 hash(insert/192.168.1.125-last_dial/100/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 unset(call_timeout)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(hangup_after_bridge=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [hangup_after_bridge]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(effective_caller_id_name=Jason Parks)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [effective_caller_id_name]=[Jason Parks]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(effective_caller_id_number=7573871818)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [effective_caller_id_number]=[7573871818]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(inherit_codec=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [inherit_codec]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(ignore_display_updates=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [ignore_display_updates]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(callee_id_number=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [callee_id_number]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 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)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [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]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 bridge(sofia/gateway/cb343a45-d82f-4f21-a1b0-105f14768075/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [domain_name]=[192.168.1.125] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [domain_uuid]=[1e7e0ef7-fbff-4126-8758-ef61d5aa669e] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [call_direction]=[outbound] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [call_direction]=[outbound] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [origination_callee_id_name]=[18004444444] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_ivr_originate.c:2301 Parsing global variables
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [NOTICE] switch_channel.c:1142 New Channel sofia/external/18004444444 [d8f54e2a-4dde-4783-bbad-6266f1574036]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:5121 (sofia/external/18004444444) State Change CS_NEW -> CS_INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_INIT (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/external/18004444444) State INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:97 sofia/external/18004444444 SOFIA INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [INFO] sofia_glue.c:1659 sofia/external/18004444444 sending invite call-id: (null)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] sofia_glue.c:1662 sofia/external/18004444444 sending invite version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit
d8f54e2a-4dde-4783-bbad-6266f1574036 Local SDP:
d8f54e2a-4dde-4783-bbad-6266f1574036 v=0
d8f54e2a-4dde-4783-bbad-6266f1574036 o=FreeSWITCH 1736719626 1736719627 IN IP4 192.168.1.125
d8f54e2a-4dde-4783-bbad-6266f1574036 s=FreeSWITCH
d8f54e2a-4dde-4783-bbad-6266f1574036 c=IN IP4 192.168.1.125
d8f54e2a-4dde-4783-bbad-6266f1574036 t=0 0
d8f54e2a-4dde-4783-bbad-6266f1574036 m=audio 23790 RTP/AVP 8 0 101
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:8 PCMA/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:0 PCMU/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:101 telephone-event/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=fmtp:101 0-15
d8f54e2a-4dde-4783-bbad-6266f1574036 a=silenceSupp
ff - - - -
d8f54e2a-4dde-4783-bbad-6266f1574036 a=ptime:20
d8f54e2a-4dde-4783-bbad-6266f1574036 a=sendrecv
d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:40 sofia/external/18004444444 Standard INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:48 (sofia/external/18004444444) State Change CS_INIT -> CS_ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/external/18004444444) State INIT going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_ROUTING (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/external/18004444444) State ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:158 sofia/external/18004444444 SOFIA ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_ivr_originate.c:67 (sofia/external/18004444444) State Change CS_ROUTING -> CS_CONSUME_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/external/18004444444) State ROUTING going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:659 (sofia/external/18004444444) State CONSUME_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:659 (sofia/external/18004444444) State CONSUME_MEDIA going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [calling][0]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:38.419355 84.83% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [calling][0]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [proceeding][180]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [NOTICE] sofia.c:7604 Ring-Ready sofia/external/18004444444!
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] switch_channel.c:3513 (sofia/external/18004444444) Callstate Change DOWN -> RINGING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [completing][200]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7503 Remote SDP:
d8f54e2a-4dde-4783-bbad-6266f1574036 v=0
d8f54e2a-4dde-4783-bbad-6266f1574036 o=BroadWorks 165936100 1 IN IP4 209.209.172.230
d8f54e2a-4dde-4783-bbad-6266f1574036 s=-
d8f54e2a-4dde-4783-bbad-6266f1574036 c=IN IP4 209.209.172.230
d8f54e2a-4dde-4783-bbad-6266f1574036 t=0 0
d8f54e2a-4dde-4783-bbad-6266f1574036 m=audio 61366 RTP/AVP 0 101
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:0 PCMU/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:101 telephone-event/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=fmtp:101 0-15
d8f54e2a-4dde-4783-bbad-6266f1574036 a=ptime:20
d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [ready][200]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5436 Set telephone-event payload to 101@8000
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:3730 Set Codec sofia/external/18004444444 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_codec.c:132 sofia/external/18004444444 Original read codec set to PCMU:0
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5796 Set telephone-event payload to 101@8000
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5854 sofia/external/18004444444 Set 2833 dtmf send payload to 101 recv payload to 101
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/external/18004444444] 192.168.1.125 port 23790 -> 209.209.172.230 port 61366 codec: 0 ms: 20
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4566 Starting timer [soft] 160 bytes per 20ms
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8971 sofia/external/18004444444 Set 2833 dtmf send payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [NOTICE] mod_sofia.c:2524 Ring-Ready sofia/internal/100@192.168.1.125!
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8978 sofia/external/18004444444 Set 2833 dtmf receive payload to 101
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:9001 sofia/external/18004444444 Set rtp dtmf delay to 40
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [NOTICE] sofia.c:8681 Channel [sofia/external/18004444444] has been answered
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [early][180]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [NOTICE] switch_ivr_originate.c:572 Ring Ready sofia/internal/100@192.168.1.125!
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_ivr_originate.c:455 Setting codec string on sofia/internal/100@192.168.1.125 to PCMU@8000h@20i
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_channel.c:3912 (sofia/external/18004444444) Callstate Change RINGING -> ACTIVE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/internal/100@192.168.1.125] 192.168.1.125 port 17456 -> 192.168.1.222 port 4132 codec: 8 ms: 20
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4566 Starting timer [soft] 160 bytes per 20ms
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8879 Activating RTCP PORT 4133
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4898 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4133
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_rtp.c:2692 Setting RTCP remote addr to 192.168.1.222:4133 2
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:8971 sofia/internal/100@192.168.1.125 Set 2833 dtmf send payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:8978 sofia/internal/100@192.168.1.125 Set 2833 dtmf receive payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:9001 sofia/internal/100@192.168.1.125 Set rtp dtmf delay to 40
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] mod_sofia.c:914 Local SDP sofia/internal/100@192.168.1.125:
9f17c7e6-5ec0-49dd-a73e-f238480673d3 v=0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 o=FreeSWITCH 1736725970 1736725971 IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 s=FreeSWITCH
9f17c7e6-5ec0-49dd-a73e-f238480673d3 c=IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 t=0 0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 m=audio 17456 RTP/AVP 8 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:8 PCMA/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:101 telephone-event/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=fmtp:101 0-15
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=ptime:20
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=sendrecv
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtcp:17457 IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [NOTICE] switch_ivr_originate.c:3855 Channel [sofia/internal/100@192.168.1.125] has been answered
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_channel.c:3912 (sofia/internal/100@192.168.1.125) Callstate Change RINGING -> ACTIVE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [completed][200]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_ivr_originate.c:3913 Originate Resulted in Success: [sofia/external/18004444444] Peer UUID: d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_ivr_bridge.c:1791 (sofia/external/18004444444) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_core_state_machine.c:650 (sofia/external/18004444444) State EXCHANGE_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] mod_sofia.c:672 SOFIA EXCHANGE_MEDIA
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.279380 85.47% [DEBUG] switch_rtp.c:7128 Correct audio RTCP ip/port confirmed.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.279380 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [ready][200]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.319374 85.47% [DEBUG] switch_rtp.c:1934 rtcp_stats_init: audio ssrc[828844949] base_seq[12084]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.319374 85.47% [DEBUG] switch_rtp.c:7698 Correct audio ip/port confirmed.
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.399392 85.47% [DEBUG] switch_rtp.c:7698 Correct audio ip/port confirmed.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [NOTICE] sofia.c:1065 Hangup sofia/internal/100@192.168.1.125 [CS_EXECUTE] [NORMAL_CLEARING]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/internal/100@192.168.1.125]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:819 sofia/internal/100@192.168.1.125 ending bridge by request from write function
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/external/18004444444]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [NOTICE] switch_ivr_bridge.c:1027 Hangup sofia/external/18004444444 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:650 (sofia/external/18004444444) State EXCHANGE_MEDIA going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_HANGUP (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:1890 sofia/external/18004444444 skip receive message [UNBRIDGE] (channel is hungup already)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:1893 sofia/internal/100@192.168.1.125 skip receive message [UNBRIDGE] (channel is hungup already)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:844 (sofia/external/18004444444) Callstate Change ACTIVE -> HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_session.c:2983 sofia/internal/100@192.168.1.125 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/100@192.168.1.125) State EXECUTE going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_HANGUP (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:846 (sofia/external/18004444444) State HANGUP
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:463 sofia/external/18004444444 Overriding SIP cause 480 with 200 from the other leg
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:469 Channel sofia/external/18004444444 hanging up, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/100@192.168.1.125) Callstate Change ACTIVE -> HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/100@192.168.1.125) State HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:469 Channel sofia/internal/100@192.168.1.125 hanging up, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:59 sofia/internal/100@192.168.1.125 Standard HANGUP, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/100@192.168.1.125) State HANGUP going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/external/18004444444
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:59 sofia/external/18004444444 Standard HANGUP, cause: NORMAL_CLEARING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:846 (sofia/external/18004444444) State HANGUP going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/100@192.168.1.125) State Change CS_HANGUP -> CS_REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:616 (sofia/external/18004444444) State Change CS_HANGUP -> CS_REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_REPORTING (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/external/18004444444) State REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:168 sofia/external/18004444444 Standard REPORTING, cause: NORMAL_CLEARING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/external/18004444444) State REPORTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_REPORTING (Cur 2 Tot 211)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/100@192.168.1.125) State REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:607 (sofia/external/18004444444) State Change CS_REPORTING -> CS_DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_session.c:1748 Session 211 (sofia/external/18004444444) Locked, Waiting on external entities
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1766 Session 211 (sofia/external/18004444444) Ended
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1770 Close Channel sofia/external/18004444444 [CS_DESTROY]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:735 (sofia/external/18004444444) Running State Change CS_DESTROY (Cur 1 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:745 (sofia/external/18004444444) State DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] mod_sofia.c:380 sofia/external/18004444444 SOFIA DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:175 sofia/external/18004444444 Standard DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:745 (sofia/external/18004444444) State DESTROY going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:168 sofia/internal/100@192.168.1.125 Standard REPORTING, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/100@192.168.1.125) State REPORTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/100@192.168.1.125) State Change CS_REPORTING -> CS_DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_session.c:1748 Session 210 (sofia/internal/100@192.168.1.125) Locked, Waiting on external entities
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1766 Session 210 (sofia/internal/100@192.168.1.125) Ended
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1770 Close Channel sofia/internal/100@192.168.1.125 [CS_DESTROY]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/100@192.168.1.125) Running State Change CS_DESTROY (Cur 0 Tot 211)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/100@192.168.1.125) State DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] mod_sofia.c:380 sofia/internal/100@192.168.1.125 SOFIA DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:175 sofia/internal/100@192.168.1.125 Standard DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/100@192.168.1.125) State DESTROY going to sleep
I cannot seem to get outbound calling to work. I get a message that states, "The number you have dialed is not in service, please check the number and try again." I am not sure if this is coming from my carrier or FusionPBX at this point. Inbound works fine and I can also call another extension fine. Any help would be appreciated! Below are the logs from the one call. It seems like a lot going on here but I don't quite understand.
2025-01-12 23:43:04.879355 73.73% [WARNING] switch_core_db.c:92 SQLite is BUSY, sane=299 [select call_id,sip_user,sip_host,contact,status,rpid,expires,user_agent,server_user,server_host,profile_name from sip_registrations where force_ping=1 and hostname='pbx' and profile_name='internal' and orig_hostname='pbx' and ping_expires > 0 and ping_expires <= 1736743384]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/100@192.168.1.125 [9f17c7e6-5ec0-49dd-a73e-f238480673d3]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_NEW (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [INFO] sofia.c:10460 sofia/internal/100@192.168.1.125 receiving invite from 192.168.1.222:65371 version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit call-id: 9b637b68b4f140ea95422292164b12cf
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:10554 verifying acl "providers" for ip/port 192.168.1.222:0.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.899380 81.83% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/100@192.168.1.125) State NEW
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:2419 detaching session 9f17c7e6-5ec0-49dd-a73e-f238480673d3
2025-01-12 23:43:35.899380 81.83% [DEBUG] sofia.c:2532 Re-attaching to session 9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.919389 81.83% [INFO] sofia.c:10460 sofia/internal/100@192.168.1.125 receiving invite from 192.168.1.222:65371 version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit call-id: 9b637b68b4f140ea95422292164b12cf
2025-01-12 23:43:35.919389 81.83% [DEBUG] sofia.c:10554 verifying acl "providers" for ip/port 192.168.1.222:0.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [received][100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7503 Remote SDP:
9f17c7e6-5ec0-49dd-a73e-f238480673d3 v=0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 o=- 3945714217 3945714217 IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 s=pjmedia
9f17c7e6-5ec0-49dd-a73e-f238480673d3 b=AS:84
9f17c7e6-5ec0-49dd-a73e-f238480673d3 t=0 0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=X-nat:0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 m=audio 4132 RTP/AVP 8 0 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 c=IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 b=TIAS:64000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:8 PCMA/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:0 PCMU/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:101 telephone-event/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=fmtp:101 0-16
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtcp:4133 IN IP4 192.168.1.222
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=ssrc:828844949 cname:3cc0532879dc702b
9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5436 Set telephone-event payload to 101@8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:3730 Set Codec sofia/internal/100@192.168.1.125 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_codec.c:132 sofia/internal/100@192.168.1.125 Original read codec set to PCMA:8
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5796 Set telephone-event payload to 101@8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_media.c:5854 sofia/internal/100@192.168.1.125 Set 2833 dtmf send payload to 101 recv payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] sofia.c:7927 (sofia/internal/100@192.168.1.125) State Change CS_NEW -> CS_INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_INIT (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/100@192.168.1.125) State INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] mod_sofia.c:97 sofia/internal/100@192.168.1.125 SOFIA INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:40 sofia/internal/100@192.168.1.125 Standard INIT
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/100@192.168.1.125) State Change CS_INIT -> CS_ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/100@192.168.1.125) State INIT going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_ROUTING (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_channel.c:2399 (sofia/internal/100@192.168.1.125) Callstate Change DOWN -> RINGING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/100@192.168.1.125) State ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] mod_sofia.c:158 sofia/internal/100@192.168.1.125 SOFIA ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [DEBUG] switch_core_state_machine.c:230 sofia/internal/100@192.168.1.125 Standard ROUTING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:35.959386 81.83% [INFO] mod_dialplan_xml.c:639 Processing 100 <100>->18004444444 in context 192.168.1.125
2025-01-12 23:43:36.059359 81.83% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_exists] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_exists] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(user_exists=false)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.099374 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [user_exists]=[false]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(from_user_exists=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [from_user_exists]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->caller-details] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_destination=${destination_number}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_destination=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_destination]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_id_name=${caller_id_name}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_id_name=100)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_id_name]=[100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(caller_id_number=${caller_id_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->global-variables] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [global-variables] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(timezone=America/New_York) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(timezone=America/New_York)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [timezone]=[America/New_York]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->domain-variables] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [domain-variables] () =~ // break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(origination_callee_id_name=${caller_destination})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(operator=1000) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(operator=1000)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [operator]=[1000]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->call_direction-outbound.11d] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] ${user_exists}(false) =~ /false/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] ${call_direction}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [call_direction-outbound.11d] destination_number(18004444444) =~ /^\+?(\d{11})$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(call_direction=outbound) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(call_direction=outbound)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.119365 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->clear_sip_auto_answer] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->call-direction] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [call-direction] ${call_direction}(outbound) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_record] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(from_user_record=)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [from_user_record]=[UNDEF]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->rtp_has_crypto] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 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
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->redial] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [redial] destination_number(18004444444) =~ /^(redial|\*870)$/ break=on-true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [redial] () =~ // break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->speed_dial] continue=false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [speed_dial] destination_number(18004444444) =~ /^\*0(.*)$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->user_hold_music] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->default_caller_id] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${emergency_caller_id_name}(Jason Parks) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${emergency_caller_id_number}(7573871818) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${outbound_caller_id_name}(Jason Parks) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(7573871818) =~ /^$/ break=never
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->default_hold_music] continue=true
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (FAIL) [default_hold_music] ${hold_music}(local_stream://default) =~ /^$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 parsing [192.168.1.125->Momentum.11d] continue=false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [Momentum.11d] ${user_exists}(false) =~ /false/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Regex (PASS) [Momentum.11d] destination_number(18004444444) =~ /^\+?(\d{11})$/ break=on-false
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action export(call_direction=outbound) INLINE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(call_direction=outbound)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action unset(call_timeout)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(hangup_after_bridge=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(effective_caller_id_name=${outbound_caller_id_name})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(effective_caller_id_number=${outbound_caller_id_number})
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(inherit_codec=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(ignore_display_updates=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action set(callee_id_number=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 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)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 Dialplan: sofia/internal/100@192.168.1.125 Action bridge(sofia/gateway/cb343a45-d82f-4f21-a1b0-105f14768075/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/100@192.168.1.125) State Change CS_ROUTING -> CS_EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/100@192.168.1.125) State ROUTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_EXECUTE (Cur 1 Tot 210)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/100@192.168.1.125) State EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_sofia.c:213 sofia/internal/100@192.168.1.125 SOFIA EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_core_state_machine.c:323 sofia/internal/100@192.168.1.125 Standard EXECUTE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(caller_id_number=100)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [caller_id_number]=[100]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(RFC2822_DATE=Sun, 12 Jan 2025 23:43:36 -0500)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [RFC2822_DATE]=[Sun, 12 Jan 2025 23:43:36 -0500]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 export(origination_callee_id_name=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.139381 81.83% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 hash(insert/192.168.1.125-last_dial/100/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 unset(call_timeout)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(hangup_after_bridge=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [hangup_after_bridge]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(effective_caller_id_name=Jason Parks)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [effective_caller_id_name]=[Jason Parks]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(effective_caller_id_number=7573871818)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [effective_caller_id_number]=[7573871818]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(inherit_codec=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [inherit_codec]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(ignore_display_updates=true)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [ignore_display_updates]=[true]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 set(callee_id_number=18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [callee_id_number]=[18004444444]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 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)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_dptools.c:1671 SET sofia/internal/100@192.168.1.125 [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]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 EXECUTE [depth=0] sofia/internal/100@192.168.1.125 bridge(sofia/gateway/cb343a45-d82f-4f21-a1b0-105f14768075/18004444444)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [domain_name]=[192.168.1.125] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [domain_uuid]=[1e7e0ef7-fbff-4126-8758-ef61d5aa669e] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [call_direction]=[outbound] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [call_direction]=[outbound] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_channel.c:1288 sofia/internal/100@192.168.1.125 EXPORTING[export_vars] [origination_callee_id_name]=[18004444444] to event
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_ivr_originate.c:2301 Parsing global variables
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [NOTICE] switch_channel.c:1142 New Channel sofia/external/18004444444 [d8f54e2a-4dde-4783-bbad-6266f1574036]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:5121 (sofia/external/18004444444) State Change CS_NEW -> CS_INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_INIT (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/external/18004444444) State INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:97 sofia/external/18004444444 SOFIA INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [INFO] sofia_glue.c:1659 sofia/external/18004444444 sending invite call-id: (null)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] sofia_glue.c:1662 sofia/external/18004444444 sending invite version: 1.10.12-release git 7b80a9a 2024-11-23 23:59:58Z 64bit
d8f54e2a-4dde-4783-bbad-6266f1574036 Local SDP:
d8f54e2a-4dde-4783-bbad-6266f1574036 v=0
d8f54e2a-4dde-4783-bbad-6266f1574036 o=FreeSWITCH 1736719626 1736719627 IN IP4 192.168.1.125
d8f54e2a-4dde-4783-bbad-6266f1574036 s=FreeSWITCH
d8f54e2a-4dde-4783-bbad-6266f1574036 c=IN IP4 192.168.1.125
d8f54e2a-4dde-4783-bbad-6266f1574036 t=0 0
d8f54e2a-4dde-4783-bbad-6266f1574036 m=audio 23790 RTP/AVP 8 0 101
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:8 PCMA/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:0 PCMU/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:101 telephone-event/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=fmtp:101 0-15
d8f54e2a-4dde-4783-bbad-6266f1574036 a=silenceSupp
ff - - - -d8f54e2a-4dde-4783-bbad-6266f1574036 a=ptime:20
d8f54e2a-4dde-4783-bbad-6266f1574036 a=sendrecv
d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:40 sofia/external/18004444444 Standard INIT
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:48 (sofia/external/18004444444) State Change CS_INIT -> CS_ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:624 (sofia/external/18004444444) State INIT going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_ROUTING (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/external/18004444444) State ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] mod_sofia.c:158 sofia/external/18004444444 SOFIA ROUTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_ivr_originate.c:67 (sofia/external/18004444444) State Change CS_ROUTING -> CS_CONSUME_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:640 (sofia/external/18004444444) State ROUTING going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:659 (sofia/external/18004444444) State CONSUME_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] switch_core_state_machine.c:659 (sofia/external/18004444444) State CONSUME_MEDIA going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:36.159390 81.83% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [calling][0]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:38.419355 84.83% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [calling][0]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [proceeding][180]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [NOTICE] sofia.c:7604 Ring-Ready sofia/external/18004444444!
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] switch_channel.c:3513 (sofia/external/18004444444) Callstate Change DOWN -> RINGING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [completing][200]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.199379 85.47% [DEBUG] sofia.c:7503 Remote SDP:
d8f54e2a-4dde-4783-bbad-6266f1574036 v=0
d8f54e2a-4dde-4783-bbad-6266f1574036 o=BroadWorks 165936100 1 IN IP4 209.209.172.230
d8f54e2a-4dde-4783-bbad-6266f1574036 s=-
d8f54e2a-4dde-4783-bbad-6266f1574036 c=IN IP4 209.209.172.230
d8f54e2a-4dde-4783-bbad-6266f1574036 t=0 0
d8f54e2a-4dde-4783-bbad-6266f1574036 m=audio 61366 RTP/AVP 0 101
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:0 PCMU/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=rtpmap:101 telephone-event/8000
d8f54e2a-4dde-4783-bbad-6266f1574036 a=fmtp:101 0-15
d8f54e2a-4dde-4783-bbad-6266f1574036 a=ptime:20
d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] sofia.c:7493 Channel sofia/external/18004444444 entering state [ready][200]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5524 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5586 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5436 Set telephone-event payload to 101@8000
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:3730 Set Codec sofia/external/18004444444 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_codec.c:132 sofia/external/18004444444 Original read codec set to PCMU:0
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5796 Set telephone-event payload to 101@8000
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:5854 sofia/external/18004444444 Set 2833 dtmf send payload to 101 recv payload to 101
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/external/18004444444] 192.168.1.125 port 23790 -> 209.209.172.230 port 61366 codec: 0 ms: 20
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4566 Starting timer [soft] 160 bytes per 20ms
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8971 sofia/external/18004444444 Set 2833 dtmf send payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [NOTICE] mod_sofia.c:2524 Ring-Ready sofia/internal/100@192.168.1.125!
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8978 sofia/external/18004444444 Set 2833 dtmf receive payload to 101
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:9001 sofia/external/18004444444 Set rtp dtmf delay to 40
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [NOTICE] sofia.c:8681 Channel [sofia/external/18004444444] has been answered
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [early][180]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [NOTICE] switch_ivr_originate.c:572 Ring Ready sofia/internal/100@192.168.1.125!
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_ivr_originate.c:455 Setting codec string on sofia/internal/100@192.168.1.125 to PCMU@8000h@20i
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_channel.c:3912 (sofia/external/18004444444) Callstate Change RINGING -> ACTIVE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/internal/100@192.168.1.125] 192.168.1.125 port 17456 -> 192.168.1.222 port 4132 codec: 8 ms: 20
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4566 Starting timer [soft] 160 bytes per 20ms
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_core_media.c:8879 Activating RTCP PORT 4133
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.219418 85.47% [DEBUG] switch_rtp.c:4898 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4133
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_rtp.c:2692 Setting RTCP remote addr to 192.168.1.222:4133 2
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:8971 sofia/internal/100@192.168.1.125 Set 2833 dtmf send payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:8978 sofia/internal/100@192.168.1.125 Set 2833 dtmf receive payload to 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_core_media.c:9001 sofia/internal/100@192.168.1.125 Set rtp dtmf delay to 40
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] mod_sofia.c:914 Local SDP sofia/internal/100@192.168.1.125:
9f17c7e6-5ec0-49dd-a73e-f238480673d3 v=0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 o=FreeSWITCH 1736725970 1736725971 IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 s=FreeSWITCH
9f17c7e6-5ec0-49dd-a73e-f238480673d3 c=IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3 t=0 0
9f17c7e6-5ec0-49dd-a73e-f238480673d3 m=audio 17456 RTP/AVP 8 101
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:8 PCMA/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtpmap:101 telephone-event/8000
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=fmtp:101 0-15
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=ptime:20
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=sendrecv
9f17c7e6-5ec0-49dd-a73e-f238480673d3 a=rtcp:17457 IN IP4 192.168.1.125
9f17c7e6-5ec0-49dd-a73e-f238480673d3
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [NOTICE] switch_ivr_originate.c:3855 Channel [sofia/internal/100@192.168.1.125] has been answered
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_channel.c:3912 (sofia/internal/100@192.168.1.125) Callstate Change RINGING -> ACTIVE
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [completed][200]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.239422 85.47% [DEBUG] switch_ivr_originate.c:3913 Originate Resulted in Success: [sofia/external/18004444444] Peer UUID: d8f54e2a-4dde-4783-bbad-6266f1574036
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_ivr_bridge.c:1791 (sofia/external/18004444444) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] switch_core_state_machine.c:650 (sofia/external/18004444444) State EXCHANGE_MEDIA
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.259398 85.47% [DEBUG] mod_sofia.c:672 SOFIA EXCHANGE_MEDIA
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.279380 85.47% [DEBUG] switch_rtp.c:7128 Correct audio RTCP ip/port confirmed.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.279380 85.47% [DEBUG] sofia.c:7493 Channel sofia/internal/100@192.168.1.125 entering state [ready][200]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.319374 85.47% [DEBUG] switch_rtp.c:1934 rtcp_stats_init: audio ssrc[828844949] base_seq[12084]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:46.319374 85.47% [DEBUG] switch_rtp.c:7698 Correct audio ip/port confirmed.
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:46.399392 85.47% [DEBUG] switch_rtp.c:7698 Correct audio ip/port confirmed.
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [NOTICE] sofia.c:1065 Hangup sofia/internal/100@192.168.1.125 [CS_EXECUTE] [NORMAL_CLEARING]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/internal/100@192.168.1.125]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:819 sofia/internal/100@192.168.1.125 ending bridge by request from write function
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/external/18004444444]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [NOTICE] switch_ivr_bridge.c:1027 Hangup sofia/external/18004444444 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:650 (sofia/external/18004444444) State EXCHANGE_MEDIA going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_HANGUP (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:1890 sofia/external/18004444444 skip receive message [UNBRIDGE] (channel is hungup already)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_ivr_bridge.c:1893 sofia/internal/100@192.168.1.125 skip receive message [UNBRIDGE] (channel is hungup already)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:844 (sofia/external/18004444444) Callstate Change ACTIVE -> HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_session.c:2983 sofia/internal/100@192.168.1.125 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/100@192.168.1.125) State EXECUTE going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_HANGUP (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:846 (sofia/external/18004444444) State HANGUP
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:463 sofia/external/18004444444 Overriding SIP cause 480 with 200 from the other leg
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:469 Channel sofia/external/18004444444 hanging up, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/100@192.168.1.125) Callstate Change ACTIVE -> HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/100@192.168.1.125) State HANGUP
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:53.159363 74.57% [DEBUG] mod_sofia.c:469 Channel sofia/internal/100@192.168.1.125 hanging up, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:59 sofia/internal/100@192.168.1.125 Standard HANGUP, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/100@192.168.1.125) State HANGUP going to sleep
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/external/18004444444
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:59 sofia/external/18004444444 Standard HANGUP, cause: NORMAL_CLEARING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:846 (sofia/external/18004444444) State HANGUP going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/100@192.168.1.125) State Change CS_HANGUP -> CS_REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:616 (sofia/external/18004444444) State Change CS_HANGUP -> CS_REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:581 (sofia/external/18004444444) Running State Change CS_REPORTING (Cur 2 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/external/18004444444) State REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:168 sofia/external/18004444444 Standard REPORTING, cause: NORMAL_CLEARING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/external/18004444444) State REPORTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.1.125) Running State Change CS_REPORTING (Cur 2 Tot 211)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/100@192.168.1.125) State REPORTING
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:607 (sofia/external/18004444444) State Change CS_REPORTING -> CS_DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_session.c:1748 Session 211 (sofia/external/18004444444) Locked, Waiting on external entities
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1766 Session 211 (sofia/external/18004444444) Ended
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1770 Close Channel sofia/external/18004444444 [CS_DESTROY]
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:735 (sofia/external/18004444444) Running State Change CS_DESTROY (Cur 1 Tot 211)
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:745 (sofia/external/18004444444) State DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] mod_sofia.c:380 sofia/external/18004444444 SOFIA DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:175 sofia/external/18004444444 Standard DESTROY
d8f54e2a-4dde-4783-bbad-6266f1574036 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:745 (sofia/external/18004444444) State DESTROY going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:168 sofia/internal/100@192.168.1.125 Standard REPORTING, cause: NORMAL_CLEARING
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/100@192.168.1.125) State REPORTING going to sleep
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/100@192.168.1.125) State Change CS_REPORTING -> CS_DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_session.c:1748 Session 210 (sofia/internal/100@192.168.1.125) Locked, Waiting on external entities
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1766 Session 210 (sofia/internal/100@192.168.1.125) Ended
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [NOTICE] switch_core_session.c:1770 Close Channel sofia/internal/100@192.168.1.125 [CS_DESTROY]
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.819355 69.53% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/100@192.168.1.125) Running State Change CS_DESTROY (Cur 0 Tot 211)
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/100@192.168.1.125) State DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] mod_sofia.c:380 sofia/internal/100@192.168.1.125 SOFIA DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:175 sofia/internal/100@192.168.1.125 Standard DESTROY
9f17c7e6-5ec0-49dd-a73e-f238480673d3 2025-01-12 23:43:55.839389 67.00% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/100@192.168.1.125) State DESTROY going to sleep
