Mailing List Archive: sql errors with tv_grab_zz_sdjson

sql errors with tv_grab_zz_sdjson_sqlite

Dec 15, 2018, 5:50 PM

Post #1 of 8 (1120 views)

I recently switched from the built-in data direct grabber to the xmltv
tv_grab_zz_sdjson_sqlite; it seems to be working ok except for sometimes
I get thousands of errors inserting into programgenres:

2018-12-15 12:02:38.455584 E DB Error (programgenres insert):
Query was:
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
(?, ?, ?, ?)
Bindings were:
:CHANID=1567, :START=2019-01-03T22:45:00Z, :genre="Series", :relevance=1
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '1567-2019-01-03 22:45:00-1' for key 'PRIMARY'

2018-12-15 12:02:38.456157 E DB Error (programgenres insert):
Query was:
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
(?, ?, ?, ?)
Bindings were:
:CHANID=1567, :START=2019-01-03T22:45:00Z, :genre="Show", :relevance=2
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '1567-2019-01-03 22:45:00-2' for key 'PRIMARY'
[...]
2018-12-15 12:06:22.645592 E DB Error (programgenres insert):
Query was:
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
(?, ?, ?, ?)
Bindings were:
:CHANID=1275, :START=2019-01-05T02:30:00Z, :genre="Series", :relevance=1
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '1275-2019-01-05 02:30:00-1' for key 'PRIMARY'

2018-12-15 12:06:22.646005 E DB Error (programgenres insert):
Query was:
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
(?, ?, ?, ?)
Bindings were:
:CHANID=1275, :START=2019-01-05T02:30:00Z, :genre="Show", :relevance=2
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '1275-2019-01-05 02:30:00-2' for key 'PRIMARY'

I *think* these are only coming from my separate cron job that runs
outside of mythtv every day at noon to refresh that night's data:

mythfilldatabase --loglevel err --refresh today --refresh nottomorrow

Since it's sporadic, I can't say for sure it won't occur when the normal
scheduled run occurs at some point.

Any thoughts on this? It doesn't appear to be impacting recording, although
I don't have any rules based on genre. Should I stop refreshing today
separately? I've had that there for ages, as I used to have bad recordings
when guide data changed a day or two before the schedule would fire.

Thanks much...
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

stephen_agent at jsw

Dec 16, 2018, 12:31 AM

Post #2 of 8 (1117 views)

Permalink

On Sat, 15 Dec 2018 17:50:41 -0800, you wrote:

>I recently switched from the built-in data direct grabber to the xmltv
>tv_grab_zz_sdjson_sqlite; it seems to be working ok except for sometimes
>I get thousands of errors inserting into programgenres:
>
>2018-12-15 12:02:38.455584 E DB Error (programgenres insert):
>Query was:
>INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
>(?, ?, ?, ?)
>Bindings were:
>:CHANID=1567, :START=2019-01-03T22:45:00Z, :genre="Series", :relevance=1
>Driver error was [2/1062]:
>QMYSQL3: Unable to execute statement
>Database error was:
>Duplicate entry '1567-2019-01-03 22:45:00-1' for key 'PRIMARY'
>
>2018-12-15 12:02:38.456157 E DB Error (programgenres insert):
>Query was:
>INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
>(?, ?, ?, ?)
>Bindings were:
>:CHANID=1567, :START=2019-01-03T22:45:00Z, :genre="Show", :relevance=2
>Driver error was [2/1062]:
>QMYSQL3: Unable to execute statement
>Database error was:
>Duplicate entry '1567-2019-01-03 22:45:00-2' for key 'PRIMARY'
>[...]
>2018-12-15 12:06:22.645592 E DB Error (programgenres insert):
>Query was:
>INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
>(?, ?, ?, ?)
>Bindings were:
>:CHANID=1275, :START=2019-01-05T02:30:00Z, :genre="Series", :relevance=1
>Driver error was [2/1062]:
>QMYSQL3: Unable to execute statement
>Database error was:
>Duplicate entry '1275-2019-01-05 02:30:00-1' for key 'PRIMARY'
>
>2018-12-15 12:06:22.646005 E DB Error (programgenres insert):
>Query was:
>INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES
>(?, ?, ?, ?)
>Bindings were:
>:CHANID=1275, :START=2019-01-05T02:30:00Z, :genre="Show", :relevance=2
>Driver error was [2/1062]:
>QMYSQL3: Unable to execute statement
>Database error was:
>Duplicate entry '1275-2019-01-05 02:30:00-2' for key 'PRIMARY'
>
>I *think* these are only coming from my separate cron job that runs
>outside of mythtv every day at noon to refresh that night's data:
>
>mythfilldatabase --loglevel err --refresh today --refresh nottomorrow
>
>Since it's sporadic, I can't say for sure it won't occur when the normal
>scheduled run occurs at some point.
>
>Any thoughts on this? It doesn't appear to be impacting recording, although
>I don't have any rules based on genre. Should I stop refreshing today
>separately? I've had that there for ages, as I used to have bad recordings
>when guide data changed a day or two before the schedule would fire.
>
>Thanks much...

