[mythtv] sql errors with tv_grab_zz_sdjson_sqlite

[Paul B. Henson]

On Sun, Dec 16, 2018 at 04:19:27PM -0600, Bill Meek wrote:

> You can run mythfilldatabase -v database and see if the DELETEs are running
> and what timestamps are used.

Hmm, I ran mythdatabase with -v; it's interesting, the output from the
command itself says it finished at

2018-12-19 12:00:25.847157 N  mythfilldatabase run complete.
2018-12-19 12:00:25.847298 I  Waiting for threads to exit.

but the first insert errors don't show up in the logs until over two
minutes later?

Dec 19 12:02:44 mythtv-dev mythfilldatabase[12053]: E CoreContext
mythdb.cpp:183 (DBError) DB Error (programgenres insert):
Dec 19 12:02:44 mythtv-dev Query was:
Dec 19 12:02:44 mythtv-dev INSERT INTO programgenres        ( chanid,
starttime, genre,  relevance) VALUES (?, ?,    ?, ?)
Dec 19 12:02:44 mythtv-dev Bindings were:
Dec 19 12:02:44 mythtv-dev :CHANID=1344, :START=2019-01-07T18:00:00Z,
:genre="series", :relevance=0
Dec 19 12:02:44 mythtv-dev Driver error was [2/1062]:
Dec 19 12:02:44 mythtv-dev QMYSQL3: Unable to execute statement
Dec 19 12:02:44 mythtv-dev Database error was:
Dec 19 12:02:44 mythtv-dev Duplicate entry '1344-2019-01-07 18:00:00-0'
for key 'PRIMARY'

So, looking at this failure, there are no DELETE's in the output for
channel 1344. There are other ones for other channels, such as:

2018-12-19 12:00:14.768207 I  MSqlQuery::exec(DBManager2) DELETE FROM
programgenres WHERE starttime >= '2018-12-19T00:00:00Z' AND starttime <
'2018-12-20T00:00:00Z' AND chanid = '1189' ; <<<< Took 3ms

but none where chanid = 1344.

Looking at another one:

Dec 19 12:06:24 mythtv-dev QMYSQL3: Unable to execute statement
Dec 19 12:06:24 mythtv-dev Database error was:
Dec 19 12:06:24 mythtv-dev Duplicate entry '1064-2018-12-22 17:00:00-4'
for key 'PRIMARY'
Dec 19 12:06:27 mythtv-dev Query was:
Dec 19 12:06:27 mythtv-dev INSERT INTO programgenres        ( chanid,
starttime, genre,  relevance) VALUES (?
, ?,    ?, ?)
Dec 19 12:06:27 mythtv-dev Bindings were:
Dec 19 12:06:27 mythtv-dev :CHANID=1565, :START=2019-01-08T03:00:00Z,
:genre="series", :relevance=0

There was a single DELETE for channel 1565, but it was only for
12/19-12/20:

2018-12-19 12:00:13.408272 I  MSqlQuery::exec(DBManager2) DELETE FROM
programgenres WHERE starttime >= '2018-12-19T00:00:00Z' AND starttime <
'2018-12-20T00:00:00Z' AND chanid = '1565' ; <<<< Took 0ms

and this duplicate was for 1/8...

Any more suggestions for tracking this down? Again, it only seems to be
happening on the manual run of mythfilldatabase from cron, not the
automatic one initiated by mythbackend.