Ruckler und Aussetzer bei HD (free to air oder andere) nach heutigem update (Änderung seit 10.3)

sebixvi · 10. April 2012

So, ich habe mal testweise xbmc angeworfen und eine HD-Aufnahme, die im vdr ruckelt, abgespielt - alles einwandfrei, Systemlast von xbmc unter 10%. Das Logfile von xbmc meldet:

Code

21:13:21 T:140287801595872 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
21:13:21 T:140287389202176  NOTICE: Creating InputStream
21:13:21 T:140287389202176  NOTICE: Creating Demuxer
21:13:21 T:140287389202176  NOTICE: Opening video stream: 0 source: 256
21:13:21 T:140287389202176  NOTICE: Creating video codec with codec id: 28
21:13:21 T:140287389202176  NOTICE: CDVDVideoCodecFFmpeg::Open() Creating VDPAU(1280x720, 28)
21:13:21 T:140287389202176  NOTICE: vdp_device = 0x00000001 vdp_st = 0x00000000
21:13:21 T:140287389202176  NOTICE: VDPAU Decoder capabilities:
21:13:21 T:140287389202176  NOTICE: name      	level macbs width height
21:13:21 T:140287389202176  NOTICE: ------------------------------------
21:13:21 T:140287389202176  NOTICE: MPEG1         	0  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: MPEG2_SIMPLE  	3  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: MPEG2_MAIN    	3  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: H264_MAIN    	41  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: H264_HIGH    	41  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: VC1_SIMPLE    	1  8190  2048  2048
21:13:21 T:140287389202176  NOTICE: VC1_MAIN      	2  8190  2048  2048
21:13:21 T:140287389202176  NOTICE: VC1_ADVANCED  	4  8190  2048  2048
21:13:21 T:140287389202176  NOTICE: MPEG4_PART2_ASP   5  8192  2048  2048
21:13:21 T:140287389202176  NOTICE: ------------------------------------
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_NOISE_REDUCTION
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_SHARPNESS
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL_SPATIAL
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_INVERSE_TELECINE
21:13:21 T:140287389202176  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_HIGH_QUALITY_SCALING_L1
21:13:21 T:140287389202176  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 (VDPAU acceleration)
21:13:21 T:140287389202176  NOTICE: Creating video thread
21:13:21 T:140287389202176  NOTICE: Opening audio stream: 3 source: 256
21:13:21 T:140287389202176  NOTICE: Finding audio codec for: 86019
21:13:21 T:140287389202176  NOTICE: Creating audio thread
21:13:21 T:140287389202176  NOTICE: Opening Subtitle stream: 4 source: 256
21:13:21 T:140287115261696  NOTICE: running thread: CDVDPlayerAudio::Process()
21:13:21 T:140287123654400  NOTICE: running thread: video_thread
21:13:21 T:140287115261696  NOTICE: Creating audio device with codec id: 86019, channels: 2, sample rate: 48000, pass-through
21:13:21 T:140287115261696 WARNING: PulseAudio: Does not support passthrough
21:13:21 T:140287123654400  NOTICE:  (VDPAU) screenWidth:0 vidWidth:1280 surfaceWidth:1280
21:13:21 T:140287123654400  NOTICE:  (VDPAU) screenHeight:0 vidHeight:720 surfaceHeight:720
21:13:21 T:140287123654400  NOTICE: Creating 1280x720 pixmap
:

Alles anzeigen

Hier wird also ebenfalls vdpau benutzt, die Ausgabe klappt einwandfrei. Auch wenn ich als Deinterlacer temporal-spatial wähle, steigt die CPU-Last von xbmc.bin nicht über 10%. Nur wenn ich als Skalierungsmethode noch "bicubic" auswähle, habe ich ca 12-15% CPU-Last und das Bild wirkt leicht unruhig, aber kein Vergleich zu den Problemen bei vdr.

Sebi

fnu · 10. April 2012

Zitat von sebixvi

Hier wird also ebenfalls vdpau benutzt,

