*97 Voicemail not working after upgrade

Status
Not open for further replies.
F

firmfoit

New Member
Jul 5, 2022
18
0
1
I'm not quite sure what is happening here, but the symptoms are as follows. This was a previously happy system, with the exception of the issues detailed (and solved) here.

- *98 works, but phrases are silent where Callie used to say 'pound'. Logs show Invalid SAY Interface [en]
- *97 hangs up after one second silence. Call in log is recorded as terminated by 'Normal Clearing' Log below.

I'm not skilled enough to see anything in the log to indicate a problem, what should I be looking for?

Thanks


Code: 
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.929637 97.60% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/101@pbx.ourdomain.com:5060 [efadd0f9-00f7-40ec-b100-15a808ff6623]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.929637 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_NEW (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.929637 97.60% [INFO] sofia.c:10462 sofia/internal/101@pbx.ourdomain.com:5060 receiving invite from xxx.xx.xxx.xxx:11856 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 0_178183181@10.70.30.81
2023-07-28 09:29:57.929637 97.60% [DEBUG] sofia.c:10556 verifying acl "providers" for ip/port xxx.xx.xxx.xxx:0.
2023-07-28 09:29:57.929637 97.60% [DEBUG] sofia.c:2419 detaching session efadd0f9-00f7-40ec-b100-15a808ff6623
2023-07-28 09:29:57.929637 97.60% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'internal' for [*97@pbx.ourdomain.com] from ip xxx.xx.xxx.xxx
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.929637 97.60% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/101@pbx.ourdomain.com:5060) State NEW
2023-07-28 09:29:57.949613 97.60% [DEBUG] sofia.c:2532 Re-attaching to session efadd0f9-00f7-40ec-b100-15a808ff6623
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.949613 97.60% [INFO] sofia.c:10462 sofia/internal/101@pbx.ourdomain.com:5060 receiving invite from xxx.xx.xxx.xxx:11856 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 0_178183181@10.70.30.81
2023-07-28 09:29:57.949613 97.60% [DEBUG] sofia.c:10556 verifying acl "providers" for ip/port xxx.xx.xxx.xxx:0.
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] sofia.c:11672 Setting NAT mode based on via received
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] sofia.c:7499 Channel sofia/internal/101@pbx.ourdomain.com:5060 entering state [received][100]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] sofia.c:7509 Remote SDP:
efadd0f9-00f7-40ec-b100-15a808ff6623 v=0
efadd0f9-00f7-40ec-b100-15a808ff6623 o=- 20009 20009 IN IP4 10.70.30.81
efadd0f9-00f7-40ec-b100-15a808ff6623 s=SDP data
efadd0f9-00f7-40ec-b100-15a808ff6623 c=IN IP4 10.70.30.81
efadd0f9-00f7-40ec-b100-15a808ff6623 t=0 0
efadd0f9-00f7-40ec-b100-15a808ff6623 m=audio 12174 RTP/AVP 0 8 18 9 101
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:0 PCMU/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:8 PCMA/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:18 G729/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=fmtp:18 annexb=no
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:9 G722/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:101 telephone-event/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=fmtp:101 0-15
efadd0f9-00f7-40ec-b100-15a808ff6623 a=ptime:20
efadd0f9-00f7-40ec-b100-15a808ff6623
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:3870 Set Codec sofia/internal/101@pbx.ourdomain.com:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_codec.c:111 sofia/internal/101@pbx.ourdomain.com:5060 Original read codec set to PCMA:8
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_media.c:5973 sofia/internal/101@pbx.ourdomain.com:5060 Set 2833 dtmf send payload to 101 recv payload to 101
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] sofia.c:7933 (sofia/internal/101@pbx.ourdomain.com:5060) State Change CS_NEW -> CS_INIT
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_INIT (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.ourdomain.com:5060) State INIT
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] mod_sofia.c:97 sofia/internal/101@pbx.ourdomain.com:5060 SOFIA INIT
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@pbx.ourdomain.com:5060 Standard INIT
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@pbx.ourdomain.com:5060) State Change CS_INIT -> CS_ROUTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.ourdomain.com:5060) State INIT going to sleep
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_ROUTING (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_channel.c:2380 (sofia/internal/101@pbx.ourdomain.com:5060) Callstate Change DOWN -> RINGING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.ourdomain.com:5060) State ROUTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] mod_sofia.c:158 sofia/internal/101@pbx.ourdomain.com:5060 SOFIA ROUTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [DEBUG] switch_core_state_machine.c:230 sofia/internal/101@pbx.ourdomain.com:5060 Standard ROUTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:57.969599 97.60% [INFO] mod_dialplan_xml.c:639 Processing 101 <101>->*97 in context pbx.ourdomain.com
2023-07-28 09:29:58.009588 97.60% [NOTICE] switch_cpp.cpp:1465 [xml_handler] multiple key:dialplan:pbx.ourdomain.com
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->user_exists] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [user_exists] () =~ // break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(user_exists=false)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [user_exists]=[false]
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->caller-details] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(caller_destination=${destination_number}) INLINE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(caller_destination=*97)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [caller_destination]=[*97]
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(caller_id_name=${caller_id_name}) INLINE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(caller_id_name=101)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [caller_id_name]=[101]
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(caller_id_number=${caller_id_number})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->global-variables] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [global-variables] () =~ // break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->call-direction] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 ANTI-Action export(call_direction=local) INLINE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 export(call_direction=local)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[local]
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->variables] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [variables] () =~ // break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action export(origination_callee_id_name=${destination_number})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->is_loopback] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->user_record] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->rtp_has_crypto] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 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
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->redial] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [redial] destination_number(*97) =~ /^(redial|\*870)$/ break=on-true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [redial] () =~ // break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->speed_dial] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [speed_dial] destination_number(*97) =~ /^\*0(.*)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->user_hold_music] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_hold_music] ${hold_music}(local_stream://default) =~ /^$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->default_caller_id] continue=true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [default_caller_id] ${emergency_caller_id_number}(61754423444) =~ /^$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(61754423444) =~ /^$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->TB_GW1.d3] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [TB_GW1.d3] ${user_exists}(false) =~ /false/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [TB_GW1.d3] destination_number(*97) =~ /^(\d{3})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->TB_GW1.d6] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [TB_GW1.d6] ${user_exists}(false) =~ /false/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [TB_GW1.d6] destination_number(*97) =~ /^(\d{6})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->TB_GW1.d8] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [TB_GW1.d8] ${user_exists}(false) =~ /false/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [TB_GW1.d8] destination_number(*97) =~ /^(\d{8})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->TB_GW1.61d9] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [TB_GW1.61d9] ${user_exists}(false) =~ /false/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [TB_GW1.61d9] destination_number(*97) =~ /^\+?61?(\d{9})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->TB_GW1.d10] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [TB_GW1.d10] ${user_exists}(false) =~ /false/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [TB_GW1.d10] destination_number(*97) =~ /^(\d{10})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->GW1 In] continue=
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [GW1 In] destination_number(*97) =~ /^R9001$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->GW2 In] continue=
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [GW2 In] destination_number(*97) =~ /^R9005$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->ring group] continue=
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [ring group] destination_number(*97) =~ /^R9003$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->ring group] continue=
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [ring group] destination_number(*97) =~ /^R9002$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->agent_status] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [agent_status] destination_number(*97) =~ /^\*22$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [agent_status] destination_number(*97) =~ /^(agent\+)(.*)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->agent_status_id] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [agent_status_id] destination_number(*97) =~ /^\*23$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->agent-status-break] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [agent-status-break] destination_number(*97) =~ /^\*24$/ break=on-true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [agent-status-break] destination_number(*97) =~ /^(?:agent\+|\*24)(.+)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->group-intercept] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [group-intercept] destination_number(*97) =~ /^\*8$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->page-extension] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [page-extension] destination_number(*97) =~ /^\*8(\d{2,7})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->eavesdrop] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [eavesdrop] destination_number(*97) =~ /^\*33(\d{2,7})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->call_privacy] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [call_privacy] destination_number(*97) =~ /^\*67(\d+)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->call_return] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [call_return] destination_number(*97) =~ /^\*69$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->intercept-ext] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [intercept-ext] destination_number(*97) =~ /^\*\*(\d+)$/ break=on-true
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [intercept-ext] destination_number(*97) =~ /^\*\*$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->extension_queue] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [extension_queue] destination_number(*97) =~ /^\*800(.*)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->intercept-ext-polycom] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [intercept-ext-polycom] destination_number(*97) =~ /^\*97(\d+)$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->dx] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [dx] destination_number(*97) =~ /^dx$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->att_xfer] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [att_xfer] destination_number(*97) =~ /^att_xfer$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->extension-to-voicemail] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->send_to_voicemail] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [send_to_voicemail] destination_number(*97) =~ /^\*99(\d{2,10})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->xfer_vm] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [xfer_vm] destination_number(*97) =~ /^xfer_vm$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->vmain] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [vmain] destination_number(*97) =~ /^vmain$|^\*4000$|^\*98$/ break=never
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [vmain] destination_number(*97) =~ /^(vmain$|^\*4000$|^\*98)(\d{2,12})$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->is_transfer] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (FAIL) [is_transfer] destination_number(*97) =~ /^is_transfer$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 parsing [pbx.ourdomain.com->vmain_user] continue=false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Regex (PASS) [vmain_user] destination_number(*97) =~ /^\*97$/ break=on-false
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action answer()
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action sleep(1000)
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(record_append=false)
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(voicemail_action=check)
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(voicemail_id=${sip_from_user})
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action set(voicemail_profile=default)
efadd0f9-00f7-40ec-b100-15a808ff6623 Dialplan: sofia/internal/101@pbx.ourdomain.com:5060 Action lua(app.lua voicemail)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/101@pbx.ourdomain.com:5060) State Change CS_ROUTING -> CS_EXECUTE
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.ourdomain.com:5060) State ROUTING going to sleep
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_EXECUTE (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.ourdomain.com:5060) State EXECUTE
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_sofia.c:213 sofia/internal/101@pbx.ourdomain.com:5060 SOFIA EXECUTE
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_state_machine.c:323 sofia/internal/101@pbx.ourdomain.com:5060 Standard EXECUTE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(caller_id_number=1001)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [caller_id_number]=[1001]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(RFC2822_DATE=Fri, 28 Jul 2023 09:29:58 +1000)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [RFC2822_DATE]=[Fri, 28 Jul 2023 09:29:58 +1000]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 export(origination_callee_id_name=*97)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_callee_id_name]=[*97]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(RFC2822_DATE=Fri, 28 Jul 2023 09:29:58 +1000)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [RFC2822_DATE]=[Fri, 28 Jul 2023 09:29:58 +1000]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 hash(insert/pbx.ourdomain.com-last_dial/1001/*97)
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 answer()
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/internal/101@pbx.ourdomain.com:5060] 103.230.156.185 port 18474 -> 10.70.30.81 port 12174 codec: 8 ms: 20
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_media.c:9089 sofia/internal/101@pbx.ourdomain.com:5060 Set 2833 dtmf send payload to 101
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_media.c:9096 sofia/internal/101@pbx.ourdomain.com:5060 Set 2833 dtmf receive payload to 101
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] switch_core_media.c:9119 sofia/internal/101@pbx.ourdomain.com:5060 Set rtp dtmf delay to 40
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] mod_sofia.c:913 Local SDP sofia/internal/101@pbx.ourdomain.com:5060:
efadd0f9-00f7-40ec-b100-15a808ff6623 v=0
efadd0f9-00f7-40ec-b100-15a808ff6623 o=FreeSWITCH 1690482124 1690482125 IN IP4 103.230.156.185
efadd0f9-00f7-40ec-b100-15a808ff6623 s=FreeSWITCH
efadd0f9-00f7-40ec-b100-15a808ff6623 c=IN IP4 103.230.156.185
efadd0f9-00f7-40ec-b100-15a808ff6623 t=0 0
efadd0f9-00f7-40ec-b100-15a808ff6623 m=audio 18474 RTP/AVP 8 101
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:8 PCMA/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=rtpmap:101 telephone-event/8000
efadd0f9-00f7-40ec-b100-15a808ff6623 a=fmtp:101 0-15
efadd0f9-00f7-40ec-b100-15a808ff6623 a=ptime:20
efadd0f9-00f7-40ec-b100-15a808ff6623 a=sendrecv
efadd0f9-00f7-40ec-b100-15a808ff6623
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [DEBUG] sofia.c:7499 Channel sofia/internal/101@pbx.ourdomain.com:5060 entering state [completed][200]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.009588 97.60% [NOTICE] mod_dptools.c:1419 Channel [sofia/internal/101@pbx.ourdomain.com:5060] has been answered
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.029583 97.60% [DEBUG] switch_channel.c:3950 (sofia/internal/101@pbx.ourdomain.com:5060) Callstate Change RINGING -> ACTIVE
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 sleep(1000)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.089580 97.60% [DEBUG] sofia.c:7499 Channel sofia/internal/101@pbx.ourdomain.com:5060 entering state [ready][200]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:58.329613 97.60% [INFO] switch_rtp.c:7894 Auto Changing audio port from 10.70.30.81:12174 to xxx.xx.xxx.xxx:12174
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(record_append=false)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.029612 97.47% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [record_append]=[false]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(voicemail_action=check)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.029612 97.47% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [voicemail_action]=[check]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(voicemail_id=101)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.029612 97.47% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [voicemail_id]=[101]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 set(voicemail_profile=default)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.029612 97.47% [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@pbx.ourdomain.com:5060 [voicemail_profile]=[default]
efadd0f9-00f7-40ec-b100-15a808ff6623 EXECUTE [depth=0] sofia/internal/101@pbx.ourdomain.com:5060 lua(app.lua voicemail)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(playback_terminators, #)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [NOTICE] switch_cpp.cpp:751 Hangup sofia/internal/101@pbx.ourdomain.com:5060 [CS_EXECUTE] [NORMAL_CLEARING]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_cpp.cpp:1209 sofia/internal/101@pbx.ourdomain.com:5060 destroy/unlink session from object
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_session.c:2983 sofia/internal/101@pbx.ourdomain.com:5060 skip receive message [PHONE_EVENT] (channel is hungup already)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.ourdomain.com:5060) State EXECUTE going to sleep
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_HANGUP (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/101@pbx.ourdomain.com:5060) Callstate Change ACTIVE -> HANGUP
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.ourdomain.com:5060) State HANGUP
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] mod_sofia.c:468 Channel sofia/internal/101@pbx.ourdomain.com:5060 hanging up, cause: NORMAL_CLEARING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/internal/101@pbx.ourdomain.com:5060
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:59 sofia/internal/101@pbx.ourdomain.com:5060 Standard HANGUP, cause: NORMAL_CLEARING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.ourdomain.com:5060) State HANGUP going to sleep
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/101@pbx.ourdomain.com:5060) State Change CS_HANGUP -> CS_REPORTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_REPORTING (Cur 1 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.069590 97.47% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.ourdomain.com:5060) State REPORTING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:168 sofia/internal/101@pbx.ourdomain.com:5060 Standard REPORTING, cause: NORMAL_CLEARING
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.ourdomain.com:5060) State REPORTING going to sleep
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/101@pbx.ourdomain.com:5060) State Change CS_REPORTING -> CS_DESTROY
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_session.c:1753 Session 3 (sofia/internal/101@pbx.ourdomain.com:5060) Locked, Waiting on external entities
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [NOTICE] switch_core_session.c:1771 Session 3 (sofia/internal/101@pbx.ourdomain.com:5060) Ended
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [NOTICE] switch_core_session.c:1775 Close Channel sofia/internal/101@pbx.ourdomain.com:5060 [CS_DESTROY]
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/101@pbx.ourdomain.com:5060) Running State Change CS_DESTROY (Cur 0 Tot 3)
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.ourdomain.com:5060) State DESTROY
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] mod_sofia.c:379 sofia/internal/101@pbx.ourdomain.com:5060 SOFIA DESTROY
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:175 sofia/internal/101@pbx.ourdomain.com:5060 Standard DESTROY
efadd0f9-00f7-40ec-b100-15a808ff6623 2023-07-28 09:29:59.169586 97.47% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.ourdomain.com:5060) State DESTROY going to sleep
 
A

agree

Member
Aug 26, 2018
135
24
18
Assuming you're using the English prompts, check if the module 'mod_say_en' is loaded.

fs_cli -x "module_exists mod_say_en"
fs_cli -x "load mod_say_en"

If you aren't comfortable using the cli, you can use the module manager in Fusion GUI.
 
F

firmfoit

New Member
Jul 5, 2022
18
0
1
OK, so there's two different, probably unrelated problems here..

On the first system, there are quite a few Say modules that aren't loading, with EN being one of them. Attempting to start it is giving:
Code: 
-ERR [module load file routine returned an error]

More pressing issue has become that any calls made to *97 are connecting then immediately hangnig up per the log above. The only thing that I think has changed is doing an update through the web interface to 5.1.0, I can't be sure but I think previously the systems were somethign like 4.5.7.

Is there anything in the log above to suggest why the call is hanging up immediately?
 
Last edited:
F

firmfoit

New Member
Jul 5, 2022
18
0
1
*98 works if I open the voicemail of the selected extension, does that mean that I've got a dialplan issue with *97?
 
Status
Not open for further replies.
Top Bottom