Crash bei drei gleichzeitig startenden Aufnahmen

MegaV0lt · October 16, 2020 at 8:22 AM

Ich beobachte schon seit einiger Zeit. dass sich der VDR verabschiedet, wenn drei Aufnahmen zur gleichen Zeit starten. Dachte erst "blöder Zufall"... Es ist aber doch recht regelmäßig, dass wenn drei Timer um 20:08 Uhr beginnen das Live-Bild schwarz wird und der VDR nicht mehr bedienbar ist. Dann schlägt der Watchdog zu.

Das Log: https://www.dropbox.com/s/efsn2tl4k6l2m60/sys.log?dl=0

Folgende Timer waren aktiv:

Code

=> Laufende Timer:
9:S19.2E-133-13-127:2020-10-15:2008:2112:50:99:Navy CIS| New Orleans~Hannahs Entscheidung  (S06E01):<epgsearch><channel>18 - 13th St HD</channel><searchtimer>Navy CIS: New Orleans</searchtimer><start>1602785280</start><stop>1602789120</stop><s-id>466</s-id><eventid>3137846</eventid></epgsearch><epgd><timerid>8536</timerid></epgd>
9:S19.2E-133-12-126:2020-10-15:2008:2117:50:99:Marvel's Runaways~Im Land der Träume  (S03E05):<epgsearch><channel>17 - SYFY HD</channel><searchtimer>Runaways</searchtimer><start>1602785280</start><stop>1602789420</stop><s-id>693</s-id><eventid>3139564</eventid></epgsearch><epgd><timerid>8537</timerid></epgd>
9:S19.2E-133-2-147:2020-10-15:2008:2047:50:99:Single Parents~Ketchup!  (S01E23):<epgsearch><channel>205 - Sky One HD</channel><searchtimer>Single Parents</searchtimer><start>1602785280</start><stop>1602787620</stop><s-id>822</s-id><eventid>3139741</eventid></epgsearch><epgd><timerid>8539</timerid></epgd>

Mir ist klar, dass ich mit dem "Problem" alleine da stehe und ich ein Einzelfall bin. Aber vielleicht hat ja jemand ne Idee was da schief geht.

PS: VDR hat vier Tuner und Tuner 1 und 2 sind verbunden (Device Bonding)

wmautner · October 16, 2020 at 9:55 AM

Da läuft auch naludump, epg2vdr usw. gleich mit den Aufnahmen los, und CAM-Entschlüsselung kann auch ein Problem sein, wenn gleichzeitig 2 Aufnahmen darüber starten sollen.

Ich würde mal naludump abstellen und ggf. erst "im Nachlauf" durchführen lassen, und den watchdog länger oder abschalten.

Das schwarze Bild mag sein, wenn gleichzeitig live-TV geguckt wird und der entspr. Tuner doch von einer Aufnahme "geklaut" wird, insbes. mit dem Bonding könnte das passieren (Tuner 1 live, 2 startet Aufnahme, aber auf anderer Pol-/Band-Ebene, 1 wird "finster").

Wie ist die Auslastung des RAM, wieviel braucht mysql?

MegaV0lt · October 16, 2020 at 11:01 AM

Zwei oder drei Aufnahmen sind kein Problem. Ich habe auch schon am fünf am laufen!

Im Log sieht man, dass der dritte Timer nicht gestartet wird. Vermutlich da wo das Bild schwarz wird und der VDR nicht mehr reagiert.

Das "Problem" tritt auch immer nur auf wenn der Startzeitpunkt bei dreien gleich ist.

RAM und MySQL sollten nicht das Problem sein.

Code

MemTotal:        4007484 kB
MemFree:          834640 kB
MemAvailable:    2006616 kB
Buffers:          282116 kB
Cached:          1870700 kB
SwapCached:            0 kB
Active:          1635424 kB
Inactive:        1399656 kB
Active(anon):     680788 kB
Inactive(anon):  1166872 kB
Active(file):     954636 kB
Inactive(file):   232784 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       4194300 kB
SwapFree:        4194300 kB
Dirty:              1444 kB
Writeback:             0 kB
AnonPages:        882560 kB
Mapped:           112520 kB
Shmem:            965096 kB
KReclaimable:      41808 kB
Slab:              69124 kB
SReclaimable:      41808 kB
SUnreclaim:        27316 kB
KernelStack:        3568 kB
PageTables:        10416 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     6198040 kB
Committed_AS:    2453876 kB
VmallocTotal:   34359738367 kB
VmallocUsed:           0 kB
VmallocChunk:          0 kB
Percpu:             1104 kB
DirectMap4k:      195364 kB
DirectMap2M:     3962880 kB