Interessante Information, aber da das wohl läuft ist das kaum hilfreich. Log-Informationen aus der Zeit wo etwas nicht korrekt funktioniert könnten bei der Problemlösung helfen.

Also nochmal, syslog, frontend-log und "htop" Screenshot (wg. CPU Last) aus der Zeit wo Du per xine/xineliboutput einen HD Sender schaust, der ruckelt.

Regards
fnu

sebixvi · 10. April 2012

Zitat von fnu

Mich würde das syslog und ein "htop" Screenshot interessieren und zwar in der Zeit wo Du auf einem HD Sender bist?

Regards
fnu

Syslog:

Code

Apr 10 21:36:06 dumbledore vdr: [18993] Text2Skin: channelInfo display update thread ended (pid=17824, tid=18993)
Apr 10 21:36:54 dumbledore vdr: [19013] Text2Skin: channelInfo display update thread started (pid=17824, tid=19013)
Apr 10 21:36:55 dumbledore vdr: [17824] switching to channel 2
Apr 10 21:36:55 dumbledore vdr: [19010] recording thread ended (pid=17824, tid=19010)
Apr 10 21:36:55 dumbledore vdr: [17824] buffer stats: 194956 (3%) used
Apr 10 21:36:55 dumbledore vdr: [19021] receiver on device 2 thread started (pid=17824, tid=19021)
Apr 10 21:36:55 dumbledore vdr: [19023] TS buffer on device 2 thread started (pid=17824, tid=19023)
Apr 10 21:36:55 dumbledore vdr: [17824] recording to '/srv/vdr/video.00/LiveBuffer/00001.ts'
Apr 10 21:36:55 dumbledore vdr: [17824] playing '/srv/vdr/video.00/LiveBuffer/00001.ts'
Apr 10 21:36:55 dumbledore vdr: [19030] recording thread started (pid=17824, tid=19030)
Apr 10 21:36:55 dumbledore vdr: [19003] TS buffer on device 1 thread ended (pid=17824, tid=19003)
Apr 10 21:36:55 dumbledore vdr: [19001] buffer stats: 194016 (9%) used
Apr 10 21:36:55 dumbledore vdr: [19001] receiver on device 1 thread ended (pid=17824, tid=19001)
Apr 10 21:37:00 dumbledore vdr: [19013] Text2Skin: channelInfo display update thread ended (pid=17824, tid=19013)
Apr 10 21:37:49 dumbledore vdr: [19031] Text2Skin: channelInfo display update thread started (pid=17824, tid=19031)
Apr 10 21:37:50 dumbledore vdr: [17824] switching to channel 1
Apr 10 21:37:50 dumbledore vdr: [19030] recording thread ended (pid=17824, tid=19030)
Apr 10 21:37:50 dumbledore vdr: [17824] buffer stats: 196836 (3%) used
Apr 10 21:37:50 dumbledore vdr: [19039] receiver on device 1 thread started (pid=17824, tid=19039)
Apr 10 21:37:50 dumbledore vdr: [19041] TS buffer on device 1 thread started (pid=17824, tid=19041)
Apr 10 21:37:50 dumbledore vdr: [17824] recording to '/srv/vdr/video.00/LiveBuffer/00001.ts'
Apr 10 21:37:50 dumbledore vdr: [17824] playing '/srv/vdr/video.00/LiveBuffer/00001.ts'
Apr 10 21:37:50 dumbledore vdr: [19048] recording thread started (pid=17824, tid=19048)
Apr 10 21:37:50 dumbledore vdr: [19023] TS buffer on device 2 thread ended (pid=17824, tid=19023)
Apr 10 21:37:50 dumbledore vdr: [19021] buffer stats: 195896 (9%) used
Apr 10 21:37:50 dumbledore vdr: [19021] receiver on device 2 thread ended (pid=17824, tid=19021)
Apr 10 21:37:55 dumbledore vdr: [19031] Text2Skin: channelInfo display update thread ended (pid=17824, tid=19031)

Alles anzeigen

