[erledigt] Systemlast kurz nach vdr-Start auf Maximum/Hänger (dvb_usb_dtt200u)

Hallo,

ich bin nach einer erfolgreichen viermonatigen Testphase von vdr derzeit dabei ein neues System aufzusetzen, dass in Zukunft als VDR-Server in unserem Haus fungieren soll.

Mein Problem derzeit: Nachdem ich vdr (1.4.7) starte steigt reproduzierbar kurze Zeit später die Load des Systems kontinuierlich auf 2 (CPU-Last nahezu 0%) - die Tastatur reagiert nur noch mit ~5s Verspätung etc, dementsprechend sehen auch die Testaufnahmen mit VDR aus (entweder sehr viele Klötzchen, einfach eine leere Datei, manchmal auch für einige Minuten super Bild über streamdev!). Auch nach neun Stunden sinkt die Load nicht. Sobald ich VDR beende UND das Kernel-Modul für meinen USB-DVB-T Receiver entlade sinkt die Load wieder. VDR beenden reicht nicht.

AMD Athlon64 X2 BE-2350, 1GB RAM, MSI K9MM-V K8M800,
Freecom USB DVB-T Stick (rev3 derzeit), Distribution: LFS
Als Kernel verwende ich derzeit 2.6.24 und die in diesem enthalten DVB-Treiber, da ich sowohl mit 2.6.23 als auch 2.6.19 und 2.6.24 mit den aktuellen v4l hg jedesmal beim Laden des Kernelmoduls dvb-usb-dtt200u meines DVB-T-Sticks OOOPs begrüßen durfte (das Kernelmodul dtt200u ist jedoch soweit ich das mit diff sehe mit dem in v4l-dvb und 2.6.24 identisch)

Den Stick habe ich in doppelter Ausführung bereits auf dem alten System erfolreich laufen gehabt. Kernel war dort 2.6.18-4 von Debian.

Nach dem Start des Systems und einstecken des USB-Sticks werden die notwendigen Module geladen (siehe auch dmesg.txt).

--
dvb-usb: schedule remote query interval to 300 msecs.
dvb-usb: WideView WT-220U PenType Receiver (Typhoon/Freecom) successfully initialized and connected.
dvb-usb: recv bulk message failed: -110
--

Mit tzap switche ich jetzt auf einen Sender und zeichne diesen mittels "cat /dev/dvb/adapter0/dvr0" auf - einwandfreies Bild, load maximal bei 0.2. Kernel-Log spricht derweil:

--
dvb-usb: recv we made it: 0 (<- von mir hinzugefügte dbg msg in dvb-usb-urb.c)
last message repeated 201 times
last message repeated 793 times
.. etc
--

Also alles ok.

Ich beende tzap und starte vdr, Kernel-Log:

--
dvb-usb: recv bulk message failed: -110 (<- kurz nach vdr start:)
last message repeated 32 times
last message repeated 62 times
usw, sprich knapp mehr als 1x pro Sekunde diese Fehlermeldung
--

VDR meldet derweil gelgentlich das was ich auch idR sehe: video data stream broken (siehe auch Anhang).

Beende ich jetzt vdr, bleibt die Load oben. Entferne ich das modul dvb_usb und dvb_usb_dtt200u sinkt die Load. Steigt jedoch sofort wieder an wenn ich das Modul wieder lade, unabhängig davon ob ich vdr starte oder nicht.

Periodische Debug-Meldung in diesem Zustand vom Modul, mit der ich nichts anfangen kann:

--
key: ff ff af f8 12
dvb-usb: recv bulk message failed: -110
dvb-usb: recv bulk message failed: -110
--

Jemand eine Idee warum nur durch vdr dieser Fehler und die damit verbundene hohe load/Hänger des Systems zustande kommt? Bin aktuell etwas verzweifelt.

Wollte es mal mit dem Debian Kernel meines alten vdr versuchen, jedoch unterstützt dieser SATA meines Mainboards noch nicht. Stecke ich den Stick in das alte System funktioniert VDR wieder anstandlos (mal von der sterbenden Festplatte abgesehen)