top - 20:08:52 up  3:04,  0 users,  load average: 0,79, 0,71, 0,62
Tasks: 163 total,   2 running, 161 sleeping,   0 stopped,   0 zombie
%CPU(s):  6,7 us, 18,3 sy,  0,0 ni, 50,0 id, 25,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Spch:   3913,6 total,    814,2 free,    955,5 used,   2143,8 buff/cache
MiB Swap:   4096,0 total,   4096,0 free,      0,0 used.   1959,3 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL
22908 root      20   0    7276    796    732 R 100,0   0,0   0:03.72 tail
15375 root      20   0 1555892 241208  38744 D   6,7   6,0   0:00.69 vdr
    1 root      20   0    4380   1476   1372 S   0,0   0,0   0:00.59 init

Display More

Hier mal das ganze Logpaket: https://www.dropbox.com/s/ey35rd0mfaut…008.tar.xz?dl=0

MegaV0lt · January 15, 2021 at 8:06 AM

Gestern Abend wieder:

- Drei Aufnahmen liefen bereits. Start: 1 x 20:07 Uhr, 2 x 20:08 Uhr

- LiveTV lief (n-tv)

- 20:10 Uhr: Bildschirm wird schwarz, als VDR das LiveTV-Device umschalten will zur Aufnahme nr 4 (20:10 Uhr)

- Ab dem Zeitpunkr reagiert der VDR schon nicht mehr auf die FB

- 30 bis 60 Sekunden Später Absturz und Neustart des VDR.

Es muss wohl irgendwas mit dem Locking der Timer zu tun haben:

Code

Jan 14 20:10:30 vdr01 vdr[16063]: [16063] PANIC: watchdog timer expired - exiting!
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ERROR: cStateKey::~cStateKey() called without releasing the lock first (tid=16063, lock=1 Timers, key=0x55c92c8bca20)
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ABORT!
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cStateKey::~cStateKey() calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /lib64/libc.so.6 at ??:?
Jan 14 20:10:31 vdr01 vdr[2826]: Last message '[16063] /lib64/libc.' repeated 1 times, suppressed by syslog-ng on vdr01
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr at ??:?
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /lib64/libc.so.6 at ??:?
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /lib64/libpthread.so.0 at ??:?
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /lib64/libpthread.so.0 pthread_mutex_lock calling __GI___pthread_mutex_lock at ??:?
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cMutex::Lock() calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cThreadLock::Lock(cThread*) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cDevice::SetCamSlot(cCamSlot*) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cCamSlot::Assign(cDevice*, bool) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cDevice::Detach(cReceiver*) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cDevice::DetachAllReceivers() calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cDvbDevice::DetachAllReceivers() calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cDevice::GetDevice(cChannel const*, int, bool, bool) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr cRecordControls::Start(cTimers*, cTimer*, bool) calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr main calling ?? at ??:0
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /lib64/libc.so.6 __libc_start_main at ??:?
Jan 14 20:10:31 vdr01 vdr[16063]: [16063] /usr/local/bin/vdr _start calling ?? at ??:0

Display More

Das ganze Logpaket: https://www.dropbox.com/s/7979iol97asf…010.tar.xz?dl=1

machtnix · January 15, 2021 at 8:22 AM

Hast Du auch markad aktiv?

Ein ähnliches Problem hatte ich auch. Bei mir hatte ich nach langer Suche festgestellt, dass markad mit automatischer Logoerzeugung (--autologo=2) zum Crash führte. Erst bei --autologo=1 trat dieses Verhalten nicht mehr auf.

MegaV0lt · January 15, 2021 at 8:51 AM

markad habe ich am laufen, den Fehler habe ich aber schon länger; auch schon vor dem neuen markad.