htop:

Code

1  [|||||||                                                                 	7.2%] 	Tasks: 73, 128 thr; 2 running
  2  [|||||||||||||||||||||||||||                                            	32.7%] 	Load average: 0.08 0.20 0.22 
  Mem[||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||459/2005MB] 	Uptime: 2 days, 20:16:29
  Swp[                                                                    	0/1905MB]


  PID USER 	PRI  NI  VIRT   RES   SHR S CPU% MEM%   TIME+  Command
18866 vdr   	10 -10  353M 49100 18084 S 32.0  2.4  3:46.15 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
18887 vdr   	10 -10  353M 49100 18084 S 30.0  2.4  3:04.36 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
17824 vdr   	10 -10  831M  115M 17300 S  3.0  5.8  2:37.93 vdr-dbg --lirc=/var/run/lirc/lircd -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -r /usr/lib/vdr/vdr-re
19081 root  	20   0 20012  1780  1176 R  2.0  0.1  0:02.52 htop
18889 vdr   	10 -10  353M 49100 18084 R  1.0  2.4  0:07.35 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
19039 vdr   	10 -10  831M  115M 17300 S  1.0  5.8  0:04.19 vdr-dbg --lirc=/var/run/lirc/lircd -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -r /usr/lib/vdr/vdr-re
19048 vdr   	10 -10  831M  115M 17300 S  1.0  5.8  0:03.08 vdr-dbg --lirc=/var/run/lirc/lircd -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -r /usr/lib/vdr/vdr-re
19041 vdr   	10 -10  831M  115M 17300 S  1.0  5.8  0:02.85 vdr-dbg --lirc=/var/run/lirc/lircd -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -r /usr/lib/vdr/vdr-re
18890 vdr   	10 -10  353M 49100 18084 S  1.0  2.4  0:03.28 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
18895 vdr   	10 -10  353M 49100 18084 S  0.0  2.4  0:03.97 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
18888 vdr   	10 -10  353M 49100 18084 S  0.0  2.4  0:26.42 /usr/bin/vdr-sxfe --post tvtime:method=use_vo_driver --reconnect --audio=alsa --syslog --silent --tcp --config /etc/vd
18065 vdr   	39  19  831M  115M 17300 S  0.0  5.8  0:20.12 vdr-dbg --lirc=/var/run/lirc/lircd -v /srv/vdr/video.00 -c /var/lib/vdr -L /usr/lib/vdr/plugins -r /usr/lib/vdr/vdr-re
 1506 nobody	20   0 19252  1324   980 S  0.0  0.1  4:13.05 /usr/sbin/LCDd -s 1 -f -c /etc/LCDd.conf
	1 root  	20   0 24404  2484  1324 S  0.0  0.1  0:01.90 /sbin/init
  282 root  	20   0 17056   628   444 S  0.0  0.0  0:00.44 upstart-udev-bridge --daemon
  288 root  	16  -4 21320   860   348 S  0.0  0.0  0:00.27 udevd --daemon
  624 daemon	20   0  8380   532   404 S  0.0  0.0  0:00.00 portmap
  658 root  	20   0 15008   620   416 S  0.0  0.0  0:00.11 upstart-socket-bridge --daemon
 1040 root  	20   0 32264   684   372 S  0.0  0.0  0:00.00 /usr/sbin/lircd --driver=default --device=/dev/lirc0 --uinput --output=/var/run/lirc/lircd-lirc0 --pidfile=/var/run/li
 1187 root  	20   0 91672  3900  2720 S  0.0  0.2  0:00.02 smbd -F
 1196 root  	20   0 61696  1816   908 S  0.0  0.1  0:01.84 nmbd -D
 1201 messageb  20   0 23852  1180   716 S  0.0  0.1  0:00.38 dbus-daemon --system --fork --activation=upstart
 1204 root  	20   0 91672  1580   404 S  0.0  0.1  0:00.00 smbd -F
 1446 root  	20   0  257M 15116  5084 S  0.0  0.7  0:03.72 /usr/bin/tntnet
 1447 root  	20   0  257M 15116  5084 S  0.0  0.7  0:03.71 /usr/bin/tntnet
 1448 root  	20   0  257M 15116  5084 S  0.0  0.7  0:03.58 /usr/bin/tntnet
 1449 root  	20   0  257M 15116  5084 S  0.0  0.7  0:03.58 /usr/bin/tntnet
 1450 root  	20   0  257M 15116  5084 S  0.0  0.7  0:04.00 /usr/bin/tntnet
 1451 root  	20   0  257M 15116  5084 S  0.0  0.7  0:00.17 /usr/bin/tntnet
 1452 root  	20   0  257M 15116  5084 S  0.0  0.7  0:00.32 /usr/bin/tntnet
