Call recording fails randomly

I’m facing a issue where call recording of a extensions fails at random.

Failed recordings will show in below format in CDR records. (missing .wav and timestamp)
external-10032-11######–1679976595.6067173.
And this file is not available /var/spool/asterisk

CLI output

[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“Local/10005@from-queue-0029b557;2”, “1?callee”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:5] Set(“Local/10031@from-queue-0029b558;2”, “CHANEXTEN=10031”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:6] Set(“Local/10031@from-queue-0029b558;2”, “CALLERID(number)=771134367”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:7] Set(“Local/10031@from-queue-0029b558;2”, “AMPUSER=771134367”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:8] Set(“Local/10031@from-queue-0029b558;2”, “HOTDESCKCHAN=10031@from-queue-0029b558;2”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:9] Set(“Local/10031@from-queue-0029b558;2”, “HOTDESKEXTEN=10031@from”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [exten@sub-record-check:11] Gosub(“Local/10005@from-queue-0029b557;2”, “recordcheck,1(force,external,10005)”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:10] Set(“Local/10031@from-queue-0029b558;2”, “HOTDESKCALL=0”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“Local/10005@from-queue-0029b557;2”, “Starting recording check against force”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:11] ExecIf(“Local/10031@from-queue-0029b558;2”, “0?Set(HOTDESKCALL=1)”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“Local/10005@from-queue-0029b557;2”, “force”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx_builtins.c: Goto (sub-record-check,recordcheck,5)
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:5] Set(“Local/10005@from-queue-0029b557;2”, “__REC_POLICY_MODE=FORCE”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:12] ExecIf(“Local/10031@from-queue-0029b558;2”, “0?Set(CALLERID(name)=)”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:6] GotoIf(“Local/10005@from-queue-0029b557;2”, “1?startrec”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:16] NoOp(“Local/10005@from-queue-0029b557;2”, “Starting recording: external, 10005”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:17] Set(“Local/10005@from-queue-0029b557;2”, “__CALLFILENAME=external-10005-112768916–1679930915.5496188”) in new stack
[2023-03-27 20:58:36] VERBOSE[9197][C-00003f8b] app_macro.c: Spawn extension (macro-exten-vm, s-BUSY, 3) exited non-zero on ‘Local/10067@from-queue-0029b556;2’ in macro ‘exten-vm’
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:13] GotoIf(“Local/10031@from-queue-0029b558;2”, “1?report”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:18] MixMonitor(“Local/10005@from-queue-0029b557;2”, “///external-10005-112768916–1679930915.5496188.,abi(),”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx_builtins.c: Goto (macro-user-callerid,s,27)
[2023-03-27 20:58:36] VERBOSE[9215][C-00003f72] app_mixmonitor.c: Begin MixMonitor Recording Local/10005@from-queue-0029b557;2
**[2023-03-27 20:58:36] WARNING[9215][C-00003f72] file.c: No such format ‘’**
**[2023-03-27 20:58:36] ERROR[9215][C-00003f72] app_mixmonitor.c: Cannot open ///external-10005-112768916–1679930915.5496188.**
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:19] Set(“Local/10005@from-queue-0029b557;2”, “__MIXMON_ID=”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:27] NoOp(“Local/10031@from-queue-0029b558;2”, “Macro Depth is 2”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:20] Set(“Local/10005@from-queue-0029b557;2”, “__RECORD_ID=Local/10005@from-queue-0029b557;2”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:28] GotoIf(“Local/10031@from-queue-0029b558;2”, “1?report2:macroerror”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:21] Set(“Local/10005@from-queue-0029b557;2”, “__REC_STATUS=RECORDING”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:29] GotoIf(“Local/10031@from-queue-0029b558;2”, “0?continue”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:30] Set(“Local/10031@from-queue-0029b558;2”, “__TTL=63”) in new stack
[2023-03-27 20:58:36] VERBOSE[9203][C-00003f72] pbx.c: Executing [recordcheck@sub-record-check:22] Set(“Local/10005@from-queue-0029b557;2”, “CDR(recordingfile)=external-10005-112768916–1679930915.5496188.”) in new stack
[2023-03-27 20:58:36] VERBOSE[9209][C-00003f62] pbx.c: Executing [s@macro-user-callerid:31] GotoIf(“Local/10031@from-queue-0029b558;2”, “1?continue”) in new stack

Setup
Asterisk 16.30.0
FreePBX 16.0.40
100 extensions with 40 queues
vm with 32 core (@2.1ghz) 32GB ram with SSD storage

Any help very much appreciated.

below topic also mentions a similar issue, but my MIXMON_FORMAT = WAV is defined correctly in extensions_additional.conf
/t/recorded-call-issues-mixmonitor-not-reading-file-format-ast-1-8/16159/1

Whilst a valid format, WAV is unusual. It is GSM encoded, rather than the PCM format used for wav.

1 Like

I normally set it to WAV from Advance Settings to save space.

changing to wav also didn’t fix the issue.

The path is missing for the recording file location. What do you have set for the recording file locatoin:

# fwconsole setting MIXMON_DIR
Setting of "MIXMON_DIR" is (dir)[]
1 Like

Following is the output. Note this is a random issue, about 1 out of 20 calls not getting recorded.

fwconsole setting MIXMON_DIR
Setting of “MIXMON_DIR” is (dir)

I tried the same setup with completely new installation with Ast 18 and Freepbx 16 but still this issue started happening. However it is noted that only calls coming through queues having the issue. Outgoing calls were being recorded fine.

What finally resolved the issue was downgrading the queue module. At the moment system is running Queues 16.0.14 and so far no issues with recording.

That’s not a resolution, that’s a work around. If you can reliably reproduce this issue using queues module version 16.0.25 please open a bug report with steps to repro and a full beginning to end call trace at https://issues.freepbx.org/