[vdr] SetEvents using too much CPU?

[Jon Burgess <jburgess@uklinux.net>]

I have been running vdr-1.3.12 for a while and was noticed that my 
keyboard and mouse seemed to freeze for about 1 second every 5 seconds. 
I tracked this behaviour down to the CPU usage by main vdr thread.

Since the main VDR thread runs with realtime priority, it blocks all 
other non-realtime tasks whenever it wants to use the CPU. After some 
digging into the code I found that it was the SetEvents code that is 
running every 5 seconds and that on my machine this was monopolising the 
CPU for almost 1 second. This starves X, xmms etc of CPU and causes my 
system to stutter badly (although the VDR recording and playback is OK).

I have attached two patches. One patch adds some debugging to printout 
some debug about how much CPU the SetEvents code is taking. On my 
machine a typical event scan takes ~0.8 seconds, with a maximum of 1.09 
seconds (which is about a ~20% CPU load). This is on a machine with an 
Athlon XP 2000 (underclocked to around 1500), so a lower end machine may 
really struggle.

Is it unusual for the SetEvents code to sonsume so much CPU time?

The second patch is a trivial one that increases the scan interval from 
5 to 60 seconds. I have been running this on my machine for a while and 
have not noticed any detrimental effects, but YMMV.

I don't expect that either patch will get applied to VDR as-is. They are 
just meant to highlight the problem and will hopefully prompt some 
further discussion.

   Jon

--- ref12/vdr-1.3.12/vdr.c	2004-06-13 14:52:09.000000000 +0100
+++ measure/vdr.c	2004-09-29 21:41:15.996245480 +0100
@@ -31,6 +31,7 @@
 #include <stdlib.h>
 #include <termios.h>
 #include <unistd.h>
+#include <sys/time.h>
 #include "audio.h"
 #include "channels.h"
 #include "config.h"
@@ -82,6 +83,24 @@
   exit(1);
 }
 
+static void display_delta(struct timeval start, struct timeval end) 
+{
+  int d_s, d_us;
+  float sec;
+  static float max_sec;
+
+  d_s  = end.tv_sec  - start.tv_sec;
+  d_us = end.tv_usec - start.tv_usec;
+
+  sec = d_s + d_us / 1000000.0;
+
+  if (sec > max_sec)
+     max_sec = sec;
+
+  printf("SetEvent took %.2f seconds, (max = %.2f)\n", sec, max_sec);
+}
+
+
 int main(int argc, char *argv[])
 {
 #ifdef _CS_GNU_LIBPTHREAD_VERSION
@@ -578,7 +597,12 @@
            if (time(NULL) - LastActivity > 10) {
               static time_t LastSetEvents = 0;//XXX trigger by actual EPG data modification???
               if (time(NULL) - LastSetEvents > 5) {
+                 struct timeval start, end;
+
+                 gettimeofday(&start, NULL);
                  Timers.SetEvents();
+                 gettimeofday(&end, NULL);
+                 display_delta(start, end);
                  LastSetEvents = time(NULL);
                  }
               }
diff -ur ref12/vdr-1.3.12/vdr.c vdr-1.3.12/vdr.c
--- ref12/vdr-1.3.12/vdr.c	2004-06-13 14:52:09.000000000 +0100
+++ vdr-1.3.12/vdr.c	2004-08-20 21:14:53.071985616 +0100
@@ -577,7 +577,7 @@
            // Assign events to timers:
            if (time(NULL) - LastActivity > 10) {
               static time_t LastSetEvents = 0;//XXX trigger by actual EPG data modification???
-              if (time(NULL) - LastSetEvents > 5) {
+              if (time(NULL) - LastSetEvents > 60) { 
                  Timers.SetEvents();
                  LastSetEvents = time(NULL);
                  }