16730 root  	20   0  257M 15116  5084 S  0.0  0.7  0:00.18 /usr/bin/tntnet
 1218 root  	20   0  257M 15116  5084 S  0.0  0.7  0:19.30 /usr/bin/tntnet
 1240 root  	20   0 27340   408   192 S  0.0  0.0  0:00.00 rpc.idmapd
 1430 syslog	20   0  181M  1632  1012 S  0.0  0.1  0:04.06 rsyslogd -c4
 1431 syslog	20   0  181M  1632  1012 S  0.0  0.1  0:00.07 rsyslogd -c4
 1241 syslog	20   0  181M  1632  1012 S  0.0  0.1  0:07.89 rsyslogd -c4
F1Help  F2Setup F3SearchF4InvertF5Tree  F6SortByF7Nice -F8Nice +F9Kill  F10Quit

Alles anzeigen

sebixvi · 10. April 2012

Zitat von fnu

Interessante Information, aber da das wohl läuft ist das kaum hilfreich. Log-Informationen aus der Zeit wo etwas nicht korrekt funktioniert könnten bei der Problemlösung helfen.

IMHO kann man damit jedenfalls ausschließen, dass das Problem im Treiber bzw. im X-Server liegt, nur darum ging es mir. Wenn die vdpau-Komponenten einen Schlag hätten, würde xbmc ebenfalls nicht korrekt laufen. Und dass eine Aufnahme in xbmc funktioniert, die im vdr stottert, schließt aus, dass es Empfangsprobleme bzw. "schlechte" DVB-Daten sind. Das wurde oben ja auch diskutiert.

Sebi

fnu · 10. April 2012

sebixvi

Ja, lt. Log-Information läuft VDPAU scheinbar korrekt. Aber sinnlos waren die Infos dennoch nicht, weil das Du LiveBuffer nutzt, hattest Du bisher nirgends erwähnt.

Ruckelt das auch wenn Du den LiveBuffer ausschaltest? Liegt der in einer sogenannten RAM-Disk (tmpfs)?

Regards
fnu

sebixvi · 10. April 2012

Guten Abend,

mein Problem ist gelöst, vdr-sxfe läuft mit ca. 3% Prozessorlast auf einem HD-Sender.

Grund war meine xorg.conf. Ich habe eine TwinView-Konfiguration (Beamer und HD-ready-Fernseher). Ersten Erfolg hatte ich, nachdem ich in der "Option ConnectedMonitors" den (nicht angeschlossenen) Fernseher zunächst rausgenommen habe. Sofort war das Bild i.o. und die CPU-Last unten.

Dann fiel mir auf, dass der Beamer 60Hz meldet, für PAL-Sendungen ebenfalls nicht optimal. Also habe ich erstmal folgende Modeline eingefügt:

Code

ModeLine "1920x1080_50" 148.50 1920 2448 2492 2640 1080 1084 1089 1125 +hsync +vsync

Damit lief der Beamer mit 50Hz, wie er soll. Da der TV maximal 1080i kann, habe ich für den TV noch

Code

ModeLine "1920x1080_50i" 74.25 1920 2448 2492 2640 1080 1084 1094 1122 +hsync +vsync interlace

