[mythtv-users] Backend Deleting Files for no Reason
Stephen Worthington
stephen_agent at jsw.gen.nz
Sat Nov 9 03:14:34 UTC 2019
On Fri, 8 Nov 2019 15:30:55 -0600, you wrote:
>This has been happening to me sine I upgraded to v30, but it has always
>been shows I do not really care about, but it happened to me just a second
>ago while I was watching, so it bothered me.
>
>A recording that was there 5 minutes before just got deleted (but not from
>the recording list - just the file)..
>
>Nov 8 15:13:43 mythtv mythbackend: mythbackend[1020]: N DeleteThread
>mainserver.cpp:2502 (DeleteRecordedFiles) DeleteRecordedFiles - recording
>id 9940 filename /ramdisk/mythtv/recordings/10501_20191107020000.ts
>Nov 8 15:13:43 mythtv mythbackend: mythbackend[1020]: N DeleteThread
>mainserver.cpp:2579 (DoDeleteInDB) DoDeleteINDB - recording id 9940 (chanid
>10501 at 2019-11-08T05:37:00Z)
>
>I know it also says doDeleteInDB, but it did not and the show had not been
>watched yet and just turned blue in the theme, so I know it happened.
>
>mythbackend.log:Nov 6 20:00:01 mythtv mythbackend: mythbackend[1020]: I
>TVRecEvent tv_rec.cpp:4231 (TuningNewRecorder) TVRec[5]:
>rec->GetPathname(): '/ramdisk/mythtv/recordings/10501_20191107020000.ts'
>mythbackend.log:Nov 6 20:56:35 mythtv mythbackend: mythbackend[1020]: W
>TFWWrite threadedfilewriter.cpp:568 (DiskLoop)
>TFW(/ramdisk/mythtv/recordings/10501_20191107020000.ts:94): write(65424)
>cnt 41 total 2468440 -- took a long time, 1484 ms
>mythbackend.log:Nov 6 20:59:33 mythtv mythbackend: mythbackend[1020]: W
>TFWWrite threadedfilewriter.cpp:568 (DiskLoop)
>TFW(/ramdisk/mythtv/recordings/10501_20191107020000.ts:94): write(65424)
>cnt 49 total 3051804 -- took a long time, 1755 ms
>mythbackend.log:Nov 8 15:13:43 mythtv mythbackend: mythbackend[1020]: N
>DeleteThread mainserver.cpp:2502 (DeleteRecordedFiles) DeleteRecordedFiles
>- recording id 9940 filename
>/ramdisk/mythtv/recordings/10501_20191107020000.ts
>mythbackend.log:Nov 8 15:15:52 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>mythbackend.log:Nov 8 15:15:52 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>mythbackend.log:Nov 8 15:16:02 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>mythbackend.log:Nov 8 15:16:03 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>mythbackend.log:Nov 8 15:17:33 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>mythbackend.log:Nov 8 15:21:15 mythtv mythbackend: mythbackend[1020]: E
>ProcessRequest programinfo.cpp:2781 (GetPlaybackURL)
>ProgramInfo(10501_20191107020000.ts): GetPlaybackURL:
>'10501_20191107020000.ts' should be local, but it can not be found.
>I see there were a couple hiccups writing according tot he block message,
>but the recording was not yellow (damaged) in the recordings screen. Like
>I said - this has happened on more than one occasion, but I am just
>checking into it.
>
>Anyone know why it would select this recording and just delete it and not
>remove the metadata too? I mean both are wrong, but
When a new recording starts, all the partitions that are found in your
storage groups are checked to see if there is sufficient space for a
new recording. If there is insufficient space, old recordings will be
expired immediately until there is sufficient space. Even if the new
recording will not be going to that partition, if there is
insufficient space on that partition, the expiring will be done. I
have never found the exact definition of "sufficient space", but it
seems to be about 20 Gibytes. As long as I maintain at least 20
Gibytes of free space on a partition, I do not get expiring happening.
There are some settings that control this, but I have not looked at
them for years as what happens works for me.
If you are using a partition in a storage group for other things than
MythTV recordings, and have used up too much space that way, MythTV
will expire recordings to get back enough free space the next time it
checks that partition.
Deleting and expiry in MythTV is a bit complicated. When you delete a
recording, it is marked as deleted and put on a list of deleted
recordings, but the file is not actually deleted. You can get
mythfrontend to list the deleted but not yet expired recordings and
undelete things if you want to. There are settings for how long
deleted recordings hang around. With the default settings, typically
in 15-20 minutes, the file will actually be deleted and removed from
the database. This is the same expiry procedure that happens when
there is too little space on a partition. You can have things set up
so that recordings remain in the deleted list "forever", which means
that your recording partitions will eventually become full and every
time a recording starts, another will be expired. But because you
have a lot of recordings on the deleted list, they will be expired to
make room (normally in oldest first order), and you will not notice
that your partitions are actually full unless you check using the
operating system's free space commands.
When a recording is expired (its actual recording file is deleted),
its database entries in the "recorded" table and all associated tables
are deleted. It remains listed in the "oldrecorded" table and any
tables associated with that.
Expired recordings should always be removed from the database when the
expiry procedure happens. If that is not happening, then the most
likely problem is that your database is corrupt. First check that the
partition your database is on has enough free space on it. It must at
all times have enough free space to make a copy of your largest
database table, which is always "recordedseek". To find the size of
your recordedseek table, this command works in Ubuntu:
root at mypvr:~# du -h -c /var/lib/mysql/mythconverg/recordedseek*
4.0K /var/lib/mysql/mythconverg/recordedseek.frm
6.9G /var/lib/mysql/mythconverg/recordedseek.MYD
6.2G /var/lib/mysql/mythconverg/recordedseek.MYI
14G total
And this command should tell you how much free space you have on that
partition:
root at mypvr:~# df -h /var/lib/mysql/mythconverg/
Filesystem Size Used Avail Use% Mounted on
/dev/nvme0n1p4 100G 55G 41G 58% /
If you have sufficient free space, you need to run the check and
repair script. This should be being run automatically every week (or
preferably every day) by anacron. I run it every day, so I have it
set up here:
/etc/cron.daily/optimize_mythdb
I get an email daily with the results of that, but in order for that
to happen, you have to have set up email services on your backend box,
and you also need to remember to check your emails in the root account
on the backend box. If you are not running optimize_mythdb regularly,
then your database will almost certainly have become corrupt at some
point. If you do not have email set up, you will likely not have seen
any messages to tell you that optimize_mythtb has failed to fix things
(if that happens). So it is best to run it manually and check the
output. If you are not running it from anacron, it will normally be
found here:
/usr/share/doc/mythtv-backend/contrib/maintenance/optimize_mythdb.pl
but the location depends on what distro you are using.
As running out of free space on the system partition can be
catastrophic, I have written myself a systemd unit that runs hourly to
check the free space there:
root at mypvr:~# systemctl cat check-free-space.service
# /etc/systemd/system/check-free-space.service
[Unit]
Description=Check free space on /
After=time-sync.target
OnFailure=notify-failure@%n.service
[Service]
ExecStart=/bin/bash -c "/usr/local/bin/check-free-space.sh"
[Install]
WantedBy=multi-user.target
root at mypvr:~# systemctl cat check-free-space.timer
# /etc/systemd/system/check-free-space.timer
[Unit]
Description=Hourly root free space check.
[Timer]
OnCalendar=hourly
Persistent=true
[Install]
WantedBy=timers.target
root at mypvr:~# cat /usr/local/bin/check-free-space.sh
#!/bin/bash
DEFAULT_MIN=16106127360
if [ -z "$1" ]; then
min_required=$DEFAULT_MIN
else
REGEX="^[[:digit:]]*$"
if ! [[ $1 =~ $REGEX ]] ; then
min_required=$DEFAULT_MIN
elif [[ $1 -eq 0 ]]; then
min_required=$DEFAULT_MIN
else
min_required=$1
fi
fi
root_free_space=$(($(stat -f --format="%a*%S" /)))
echo "Free space on root is $root_free_space"
if [ $root_free_space -lt $min_required ]; then
# Free space too low for /etc/cron.daily/optimize_db to run safely
on
# mythconverg.recordedseek table.
echo "Free space too low (< $min_required)"
exit 1
fi
# Free space is sufficient.
echo "Free space is sufficient (>= $min_required)"
exit 0
root at mypvr:~# cd /var/log
root at mypvr:/var/log# grep -i "free space" syslog
Nov 9 10:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 10:00:04 mypvr bash[14683]: Free space on root is 43011833856
Nov 9 10:00:04 mypvr bash[14683]: Free space is sufficient (>=
16106127360)
Nov 9 11:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 11:00:04 mypvr bash[19859]: Free space on root is 43011629056
Nov 9 11:00:04 mypvr bash[19859]: Free space is sufficient (>=
16106127360)
Nov 9 12:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 12:00:04 mypvr bash[24513]: Free space on root is 43006447616
Nov 9 12:00:04 mypvr bash[24513]: Free space is sufficient (>=
16106127360)
Nov 9 13:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 13:00:04 mypvr bash[29437]: Free space on root is 42999521280
Nov 9 13:00:04 mypvr bash[29437]: Free space is sufficient (>=
16106127360)
Nov 9 14:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 14:00:04 mypvr bash[2521]: Free space on root is 42983346176
Nov 9 14:00:04 mypvr bash[2521]: Free space is sufficient (>=
16106127360)
Nov 9 15:00:04 mypvr systemd[1]: Started Check free space on /.
Nov 9 15:00:04 mypvr bash[8579]: Free space on root is 42966700032
Nov 9 15:00:04 mypvr bash[8579]: Free space is sufficient (>=
16106127360)
root at mypvr:/etc/systemd/system# cat notify-failure at .service
#notify-failure at .service:
[Unit]
Description=OnFailure for %i
[Service]
Type=oneshot
ExecStart=/usr/local/bin/onfailure.sh %i
root at mypvr:/usr/local/bin# cat onfailure.sh
#!/bin/bash
#
# Author: Kyle Manna <kyle at kylemanna.com>
#
# Simple systemd script used to be called via something like:
#
# Example Unit section of a service file:
#
# [Unit]
# ...
# Onfailure=failure-email@%i.service
#
#
# failure-email at .service:
#
# [Unit]
# Description=OnFailure for %i
#
# [Service]
# Type=oneshot
# ExecStart=/path/to/onfailure.sh %i
#
svc=${1-unknown}
email="root *******@****** *****@gmail.com"
cat <<EOF | sendmail -i "$email"
Subject: [$HOSTNAME] OnFailure Email for $svc
# Status
$(systemctl status -l -n 1000 "$svc")
EOF
When the free space is too low, the check-free-space.sh script exits
with a non-zero exit code, and that causes the "OnFailure" line to be
triggered which runs the notify-failure at .service unit that sends me an
urgent email using the "onfailure.sh" script.
I have been meaning to get around to updating check-free-space.sh so
that it automatically checks the recordedseek table size. It looks
like I need to do that, as it has grown to be fairly close to the size
I have in the script.
More information about the mythtv-users
mailing list