[yaVDR 0.5 stable ] VDR (server) crashed in unregelmässigen Abständen

dxwilli · 14. Februar 2015

Hallo

habe hier merkwürdige Abstürze des VDR, heute nachmittag schon 4 mal:

Feb 14 18:45:45 vdr: last message repeated 11 times
Feb 14 18:45:45 VDRServer vdr: [9312] connect from 192.168.1.107, port 46805 - accepted
Feb 14 18:46:45 VDRServer vdr: [9312] PANIC: watchdog timer expired - exiting!
Feb 14 18:46:45 VDRServer vdr: [12015] streamdev-livestreaming thread ended (pid=9312, tid=12015)
Feb 14 18:46:45 VDRServer vdr: [12017] TS buffer on device 2 thread ended (pid=9312, tid=12017)
Feb 14 18:46:45 VDRServer vdr: [12016] buffer stats: 230864 (2%) used
Feb 14 18:46:45 VDRServer vdr: [12016] receiver on device 2 thread ended (pid=9312, tid=12016)
Feb 14 18:46:45 VDRServer vdr: [12014] streamdev-writer thread ended (pid=9312, tid=12014)
Feb 14 18:46:45 VDRServer vdr: [9312] buffer stats: 231240 (6%) used
Feb 14 18:46:45 VDRServer vdr: [9443] GraphTFT plugin display thread ended (pid=9312)
Feb 14 18:46:45 VDRServer vdr: [9312] GraphTFT plugin try to stop communication thread
Feb 14 18:46:45 VDRServer vdr: [9457] fatal error, server exiting: UngÃ¼ltiger Dateideskriptor
Feb 14 18:46:45 VDRServer vdr: [9457] streamdev server thread ended (pid=9312, tid=9457)
Feb 14 18:46:46 VDRServer vdr: scraper2vdr: Statement statistic of last 300 seconds from '':
Feb 14 18:46:46 VDRServer vdr: scraper2vdr: calls 5 in 1.74ms; total 62 [select uuid, inssp, updsp, name, version, dbapi, lastupd, nextupd, state, master, ip from vdrs where uuid = ?;]
Feb 14 18:46:46 VDRServer vdr: scraper2vdr: calls 1 in 0.12ms; total 11 [select rec_path, rec_start, movie_id, series_id, episode_id from recordings where uuid = ? and scrap_new = 0]
Feb 14 18:46:48 VDRServer vdr: [9312] ERROR: thread 9442 won't end (waited 3 seconds) - canceling it...
Feb 14 18:46:48 VDRServer vdr: epg2vdr: Update thread ended (pid=9312)
Feb 14 18:46:48 VDRServer vdr: [9468] update thread started thread ended (pid=9312, tid=9468)
Feb 14 18:46:48 VDRServer vdr: [9393] Leaving cXineRemote thread
Feb 14 18:46:48 VDRServer vdr: [9393] XineRemote control thread ended (pid=9312, tid=9393)
Feb 14 18:46:48 VDRServer vdr: epg2vdr: Trying to re-connect to database!
Feb 14 18:46:48 VDRServer vdr: epg2vdr: Statement 'select uuid, inssp, updsp, name, version, dbapi, lastupd, nextupd, state, master, ip from vdrs where uuid = ?;' with (1) in parameters and (11) out bindings prepared
Feb 14 18:46:48 VDRServer vdr: epg2vdr: Statement 'insert into vdrs set uuid = ?, inssp = ?, updsp = ?, name = ?, version = ?, dbapi = ?, lastupd = ?, nextupd = ?, state = ?, master = ?, ip = ?;' with (11) in parameters and (0) out bindings prepared
Feb 14 18:46:48 VDRServer vdr: epg2vdr: Statement 'update vdrs set updsp = ?, name = ?, version = ?, dbapi = ?, lastupd = ?, nextupd = ?, state = ?, master = ?, ip = ? where uuid = ?;' with (10) in parameters and (0) out bindings prepared
Feb 14 18:46:48 VDRServer kernel: [18445.653593] section handler[9405]: segfault at 0 ip 00007ff0aef39600 sp 00007ff0a2ffb450 error 4 in libvdr-epg2vdr.so.2.0.6[7ff0aef19000+32000]
Feb 14 18:46:48 VDRServer kernel: [18445.781749] init: vdr main process (9312) killed by SEGV signal
Feb 14 18:46:48 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 18:46:48 VDRServer kernel: [18445.798338] init: vdr-exit-other main process (12060) terminated with status 1
Feb 14 18:46:48 VDRServer vdr: [12065] VDR version 2.0.6 started
Feb 14 18:46:48 VDRServer vdr: [12065] switched to user 'vdr'
Feb 14 18:46:48 VDRServer vdr: [12065] codeset is 'UTF-8' - known
Feb 14 18:46:48 VDRServer vdr: [12065] found 28 locales in /usr/share/locale

