Every two and a half minute, my syslog gets an entry like:
Jan 3 06:04:40 htpc kernel: cx88[1]/2: cx8802_timeout Jan 3 06:04:49 htpc vdr: [2369] frontend 1 timed out while tuning to channel 9, tp 578
About 30 seconds before i get this entry, thee's a vdr thread that eats about 25% system cpu time. I'm wondering what it's doing with all that processor power? As I'm using budget cards with softdevice, this has an effect on tv playback.. It only happens when I'm using two cards at the same time.
top - 06:10:04 up 21 min, 2 users, load average: 2.18, 2.63, 2.10 Tasks: 96 total, 7 running, 89 sleeping, 0 stopped, 0 zombie Cpu(s): 50.2% us, 24.3% sy, 0.3% ni, 24.6% id, 0.3% wa, 0.0% hi, 0.3% si, 0.0% st Mem: 515672k total, 160352k used, 355320k free, 22520k buffers Swap: 1815304k total, 0k used, 1815304k free, 61232k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2388 root 15 0 242m 29m 4140 R 46.9 5.8 13:28.16 vdr 2369 root 15 0 242m 29m 4140 S 17.6 5.8 1:04.57 vdr 2368 root 15 0 0 0 0 S 3.0 0.0 0:13.46 kdvb-fe-1
Torgeir Veimo wrote:
It would help if you could find out which particular thread is using that CPU percentage. You can do
ps -T u -C vdr
to get a display like
USER PID SPID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND kls 27146 27146 3.7 5.8 124132 22568 pts/0 Sl+ 10:49 0:08 ./vdr kls 27146 27150 0.0 5.8 124132 22568 pts/0 Sl+ 10:49 0:00 ./vdr kls 27146 27151 0.0 5.8 124132 22568 pts/0 Sl+ 10:49 0:00 ./vdr kls 27146 27152 1.6 5.8 124132 22568 pts/0 RNl+ 10:49 0:03 ./vdr kls 27146 27154 0.0 5.8 124132 22568 pts/0 Sl+ 10:49 0:00 ./vdr
where the SPID number corresponds to the thread's "tid" number in VDR's log entries, as in
Jan 3 10:49:19 video vdr: [27152] section handler thread started (pid=27146, tid=27152)
Klaus
On 3 Jan 2007, at 09:58, Klaus Schmidinger wrote:
Hmm, it looks like the thread 5748 (tuner on device 2 thread started).
Jan 3 11:37:29 htpc vdr: [5741] loading /video/vdr/remote.conf [...] Jan 3 11:37:29 htpc vdr: [5742] video directory scanner thread started (pid=5741, tid=5742) Jan 3 11:37:29 htpc vdr: [5742] video directory scanner thread ended (pid=5741, tid=5742) Jan 3 11:37:29 htpc vdr: [5743] video directory scanner thread started (pid=5741, tid=5743) Jan 3 11:37:29 htpc vdr: [5743] video directory scanner thread ended (pid=5741, tid=5743) Jan 3 11:37:29 htpc vdr: [5741] probing /dev/dvb/adapter0/frontend0 Jan 3 11:37:29 htpc vdr: [5741] probing /dev/dvb/adapter1/frontend0 Jan 3 11:37:29 htpc vdr: [5745] tuner on device 1 thread started (pid=5741, tid=5745) Jan 3 11:37:29 htpc vdr: [5746] section handler thread started (pid=5741, tid=5746) Jan 3 11:37:29 htpc vdr: [5741] found 2 video devices Jan 3 11:37:29 htpc vdr: [5741] initializing plugin: softdevice (0.3.0): A software emulated MPEG2 device Jan 3 11:37:29 htpc vdr: [5748] tuner on device 2 thread started (pid=5741, tid=5748) Jan 3 11:37:29 htpc vdr: [5749] section handler thread started (pid=5741, tid=5749) Jan 3 11:37:29 htpc vdr: [5741] [softdevice] videoOut OK ! [...] Jan 3 11:40:59 htpc vdr: [5748] frontend 1 timed out while tuning to channel 9, tp 578 Jan 3 11:41:54 htpc kernel: cx88[1]/2: cx8802_timeout
[root@htpc ~]# ps -T u -C vdr USER PID SPID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND root 5741 5741 0.2 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5745 0.3 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5746 0.5 5.4 220216 28016 ? RNLl 11:37 0:01 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5748 1.1 5.4 220216 28016 ? SLl 11:37 0:02 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5749 0.4 5.4 220216 28016 ? SNLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5752 0.0 5.4 220216 28016 ? S<Ll 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5753 0.0 5.4 220216 28016 ? S<Ll 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5754 0.0 5.4 220216 28016 ? S<Ll 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5755 0.0 5.4 220216 28016 ? S<Ll 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5756 0.0 5.4 220216 28016 ? S<Ll 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5757 0.0 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5760 0.0 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5762 0.1 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5763 0.0 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5764 0.1 5.4 220216 28016 ? SLl 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5765 0.5 5.4 220216 28016 ? SLl 11:37 0:01 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5767 71.6 5.4 220216 28016 ? SLl 11:37 2:29 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5741 5768 1.2 5.4 220216 28016 ? SLl 11:37 0:02 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo root 5759 5759 0.0 1.7 122400 9260 ? Ss 11:37 0:00 ./vdr -v /video/vdr -m 0 -s killall vdr;/bin/false -Psoftdevice - vo dfb:mgatv -Premo [root@htpc ~]#
Tasks: 104 total, 5 running, 99 sleeping, 0 stopped, 0 zombie Cpu(s): 51.7% us, 24.5% sy, 0.3% ni, 22.8% id, 0.0% wa, 0.3% hi, 0.3% si, 0.0% st Mem: 515672k total, 181684k used, 333988k free, 40848k buffers Swap: 1815304k total, 0k used, 1815304k free, 61916k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5767 root 15 0 232m 28m 4132 R 49.3 5.7 5:48.45 vdr 5748 root 15 0 232m 28m 4132 S 18.2 5.7 0:22.78 vdr 5747 root 15 0 0 0 0 S 3.3 0.0 0:04.85 kdvb-fe-1 5761 root 10 -5 0 0 0 S 1.7 0.0 0:06.69 cx88[0] dvb
On 3 Jan 2007, at 11:59, Klaus Schmidinger wrote:
*** thread 5767 is eating most of the CPU time. Unfortunately this one isn't listed in your log file excerpt.
No that's the softdevice output thread. It uses about 70% which is expected with this particular setup and gfx card.
Hi Klaus,
On Mi, Jan 03, 2007 at 01:22:14 +0100, Klaus Schmidinger wrote:
few weeks ago I noticed a similar Problem, that vdr eats a lot of cpu power. In my HTPC there is a tt 2.3 dvb-s and a usb-dvb-t stick. I did some tests with dvb-t stick plugged in and without. The cpu load is about 20% higher with the stick. Please tell me if you need more info to find the Problem. Thanks Halim
Hi, On Mi, Jan 03, 2007 at 04:25:57 +0100, Klaus Schmidinger wrote:
Can you identify a particular VDR thread that consumes those 20% more CPU time?
Thats very dificult. After observing this a time here is the output of ps -T u -C vdr
USER PID SPID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND root 5252 5252 0.0 1.0 31536 10628 tty1 Rl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5262 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5263 0.4 1.0 31536 10628 tty1 SNl+ 17:59 0:01 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5265 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5266 0.3 1.0 31536 10628 tty1 RNl+ 17:59 0:01 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5267 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5268 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5283 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5284 0.0 1.0 31536 10628 tty1 Sl+ 17:59 0:00 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr root 5252 5285 0.3 1.0 31536 10628 tty1 Sl+ 17:59 0:01 ./vdr -E /dev/shm/epg.data -w 40 -s /sbin/go_down -l 0 -c /etc/vdr
I am not shure that you can read someting out of this. I can only tell you, that the cpuload without the dvb-t stick pluged in is lower. Thanks Halim
-
Halim Sahin -
Klaus Schmidinger -
Torgeir Veimo