[mythtv-users] Many instances of mythlogserver running and taking up 98% of CPU

[Bill Meek]

On 12/02/2012 06:32 AM, Matthias.myth wrote:

Hi;

Summary; there are things below that can make the logging easier to read, but
the key issue is the multiple copies and abnormally high CPU usage. So far, I
don't see the answer to that.

Comments in line.

> thanks for your reply. I had read the entry in the wiki, but I did not really get much out of it.

Sorry to hear that.

You'd asked how the logserver is started, which others have asked. The answer is in
the Wiki, and the reasons for starting/stopping are there too. The Wiki doesn't
address how the various distributions elect to do their logging. It does have links
to options that could be used.

> I also have few lines in the syslog:
>
> Dec  2 07:45:41 **** mythlogserver: mythlogserver[27342]: I LogForward loggingserver.cpp:1310 (forwardMessage) New Client:
> 0092bb6f0a51854f99bf1e98ee4adbdb2f (#4)
> Dec  2 08:11:30 **** mythlogserver: mythlogserver[27342]: I LogForward loggingserver.cpp:1204 (expireClients) Expiring client
> 0092bb6f0a51854f99bf1e98ee4adbdb2f (#3)

These entries are generated by mythlogserver itself. In the above, note "mythlogserver:",
that's the program name. everything after the ":" is the message for the logfile. This is
normal for 0.26 using --syslog.

There is a way around this. See: http://www.mythtv.org/wiki/Simple_rsyslog_Configuration.
Be sure to see the 0.26 version halfway down the page. I tested it and it works. Stop
your backend and kill the logserver (or wait for it to time out in 5 minutes.) Then
restart the backend.

Or, you can replace "--syslog local7" in your /etc/init/mythbackend.conf file with
"--logpath /var/log/mythtv".

I wouldn't suggest changing now, just had to write it for completeness.

> But I have many lines in /var/log/mythtv/mythbackend.log, see at the end of this message.

I deleted all but 1 line and moved it here:

 > Dec  2 11:02:28 ***** mythlogserver: mythbackend[27816]: N Expire autoexpire.cpp:264 .....

The program making the log entry is mythlogserver, its client is mythbackend. This is not a problem.
The rsyslog solution just mentioned cleans this up.

(Thanks for pasting without line wrapping, wish everyone would do that)

> I have also read the page about logging in the wiki; but unfortunately, the distribution-dependant information is (obviously) not here. So I
> have checked, and I can find in /etc/init/mythbackend.conf, how mythbackend is started:
>
> /usr/bin/mythbackend --syslog local7 --user mythtv

Correct, that's the only place the backend sets the logging. Unless
Mythbuntu uses a wrapper script for the backend. It doesn't look like
it from the "top" output you posted. Unless you typed the command
manually (not using sudo start mythtv-backend.)

Remember, as in the mythlogserver Wiki, the 1st program to run will kick
off the logserver. I have used "mythshutdown --lock --nodblog --quiet" in
my own .profile and when starting the machine, mythshutdown ran before
mythbackend, so the logging was based on the parameters passed to
mythshutdown. Unusual, but it happened.

> About how I was finding the multiple copies: I have been looking at top:
>
> root@*****:/home/mth# top
> Cpu(s): 96.7%us,  2.6%sy,  0.0%ni,  0.0%id,  0.0%wa, 0.0%hi,  0.7%si, 0.0%st
>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM TIME+  COMMAND
>   1416 mythtv    20   0  202m  27m 2972 R  182  1.3 929:39.28 mythlogserver
> 27816 mythtv    20   0  516m  32m 6380 S    2  1.6 64:25.29 mythbackend
> 15787 myth      20   0 1300m 537m  28m S    1 26.7 235:04.10 mythfrontend.re
> 27342 mythtv    20   0  326m 2500 1756 S    1  0.1 13:24.32 mythlogserver
...
>
> You can see that at this moment, I have one process of mythlogserver going to 200%, if it can, and one with 1% CPU. That was different the last
> times I looked, the crazy one would only go to 100%.... -> ?

Now to the important part of your post. With the above and the next ps, you should
be able to look in your log files (both /var/log/syslog for mythlogserver and
/var/log/mythtv/myth*.log for *anything* else) to see who is starting up
mythlogserver.

> ps ax | grep mythlog will give me 2, like top at this moment:
 >
>   1416 ?        Rsl  932:20 /usr/bin/mythlogserver --daemon --verbose general --loglevel info --quiet --syslog local7
> 10290 pts/8    S+     0:00 grep mythlog
> 27342 ?        Ssl   13:25 /usr/bin/mythlogserver --daemon --verbose general --loglevel info --syslog local7

Recall from the Wiki that logserver's logging options are inherited from the program that
starts it. By now you probably guessed that I wrote the Wiki ;)

Note that in PID 1416 the options include --quiet, but in PID 27342 --quiet is gone.
That suggests logserver was started by different programs. The 2nd instance probably
by the line in mythtv-backend.conf. The 1st, ???

> but ps axH will give me 16.

16 is the same as I have, I said 17 in my  previous post, but forgot to exclude "grep mythlog".

> In the top list you can see that it is the mythlogserver with id 1416, the oder one, which goes crazy. I tried a "killall mythlogserver", both
> instances were killed and now I have only one process left, id 22346. I notice that, according to the process id and the time, the instance that
> went mad seems to be quite old... but I had killall'ed them yesterday, too, with the load going back to normal, so I am not sure what this means.

Neither do I. I've never had more than one logserver running.

I'd have expected to see "sudo killall...", unless you're running as root
(which I *rarely* do) or mythtv. Both instances of the logserver are owned
by mythtv. When this happens again, try using "kill <theOldPidNumber>" rather
than "killall...".

But, I'd still try to figure out what process is starting the "mad" logserver by
looking at the timestamps in all the logs as mentioned above. Look for text like:

     Logger logging.cpp:488 (launchLogServer) - Starting mythlogserver

They could be in any /var/log/mythtv/myth*.log file. Although that again depends
on your distribution. If you have /etc/rsyslog.d/40-mythtv.conf or something like
it and want to use pastebinit <filename>, put the link in a response here.

-- 
Bill