[mythtv-users] mythfilldatabase stops running after a few days

Tue Jul 19 15:56:38 UTC 2022

On Tue, Jul 19, 2022 at 11:43 AM Stephen Worthington <
stephen_agent at jsw.gen.nz> wrote:

> On Tue, 19 Jul 2022 10:16:01 -0400, you wrote:
>
> >Hi All.
> >
> >For some reason mythfilldatabase just stops automatically starting.
> >
> >Last mythfilldatabase run started on Sat Jul 16 2022, 7:36 PM and ended on
> >Sat Jul 16 2022, 7:37 PM. mythfilldatabase ran, but did not insert any new
> >data into the Guide for 1 of 1 sources. This can indicate a potential
> >grabber failure.
> >Suggested next mythfilldatabase run: Sun Jul 17 2022, 7:36 PM.
> >There's guide data until 2022-08-03 01:30:00 (15 days).
> >
> >Today is July 19th.  So it has not automatically started since then.
> >This happens randomly.  If i run mythfilldatabase as user mythtv it starts
> >working normally again for a week or two.  Then it starts failing again.
> >
> >Ubuntu 20.04
> >
> >  Candidate: 2:31.0+fixes.202203040618.7e4ce1ba98~ubuntu20.04.1
> >  Version table:
> >     2:31.0+fixes.202203040618.7e4ce1ba98~ubuntu20.04.1 500
> >        500 http://ppa.launchpad.net/mythbuntu/31/ubuntu focal/main amd64
> >Packages
> >     2:31.0+fixes.20200323.9579662cdc-0ubuntu1 500
> >        500 http://us.archive.ubuntu.com/ubuntu focal/multiverse amd64
> >Packages
> >
> >Log file shows this from last run.  Nothing else after this.Jul 16
> 19:38:52
> >hemlock mythfilldatabase: mythfilldatabase[408006]: N CoreContext
> >main.cpp:409 (main) Data fetching complete.
> >Jul 16 19:38:52 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:417 (main) Adjusting program database end times.
> >Jul 16 19:38:52 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:422 (main)     0 replacements made
> >Jul 16 19:38:52 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:425 (main) Marking generic episodes.
> >Jul 16 19:38:52 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:436 (main)     Found 1113
> >Jul 16 19:38:52 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:439 (main) Extending non-unique programids with
> >multiple parts.
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:490 (main)     Found 0
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:492 (main) Fixing missing original airdates.
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:506 (main)     Found 510 with programids
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:528 (main)     Found 0 without programids
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:535 (main) Marking repeats.
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:548 (main)     Found 482
> >Jul 16 19:38:53 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:551 (main) Unmarking new episode rebroadcast repeats.
> >Jul 16 19:38:54 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:560 (main)     Found 744
> >Jul 16 19:38:54 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:570 (main) Marking episode first showings.
> >Jul 16 19:38:55 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:606 (main)     Found 29855
> >Jul 16 19:38:55 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:608 (main) Marking episode last showings.
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:644 (main)     Found 29773
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext main.cpp:660 (main)
> >#012===============================================================#012|
> >Attempting to contact the master backend for rescheduling.  |#012| If the
> >master is not running, rescheduling will happen when |#012| the master
> >backend is restarted.
> > |#012===============================================================
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: N
> >CoreContext main.cpp:674 (main) mythfilldatabase run complete.
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext platforms/mythpowerdbus.cpp:72 (~MythPowerDBus) PowerDBus:
> >Closing interfaces
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext mythcontext.cpp:1659 (~MythContext) Waiting for threads to
> exit.
> >Jul 16 19:38:56 hemlock mythfilldatabase: mythfilldatabase[408006]: I
> >CoreContext mythcontext.cpp:1665 (~MythContext) Exiting
> >
> >I also find the metadata lookup is failing too.
> >
> >Any idea where I should start troubleshooting?
> >Thank you
>
> What does the output of this command show?
>
> sudo mysql mythconverg -e "select * from settings where value like
> '%mythfill%';"
>
> This is what I get on my system where mythfilldatabase is run
> externally via a user cron job:
>
> +---------------------------------+----------------------+----------+
> | value                           | data                 | hostname |
> +---------------------------------+----------------------+----------+
> | mythfilldatabaseLastRunStart    | 2022-07-19T03:11:30Z | NULL     |
> | MythFillSuggestedRunTime        | 2022-07-20T03:11:30Z | NULL     |
> | MythFillGrabberSuggestsTime     | 1                    | NULL     |
> | MythFillEnabled                 | 0                    | NULL     |
> | MythFillDatabasePath            | mythfilldatabase     | NULL     |
> | MythFillDatabaseArgs            | --only-update-guide  | NULL     |
> | MythFillDatabaseLog             | /var/log/mythtv      | NULL     |
> | MythFillPeriod                  | 1                    | NULL     |
> | MythFillMinHour                 |                      | NULL     |
> | MythFillMaxHour                 | 23                   | NULL     |
> | MythFillFixProgramIDsHasRunOnce | 1                    | mypvr    |
> | mythfilldatabaseLastRunEnd      | 2022-07-19T03:11:32Z | NULL     |
> | mythfilldatabaseLastRunStatus   | Successful.          | NULL     |
> +---------------------------------+----------------------+----------+
>
> The MythFillSuggestedRunTime, MythFillMinHour and MythFillMaxHour
> values normally determine when mythbackend will next run
> mythfilldatabase when it is being run that from mythbackend.  I am not
> sure what happens if mythbackend is shut down when it would normally
> run.

> | value                         | data                 | hostname |
> +-------------------------------+----------------------+----------+
> | mythfilldatabaseLastRunEnd    | 2022-07-19T14:17:07Z | NULL     |
> | MythFillEnabled               | 1                    | NULL     |
> | MythFillDatabasePath          | mythfilldatabase     | NULL     |
> | MythFillMinHour               | 0                    | NULL     |
> | MythFillMaxHour               | 23                   | NULL     |
> | MythFillGrabberSuggestsTime   | 1                    | NULL     |
> | MythFillSuggestedRunTime      | 2022-07-20T14:16:15Z | NULL     |
> | mythfilldatabaseLastRunStart  | 2022-07-19T14:16:15Z | NULL     |
> | MythFillDatabaseArgs          |                      | NULL     |
> | mythfilldatabaseLastRunStatus | Successful.          | NULL

What caught my attention in your reply is the comment about the backend
being shutdown.
Now that I think about it, the backend was restarted due to a power outage
a few days back.  And I think mythfilldatabase has not run since then.
I have since run mythfilldatabase manually.  I will monitor and see if
everything is back to normal.

What would cause this issue after a restart?  If that is indeed why this
happens.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20220719/971fafe3/attachment.htm>