Der VDR hängt sich ja anscheinend genau zum Umschaltzeitpunkt auf. Im Log sieht amn da kein markad starten. Auch das Umschalten wird nicht mehr geloggt...

Code

Jan 14 20:09:35 vdr01 vdr[16063]: video: 18:38:08.258  +23  476   0/\ms  32+6+4 v-buf
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Update info.epg2vdr recordings
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Storing event details to '/video/The_100/Willkommen_auf_Bardo__(S07E05)/2021-01-14.20.07.43-0.rec/info.epg2vdr'
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Update recording info for 3906515 in info.epg2vdr with 2 changes
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Storing event details to '/video/Channel_Zero/Liebe_tut_weh__(S04E03)/2021-01-14.20.08.21-0.rec/info.epg2vdr'
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Update recording info for 3907134 in info.epg2vdr with 2 changes
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Storing event details to '/video/Wynonna_Earp/Friends_in_Low_Places__(S04E02)/2021-01-14.20.08.17-0.rec/info.epg2vdr'
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Update recording info for 3906458 in info.epg2vdr with 2 changes
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Updated 3 info.epg2vdr files
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Updating table timers (and remove deleted and finished timers older than 2 days)
Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Updating table timers done

>>> LiveTV bis hier (20:10)
>>> Timer (Nr. 4) auf ZDF_neo soll starten (20:10)
>>> Umschalten erfolgt nicht. Bild wird schwarz und der VDR hängt bis später der Watchdog zuschlägt

Jan 14 20:10:00 vdr01 vdr[16063]: audio/alsa: using pass-through device 'hw:NVidia,7'
Jan 14 20:10:00 vdr01 vdr[16063]: audio/alsa: start delay 336ms
Jan 14 20:10:01 vdr01 cron[18994]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons)
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] PANIC: watchdog timer expired - exiting!
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ERROR: cStateKey::~cStateKey() called without releasing the lock first (tid=16063, lock=1 Timers, key=0x55c92c8bca20)
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ABORT!

Display More

kfb77 · January 15, 2021 at 9:04 AM

Quote from machtnix

ei mir hatte ich nach langer Suche festgestellt, dass markad mit automatischer Logoerzeugung (--autologo=2) zum Crash führte. Erst bei --autologo=1 trat dieses Verhalten nicht mehr auf.

Auch --autologo=1 macht eine automatische Logoerzeugung, aber mit weniger Speicherverbrauch. Die Variante hatte ich extra gebaut, damit es auf Systemen mit wenig Speicher (ich hatte es damals auf einem Pi1 mit 512 MB erfolgreich getestet) auch läuft. Das wäre dann ein sicherer Hinweis, dass dir der Speicher ausgeht. Wieviel Speicher und Swap hast du denn ?

Die eigentliche Funktion von Markad läuft nicht im Plugin innerhalb VDR, sondern in einem eigenen Programm. Das Plugin startet nur das Programm. Somit kann Markad nicht den VDR abschießen (genau das war ja das Ziel dieser Aufteilung), außer: Der Speicher vom System ist komplett verbraucht.

machtnix · January 15, 2021 at 9:59 AM

Sorry MegaV0lt fürs kapern

Hallo kfb77,

im meinem Server sind 8 GB RAM und 4GB Swapfile vorhanden. Der Proz ist ein I5 5th Generation. Also eigentlich genug Power/Resourcen.

Der emergency exit vom VDR passierte meist dann, wenn >2 Aufnahmen zeitgleich stattfinden und wenigstens eine davon auf einem Kanal ohne vorhandenes Logo stattfand. Dabei handelt es sich um verschlüsselte Kanäle in HD

Das Plugin ist auf "während" eingestellt, da ich meist im Timeshift schaue und die Marks gerne nutze.

Nach einem emergency exit des VDR wurde alles noch schlimmer, da die Aufnahmen immer wieder neu gestartet wurden und jedes mal markad mitgespielt hat

Jetzt mit --autologo=1 klappts mit den Aufnahmen (können auch schon mal 5 parallel sein) Für mich ist das so erstmal ok, auch wenn eine schnellere marks Erstellung bei Timeshift schon besser wäre.

