Opened 6 years ago

Closed 5 years ago

Last modified 5 years ago

#11461 closed Bug Report - General (fixed)

mythlogserver busy with 200 poll() calls per second even if there is nothing to log

Reported by: tino@… Owned by: JYA
Priority: minor Milestone: 0.27.3
Component: MythTV - Mythlogserver Version: 0.26-fixes
Severity: medium Keywords:
Cc: Ticket locked: no

Description

I use the mythtv 0.26/fixes packages for Debian from www.deb-multimedia.org (0.26.0+fixes20130311-dmo1). The computer has Intel graphics only.

I start mythbackend this way:

mythbackend -v channel,idle,eit --nodblog --syslog none

This is mostly a backend-only machine, the frontend is usually run on another computer.

mythlogserver constantly eats CPU time in this setup.

I used strace to see what it is doing, and it seems to be busy with poll() calls with timeout 0, so it immediately returns. It looks like this:

[pid 4940] poll([{fd=28, events=POLLIN}], 1, 0) = 0 (Timeout)

I tried to measure this, with the following result:

$ ps aux | grep mythlogserver | grep -v grep
mythtv    4938  0.5  0.1 613324 14772 ?        Ssl  Mar17  11:17 /usr/bin/mythlogserver --daemon --verbose general,channel,idle,eit --loglevel info --nodblog
$ timeout 10 strace -ff -p 4938 2>&1 | grep "poll.*, 0)" 2>&1 > out
$ wc -l out 
2051 out

So there are more 2051 poll() invokations with zero timeout in 10 seconds, more than 200 per second.

I also log console output, and the above also happens when nothing happens in console output. So mythlogserver is constantly busy even if there is nothing to log.

I expect mythlogserver to be idle when there is nothing to log.

Change History (6)

comment:1 Changed 6 years ago by Karl Egly

You could try this patch to reduce the wake ups from 200/sec to 20/sec, see also [4a9a609c450f865c898b7b474dc4b609472e4aef]

diff --git a/mythtv/libs/libmythbase/loggingserver.cpp b/mythtv/libs/libmythbase/loggingserver.cpp
index 602f518..1223454 100644
--- a/mythtv/libs/libmythbase/loggingserver.cpp
+++ b/mythtv/libs/libmythbase/loggingserver.cpp
@@ -789,7 +789,7 @@ void LogServerThread::run(void)
     m_zmqContext = nzmqt::createDefaultContext(NULL);
     nzmqt::PollingZMQContext *ctx = static_cast<nzmqt::PollingZMQContext *>
                                         (m_zmqContext);
-    ctx->setInterval(100);
+    ctx->setInterval(10);
     ctx->start();
 
     bool abortThread = false;
@@ -1101,6 +1101,7 @@ void LogForwardThread::run(void)
     m_zmqContext = nzmqt::createDefaultContext(NULL);
     nzmqt::PollingZMQContext *ctx = static_cast<nzmqt::PollingZMQContext *>
                                         (m_zmqContext);
+    ctx->setInterval(10);
     ctx->start();
 
     m_zmqPubSock = m_zmqContext->createSocket(nzmqt::ZMQSocket::TYP_PUB, this);

comment:2 Changed 6 years ago by tino@…

With setInterval(10); it is even worse, which is in line with the code comment for setInterval(). So I used 1000 instead of 10 and it is much better now.

comment:3 Changed 6 years ago by Karl Egly

Doh, you're right. that should be "ctx->setInterval(100);" to signal "poll 10 times per second" instead of the default of "ctx->setInterval(10);" to signal "poll 100 times per second".

comment:4 Changed 5 years ago by Jean-Yves Avenard <jyavenard@…>

Resolution: fixed
Status: newclosed

comment:5 Changed 5 years ago by Jean-Yves Avenard <jyavenard@…>

In f0f9e431d9af903b2ae3054c51fe20b439e87ba3/mythtv:

reduce poll interval.

Fixes #11461

(cherry picked from commit 71c2c41f6aae840ef21a84f2c8ab6831cb7000c0)

comment:6 Changed 5 years ago by paulh

Milestone: unknown0.27.3
Owner: changed from beirdo to JYA
Note: See TracTickets for help on using tickets.