Habe nur den Speicher auf 12 Gb erhöht. Kann jemand ergründen, was da los ist ?

Gruss Willi

dxwilli · 14. Februar 2015

Ich hab das Syslog nochmal durchforstet. An der Speichererweiterung kann es nicht liegen, die Abstürze waren auch vorher da.

Merkwürdig, eine Regelmässigkeit, fast immer nach 1h und 2 min:

Code

Feb 14 08:12:39 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 08:16:26 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 08:31:48 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 09:06:28 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 14:36:21 VDRServer vdr-crash: vdr exit with exit status 6 . Restarting
Feb 14 15:38:26 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 16:40:55 VDRServer vdr-crash: vdr exit with exit status 6 . Restarting
Feb 14 17:44:59 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 18:46:48 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 19:50:03 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting

Jedesmal ging das auf dem Server voraus:

Code

Feb 14 15:38:26 VDRServer vdr: [3290] PANIC: watchdog timer expired - exiting!
Feb 14 15:38:26 VDRServer vdr: [3477] streamdev-livestreaming thread ended (pid=3290, tid=3477)
Feb 14 15:38:26 VDRServer vdr: [3479] TS buffer on device 2 thread ended (pid=3290, tid=3479)
Feb 14 15:38:26 VDRServer vdr: [3478] buffer stats: 242144 (2%) used
Feb 14 15:38:26 VDRServer vdr: [3478] receiver on device 2 thread ended (pid=3290, tid=3478)
Feb 14 15:38:26 VDRServer vdr: [3476] streamdev-writer thread ended (pid=3290, tid=3476)
Feb 14 15:38:26 VDRServer vdr: [3290] buffer stats: 242520 (6%) used
Feb 14 15:38:26 VDRServer kernel: [ 7173.651763] streamdev serve[3434]: segfault at 7f953bdd79d0 ip 00007f96024a6f60 sp 00007f9548ff0bc8 error 4 in libpthread-2.15.so[7f960249a000+18000]
Feb 14 15:38:26 VDRServer kernel: [ 7173.811864] init: vdr main process (3290) killed by SEGV signal
Feb 14 15:38:26 VDRServer vdr-crash: vdr exit with signal SEGV . Restarting
Feb 14 15:38:26 VDRServer kernel: [ 7173.827532] init: vdr-exit-other main process (4093) terminated with status 1
Feb 14 15:38:27 VDRServer vdr: [4098] VDR version 2.0.6 started
Feb 14 15:38:27 VDRServer vdr: [4098] switched to user 'vdr'

Alles anzeigen

Gruss Willi

TheChief · 14. Februar 2015

Also anscheinend hast du ja täglich neue Probleme, was machst du denn immer? (Nicht erst gemeint)

Würd halt wie immer einen Backtrace anhängen. Einmal scheints ja streamdev zu betreffen, ein anderes mal epg2vdr. Netzwerkprobleme?

dxwilli · 14. Februar 2015

nein, Netzwerk ist iO. Dieses Problem trat erst nach meiner Client Neuinstallation auf.

Eben ist es 20.52, und der VDR crashte wieder.

TheChief · 14. Februar 2015

Naja, dann starte vdr-dbg und lad den BT hoch.

Wenn es aber auf dem Server crashed, kann es natütlich auch sein, dass es dann auf dem Client crashed, wenn plötzlich die VDR Verbindung weg ist.

dxwilli · 14. Februar 2015

was mir gerade noch auf dem Clientlog auffällt, die Abstürze folgen immer einer EPGSYNC Anfrage:

Spoiler anzeigen