Gerne können wir auf dem markad treath weitermachen.

MegaV0lt · January 15, 2021 at 11:16 AM

kls

Vielleicht ne Idee?

Crash bei drei gleichzeitig startenden Aufnahmen

Passiert, wenn das letzte Device das noch frei ist umgeschaltet werden soll. (Meiner Meinung nach)

wmautner · January 15, 2021 at 12:48 PM

Hmm. Gäbe es eine Möglichkeit, daß in solchen Fällen Live-TV nicht durch eine Autotimer-Aufnahme unterbrochen werden kann, bzw. das Live-TV-Device, wenn softhddevice attached ist, den Tuner als "belegt" markiert oder zumindest eine OSD-Meldung erscheint, mit Abfrage, ob umgeschaltet werden soll?

MegaV0lt · January 15, 2021 at 12:51 PM

Ich denke Aufnahmen haben Priorität! LiveTV geht halt nur auf Transpondern, die von den Aufnehmenden Tunern belegt sind.

Eine Abfrage wäre kontraproduktiv, da man ja nicht immer davor sitzt.

Ich möchte sogar, dass der VDR das LiveTV Device ungefragt umschaltet, wenn alle anderen belegt sind. Nur so macht das doch sinn

wmautner · January 15, 2021 at 1:51 PM

Für manuell erstellte Timer, ja. Auto-Timer (epgsearch etc.) nicht unbedingt, da sollte Live-TV zumindest standardmäßig eine höhere Priorität haben. Bei Bedarf läßt sich die Priorität der Autotimer ja anpassen.

MegaV0lt · January 15, 2021 at 3:56 PM

Bei 200+ Timern bei epgsearch recht mühselig

Hat aber nichts mit dem Problem zu tun:

Jan 14 20:09:51 vdr01 vdr[16063]: epg2vdr: Updating table timers done
>>> LiveTV bis hier (20:10)
>>> Timer (Nr. 4) auf ZDF_neo soll starten (20:10)
>>> Umschalten erfolgt nicht. Bild wird schwarz und der VDR hängt bis später der Watchdog zuschlägt
Jan 14 20:10:00 vdr01 vdr[16063]: audio/alsa: using pass-through device 'hw:NVidia,7'
Jan 14 20:10:00 vdr01 vdr[16063]: audio/alsa: start delay 336ms
Jan 14 20:10:01 vdr01 cron[18994]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons)
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] PANIC: watchdog timer expired - exiting!
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ERROR: cStateKey::~cStateKey() called without releasing the lock first (tid=16063, lock=1 Timers, key=0x55c92c8bca20)
Jan 14 20:10:30 vdr01 vdr[16063]: [16063] ABORT!

MegaV0lt · July 9, 2021 at 7:51 AM

Inzwischen hab ich die Dist gewechselt von Gen2VDR auf yaVDR. Das gleiche Problem hatte ich gestern wieder.

Dev 0 LiveTV (verschlüsstelt)
Drei Timer starten Gleichzeitig.

Folge: Schwarzes Bild und VDR hängt komplett und musste resettet werden.

Code

