[mythtv-users] INSERT INTO recordedmarkup fails w/duplicate; recording status changes

[Stephen Worthington]

On Sun, 9 Apr 2023 15:14:40 -0700, you wrote:

>Jan and Stephen, thank you for your advice.  I ran mysqlcheck and then
>(redundantly?) optimize_mythdb.  The former reported OK for every
>table; I'm not sure if that means it was OK before or after the run.
>
>I restarted the backend (--version info below) and, at least for now,
>all recordings show as having positive size.  Which is odd, since when
>I query the database directly there are just as many with
>recorded.filesize=0 as before.
>
>As root I ran mythcommflag --rebuild on one of the files.  It produced
>a bunch of errors like
>2023-04-09 14:37:01.979810 E  DB Error (delta position map insert):
>Query was:
>INSERT INTO recordedseek (chanid, starttime, type, mark, `offset`)
>VALUES
>(10501,'2023-04-08T04:59:00Z',9,0,376),(10501,'2023-04-08T04:59:00Z',9,87,5975016),(10501,'2023-04-08T04:59:00Z',9,96,6595040),(10501,'2023-04-08T04:59:00Z',9,177,12453872),(10501,'2023-04-08T04:59:00Z',9,242,17192224),(10501,'2023-04-08T04:59:00Z',9,251,17963400),(10501,'2023-04-08T04:59:00Z',9,259,18314020),(10501,'2023-04-08T04:59:00Z',9,294,20370176),(10501,'2023-04-08T04:59:00Z',9,366,24934628),(10501,'2023-04-08T04:59:00Z',9,438,29536492),(10501,'2023-04-08T04:59:00Z',9,510,34433328),(10501,'2023-04-08T04:59:00Z',9,560,37335296),(10501,'2023-04-08T04:59:00Z',9,611,40210944),(10501,'2023-04-08T04:59:00Z',9,647,42266536),(10501,'2023-04-08T04:59:00Z',9,648,42378208),(10501,'2023-04-08T04:59:00Z',9,651,42579368),(10501,'2023-04-08T04:59:00Z',9,685,44738172),(10501,'2023-04-08T04:59:00Z',9,711,46408176),(10501,'2023-04-08T04:59:00Z',9,765,49665276),(10501,'2023-04-08T04:59:00Z',9,792,51293356),(10501,'2023-04-08T04:59:00Z',9,812,52881392),(10501,'2023-04-08T04:59:00Z',9,833,5386670
>0),(10501,'2023-04-08T04:59:00Z',9,858,55807236),(10501,'2023-04-08T04:59:00Z',9,874,56442676),(10501,'2023-04-08T04:59:00Z',9,899,57998000),(10501,'2023-04-08T04:59:00Z',9,924,59380928),(10501,'2023-04-08T04:59:00Z',9,946,60735656),(10501,'2023-04-08T04:59:00Z',9,970,62145844),(10501,'2023-04-08T04:59:00Z',9,990,63564492),(10501,'2023-04-08T04:59:00Z',9,1062,67640144),(10501,'2023-04-08T04:59:00Z',9,1093,69616212),(10501,'2023-04-08T04:59:00Z',9,1102,70251652),(10501,'2023-04-08T04:59:00Z',9,1111,70428936),(10501,'2023-04-08T04:59:00Z',9,1144,72631732),(10501,'2023-04-08T04:59:00Z',9,1151,72733440),(10501,'2023-04-08T04:59:00Z',9,1172,73935512),(10501,'2023-04-08T04:59:00Z',9,1235,77416708),(10501,'2023-04-08T04:59:00Z',9,1267,79437144),(10501,'2023-04-08T04:59:00Z',9,1288,80898092),(10501,'202
>
>Interspersed, slightly less frequent, were
>Driver error was [2/1062]:
>QMYSQL: Unable to execute query
>Database error wa
>2023-04-09 14:37:03.987264 E  DB Error (delta position map insert):
>
>after many more like the above:
>
>Rebuild completed at Sun Apr 9 14:38:16 2023
>2023-04-09 14:38:16.318015 E  decoding error End of file (-541478725)
>2023-04-09 14:38:16.319383 E  DB Error (Duration insert):
>Query was:
>INSERT INTO recordedmarkup    (chanid, starttime, mark, type, data)
>VALUES ( 10501, '2023-04-08T04:59:00Z', 0, 33, 3772191);
>Bindings were:
>:CHANID=10501, :DATA=3772191, :STARTTIME=2023-04-08T04:59:00.000Z, :TYPE=33
>Driver error was [2/1062]:
>QMYSQL: Unable to execute query
>Database error was:
>Duplicate entry '10501-2023-04-08 04:59:00-33-0' for key 'PRIMARY'
>
>2023-04-09 14:38:16.320471 E  DB Error (Total Frames insert):
>
>There are a lot of things that seem odd:
>1. I thought the database did a check on restart--that seems to be in my logs.

No, a full database check takes too long to be done when MySQL/MariaDB
starts.  I believe that there is a very basic check done that the
database files are available, but nothing beyond that.  The
/etc/cron.daily/optimize_mythdb script is run daily by anacron (if
present), and that normally keeps the database clean.  Anacron will
also run it shortly after boot time if the PC is rebooted and it has
not been run in the last day.  If you do not have daily runs of
optimize_mythdb happening, then any database errors will just
accumulate.  These are errors that mysqlcheck from optimize_mythdb
will be able to fix, but without daily fixing, but eventually one
error lands on top of another and that then causes the problem to
become unfixable.

>2. Databases are supposed to be corruption resistant, though
>mysql/maria may be less so (I know that used to be true).

They are somewhat corruption resistant, but it varies.  No database I
know of is resistant to what happens when it is not shut down and is
killed in the middle of doing something.  Hence the need to run a full
check after each such event, to prevent the accumulation problem.

>2b. And I didn't even have an uncontrolled shutdown.

Your report says you probably did.  Even though you were able to ssh
in and do a shutdown command, my guess is that the shutdown will have
taken a long time as something was locked up and failed to shut down.
That something may have had the database locked, so when systemd's
shutdown routines timed out that process and forcibly killed it, the
database was left corrupted.

>3. Why are the problems affecting brand new recordings?

Clearly the database is not working - the recordedseek table is still
corrupt.

>recordedseek.MYD is 724Mb on disk; the .MYI file is 651Mb.  The
>partition has plenty of free space and is ext4 formatted.
>
>Obviously, when I figure out how to recover I hope to do it just for
>recordings affected by the problem.

At this point, I would advise finding your backups of your database
and copying all the files to somewhere else so they do not get
overwritten by new backups of the corrupted database.  Backups get
rotated as each new one is done, so only 5 copies are kept.  If your
database corruption has been there for a long time, potentially all of
the backups may be corrupt also.  If the original problem is more
recent, the older backups should still be fine, but you do not want to
find out that only the oldest one that got deleted yesterday was the
last OK one.

The next thing to try is to manually do a full check of the
recordedseek table.  Shut down mythbackend and do these commands:

sudo mysqlcheck --repair mythconverg recordedseek
sudo mysqlcheck --optimize mythconverg recordedseek
sudo mysqlcheck --analyze mythconverg recordedseek

If there are any errors at all, keep repeating those commands until
there are no more errors, or it does not fix anything.  In the latter
case, the table is unfixable and will need to be deleted and
re-created, which it is possible to do, but takes a lot of work.  Or
you can get back an older, possibly non-corrupt version from you
backups, which again is possible but is a bit difficult - you need a
good editor that can edit huge .sql text files in order to just edit
out the recordedseek table in the backup file.  Most editors can not
handle files of that size.

If manually checking recordedseek does not show any errors, then you
need to try manually inserting data, like mythbackend is trying to do.
Copy one of the commands it is logging as failing and try running it
manually.  Do only a single insert, not a multiple one as is in the
log messages.  For example, from your post, you could try:

INSERT INTO recordedseek (chanid, starttime, type, mark, `offset`)
VALUES (10501,'2023-04-08T04:59:00Z',9,0,376);

Keep track of any INSERT commands you do so you can do a corresponding
DELETE FROM command if it succeeds.  So for the above, if it works,
you would want to do:

DELETE FROM recordedseek WHERE chanid=10501 and
starttime='2023-04-08T04:59:00Z' and type=9 and mark=0 and offset=376;

If that succeeds, try a full multiple insert that has failed and been
logged.

If that succeeds, then the recordedseek table is likely working
properly again and you can try starting mythbackend and running
mythcommflag --rebuild.

If you can not get recordedseek to work, then the next thing to try is
deleting just that table and restoring it from a backup.  You do that
by first finding a non-corrupt backup file.  Backups made from a
corrupt table will often stop part way through the backup, and this
normally results in the compressed backup file being significantly
smaller than previous compressed backup files.  So look at your backup
files and see if that has happened, and choose the bigger file before
the smaller ones started to occur.  Also look back in your mythbackend
log files and see if you can see when the error messages first
started.  You may not be able to if it was too long ago, as the
mythbackend logs where it happened may have been rotated and deleted.
In which case you may want to try restoring from the oldest backup you
have.

Uncompress the chosen backup file, then edit the resulting .sql file
and cut out only the recordedseek table, including all the commands
that drop and restore it, just above the data.  Save this to a file,
perhaps called recordedseek.sql.

Shut down mythbackend and attempt to make another database backup
using mythconverg_backup.pl, making sure to have first saved all the
old backups.

Then run this command from the directory where the recordedseek.sql
file is:

sudo mysql mythconverg

and from the MySQL/MariaDB prompt, run this command:

source recordedseek.sql

It is possible that you might get an error message about the "source"
command if your database has the wrong options set, in which case you
will need to either change that option, or try using the "mysql
mythconverg" command with an option to pipe it the recordedseek.sql
file.  I can not remember the exact syntax for doing that at the
moment.

Once you have restored recordedseek, you will need to work out what
recordings you have that now do not have recordedseek entries and will
need mythcommflag --rebuild done for them.  Doing SQL to compare the
chanid/starttime values in the recorded table and the recordedseek
table and listing those not in both should do that for you.  Then you
will need to run mythcommflag for all those recordings.  There is also
a new command I have never tried:

mythutil --checkrecordings

which may be able to tell you which recordings do not have seek
tables, and:

mythutil --checkrecordings --fixseetable

may then run mythcommflag --rebuild on them all automatically.

If your recordedseek table is unable to be recovered by restoring a
backup, you can still recover it as mythcommflag is able to recreate
all the data.  So you would take your recordedseek.sql file and delete
all the commands that restore the data, then run that as above to
delete and re-create an empty recordedseek table.  Then you can run:

mythutil --checkrecordings --fixseektable

and all the basic data (not the commercial flagging data) should be
re-created.  If you have many recordings, it will of course take a
very long time.