ergänzt, in der Einstellung ConnectedMonitors DFP-0 wieder eingesetzt und MetaModes wie folgt gesetzt:

MetaModes "DFP-1:1920x1080_50, DFP-0:1920x1080_50i"

Jetzt läuft der Beamer mit 50Hz progressive, die Ruckler sind weg und die CPU-Last liegt unter 5%. Gelegentlich muss ich noch nachsehen, ob der TV im Nebenraum ein Bild zeigt, aber ich gehe davon aus. Die Modelines habe ich dem erweiterten Log entnommen (startx -- -logverbose 6).

Bleibt die Frage, wieso die 60Hz bisher nicht gestört haben, optimal ist es natürlich so oder so nicht.

Schönen Abend,
Sebi

gda · 10. April 2012

In Zukunft würde ich mir wünschen, dass Änderungen an der Default-Installation von yaVDR früher mitgeteilt würden.

Gerald

sebixvi · 10. April 2012

Hallo Gerald,

da der TV derzeit nicht benutzt wird, habe ich schlicht nicht daran gedacht. Das ist so eine typische Geschichte, die man irgendwann mal konfiguriert und dann nie wieder anfasst, weil es einfach funktioniert.

Und 60Hz sollten lt. Forum zu Mikrorucklern, nicht aber zu 75% CPU-Last und ähnlichen Problemen führen.

Trotzdem versuche ich, nächstes Mal dran zu denken!

Gute Nacht,
Sebi

seahawk1986 · 11. April 2012

Zitat von sebixvi

Und 60Hz sollten lt. Forum zu Mikrorucklern, nicht aber zu 75% CPU-Last und ähnlichen Problemen führen.

Wie sieht deine Audio-Konfiguration aus? Nutzt du zufälligerweise mehrere Ausgabegeräte?

sebixvi · 11. April 2012

Hallo Seahawk,

ja, ich nutze mehrere Ausgabegeräte per asound.conf, im VDR ist passthrough eingestellt.

Testweise habe ich gestern auf Ausgabe per SPDIF bzw. analog umgestellt, ohne dass das etwas geändert hätte. Damit hat es wohl nichts zu tun.

Sebi

fnu · 11. April 2012

sebixvi

Es gibt einige Meldungen von Nutzern, das die Nutzung von mehreren Soundausgaben parallel eben genau zu der deutlich erhöhten CPU Last führt. Konfiguriere mal nur eine Ausgabe und schau Dir die CPU Last dann an.

Regards
fnu

sebixvi · 11. April 2012

Hallo fnu,

Zitat

Testweise habe ich gestern auf Ausgabe per SPDIF bzw. analog umgestellt,
ohne dass das etwas geändert hätte. Damit hat es wohl nichts zu tun.

Das hatte ich schon probiert, brachte aber keine Änderung. Die asound.conf hatte ich außerdem komplett gelöscht, um wirklich nur ein Ausgabedevice zu haben. Erst die Umstellung der xorg.conf brachte die Lösung.

Seltsam finde ich, dass die xorg.conf ja bei vdr-sxfe und xbmc identisch ist, da wird ja kein X-Server neu gestartet. Trotzdem kam xbmc mit der Konfiguration offenbar zurecht, während vdr-sxfe seit dem letzten Update strauchelte.

Grüße,
Sebi

Tommy.Z · 12. April 2012

Zitat von fnu

Es gibt einige Meldungen von Nutzern, das die Nutzung von mehreren Soundausgaben parallel eben genau zu der deutlich erhöhten CPU Last führt. Konfiguriere mal nur eine Ausgabe und schau Dir die CPU Last dann an.

Hallo
kann ich auch bestätigen. Hab eine GT430. Allerdings hatte die Einstellung gar keinen Sinn mehr nach dem Grafikkartenwechsel und der folgenden asound.conf:

pcm.!default {
type hw
card 1
device 9
}

Gruß

Ruckler und Aussetzer bei HD (free to air oder andere) nach heutigem update (Änderung seit 10.3)

Jetzt mitmachen!

Teilen