Jul 08 20:08:08 vdr01 yaVDR_11420_11418[11435]: /etc/vdr.d/scripts/vdr_rec_msg.sh Aufnahme:  Pandora~Ein Herz kann man nicht reparieren  (S02E05)
Jul 08 20:08:08 vdr01 yaVDR_11420_11418[11436]: /etc/vdr.d/scripts/vdr_rec_msg.sh <END>
Jul 08 20:08:09 vdr01 vdr[1432]: [1432] markad: cStatusMarkAd::Start(): executing "/usr/bin"/markad  -v  -I  -R  --autologo=2  -l "/var/lib/markad" --online=2 before "/video/Pandora/Ein_Herz_kann_man_nicht_>
Jul 08 20:08:09 vdr01 vdr[1432]: [11431] executing '/usr/lib/vdr/vdr-recordingaction started "/video/Pandora/Ein_Herz_kann_man_nicht_reparieren__(S02E05)/2021-07-08.20.08.18-0.rec"'
Jul 08 20:08:09 vdr01 recordingaction[11443]: executing /usr/share/vdr/recording-hooks/R10.vdr_record.sh
Jul 08 20:08:09 vdr01 yaVDR_11444_11439[11450]: /etc/vdr.d/scripts/vdr_record.sh <START>
Jul 08 20:08:09 vdr01 yaVDR_11444_11439[11451]: /etc/vdr.d/scripts/vdr_record.sh <END>
Jul 08 20:08:09 vdr01 recordingaction[11452]: executing /usr/share/vdr/recording-hooks/R90.custom  as shell script
Jul 08 20:08:10 vdr01 vdr[1432]: [1432] markad: cStatusMarkAd::Start(): index 1, pid 11438, filename /video/Pandora/Ein_Herz_kann_man_nicht_reparieren__(S02E05)/2021-07-08.20.08.18-0.rec: running markad sto>
Jul 08 20:08:10 vdr01 vdr[1432]: [1432] writing timer id '5@vdr01' to /video/Pandora/Ein_Herz_kann_man_nicht_reparieren__(S02E05)/2021-07-08.20.08.18-0.rec/.timer
Jul 08 20:08:10 vdr01 vdr[1432]: [1432] info: Aufnahme:  Pandora~Ein Herz kann man nicht reparieren  (S02E05)
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Info: Detected resume of 'Pandora~Ein Herz kann man nicht reparieren  (S02E05)' on device 3
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Info: Recording 'Pandora~Ein Herz kann man nicht reparieren  (S02E05)' with doneid -1 added to running list
Jul 08 20:08:10 vdr01 vdr[1432]: [1432] skinflatplus: create osd SUCCESS left: 0 top: 0 width: 1920 height: 1080
...
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Got epgd state 'standby' (1)
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Change handler state to 'active'
Jul 08 20:08:10 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47246 lost connection to client
Jul 08 20:08:10 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47246 connection closed
Jul 08 20:08:10 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47246 server destroyed
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Info: Found 698 recordings; 1 inserted; 1 updated and 56 directories
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Updating recording info in info.epg2vdr
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Storing event details to '/video/Pandora/Ein_Herz_kann_man_nicht_reparieren__(S02E05)/2021-07-08.20.08.18-0.rec/info.epg2vdr'
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Updated/Created recording info for 360011 in info.epg2vdr with 11 changes
Jul 08 20:08:10 vdr01 vdr[1432]: epg2vdr: Updated 1 pending info.epg2vdr files
Jul 08 20:08:16 vdr01 vdr[1432]: audio/alsa: using pass-through device 'pulse'
Jul 08 20:08:16 vdr01 vdr[1432]: audio/alsa: start delay 336ms
Jul 08 20:08:21 vdr01 vdr[1432]: video: --:--:--.---   +0    0   0/\ms   0-1+4 v-buf
Jul 08 20:08:25 vdr01 vdr[1432]: scraper2vdr: Got 1 new/updated Series in 0s from Database (new max scrsp: 1625767690)
Jul 08 20:08:25 vdr01 vdr[1432]: scraper2vdr: Loading Series content from Database...
Jul 08 20:08:25 vdr01 vdr[1432]: scraper2vdr: Got 0 new/updated Episodes and 0 new/updated Image information (including 0 possible not available season poster) in 0s from Database
Jul 08 20:08:25 vdr01 vdr[1432]: scraper2vdr: Loading Image content from Database...
Jul 08 20:08:25 vdr01 vdr[1432]: scraper2vdr: Got 0 new/updated Images (found 0 not available images) in 0s from Database
Jul 08 20:08:39 vdr01 epgd[1548]: State now 'busy (scraping)'
Jul 08 20:08:39 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47248 client connection accepted
Jul 08 20:08:39 vdr01 vdr[1432]: [1547] SVDRP vdr01 > 127.0.0.1:47248 server created
Jul 08 20:08:39 vdr01 epgd[1548]: Send 'PLUG epg2vdr STATE busy (scraping)' to '127.0.0.1:6419'
Jul 08 20:08:39 vdr01 vdr[1432]: epg2vdr: Got epgd state 'busy (scraping)' (5)
Jul 08 20:08:39 vdr01 vdr[1432]: epg2vdr: Change handler state to 'standby'
Jul 08 20:08:39 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47248 lost connection to client
Jul 08 20:08:39 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47248 connection closed
Jul 08 20:08:39 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47248 server destroyed
Jul 08 20:08:41 vdr01 epgd[1548]: SCRAP: Scraping new recordings, 2 pending
Jul 08 20:08:41 vdr01 epgd[1548]: -------------------------------------------------------
Jul 08 20:08:41 vdr01 epgd[1548]: Found new recording 'Pandora'/'Ein Herz kann man nicht reparieren'
Jul 08 20:08:41 vdr01 epgd[1548]: SCRAP: Found active event for recording 'Pandora'
Jul 08 20:08:41 vdr01 epgd[1548]: -------------------------------------------------------
Jul 08 20:08:41 vdr01 epgd[1548]: Found new recording 'Die Goldbergs'/'Beverly im Schönheitsrausch'
Jul 08 20:08:41 vdr01 epgd[1548]: SCRAP: Found active event for recording 'Die Goldbergs'
Jul 08 20:08:41 vdr01 epgd[1548]: -------------------------------------------------------
Jul 08 20:08:41 vdr01 epgd[1548]: SCRAP: Scraping 2 new recordings done
Jul 08 20:08:41 vdr01 epgd[1548]: State now 'standby'
Jul 08 20:08:41 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47250 client connection accepted
Jul 08 20:08:41 vdr01 vdr[1432]: [1547] SVDRP vdr01 > 127.0.0.1:47250 server created
Jul 08 20:08:41 vdr01 epgd[1548]: Send 'PLUG epg2vdr STATE standby' to '127.0.0.1:6419'
Jul 08 20:08:41 vdr01 vdr[1432]: epg2vdr: Got epgd state 'standby' (1)
Jul 08 20:08:41 vdr01 vdr[1432]: epg2vdr: Change handler state to 'active'
Jul 08 20:08:41 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47250 lost connection to client
Jul 08 20:08:41 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47250 connection closed
Jul 08 20:08:41 vdr01 vdr[1432]: [1547] SVDRP vdr01 < 127.0.0.1:47250 server destroyed
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] PANIC: watchdog timer expired - exiting!
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] ERROR: cStateKey::~cStateKey() called without releasing the lock first (tid=1432, lock=1 Timers, key=0x55fc1ebc9be0)
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] ABORT!
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cStateKey::~cStateKey() calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libc.so.6 at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: Magick: abort due to signal 6 (SIGABRT) "Abort"...
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libc.so.6 on_exit at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libc.so.6 at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libpthread.so.0 at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libpthread.so.0 pthread_mutex_lock calling __GI___pthread_mutex_lock at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cMutex::Lock() calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cThreadLock::Lock(cThread*) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cDevice::SetCamSlot(cCamSlot*) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cCamSlot::Assign(cDevice*, bool) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cDevice::Detach(cReceiver*) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cDevice::DetachAllReceivers() calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cDvbDevice::DetachAllReceivers() calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cDevice::GetDevice(cChannel const*, int, bool, bool) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr cRecordControls::Start(cTimers*, cTimer*, bool) calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr main calling ?? at ??:0
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /lib/x86_64-linux-gnu/libc.so.6 __libc_start_main at ??:?
Jul 08 20:08:46 vdr01 vdr[1432]: [1432] /usr/bin/vdr _start calling ?? at ??:0
Jul 08 20:08:46 vdr01 yavdr-frontend[1491]: INFO:pydbus2vdr:VDR Status: stopped
Jul 08 20:08:46 vdr01 yavdr-frontend[1491]: DEBUG:softhddevice:g-dbus-error-quark: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name de.tvdr.vdr was not provided by any .service files (2)
Jul 08 20:08:46 vdr01 systemd[1]: vdr.service: Main process exited, code=killed, status=6/ABRT
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:SystemdUnitFrontend:init SystemdUnit with name: kodi and fe_type: unit
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:SystemdUnitFrontend:set_unit_name: kodi.service
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:called set_next_fe with fe_type=kodi, fe_name=
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:called switch()
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:called stop(extern=False)
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:stop: current frontend is VDR-Frontend
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:self.frontends[0].is_running: None
Jul 08 20:09:09 vdr01 yavdr-frontend[1491]: DEBUG:yaVDRFrontend:switch(): got result (True, 'OK')