Those error messages are primary key errors. It is attempting to
insert a new row into the programgenres table using a primary key that
is already present in the table. Primary keys are normally unique
indexes into a table, so they can not have duplicates. So the "insert
row" operation is rejected with a "Duplicate entry" error.

What it looks like is the XML data has multiple genres specified for
some programs. The first genre gets inserted into the programgenres
table, and then any subsequent ones produce the error. If there is an
option to do so, you could get tv_grab_zz_sdjson_sqlite to download
and store the XML file and then have a look and see if you do have any
programs at the time in those messages that have multiple genres. If
so, then the devs will have to decide what they should be doing about
it, so you may need to file a bug report with examples for them.
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

henson at acm

Dec 16, 2018, 12:14 PM

Post #3 of 8 (1115 views)

Permalink

On Sun, Dec 16, 2018 at 09:31:21PM +1300, Stephen Worthington wrote:

> What it looks like is the XML data has multiple genres specified for
> some programs.

Hmm, yes, looking at the file there are multiple genres (which appear to
be called categories in the xml):

<programme channel="I96011.json.schedulesdirect.org" start="20181216010000 +0000" stop="20181216020000 +0000"
>
<title>Barefoot Dreams - California Style</title>
<desc lang="en">Super-soft wraps, cardigans, blankets and more.</desc>
<credits></credits>
<category>series</category>
<category>Fashion</category>
<category>Shopping</category>
<category>Series</category>
<category>Show</category>

However, it looks like the table schema allows multiple genres per
program, the primary key is the tuple (`chanid`,`starttime`,`relevance`),
and while there is an index on genre it is multivalued.

Looking at the data, there are multiple entries in the table for most
shows, but it seems they have to have a different relevance column. I
think it's breaking because it's trying to insert two rows for the same
show with the same relevance. I don't see any reference to relevance
in the xml, where does the mapping from xml category to genre relevance
come from?

One odd thing is that the xml includes both "series" and "Series" in
the categories.

Thanks for the help...

_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

rkulagow at gmail

Dec 16, 2018, 12:31 PM

Post #4 of 8 (1114 views)

Permalink

On Sun, Dec 16, 2018 at 2:15 PM Paul B. Henson <henson@acm.org> wrote:
>
> On Sun, Dec 16, 2018 at 09:31:21PM +1300, Stephen Worthington wrote:
>
> > What it looks like is the XML data has multiple genres specified for
> > some programs.
>
> Hmm, yes, looking at the file there are multiple genres (which appear to
> be called categories in the xml):
>
> <programme channel="I96011.json.schedulesdirect.org" start="20181216010000 +0000" stop="20181216020000 +0000"
> >
> <title>Barefoot Dreams - California Style</title>
> <desc lang="en">Super-soft wraps, cardigans, blankets and more.</desc>
> <credits></credits>
> <category>series</category>
> <category>Fashion</category>
> <category>Shopping</category>
> <category>Series</category>
> <category>Show</category>

