Mythbackend continuously restarting

Have a MythTV related problem? Ask for help from other MythTV users here.

Moderator: Forum Moderators

Post Reply
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Mythbackend continuously restarting

Post by yawlhoo »

I upgraded my backend from (Myth)Ubuntu 14.04 to 16.04. Trying to run down a problem with cron I was inspecting syslog and see messages like this continuously:
======
...
Sep 26 06:29:57 nuc2 systemd[1]: Stopped MythTV Backend.
Sep 26 06:29:57 nuc2 systemd[1]: Starting MythTV Backend...
Sep 26 06:30:17 nuc2 systemd[1]: Started MythTV Backend.
Sep 26 06:30:35 nuc2 wpa_supplicant[908]: wlan0: Failed to initiate sched scan
Sep 26 06:31:09 nuc2 mythbackend[11756]: Cannot login to database
Sep 26 06:31:09 nuc2 mythbackend[11756]: Would you like to configure the database connection now? [no]
Sep 26 06:31:09 nuc2 mythbackend[11756]: [console is not interactive, using default 'no']
Sep 26 06:31:09 nuc2 systemd[1]: mythtv-backend.service: Main process exited, code=exited, status=130/n/a
Sep 26 06:31:09 nuc2 systemd[1]: mythtv-backend.service: Unit entered failed state.
Sep 26 06:31:09 nuc2 systemd[1]: mythtv-backend.service: Failed with result 'exit-code'.
Sep 26 06:31:10 nuc2 systemd[1]: mythtv-backend.service: Service hold-off time over, scheduling restart.
Sep 26 06:31:10 nuc2 systemd[1]: Stopped MythTV Backend.
Sep 26 06:31:10 nuc2 systemd[1]: Starting MythTV Backend...
Sep 26 06:31:30 nuc2 systemd[1]: Started MythTV Backend.
Sep 26 06:31:38 nuc2 wpa_supplicant[908]: wlan0: Failed to initiate sched scan
Sep 26 06:32:23 nuc2 mythbackend[11777]: Cannot login to database
Sep 26 06:32:23 nuc2 mythbackend[11777]: Would you like to configure the database connection now? [no]
Sep 26 06:32:23 nuc2 mythbackend[11777]: [console is not interactive, using default 'no']
Sep 26 06:32:23 nuc2 systemd[1]: mythtv-backend.service: Main process exited, code=exited, status=130/n/a
Sep 26 06:32:23 nuc2 systemd[1]: mythtv-backend.service: Unit entered failed state.
Sep 26 06:32:23 nuc2 systemd[1]: mythtv-backend.service: Failed with result 'exit-code'.
Sep 26 06:32:24 nuc2 systemd[1]: mythtv-backend.service: Service hold-off time over, scheduling restart.
Sep 26 06:32:24 nuc2 systemd[1]: Stopped MythTV Backend.
Sep 26 06:32:24 nuc2 systemd[1]: Starting MythTV Backend...
Sep 26 06:32:41 nuc2 wpa_supplicant[908]: wlan0: Failed to initiate sched scan
Sep 26 06:32:44 nuc2 systemd[1]: Started MythTV Backend.
....
===========
and on and on. Yet it seems the system is working OK, I can record and watch TV, etc.

Any idea what is happening here?
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

Hi,

Hmmm, everything's working, but systemd is constantly restarting a mythtv-backend service.

Could there be two services running? You could do: systemctl status myth<tab><tab> to
let the command autocomplete just to see if there's a second service (we have had folks use
mythbackend.service, for example.) But I wouldn't expect that with a normal Mythbuntu install.

How 'bout this, sudo systemctl disable mythtv-backend.service . That will turn the offending
service in, the logs above, off. Now all you have to do is figure out what is starting the
working version.

mythtv-backend.service, by the way, is the 'standard' name of the Mythbuntu service. I'd
consider whatever else is starting an instance of the backend to be in error. I'd remove it
and re-enable the one above.
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

The system stops spewing stop/start messages into the syslog after a while.

Checking as you indicate, it seems only one backend is running.

It appears that the start up of the backend is problematical somehow, multiple stop/starts are required before it is successful in getting running?

Wonderful, just the sort of erratic behavior that one fears...
daraden
Senior
Posts: 175
Joined: Tue Feb 23, 2016 7:33 am
United States of America