Display More

kfb77 · July 9, 2021 at 9:16 AM

Noch eine kleine Info, die ich aus dem markad Log dabei sehen kann:

Jede Aufnahme, die tatsächlich startet, erzeugt:

Code

markad: cStatusMarkAd::Start(): executing "/usr/bin"/markad  -v  -I  -R  --autologo=2  -l "/var/lib/markad" --online=2 before "/video/Pandora/Ein_Herz_kann_man_nicht_>

Die gibt es aber nur von einer Aufnahme, also knallt es schon beim Start der 2. Aufnahme.

seahawk1986 · July 9, 2021 at 9:41 AM

Anhand des Logs ist mir nicht völlig klar, was da alles passiert - kannst du mal ein ungekürztes Log posten (journalctl -b -l bzw. für einen Zeitraum von mindestens 5 Minuten um die Aufnahme herum) und zeigen, was die Skripte machen, die um die Aufnahmen herum ausgeführt werden?

Generell würde ich da erst mal Komplexität rausnehmen und mich dann hocharbeiten - also alle nicht essentiellen Skripte und Plugins (außer das Zeug fürs CAM, dbus2vdr und das Ausgabeplugin) deaktivieren (insbesondere epgd/epg2vdr/scraper2vdr und epgsearch) und den Watchdog deaktivieren und dann mal schauen, ob man da mit vielen parallelen Aufnahmen und Umschalten das Problem reproduzieren kann - wenn der VDR hängt mit installierten Debug-Symbolen (vdr-dbg und dbg-Pakete für die Plugins) mit gdb an den VDR Prozess hängen, ein SIGSTOP senden und schauen, was er gerade in den einzelnen Threads macht.

