[mythtv-users] Backend Deleting Files for no Reason
Greg Oliver
oliver.greg at gmail.com
Sun Nov 10 12:45:00 UTC 2019
Thanks for the response.
On Fri, Nov 8, 2019 at 9:15 PM Stephen Worthington <stephen_agent at jsw.gen.nz>
wrote:
> 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.
I have several TB of free space on this system. I was originally using a
system with all of my storage for work and the rest of the house shared
over NFS, but I rebuilt everything several months back and dedicated (2)
large disks in raid-1 for MythTV.
> 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.
>
I know the exact setting you speak of and although they have been removed
from the setup GUI, they are still there and function. Keep in mind, the
file in question shows deleted by MythTV, but the metadata is still all in
the DB for it. Also, no auto expire for the show:
root at mythtv:/var/log# grep -i expire mythtv/*|grep Chicago|grep 2019-11
root at mythtv:/var/log#
> 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.
>
I run that and the backup script every morning from cron.
>
> 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.
>
Yeah - I have checked all linux things I know to check and the system has
had no hiccups and MythTV did not expire it - just the message to delete it
was in the log. Like I said, I have plenty of storage and free space and
also notice the hour and minute it deleted it was no where near the next
Expiration run time interval of 15 minutes. Just a random entry in the
log. I enabled some debugs on the backend, but it has been months since I
have seen this - hopefully I will see it again.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20191110/39da6e40/attachment.htm>
More information about the mythtv-users
mailing list