Re: Mythbackend continuously restarting

Post by daraden »

Is this happening when you first boot or any time you start the backend?
you can use

Code: Select all

sudo systemctl stop mythtv-backend.service
to stop and

Code: Select all

sudo systemctl start mythtv-backend.service
to start the backend.
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

It sounded like the logs in the initial post kept printing (the
"and on and on" commnt.) Since the backend
does work, then go after the: "Cannot login to database" log
entry and make sure mysql is running before the backend
starts.

Type: systemctl cat mythtv-backend.service and see if there's a
line like this in the output:

Code: Select all

[Unit]
After=mysql.service network-online.target
If the backend isn't waiting for mysql to start, you can edit the
service with: sudo -i systemctl edit mythtv-backend.service.

You can also type: journalctl and see all activity around the backend message
you're asking about.
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

Following daraden's tip, stopping, then starting the backend results in a repeating set of messages in syslog:
===
...
Sep 27 07:47:25 nuc2 systemd[1]: Stopped MythTV Backend.
Sep 27 07:47:25 nuc2 systemd[1]: Started MythTV Backend.
Sep 27 07:48:17 nuc2 mythbackend[12224]: Cannot login to database
Sep 27 07:48:17 nuc2 mythbackend[12224]: Would you like to configure the database connection now? [no]
Sep 27 07:48:17 nuc2 mythbackend[12224]: [console is not interactive, using default 'no']
Sep 27 07:48:18 nuc2 systemd[1]: mythtv-backend.service: Main process exited, code=exited, status=130/n/a
Sep 27 07:48:18 nuc2 systemd[1]: mythtv-backend.service: Unit entered failed state.
Sep 27 07:48:18 nuc2 systemd[1]: mythtv-backend.service: Failed with result 'exit-code'.
Sep 27 07:48:19 nuc2 systemd[1]: mythtv-backend.service: Service hold-off time over, scheduling restart.
Sep 27 07:48:19 nuc2 systemd[1]: Stopped MythTV Backend.
Sep 27 07:48:19 nuc2 systemd[1]: Started MythTV Backend.
...
===
This is happening every minute or so: following bill6502's tip, "journalctl |grep configure" yields:
===
Sep 27 07:41:10 nuc2 mythbackend[12092]: Would you like to configure the database connection now? [no]
Sep 27 07:42:03 nuc2 mythbackend[12103]: Would you like to configure the database connection now? [no]
Sep 27 07:42:57 nuc2 mythbackend[12119]: Would you like to configure the database connection now? [no]
Sep 27 07:43:50 nuc2 mythbackend[12139]: Would you like to configure the database connection now? [no]
Sep 27 07:44:44 nuc2 mythbackend[12159]: Would you like to configure the database connection now? [no]
Sep 27 07:45:37 nuc2 mythbackend[12171]: Would you like to configure the database connection now? [no]
Sep 27 07:46:31 nuc2 mythbackend[12184]: Would you like to configure the database connection now? [no]
Sep 27 07:47:24 nuc2 mythbackend[12194]: Would you like to configure the database connection now? [no]
Sep 27 07:48:17 nuc2 mythbackend[12224]: Would you like to configure the database connection now? [no]
Sep 27 07:49:11 nuc2 mythbackend[12244]: Would you like to configure the database connection now? [no]
Sep 27 07:50:04 nuc2 mythbackend[12276]: Would you like to configure the database connection now? [no]
...
===
Yet, the mythbackend-service file looks OK from the mysql standpoint:
===
$ sudo systemctl status mysql.service
mysql.service - MySQL Community Server
Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: en
Active: active (running) since Tue 2017-09-26 22:42:51 PDT; 9h ago
Process: 1913 ExecStartPost=/usr/share/mysql/mysql-systemd-start post (code=ex
Process: 1893 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exit
Main PID: 1912 (mysqld)
CGroup: /system.slice/mysql.service
1912 /usr/sbin/mysqld

Sep 26 22:42:50 nuc2 systemd[1]: Starting MySQL Community Server...
Sep 26 22:42:51 nuc2 systemd[1]: Started MySQL Community Server.
====
that is, it's been running since yesterday.

And, in fact, the puzzling thing is that in spite of all this stopping and starting, recordings happen, I can watch recordings, mythweb looks mostly normal (there are some metadata lookup messages that I need to nail down when all this is under control...)

I wonder if my 2 HDHomerun units are responsible for battening the hatches and manning the steering wheel in this storm of backend problems, once started recording they just copy the bytes and cache them as needed?
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

If the backend stops, writing the data (in hdhrstreamhandler.cpp) stops. I'm
not aware of any caching ability. Your frontend would complain about the
backend being gone too. You're right, this is puzzling (clearly in the realm of
this can't possibly happen, but it does.)

To answer your earlier question: "...multiple stop/starts are required before it is successful in getting running".
No, mine's rock solid. I've not heard of this issue here or on the mailing lists. I
have heard of folks with two services: mythbackend.service and mythtv-backend.service.
That was the reason for: systemctl status myth<tab><tab>

If the mysql is up, as you proved, then I'd look at how the backend is getting
to it. See if config.xml is available to the user running the backend. That's
user mythtv normally. This has some hints: https://www.mythtv.org/wiki/Config.xml#Troubleshooting
Especially the comment about symbolic links, which Mythbuntu uses. And,
which have been known to break.

Do this when the backend is failing: mysql -u mythtv -p mythconverg , where the
password is from ~mythtv/.mythtv/config.xml . That's verifies that the backend's
access to the DB using it's credentials.

I'm assuming that everything is running on host nuc2, e.g. mysql, mythbackend,
the users are on /home. No mounts going away etc. I see mention of wlan0 in
the initial post, so I'm wondering if some resource is taking a vacation from the
network.

I'd prefer to see your backend log probably in /var/log/mythtv/mythbackend.log.
Starting at the last line that looks similar to this:

mythbackend version: master [v30-Pre-43-g211b8da] www.mythtv.org

It shouldn't be too long given the number of restarts.
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

mythbackend.log
(5.02 KiB) Downloaded 96 times
I'm not sure why wlan0 shows up, I have disabled wifi completely, the backend is connected via ethernet only.

It would be really difficult, I think, to try logging into mysql when the connection is out, because it happens so briefly.

The log you'd like is posted below. Note that it says it is using /home/mythtv/.mythtv. In that directory config.xml is a link (owned by root.root):
==
$ ls -l
total 64
drwxr-xr-x 2 mythtv mythtv 4096 Jun 7 2014 3rdParty
drwxr-xr-x 6 mythtv mythtv 4096 Apr 29 2016 cache
drwxr-xr-x 4 mythtv mythtv 4096 Jun 7 2014 Cache-mythbackend-nuc2
drwxr-xr-x 4 mythtv mythtv 4096 Jun 7 2014 Cache-mythfilldatabase-nuc2
drwxr-xr-x 4 mythtv mythtv 4096 Aug 16 2014 Cache-mythmetadatalookup-nuc2
drwxr-xr-x 2 mythtv mythtv 4096 Jun 7 2014 channels
lrwxrwxrwx 1 root root 22 Jun 7 2014 config.xml -> /etc/mythtv/config.xml
-rw-r--r-- 1 mythtv mythtv 32131 Apr 27 2016 pytmdb3.cache
drwxr-xr-x 2 mythtv mythtv 4096 Jun 7 2014 themes
drwxr-xr-x 4 mythtv mythtv 4096 Sep 8 2016 tmp
=========
and:
========
$ ls -l /etc/mythtv/config.xml
-rw-rw---- 1 mythtv mythtv 452 Sep 26 11:05 /etc/mythtv/config.xml
========
Contents of config.xml
=======
<Configuration>
<Database>
<PingHost>1</PingHost>
<Host>localhost</Host>
<UserName>mythtv</UserName>
<Password>xxxxxxx (redacted)</Password>
<DatabaseName>mythconverg</DatabaseName>
<Port>3306</Port>
</Database>
<WakeOnLAN>
<Enabled>0</Enabled>
<SQLReconnectWaitTime>0</SQLReconnectWaitTime>
<SQLConnectRetry>5</SQLConnectRetry>
<Command>echo 'WOLsqlServerCommand not set'</Command>
</WakeOnLAN>
</Configuration>
====
Thanks for your help.
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

Does the frontend (that's working and allowing you to watch recordings) live on host nuc2
or on some other host?

Run this on nuc2: curl --header "Accept: application/json" localhost:6544/Myth/GetHostName
and on any other hosts involved please. When the backend is running, the response will look
similar to mine: {"String": "ofc0"}. nmap -p 6544 --reason yourHostNameOrIP is another good
tool. I'm looking to see if there's another backend running on another host.

The link, owned by root:root is OK, that's just the user:group that created the link.
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

nuc2 is exclusively the backend, no frontend.
The frontend is on a different system, a Raspberry Pi 3, no backend.
On nuc2, the curl command gives:
===
$ curl --header "Accept: application/json" localhost:6544/Myth/GetHostName
{"String": "nuc2"}
===
On the frontend (rpi3) the command yields:
===
$ curl --header "Accept: application/json" localhost:6544/Myth/GetHostName
curl: (7) Failed to connect to localhost port 6544: Connection refused
===
There are no other Mythtv boxes running in the house.
Really appreciate the effort you're putting into this.
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

This afternoon I was looking at syslog and it seemed "clean", there was no stop/start behavior, etc. So I decided to stop, then start the backend using systemctl and watch "top". I get the usual cycle of start/stop of the backend.

I see briefly two instances of mythbackend in top, one owned by "user" (how I log in as user) and the other by mythtv. I tried to take a screenshot, but was unsuccessful, the instances bounce around in top too quickly.

But I did see a strange dissonance: in syslog, systemd finally reports failure :

Sep 28 14:43:37 nuc2 systemd[1]: Failed to start MythTV Backend.

I'm tailing syslog, there are no further messages.

But at the same time, "ps -ax" reports a mythbackend process that has been running for some time:

2334 ? Sl 50:54 mythbackend

This latter case must rule because Mythweb reports all is well, and in fact I'm recording a show, even though systemd says it couldn't start the backend!

Queer!

Is it some kind of problem with systemd?
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

Re problem with systemd. None that I've ever had. And everything I'm seeing
looks good. Thanks running the curl to confirm things.

Can't explain the transient 'user' you spotted. It may have been you running
the systemctl start command. Confirming the expected, try this:
sudo stat /proc/1/exe|grep File (should see: /lib/systemd/systemd .)

Paste the output of this (which should be the 'stock' Mythbuntu version.)

systemctl cat mythtv-backend.service

Once the backend is actually working, the output of this should show how
long it takes to connect tot he DB:

journalctl | egrep "Cannot login to database|New static DB connection"

You'll be able to compare the timestamps from the above with the output
of this, assuming mysql is the culprit:

sudo cat /var/log/mysql/error.log
yawlhoo
Senior
Posts: 120
Joined: Wed Apr 15, 2015 4:18 pm
United States of America

Re: Mythbackend continuously restarting

Post by yawlhoo »

Thank you for all your effort.

Tonight I was in a big mess, caused by starting and stopping the backend via systemctl to test various "fixes." At one point I found myself with the condition that **at the command line** everything looked fine in a ssh session on the backend. But the frontend wouldn't connect to the backend, and mythweb complained "is the backend running?" I realized that I had been here before, and that previously I had tried to rescue the situation by running mythtv-setup on the backend in a VNC session. The problem with doing this is that a bug in mythtv-setup won't allow you to quit setup after your fiddling, the interface freezes. I think maybe this is why there are multiple instances of mythtvbackend processes running.

But returning to the frontend/backend connection issue, I was thinking about why mythweb and the frontend were unable to connect to the backend. It's got to be some kind of network lookup (the frontend screen at some point complains about "no UPnP servers"), right?

I looked at /etc/mythtv/config.xml. The line:

<Host>localhost</Host>

caught my eye. I have set the hostname, the backend is not "localhost" in the bash prompt, it is "nuc2." I changed the entry to reflect this, rebooted, and voila! everything now works.

I believe this tiny config detail is the solution.
User avatar
bill6502
Developer
Posts: 2323
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Mythbackend continuously restarting

Post by bill6502 »

localhost is a valid <Host> for the backend (assuming, as in this case, the DB is
on the localhost too.) I'd assume that localhost is defined in /etc/hosts (or wherever
you do DNS on your boxen.) I'd expect the following (at least the IPv4 address.)

Code: Select all

$ host localhost
localhost has address 127.0.0.1
localhost has IPv6 address ::1
Post Reply