Quote from MegaV0lt

Jul 08 20:08:46 vdr01 vdr[1432]: [1432] PANIC: watchdog timer expired - exiting!

Auf welche Zeit ist der Watchdog bei dir aktuell eingestellt? Bei yaVDR ist der nicht standardmäßig aktiv, weil es mir im Zweifelsfall lieber ist, dass der Thread für eine Aufnahme weiterläuft als unterbrochene Aufnahmen zu haben.

Fourty2 · July 9, 2021 at 11:53 AM

Das kenne ich doch irgendwoher...

Habe den VDSB Neustart deaktiviert und den Watchdog auf 300s gesetzt. Das reicht in der Regel, bis epgsearch, epg2vdr, scraper2vdr und der vdr mit dem Streit um das Aufnahmen-Lock durch sind.

Alternativ Aufnamestart bei manuell erzeugten Timer auf +/- 1 Min legen.

Stefan

MegaV0lt · July 11, 2021 at 8:50 AM

Die Timeoutsettings sind es vermutlich nicht, da der VDR ja komplett hängt, schwarzes Bild hat und nicht bedienbar ist.

Das mit den +-1 Min. hab ich auch gemacht, Nur manchmal vergisst man es, bzw. bin ich ja auch nicht immer vor Ort...

Der watchdog steht auf 30 Sekunden. Wenn der Zuschlägt, ist der VDR aber auch schon 30 Sekunden "Tot"

kls · November 30, 2022 at 10:01 AM

Quote from MegaV0lt

Passiert, wenn das letzte Device das noch frei ist umgeschaltet werden soll. (Meiner Meinung nach)

Gerade habe ich diese alte Meldung auf meiner TODO-Liste "ausgegraben".

Als Versuch habe ich mal auf einem Raspberry Pi mit zwei SatIP-Devices zwei Timer definiert, die gleichzeitig starten und von unterschiedlichen Transpondern aufnehmen sollen. Live habe ich auf einen dritten Transponder geschaltet. Die Timer starteten problemlos und Live war dann auf dem Kanal des zuletzt gestarteten Timers.

MegaV0lt · November 30, 2022 at 10:13 AM

Blöde Frage: Könnte es am eventuel OSDTeletext liegen?

Nachstellen ist sehr schwer, da es nicht immer auftritt

Crash bei drei gleichzeitig startenden Aufnahmen

Participate now!

Users Viewing This Thread