[mythtv-users] Question on mythfilldatabase logs and "mythfilldatabase ran, but did not insert any new data into the Guide" message

[Stephen Worthington]

On Wed, 16 Oct 2019 19:04:49 -0400, you wrote:

>I'm using the tv_grab_zz_sdjson XMLTV grabber for one OTA source on
>SD. Every once in a while the status has that message that says
>"mythfilldatabase ran, but did not insert any new data into the Guide
>for 1 of 1 sources. This can indicate a potential grabber failure". My
>guess is that this is just a timing issue where SD just may have not
>yet changed, as it's always clear that the data fetch is working.
>
>What I don't understand is how I can tell from the logs that the above
>occurred. That is that no new data was inserted. When I compare logs
>where this happened with ones where it didn't I can't for the life of
>me make sense out of it. I got the above warning from this morning's
>run and here is the end of the log:
>
>2019-10-16 09:08:08.853862 N [13548/13548] CoreContext main.cpp:436
>(main) - Data fetching complete.
>2019-10-16 09:08:08.853933 I [13548/13548] CoreContext main.cpp:444
>(main) - Adjusting program database end times.
>2019-10-16 09:08:08.863158 I [13548/13548] CoreContext main.cpp:450
>(main) -     0 replacements made
>2019-10-16 09:08:08.863172 I [13548/13548] CoreContext main.cpp:452
>(main) - Marking generic episodes.
>2019-10-16 09:08:09.476512 I [13548/13548] CoreContext main.cpp:464
>(main) -     Found 0
>2019-10-16 09:08:09.476533 I [13548/13548] CoreContext main.cpp:467
>(main) - Extending non-unique programids with multiple parts.
>2019-10-16 09:08:09.611484 I [13548/13548] CoreContext main.cpp:518
>(main) -     Found 0
>2019-10-16 09:08:09.611510 I [13548/13548] CoreContext main.cpp:520
>(main) - Fixing missing original airdates.
>2019-10-16 09:08:10.578951 I [13548/13548] CoreContext main.cpp:535
>(main) -     Found 0 with programids
>2019-10-16 09:08:10.581110 I [13548/13548] CoreContext main.cpp:555
>(main) -     Found 0 without programids
>2019-10-16 09:08:10.581125 I [13548/13548] CoreContext main.cpp:559
>(main) - Marking repeats.
>2019-10-16 09:08:10.706526 I [13548/13548] CoreContext main.cpp:573
>(main) -     Found 0
>2019-10-16 09:08:10.706543 I [13548/13548] CoreContext main.cpp:575
>(main) - Unmarking new episode rebroadcast repeats.
>2019-10-16 09:08:11.467337 I [13548/13548] CoreContext main.cpp:585
>(main) -     Found 3604
>2019-10-16 09:08:12.994175 I [13548/13548] CoreContext main.cpp:594
>(main) - Marking episode first showings.
>2019-10-16 09:08:16.196736 I [13548/13548] CoreContext main.cpp:628
>(main) -     Found 21539
>2019-10-16 09:08:16.196752 I [13548/13548] CoreContext main.cpp:630
>(main) - Marking episode last showings.
>2019-10-16 09:08:19.421925 I [13548/13548] CoreContext main.cpp:664
>(main) -     Found 21860
>2019-10-16 09:08:19.469058 I [13548/13548] CoreContext main.cpp:691 (main) -
>===============================================================
>| Attempting to contact the master backend for rescheduling.  |
>| If the master is not running, rescheduling will happen when |
>| the master backend is restarted.                            |
>===============================================================
>2019-10-16 09:08:19.481632 N [13548/13548] CoreContext main.cpp:701
>(main) - mythfilldatabase run complete.
>2019-10-16 09:08:19.485861 I [13548/13548] CoreContext
>mythcontext.cpp:1610 (~MythContext) - Waiting for threads to exit.
>
>Is there anything in there that tells me whether or not new data was
>added? Thanks in advance.
>
>Tom

I believe that "did not insert any new data" message happens when the
number of new programmes is low, not actually zero, or if the time of
the most future recording des not change.  For my XMLTV grabber here
in New Zealand, I do a grep of the log file to find out what updates
happened:

grep "Updated programs:" /var/log/mythtv/epg_temp.log

My mythfilldatabase output is found in my epg_temp.log file as I run
mythfilldatabase manually from my epg_temp.sh script, not
automatically from mythbackend.  So in your case the grep would be:

grep "Updated programs:" /var/log/mythtv/mythfilldatabase.log

This is from yesterday:

root at mypvr:~# grep "Updated programs:" /var/log/mythtv/epg_temp.log
2019-10-16 15:11:28.649765 I  Updated programs: 757 Unchanged
programs: 4714
2019-10-16 15:11:52.434876 I  Updated programs: 2345 Unchanged
programs: 10636
2019-10-16 15:12:16.252418 I  Updated programs: 2419 Unchanged
programs: 11010

I do not know if your tv_grab_zz_sdjson grabber produces the same
messages - from your log snippet, it looks like it does not.

You can also use SQL queries to see the state of the program table:

MariaDB [mythconverg]> select count(*) from program;
+----------+
| count(*) |
+----------+
|    89164 |
+----------+
1 row in set (0.00 sec)

MariaDB [mythconverg]> select count(*) from program where starttime >
now();
+----------+
| count(*) |
+----------+
|    25196 |
+----------+
1 row in set (0.02 sec)

MariaDB [mythconverg]> select starttime from program order by
starttime desc limit 1;
+---------------------+
| starttime           |
+---------------------+
| 2019-10-24 05:24:32 |
+---------------------+
1 row in set (0.00 sec)

If you do those queries before and after mythfilldatabase is run, you
should see the starttime of the furthest into the future recording
time increase by about one day every time you do the daily
mythfilldatabase run.