*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
 
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.
 
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:
*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