[I run the JSON service at Schedules Direct]

If you send me the programID then I can check if the program data on
our end is wrong.
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

keemllib at gmail

Dec 16, 2018, 2:19 PM

Post #5 of 8 (1114 views)

Permalink

On 12/16/18 2:31 PM, Robert Kulagowski wrote:
> On Sun, Dec 16, 2018 at 2:15 PM Paul B. Henson <henson@acm.org> wrote:
>>
>> On Sun, Dec 16, 2018 at 09:31:21PM +1300, Stephen Worthington wrote:
>>
>>> What it looks like is the XML data has multiple genres specified for
>>> some programs.
>>
>> Hmm, yes, looking at the file there are multiple genres (which appear to
>> be called categories in the xml):
>>
>> <programme channel="I96011.json.schedulesdirect.org" start="20181216010000 +0000" stop="20181216020000 +0000"
>>>
>> <title>Barefoot Dreams - California Style</title>
>> <desc lang="en">Super-soft wraps, cardigans, blankets and more.</desc>
>> <credits></credits>
>> <category>series</category>
>> <category>Fashion</category>
>> <category>Shopping</category>
>> <category>Series</category>
>> <category>Show</category>
>
> [I run the JSON service at Schedules Direct]
>
> If you send me the programID then I can check if the program data on
> our end is wrong.

I don't have the issue and there are thousands of Series/series cases:

mysql> SELECT COUNT(genre) FROM programgenres WHERE BINARY 'series' = genre;
+--------------+
| COUNT(genre) |
+--------------+
| 42624 |
+--------------+
mysql> SELECT COUNT(genre) FROM programgenres WHERE BINARY 'Series' = genre;
+--------------+
| COUNT(genre) |
+--------------+
| 42206 |
+--------------+

I obviously didn't see if all have a Series and series for the same chanid/startrtime
case, but running mythfilldatabase -v database shows this one example. Note that the
programgenres entry is cleared first:

DELETE FROM programgenres WHERE starttime >= '2018-12-16T13:00:00Z' AND starttime < '2018-12-16T14:30:00Z' AND chanid = '1321' ;
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES ('1321', '2018-12-16T13:00:00Z', 'series', '0')
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES ('1321', '2018-12-16T13:00:00Z', 'News', '1')
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES ('1321', '2018-12-16T13:00:00Z', 'Series', '2')
INSERT INTO programgenres ( chanid, starttime, genre, relevance) VALUES ('1321', '2018-12-16T13:00:00Z', 'Show', '3')

So it appears that the DELETE is failing in this case.

There aren't any log messages here, but it does fire when I added one:

https://code.mythtv.org/cgit/mythtv/tree/mythtv/libs/libmythtv/programdata.cpp#n1277

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

--
Bill
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

henson at acm

Dec 17, 2018, 12:00 PM

Post #6 of 8 (1111 views)

Permalink

On 12/16/2018 12:31 PM, Robert Kulagowski wrote:
>
> [I run the JSON service at Schedules Direct]

Thank you guys for SD, it's been great :).

> If you send me the programID then I can check if the program data on
> our end is wrong.

It doesn't seem to do it on a regular basis, just sporadically; the next
time it blows up I will send in some more information, thanks…
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

henson at acm

Dec 17, 2018, 12:02 PM

Post #7 of 8 (1111 views)

Permalink

On 12/16/2018 2:19 PM, Bill Meek wrote:
>
> I don't have the issue and there are thousands of Series/series cases:

Even if that is not causing my specific problem, that does seem a bit
redundant?

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

Cool, I added that flag and will wait for it to generate errors again
and see what it says.

Thanks much…
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org

Re: sql errors with tv_grab_zz_sdjson_sqlite [ In reply to ]

henson at acm

Dec 19, 2018, 5:17 PM

Post #8 of 8 (1102 views)

Permalink

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.
_______________________________________________
mythtv-dev mailing list
mythtv-dev@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-dev
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org