Jeder noch so kleine Hinweis .. ist hilfreich

Edit2:
Das Streamen geht in den ersten 1-2 Minuten nach dem Start von VDR und sieht so aus:

[Blockierte Grafik: http://img11.myimg.de/0902200834633189_thumb.jpg][Blockierte Grafik: http://img11.myimg.de/09022008347e0888_thumb.jpg][Blockierte Grafik: http://img11.myimg.de/09022008348bdcaf_thumb.jpg]
Beispielaufnahme

Wie gesagt, wenn ich hingegen einen Sender mit tzap einstelle und dann mittels "cat /dev/dvb/adapter0/dvr0 > test.mpg" aufzeichne ist Bild+Ton 1A.

--
Feb 9 22:22:13 keller vdr: [2566] switching to channel 1
Feb 9 22:22:13 keller vdr: [2566] setting watchdog timer to 30 seconds
Feb 9 22:22:13 keller vdr: [2566] ERROR: no OSD provider available - using dummy OSD!
Feb 9 22:22:23 keller vdr: [2566] max. latency time 1 seconds
Feb 9 22:22:41 keller vdr: [2575] Streamdev: Accepted new client (HTTP) 192.168.1.5:4813
Feb 9 22:22:41 keller vdr: [2617] streamdev-writer thread started (pid=2566, tid=2617)
Feb 9 22:22:41 keller vdr: [2618] streamdev-livestreaming thread started (pid=2566, tid=2618)
Feb 9 22:22:41 keller vdr: [2619] receiver on device 2 thread started (pid=2566, tid=2619)
Feb 9 22:22:41 keller vdr: [2620] TS buffer on device 2 thread started (pid=2566, tid=2620)
Feb 9 22:22:41 keller vdr: [2570] frontend 0 lost lock on channel 1, tp 198
Feb 9 22:22:42 keller vdr: [2570] frontend 0 regained lock on channel 1, tp 198
Feb 9 22:23:25 keller vdr: [2573] frontend 1 lost lock on channel 1, tp 198
===> Ab hier dann gar keine Ausgabe mehr über streamdev (standbild im vlc)
Feb 9 22:23:26 keller vdr: [2573] frontend 1 regained lock on channel 1, tp 198
Feb 9 22:24:07 keller vdr: [2573] frontend 1 lost lock on channel 1, tp 198
Feb 9 22:24:07 keller vdr: [2573] frontend 1 regained lock on channel 1, tp 198
Feb 9 22:24:29 keller vdr: [2573] frontend 1 lost lock on channel 1, tp 198
Feb 9 22:24:31 keller vdr: [2573] frontend 1 timed out while tuning to channel 1, tp 198
--

Spätestens wenn gar kein Bild mehr kommt steigt die Load nach und nach an und die Tastatur reagiert kaum noch (s.o.).

channels.conf von vdr

Zitat

PHOENIX;ARD:198500:C23D23M16B7T8G4Y0:T:27500:301:302=ger:304:0:3:8468:0:0

channels.conf für tzap

Zitat

PHOENIX:198500000:INVERSION_AUTO:BANDWIDTH_7_MHZ:FEC_2_3:FEC_2_3:QAM_16:TRANSMISSION_MODE_8K:GUARD_INTERVAL_1_4:HIERARCHY_NONE:301:302:3

Edit3: w_scan (hatte vorher scan verwendet) hat mir eine etwas andere channels.conf generiert, trotzdem leider keine Änderung. Abgesehen davon, dass es gelegentlich für 2-3 Minuten mit klarem Bild geht.

Zitat

PHOENIX;ARD:198500:I999B7C23D23M16T8G4Y0:T:27500:301:302=ger:304:0:3:8468:17920:0

Die Bildstörungen mit vdr bin ich mittlerweile los, die hohe load kurz nachdem vdr gestartet wurde bleibt leider.

30-70x / sekunde
--
dvb-usb: recv bulk message failed: -110
--

Aktuelle v4l habe ich mittlerweile auch zum laufen bekommen, leider keine positiven Änderungen, habe jetzt folgende kernel durch:

2.6.24, 2.6.24.1, 2.6.19, 2.6.23.14 sowohl mit im kernel enthaltenen als mit den aktuellen v4l treibern inkl. 87 Bootvorgängen lt meinem Dateisystem :>

Mir ist außerdem aufgefallen, das nach dem laden des Treiber dvb_usb_dtt200u idR zwei adapter "registriert" werden - es ist aber nur ein Stick eingesteckt:

--
dvb-usb: found a 'WideView WT-220U PenType Receiver (Typhoon/Freecom)' in warm state.
dvb-usb: will use the device's hardware PID filter (table count: 15).
DVB: registering new adapter (WideView WT-220U PenType Receiver (Typhoon/Freecom))
DVB: registering frontend 0 (WideView USB DVB-T)...
input: IR-receiver inside an USB DVB receiver as /devices/pci0000:00/0000:00:10.4/usb5/5-4/input/input3
dvb-usb: schedule remote query interval to 300 msecs.
dvb-usb: WideView WT-220U PenType Receiver (Typhoon/Freecom) successfully initialized and connected.
dvb-usb: found a 'WideView WT-220U PenType Receiver (Typhoon/Freecom)' in warm state.
dvb-usb: will use the device's hardware PID filter (table count: 15).
DVB: registering new adapter (WideView WT-220U PenType Receiver (Typhoon/Freecom))
DVB: registering frontend 1 (WideView USB DVB-T)...
input: IR-receiver inside an USB DVB receiver as /devices/pci0000:00/0000:00:10.4/usb5/5-4/input/input4
dvb-usb: schedule remote query interval to 300 msecs.
dvb-usb: WideView WT-220U PenType Receiver (Typhoon/Freecom) successfully initialized and connected.
dvb-usb: recv bulk message failed: -110
--

und beim entladen:
--
usbcore: deregistering interface driver dvb_usb_dtt200u
dvb-usb: WideView WT-220U PenType Receiver (Typhoon/Freecom) successfully deinitialized and disconnected.
dvb-usb: WideView WT-220U PenType Receiver (Typhoon/Freecom) successfully deinitialized and disconnected.
--

Ich kann zwar über beide mit tzap tunen, aber vielleicht ist es das was vdr zu schaffen macht. Kann ich vdr anweisen nur ein bestimmtes dvb device zu verwenden?

Edit:

Habe es jetzt mal rabiat mit rm -rf /dev/dvb/adapter1/ gemacht (heute auf udev umgestiegen).

Jemand eine Idee woran das liegen könnte, dass er aus meinem einzelnen Stick zwei Stück macht (nicht immer ...) nachdem die Firmware geladen wurde?

Für knapp 30 Minuten lief es so tatsächlich tadellos. Load war max 0.02 und nur die "-75" Fehlermeldungen. Nach knapp einer halben Stunde jedoch das alte Bild mit der "-100" Fehlermeldung und steigender Load:

----
<vdr start>
Feb 10 06:57:53 keller kernel: dvb-usb: recv bulk message failed: -75
Feb 10 06:58:38 keller kernel: dvb-usb: recv bulk message failed: -75
Feb 10 07:02:56 keller last message repeated 406 times
Feb 10 07:06:33 keller last message repeated 140 times
Feb 10 07:06:43 keller last message repeated 705 times
Feb 10 07:27:43 keller kernel: dvb-usb: recv bulk message failed: -110
<ab hier wieder steigende load, tastatur hänger etc>
Feb 10 07:28:15 keller last message repeated 24 times
Feb 10 07:29:17 keller last message repeated 46 times
Feb 10 07:30:19 keller last message repeated 47 times
Feb 10 07:31:21 keller last message repeated 46 times
.
.
.
Feb 10 14:30:51 keller last message repeated 47 times
Feb 10 14:31:53 keller last message repeated 46 times
Feb 10 14:32:55 keller last message repeated 46 times
----

> Freu mich schon wenn ich den Rechner morgen wieder hochfahre und
> das wie vorher ist :>

Ich hatte recht

Mittlerweile bekomme ich immer kurz vor/während der 110er Fehlermeldung von vdr "PES packet shortened"

--
==> /var/log/vdr.log <==
Feb 10 19:37:30 keller vdr: [1722] frontend 0 timed out while tuning to channel 1, tp 198
Feb 10 19:37:31 keller vdr: [1730] 14 cRepacker messages suppressed
Feb 10 19:37:31 keller vdr: [1730] cAudioRepacker(0xC0): skipped 320 bytes to sync on next audio frame
Feb 10 19:37:32 keller vdr: [1722] frontend 0 regained lock on channel 1, tp 198
Feb 10 19:37:33 keller vdr: [1730] PES packet shortened to 1606 bytes (expected: 2894 bytes)
Feb 10 19:37:33 keller vdr: [1722] frontend 0 lost lock on channel 1, tp 198
Feb 10 19:37:35 keller vdr: [1722] frontend 0 regained lock on channel 1, tp 198

==> /var/log/kernel <==
Feb 10 19:37:35 keller last message repeated 444 times
Feb 10 19:39:27 keller kernel: dvb-usb: recv bulk message failed: -110
Feb 10 19:39:27 keller kernel: dvb-usb: bulk message failed: -110 (4/0)

==> /var/log/vdr.log <==
Feb 10 19:39:29 keller vdr: [1722] frontend 0 lost lock on channel 1, tp 198

==> /var/log/kernel <==
Feb 10 19:39:29 keller kernel: dvb-usb: bulk message failed: -110 (1/0)
Feb 10 19:39:33 keller last message repeated 2 times
Feb 10 19:39:33 keller kernel: dvb-usb: bulk message failed: -110 (4/0)
Feb 10 19:39:35 keller kernel: dvb-usb: bulk message failed: -110 (1/0)
Feb 10 19:39:39 keller last message repeated 2 times
Feb 10 19:39:39 keller kernel: dvb-usb: bulk message failed: -110 (4/0)
--

oder auch schon mal:

--
Feb 10 20:16:22 keller vdr: [1461] cVideoRepacker: found system start code: stream seems to be scrambled or not demultiplexed
Feb 10 20:16:23 keller vdr: [1461] cAudioRepacker(0xC0): skipped 1262 bytes to sync on next audio frame
Feb 10 20:16:23 keller vdr: [1461] PES packet shortened to 2392 bytes (expected: 2894 bytes)
Feb 10 20:16:23 keller vdr: [1461] PES packet shortened to 1790 bytes (expected: 2894 bytes)
Feb 10 20:16:23 keller vdr: [1461] PES packet shortened to 672 bytes
etc
--

Wenn ich sobald die load steigt, also die o.g. 110er Fehlermeldung kommt, vdr beende und dann femon eingebe (tzap hängt an dieser Stelle wenn ich es damit versuche):

--
FE: WideView USB DVB-T (DVBT)
status | signal 4646 | snr b9b9 | ber 00489946 | unc 00009946 |
status | signal 4646 | snr b9b9 | ber 00489946 | unc 00009946 |
status | signal 4646 | snr b9b9 | ber 00489946 | unc 00009946 |
status | signal 4646 | snr b9b9 | ber 00489946 | unc 00009946 |
--

Nachdem ich den Stick entfernt habe (dauert ca 30s bis das Entfernen des Sticks vom System verarbeitet wurde):

--
status 1f | signal 3939 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3939 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3939 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3838 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3939 | snr 9f9f | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3939 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
status 1f | signal 3939 | snr a7a7 | ber 00000000 | unc 00000000 | FE_HAS_LOCK
--

Danke, dass Du an meinem Leid teilnimmst

Zitat

Altes System, nur neue Software oder auch Hardware?

Hardware ist auch neu, lief vorher auf einem Alton XP 3000+ mit nforce Chipsatz und IDE-Festplatte.

Zitat

Es sieht irgendwie so aus, als ob die Probleme anfangen, nach dem der zweite Stick erkannt wird.

Die erste -110er Fehlermeldung ist einmal direkt nach dem Einstecken/Erkennung lt. anderer Berichte vollkommen normal, hatte ich auch auf dem alten System.

Mir ist mittlerweile auch aufgefallen, wenn ich den Rechner mit der hohen load/den 110er Fehlern neu boote aber den Stick nicht entferne steigt die load direkt nach dem Reboot wieder an, egal ob vdr oder irgendwas anderes an DVB verwendet wird. Erst wenn ich den Stick entferne und neu einstecke beruhigt sich das ganze wieder.

Meine Theorie derzeit: Es hat was mit USB und dem Mainboardchipsatz zu tun. Wenn ich den Rechner mit noapic (+routeirq bringt spürbar keine Verbesserung) starte kann ich VDR reproduzierbar länger ohne steigende Load/110er Fehler nutzen als ohne. Im BIOS habe ich schon rumgespielt, ohne Erfolg. EAPIC lässt sich dort nicht ausschalten, wenngleich es als Option vorhanden ist, aber ausgegraut.
Ich hätte meinem Prinzip treu bleiben sollen und kein MSI-Board mehr kaufen sollen

Als nächstes werde ich vermutl. die SATA-Festplatte auf eine IDE-Platte kopieren und auf der alten Hardware mir mal die Ergebnisse ansehen.

Was mich nach wie vor verwundert: Ich habe schon testweise eine Stunde mit tzap einen Kanal aufgenommen und hatte keine Probleme

Der Vollständigkeit halber:

Alle späteren Versuche scheiterten, wenn nicht schon eher, spätestens nach Beginn eines größeren Dateitransfers von der SATA-Festplatte mit o.g. Problem.

Das Problem konnte ich nur mit Revision 3 des Sticks reproduzieren. Sowohl die steigende Load bei > 500interrupts/5s von usb (also die -110er/Timeout Fehler) als auch das der Stick doppelt erkannt wurde. Mit Revision 2 (lt. lsusb, kein entsprechener Vermerk auf dem Aufkleber des Sticks über die Revision) kein Problem. Leider habe ich 3x Rev 3 und nur einmal Rev2

Das Problem tritt auch auf der alten Hardware auf mit SATA - wenn auch deutlich seltener. Vermutlich hatte ich die letzten vier Monate nur Glück weil als primäres device ein Rev2 Stick verwendet wurde und der Rev3 nur selten von vdr bei zwei gleichzeitigen Aufnahmen unterschiedlicher Transponder (kann leider nicht mehr mit Sicherheit nachvollziehen welche Revisionen ich im alten System verwendet habe).

Aus purer Verzweiflung habe ich heute früh nochmal mit einer komplett leeren Kernel-Konfiguration begonnen und die läuft noch anstandslos, aber das hies ja bisher auch nichts. Sollte das Problem wirklich nicht mehr auftreten werde ich die funktionierende als auch die alte Config für die Nachwelt posten.

Rev 3 wird bereits seit einiger Zeit unterstützt.

Aber: Das Problem existiert (leider)
nicht mehr. Selbst wenn ich den vorherigen Kernel boote mit den alten
Modulen etc unverändert wird der Stick korrekt nur noch 1x erkannt und
bislang keine Timeoutmeldungen.

Alles was ich seit vorgestern morgen als es zum letzten mal aufgetreten ist
gemacht habe war kurz ein anderes Netzteil - mittlerweile wieder das
alte - die Firmware von Rev2 und Rev1 geladen und natürlich den "neuen"
Kernel kompiliert um die Option zu finden die das Problem verursacht,
was nicht erfolgreich war, weil selbst mit der alten config der Kernel
plötzlich mit dem Stick klarkommt. Sicherheitshalber alle Sticks
durchprobiert etc, Problem ist _derzeit_ einfach weg. VDR lief jetzt also knapp zwei Tage ohne das von mir beschriebene Problem.

Falls ich die Ursache des einstgen Fehlers finden sollte werde ich es hier posten.