FFeb 14 20:46:52 VDRStube vdr: scraper2vdr: Statement statistic of last 180 seconds from '':
Feb 14 20:46:52 VDRStube vdr: scraper2vdr: calls 3 in 1.76ms; total 429 [select uuid, inssp, updsp, name, version, dbapi, lastupd, nextupd, state, master, ip from vdrs where uuid = ?;]
Feb 14 20:46:52 VDRStube vdr: scraper2vdr: calls 1 in 0.80ms; total 137 [select eventid, channelid, masterid, scrseriesid, scrseriesepisode, scrmovieid, scrsp from events where ((scrseriesid is not null and scrseriesid > 0) or (scrmovieid is not null and scrmovieid > 0)) and scrsp > ? order by inssp]
Feb 14 20:46:52 VDRStube vdr: scraper2vdr: calls 1 in 0.34ms; total 70 [select rec_path, rec_start, movie_id, series_id, episode_id from recordings where uuid = ? and scrap_new = 0]
Feb 14 20:47:37 VDRStube vdr: video: 4:40:47.935 +36 370 0/\ms 30+2 v-buf
Feb 14 20:48:01 VDRStube vdr: [1747] timersync: syncing with 192.168.1.108
Feb 14 20:48:01 VDRStube vdr: [1747] SvdrpService: connected to 192.168.1.108:6419
Feb 14 20:48:01 VDRStube vdr: [1747] timersync: Connected to 192.168.1.108:6419
Feb 14 20:48:37 VDRStube vdr: video: 4:41:47.935 +36 370 0/\ms 29+2 v-buf
Feb 14 20:49:37 VDRStube vdr: video: 4:42:47.935 +36 402 0/\ms 33+2 v-buf
Feb 14 20:49:52 VDRStube vdr: scraper2vdr: Statement statistic of last 180 seconds from '':
Feb 14 20:49:52 VDRStube vdr: scraper2vdr: calls 3 in 1.71ms; total 432 [select uuid, inssp, updsp, name, version, dbapi, lastupd, nextupd, state, master, ip from vdrs where uuid = ?;]
Feb 14 20:49:52 VDRStube vdr: scraper2vdr: calls 1 in 0.79ms; total 138 [select eventid, channelid, masterid, scrseriesid, scrseriesepisode, scrmovieid, scrsp from events where ((scrseriesid is not null and scrseriesid > 0) or (scrmovieid is not null and scrmovieid > 0)) and scrsp > ? order by inssp]
Feb 14 20:50:37 VDRStube vdr: video: 4:43:47.935 +36 338 0/\ms 23+2 v-buf
Feb 14 20:51:27 VDRStube vdr: [1747] Starting scheduled EpgSync
Feb 14 20:51:27 VDRStube vdr: [5793] epgsync thread started (pid=1747, tid=5793, prio=high)
Feb 14 20:51:27 VDRStube vdr: [5793] SvdrpService: connected to 192.168.1.108:6419
Feb 14 20:51:37 VDRStube vdr: video: 4:44:47.935 +36 274 0/\ms 26+2 v-buf
Feb 14 20:51:52 VDRStube vdr: [5794] epg data writer thread started (pid=1747, tid=5794, prio=low)
Feb 14 20:51:52 VDRStube vdr: [5794] epg data writer thread ended (pid=1747, tid=5794)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (0)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (1)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (2)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (3)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (4)
Feb 14 20:52:27 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (5)
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (6)
Feb 14 20:52:28 VDRStube vdr: video: decoder buffer empty, duping frame (222070/185521) 0 v-buf
Feb 14 20:52:28 VDRStube vdr: video: 4:45:38.935+8888 0 0/\ms 0+0 v-buf
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (7)
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (8)
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (9)
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamDevice::GetTSPacket: GetChecked: NOTHING (10)
Feb 14 20:52:28 VDRStube vdr: [5487] cStreamdevDevice::GetTSPacket(): disconnected
Feb 14 20:52:28 VDRStube vdr: [5487] ERROR: streamdev-client: Couldn't connect to 192.168.1.108:2004: Verbindungsaufbau abgelehnt
Feb 14 20:52:28 VDRStube vdr: [5488] TS buffer on device 11 thread ended (pid=1747, tid=5488)
Feb 14 20:52:28 VDRStube vdr: [5487] buffer stats: 358704 (17%) used
Feb 14 20:52:28 VDRStube vdr: [5487] receiver on device 11 thread ended (pid=1747, tid=5487)
Feb 14 20:52:29 VDRStube vdr: [5793] svdrpservice: lost connection to 192.168.1.108
Feb 14 20:52:29 VDRStube vdr: [5793] EpgSync: LSTE error 0
Feb 14 20:52:29 VDRStube vdr: [5793] svdrpservice: unable to send command to 192.168.1.108. Socket is closed
Feb 14 20:52:30 VDRStube vdr: [5799] epg data writer thread started (pid=1747, tid=5799, prio=low)
Feb 14 20:52:30 VDRStube vdr: [5793] epgsync thread ended (pid=1747, tid=5793)
Feb 14 20:52:31 VDRStube vdr: [5799] epg data writer thread ended (pid=1747, tid=5799)
Feb 14 20:52:37 VDRStube vdr: video: decoder buffer empty, duping frame (222520/185521) 0 v-buf
Feb 14 20:52:37 VDRStube vdr: video: 4:45:38.935+8888 0 0/\ms 0+0 v-buf
Feb 14 20:52:39 VDRStube vdr: [1747] ERROR: streamdev-client: Couldn't connect to 192.168.1.108:2004: Verbindungsaufbau abgelehnt
Feb 14 20:52:45 VDRStube vdr: [1747] switching to channel 107
Feb 14 20:52:45 VDRStube vdr: [1747] [softhddev]SetPlayMode: 0
Feb 14 20:52:45 VDRStube vdr: [1747] [softhddev]SetVideoDisplayFormat: 1
Feb 14 20:52:45 VDRStube vdr: [1747] [softhddev]GetSpuDecoder:
Feb 14 20:52:45 VDRStube vdr: [5489] osdteletext-receiver thread ended (pid=1747, tid=5489)
Feb 14 20:52:45 VDRStube vdr: [1747] buffer stats: 0 (0%) used
Feb 14 20:52:45 VDRStube vdr: [1747] ERROR: Transfer-Mode kann nicht gestartet werden!eb 14 20:52:48 VDRStube vdr: [1747] ERROR: Transfer-Mode kann nicht gestartet werden!
Feb 14 20:52:48 VDRStube vdr: [1747] streamdev-client: Connected to server 192.168.1.108:2004 using protocol version 1.0
Feb 14 20:52:48 VDRStube vdr: [1747] streamdev-client: Command 'PRIO -100' rejected by 192.168.1.108:2004: 550 Priority not applicable
Feb 14 20:52:50 vdr: last message repeated 164 times
Feb 14 20:52:50 VDRStube vdr: [1747] streamdev-client: Connected to server 192.168.1.108:2004 using protocol version 1.0
Feb 14 20:52:50 VDRStube vdr: [1747] streamdev-client: Connected to server 192.168.1.108:2004 using protocol version 1.0

