Voicemail being truncated after it is left

I have a strange issue where our vm’s are getting truncated. Not cut short the system lets you leave up to a 300 sec VM (in other words it doesn’t just say good bye and hang up it lets you record), but that isn’t what is saved for replay. For example I left a message couting to 30, and received a 7 sec VM that is cut off. This is both the emailed version and the one on UCP.

VM Admin shows 300 for max length, 10 sec silence, 128 Silence threshold. Below is a call I made. Don’t know if it helps figure it our or not, but I also cannot play the VM back in Sangoma Phone desktop app, it shows up but if I click the play button nothing happens. It will play back in UCP. In any app they all show 7 sec instead of 30+


280	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/985415-0000001d Internal Gosub(app-missedcall-hangup,985415,1) start	
281	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:1] NoOp("PJSIP/985415-0000001d", "Dialed: 985415") in new stack	
282	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:2] NoOp("PJSIP/985415-0000001d", "Caller: ") in new stack	
283	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:3] GotoIf("PJSIP/985415-0000001d", "0?exit") in new stack	
284	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:4] Set("PJSIP/985415-0000001d", "EXTENNUM=985415") in new stack	
285	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:5] Set("PJSIP/985415-0000001d", "FEXTENNUM=5415") in new stack	
286	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:6] GotoIf("PJSIP/985415-0000001d", "1?exit") in new stack	
287	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (app-missedcall-hangup,985415,8)	
288	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [985415@app-missedcall-hangup:8] Return("PJSIP/985415-0000001d", "") in new stack	
289	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: Spawn extension (from-internal, 5415, 1) exited non-zero on 'PJSIP/985415-0000001d'	
290	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/985415-0000001d Internal Gosub(app-missedcall-hangup,985415,1) complete GOSUB_RETVAL=	
291	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/985415-0000001d Internal Gosub(crm-hangup,s,1) start	
292	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/985415-0000001d", "Sending Hangup to CRM") in new stack	
293	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/985415-0000001d", "HANGUP CAUSE: 21") in new stack	
294	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/985415-0000001d", "0?Set(__CRM_VOICEMAIL=)") in new stack	
295	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/985415-0000001d", "MASTER CHANNEL: 1747504832.301 = 1747504831.300") in new stack	
296	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/985415-0000001d", "1?return") in new stack	
297	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (crm-hangup,s,8)	
298	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/985415-0000001d", "") in new stack	
299	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: Spawn extension (from-internal, 5415, 1) exited non-zero on 'PJSIP/985415-0000001d'	
300	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/985415-0000001d Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=	
301	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] app_dial.c: Everyone is busy/congested at this time (1:0/0/1)	
302	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@dialOne-with-exten:3] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
303	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-dial-one:60] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Return()") in new stack	
304	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-dial-one:61] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(DIALSTATUS=)") in new stack	
305	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-dial-one:62] GosubIf("PJSIP/Nortex_SIP-0000001c", "0?s-CHANUNAVAIL,1()") in new stack	
306	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-dial-one:63] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
307	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:35] Set("PJSIP/Nortex_SIP-0000001c", "SV_DIALSTATUS=CHANUNAVAIL") in new stack	
308	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:36] GosubIf("PJSIP/Nortex_SIP-0000001c", "0?docfu,1()") in new stack	
309	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:37] GosubIf("PJSIP/Nortex_SIP-0000001c", "0?docfb,1()") in new stack	
310	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:38] Set("PJSIP/Nortex_SIP-0000001c", "DIALSTATUS=CHANUNAVAIL") in new stack	
311	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:39] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Return()") in new stack	
312	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:40] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?s-CHANUNAVAIL,1") in new stack	
313	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-exten-vm:41] Gosub("PJSIP/Nortex_SIP-0000001c", "macro-vm,s,1(5415,CHANUNAVAIL,)") in new stack	
314	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-vm:1] Gosub("PJSIP/Nortex_SIP-0000001c", "macro-user-callerid,s,1(SKIPTTL)") in new stack	
315	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/Nortex_SIP-0000001c", "TOUCH_MONITOR=1747504831.300") in new stack	
316	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/Nortex_SIP-0000001c", "CHANCONTEXT=") in new stack	
317	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:3] Set("PJSIP/Nortex_SIP-0000001c", "CHANCONTEXT=") in new stack	
318	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:4] Set("PJSIP/Nortex_SIP-0000001c", "CHANEXTENCONTEXT=Nortex_SIP-0000001c") in new stack	
319	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/Nortex_SIP-0000001c", "CHANEXTEN=Nortex_SIP-0000001c") in new stack	
320	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:6] Set("PJSIP/Nortex_SIP-0000001c", "CALLERID(number)=9405944299") in new stack	
321	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/Nortex_SIP-0000001c", "AMPUSER=9405944299") in new stack	
322	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:8] Set("PJSIP/Nortex_SIP-0000001c", "HOTDESCKCHAN=Nortex_SIP-0000001c") in new stack	
323	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:9] Set("PJSIP/Nortex_SIP-0000001c", "HOTDESKEXTEN=Nortex_SIP") in new stack	
324	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/Nortex_SIP-0000001c", "HOTDESKCALL=0") in new stack	
325	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:11] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(HOTDESKCALL=1)") in new stack	
326	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:12] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(CALLERID(name)=)") in new stack	
327	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?report") in new stack	
328	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(REALCALLERIDNUM=9405944299)") in new stack	
329	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:15] Set("PJSIP/Nortex_SIP-0000001c", "AMPUSER=") in new stack	
330	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?limit") in new stack	
331	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:17] Set("PJSIP/Nortex_SIP-0000001c", "AMPUSERCIDNAME=") in new stack	
332	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:18] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(__CIDMASQUERADING=TRUE)") in new stack	
333	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?report") in new stack	
334	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-user-callerid,s,28)	
335	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:28] NoOp("PJSIP/Nortex_SIP-0000001c", "Macro depricated!! To keep the same line numbers") in new stack	
336	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:29] NoOp("PJSIP/Nortex_SIP-0000001c", "Macro depricated !! To keep the same line numbers") in new stack	
337	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:30] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?continue") in new stack	
338	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-user-callerid,s,49)	
339	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:49] Set("PJSIP/Nortex_SIP-0000001c", "CALLERID(number)=9405944299") in new stack	
340	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:50] Set("PJSIP/Nortex_SIP-0000001c", "CALLERID(name)=BRADLEY HIEB") in new stack	
341	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:51] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?cnum") in new stack	
342	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:52] Set("PJSIP/Nortex_SIP-0000001c", "__MCNUM=9405944299") in new stack	
343	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:53] Set("PJSIP/Nortex_SIP-0000001c", "__MCNAME=BRADLEY HIEB") in new stack	
344	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:54] Set("PJSIP/Nortex_SIP-0000001c", "__MCEXTEN=") in new stack	
345	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:55] Set("PJSIP/Nortex_SIP-0000001c", "__MCORGCHAN=PJSIP/Nortex_SIP-0000001c") in new stack	
346	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:56] Set("PJSIP/Nortex_SIP-0000001c", "CDR(cnam)=BRADLEY HIEB") in new stack	
347	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:57] Set("PJSIP/Nortex_SIP-0000001c", "CDR(cnum)=9405944299") in new stack	
348	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-user-callerid:58] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
349	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-vm:2] Set("PJSIP/Nortex_SIP-0000001c", "VMGAIN=") in new stack	
350	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-vm:3] Gosub("PJSIP/Nortex_SIP-0000001c", "macro-blkvm-check,s,1()") in new stack	
351	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-blkvm-check:1] Set("PJSIP/Nortex_SIP-0000001c", "GOSUB_RETVAL=") in new stack	
352	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("PJSIP/Nortex_SIP-0000001c", "0?Set(GOSUB_RETVAL=TRUE)") in new stack	
353	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-blkvm-check:3] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
354	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-vm:4] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?vmx,1") in new stack	
355	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-vm,vmx,1)	
356	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:1] Set("PJSIP/Nortex_SIP-0000001c", "__EXTTOCALL=5415") in new stack	
357	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:2] Set("PJSIP/Nortex_SIP-0000001c", "__CRM_VOICEMAIL=5415") in new stack	
358	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:3] Set("PJSIP/Nortex_SIP-0000001c", "MEXTEN=5415") in new stack	
359	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:4] Set("PJSIP/Nortex_SIP-0000001c", "MMODE=CHANUNAVAIL") in new stack	
360	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:5] Set("PJSIP/Nortex_SIP-0000001c", "RETVM=") in new stack	
361	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:6] Set("PJSIP/Nortex_SIP-0000001c", "MODE=unavail") in new stack	
362	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:7] Gosub("PJSIP/Nortex_SIP-0000001c", "macro-get-vmcontext,s,1(5415)") in new stack	
363	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:1] Set("PJSIP/Nortex_SIP-0000001c", "VMCONTEXT=default") in new stack	
364	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?200:300") in new stack	
365	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)	
366	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("PJSIP/Nortex_SIP-0000001c", "") in new stack	
367	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:301] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
368	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:8] Set("PJSIP/Nortex_SIP-0000001c", "MODE=unavail") in new stack	
369	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:9] NoOp("PJSIP/Nortex_SIP-0000001c", "MODE IS: unavail") in new stack	
370	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:10] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?chknomsg") in new stack	
371	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-vm,vmx,12)	
372	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:12] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?s-CHANUNAVAIL,1") in new stack	
373	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:13] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?notdirect") in new stack	
374	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-vm,vmx,15)	
375	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:15] NoOp("PJSIP/Nortex_SIP-0000001c", "Checking if ext 5415 is enabled: ") in new stack	
376	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [vmx@macro-vm:16] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?s-CHANUNAVAIL,1") in new stack	
377	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-vm,s-CHANUNAVAIL,1)	
378	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s-CHANUNAVAIL@macro-vm:1] Gosub("PJSIP/Nortex_SIP-0000001c", "macro-get-vmcontext,s,1(5415)") in new stack	
379	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:1] Set("PJSIP/Nortex_SIP-0000001c", "VMCONTEXT=default") in new stack	
380	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?200:300") in new stack	
381	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)	
382	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("PJSIP/Nortex_SIP-0000001c", "") in new stack	
383	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@macro-get-vmcontext:301] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
384	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] pbx.c: Executing [s-CHANUNAVAIL@macro-vm:2] VoiceMail("PJSIP/Nortex_SIP-0000001c", "5415@default,u") in new stack	
385	[2025-05-17 13:00:35] NOTICE[20026][C-0000000d] res_rtp_asterisk.c: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client address: 209.132.160.162:24888	
386	[2025-05-17 13:00:35] VERBOSE[20026][C-0000000d] file.c: <PJSIP/Nortex_SIP-0000001c> Playing '/var/spool/asterisk/voicemail/default/5415/unavail.slin' (language 'en')	
387	[2025-05-17 13:00:39] VERBOSE[20026][C-0000000d] file.c: <PJSIP/Nortex_SIP-0000001c> Playing 'vm-intro.ulaw' (language 'en')	
388	[2025-05-17 13:00:45] VERBOSE[20026][C-0000000d] file.c: <PJSIP/Nortex_SIP-0000001c> Playing 'beep.ulaw' (language 'en')	
389	[2025-05-17 13:00:45] VERBOSE[20026][C-0000000d] app_voicemail.c: Recording the message	
390	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app.c: User hung up	
391	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on 'PJSIP/Nortex_SIP-0000001c'	
392	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/Nortex_SIP-0000001c Internal Gosub(app-missedcall-hangup,5415,1) start	
393	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:1] NoOp("PJSIP/Nortex_SIP-0000001c", "Dialed: 5415") in new stack	
394	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:2] NoOp("PJSIP/Nortex_SIP-0000001c", "Caller: ") in new stack	
395	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:3] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?exit") in new stack	
396	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:4] Set("PJSIP/Nortex_SIP-0000001c", "EXTENNUM=5415") in new stack	
397	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:5] Set("PJSIP/Nortex_SIP-0000001c", "FEXTENNUM=5415") in new stack	
398	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:6] GotoIf("PJSIP/Nortex_SIP-0000001c", "1?exit") in new stack	
399	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx_builtins.c: Goto (app-missedcall-hangup,5415,8)	
400	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [5415@app-missedcall-hangup:8] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
401	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on 'PJSIP/Nortex_SIP-0000001c'	
402	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/Nortex_SIP-0000001c Internal Gosub(app-missedcall-hangup,5415,1) complete GOSUB_RETVAL=	
403	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/Nortex_SIP-0000001c Internal Gosub(crm-hangup,s,1) start	
404	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/Nortex_SIP-0000001c", "Sending Hangup to CRM") in new stack	
405	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/Nortex_SIP-0000001c", "HANGUP CAUSE: 21") in new stack	
406	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/Nortex_SIP-0000001c", "1?Set(__CRM_VOICEMAIL=SUCCESS)") in new stack	
407	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/Nortex_SIP-0000001c", "MASTER CHANNEL: 1747504831.300 = 1747504831.300") in new stack	
408	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/Nortex_SIP-0000001c", "0?return") in new stack	
409	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/Nortex_SIP-0000001c", "__CRM_HANGUP=1") in new stack	
410	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/Nortex_SIP-0000001c", "agi://127.0.0.1/sangomacrm.agi") in new stack	
411	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] res_agi.c: <PJSIP/Nortex_SIP-0000001c>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0	
412	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/Nortex_SIP-0000001c", "") in new stack	
413	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on 'PJSIP/Nortex_SIP-0000001c'	
414	[2025-05-17 13:01:14] VERBOSE[20026][C-0000000d] app_stack.c: PJSIP/Nortex_SIP-0000001c Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

You can see form Line 389 to 390 that the VM should be about 1:14 sec but the system only did 4 seconds.

This appears systemic as many users have reported it. I also don’t see anything from a storage perspective that would be a problem as it has over 65% free space on the drive.

It is running as a VM on hyper-v. I currently I have it on a test host, and it is the only guest. I moved it from our production host earlier today to eliminate a hardware/resource issue.

This is the issue. Sounds like Asterisk is ignoring any packets that are comfort noise…so even if you leave a 60 second voicemail, if 20 seconds is CN you might end up with a 40 second voicemail.

Any tips on how to fix it? The call is coming in over an external SIP trunk provided by out local ISP.

Why would you want to keep what is, essentially, silence?

Then that isn’t the issue. I literally counted to 30, it acted like it recorded but only played 4 seconds. I would upload the wav file but it won’t let me. It isn’t like I counted to 30 in 4 seconds with 26 of silence. That I would agree it should trim the silence.

You can see on the log there is 1:14 of time between when vm Started recording and when I hung up, and although there was some silence, there wasn’t that much. And it is repeatable. Even constantly snapping or clapping will still do it

Just bumping this to see if anyone has any ideas. I have a case open with Sangoma, but they aren’t having any luck either.