A few recoding files missing randomly


Running FreePBX 14.1 and asterisk16-16.11.1-1.sng7.x86_64 on Sangoma Linux release 7.5.1805.

All our extensions and queues have “Force” in the call recording options, and in general this works most of the time. We have recordings stored on the filesystem and we use a script that converts wav files to mp3.

But there are a few times where the actual recording file is missing from the filesystem.
We have added logging in this conversion script, and the very first thing it logs before conversion is if the input .wav filename exists on the filesystem.

Between many many successful conversions, there are a few missing the input file.

After logging for many days and trying to find what’s wrong, the only common thing we can find is that the missing files are always in the last 10 minutes of the hour, e.g. somewhere in between 09:50:00 - 10:00:00, 11:50:00 - 12:00:00, 12:50:00 - 13:00:00, 13:50:00 - 14:00:00, 14:50:00 - 15:00:00 … (time is part of the filename)

/var/spool/asterisk/monitor/2020/09/09/out-69xxx87767-7418-20200909-095907-1599634747.21595.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/q-7099-23xxx45051-20200909-095955-1599634795.21599.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/q-7000-23xxx04192-20200909-095735-1599634655.21578.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/q-7000-21xxx77934-20200909-115503-1599641703.22634.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/q-7000-21xxx11737-20200909-115508-1599641708.22635.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/internal-7426-21xxx57451-20200909-125956-1599645596.23160.wav does not exist
/var/spool/asterisk/monitor/2020/09/09/out-69xxx83898-7466-20200909-135954-1599649194.23741.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/internal-7409-69xxx29368-20200910-095903-1599721200.26073.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/out-69xxx71720-7425-20200910-100000-1599721200.26070.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/internal-7416-69xxx30403-20200910-105656-1599724796.26557.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7099-69xxx10556-20200910-105850-1599724730.26537.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/internal-7426-69xxx62525-20200910-115952-1599728392.27173.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7000-69xxx07839-20200910-115745-1599728265.27159.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7099-25xxx00273-20200910-115938-1599728378.27170.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7000-69xxx29381-20200910-125942-1599731982.27650.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7099-21xxx62400-20200910-125911-1599731951.27646.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7066-69xxx86988-20200910-125950-1599731990.27651.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/internal-7409-21xxx28719-20200910-145959-1599739199.28472.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7099-21xxx99515-20200910-145957-1599739197.28466.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/q-7099-69xxx28160-20200910-155933-1599742773.28870.wav does not exist
/var/spool/asterisk/monitor/2020/09/10/out-69xxx52002-7466-20200910-175946-1599749986.29359.wav does not exist

Here is a trace log from one call where the recording is missing.

Any help to further troubleshoot this would be really appreciated!

To answer my own question …

We had a cronjob like this
0 * * * * /usr/bin/find /var/spool/asterisk/monitor/ -type f -size 44c -delete

This was put there with the intention to delete all empty recordings (length 00:00) after they have ended.

But the law of unintended consequences strikes again…

Apparently, some calls that are still in progress when the cronjob runs, match the size of 44 bytes and the file gets deleted.

We have commented out the cronjob for the past two days, and have no missing recordings since.

That’s a lot of processing power to run every minute.

I’d switch that up so that it ran at a specific time every day, preferably while you’re system is quiet. Once or twice every 24 hours should be plenty.

Possible solution

yum/apt install inotify-tools
inotifywait -m  -r /var/spool/asterisk/monitor/ -e "CLOSE_WRITE" --format '%w%f'

Only the final close on any file will be notified and you can THEN test the size of the file and delete conditionally, The other advantage is that it works in real time.

realworld solution

inotifywait -qmr /var/spool/asterisk/monitor/ -e "CLOSE_WRITE" --format '%w%f'|while read LINE;do [[ $( wc -c $LINE|awk '{print $1}') -le 44 ]]&&rm $LINE;done  &

It would also be less cpu intensive.

I haven’t used a watch on the monitor files. I assume asterisk is well behaved with them - its a clean open/write/close and done sequence?

Alternative could be adding -mmin +60 or similar to find and only pickup files older than an hour.

Or just modify the conversion script to do it and eliminate a process.

the monitor files are. not so much the voicemail files, where the files themselves are never ‘closed’ , but tmp files are ‘renamed’

Thank you all very much for your suggestions!

I’ve added -mtime +1 in the find command that runs every hour, but I’ll probably move it inside the conversion script at some point in the future.

-mtime +1 means operate on files older than 24 hours, (you can use a decimal value)

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.