TheChief · 14. Februar 2015

Wozu epgsync, wenn du epgd laufen hast? Dann nimmt man epg2vdr.

dxwilli · 14. Februar 2015

Konnte es eben auf dem Client nachvollziehen. EPGSYNC ist auf 1 Stunde eingestellt, was sich mit den Crash Zeiten deckt.
Hab das von Hand angestossen, sofort gab es den Crash auf dem Server.

TheChief · 14. Februar 2015

Epgsync benutze ich nicht mehr seit epg2vdr. Und ohne BT wird dir keiner helfen können.

dxwilli · 14. Februar 2015

hab EPGSYNC mal deinstalliert, mal sehen, ob es das war.

dxwilli · 14. Februar 2015

was genau mache ich bei BT ?

TheChief · 14. Februar 2015

Ich meine einen Backtrace erstellen mit vdr-dbg.

dxwilli · 14. Februar 2015

ich glaube, Problem gelöst. Nach Deaktivieren von EPGSYNC gab es keinen Absturz mehr. Noch mal weiter beobachten, aber denke, das wars.

PS zu früh gefreut, eben wieder. Ich geh erstmal zu Bett

dxwilli · 15. Februar 2015

Morgen

musste nach dem Deinstallieren noch vdr neu starten. Nun ist anscheinend das Problem gelöst und die Abstürze
lagen wohlan dem Plugin 'epgsync'.

Gruss Willi

[yaVDR 0.5 stable ] VDR (server) crashed in unregelmässigen Abständen

Jetzt mitmachen!

Teilen