DVD erzegen dauert Stunden

eurofinder · 16. Mai 2006

Hallo,

habe seit kurzem das Problem, dass die Generierung eines ISO-Files mit dem Burn-Plugin unendlich lange dauert. Habe gestern zwei Folgen "Julia" vom ZDF mit burn-plugin als DVD-ISO berechnen lassen. Das hat gute sieben Stunden gedauert.

Installation ist eine gen2vdr rc4. Das Problem hatte ich vorher nicht, da war das in ca. 30 - 45 Minuten erledigt. Datein benötigen ca. 3600 MByte.

Hat noch jemand das Problem? Woran kann es liegen?
Gruß
Eurofinder

NeoTrace · 16. Mai 2006

schau mal im log nach bzw post ihn, das wär wahrscheinlich hilfreicher
als das jetzt alle zum raten anfangen

eurofinder · 16. Mai 2006

So,

habe inzwischen mal die gen2vdr auf vdr-1.4.0 mit Bigpatch und Pluginpaket von Frank99 auf einen aktuelleren Stand gebracht. Burn-plugin ist hier 0.0.009 - > hat aber nichts gebracht. Dauert noch genauso.

Was ich nicht verstehe ist, dass das früher lief. Ich habe da keine Änderungen an irgendwelchen Einstellungen vorgenommen.

Hier mal ein Auszug aus dem Log:

++ started: sh -c 'vdrburn.sh SYNC '/tmp/.vdr-burn.h0c5sk' 0 '/video/Tatort/Tatort/Tödliches_Vertrauen/2006-05-14.20.05.99.99.rec''
logger: <SYNC /tmp/.vdr-burn.h0c5sk 0 /video/Tatort/Tatort/Tödliches_Vertrauen/2006-05-14.20.05.99.99.rec>
logger: Starting <nice -n 19 vdrsync.pl -cut -o /tmp/.vdr-burn.h0c5sk/VDRSYNC.0 /video/Tatort/Tatort/Tödliches_Vertrauen/2006-05-14.20.05.99.99.rec>
Parameter validation not complete yet
Initialising and analysing the streams....
****************************************
READING INDEX FILE, please be patient
****************************************
Got only 133419, you wanted 133408 and last IFrame is 133407...
Got only 133419, you wanted 133408 and last IFrame is 133407...
Got only 133419, you wanted 133408 and last IFrame is 133407...

10 Mbytes of 3458 read

Warning! Probably a VDR Version > 1.3.19 was used to record this broadcast.
Warning! AC3 processing highly experimental!

20 Mbytes of 3458 read
30 Mbytes of 3458 read
40 Mbytes of 3458 read
50 Mbytes of 3458 read
60 Mbytes of 3458 read

Kann es sein, das es am "nice -n 19" liegt?

Wie sieht eure vdrburn.sh aus?

Wenn das noch nicht reicht, dann bitte kurz mitteilen, welche Infos ihr noch braucht.
Gruß
Eurofinder

foobar42 · 16. Mai 2006

Zitat

Original von eurofinder
Kann es sein, das es am "nice -n 19" liegt?

Eigentlich nicht, es sei denn du hättest x vorrangige Prozesse über so lange Zeit laufen, die dem vdrburn keine Luft zum Atmen ließen.

kilroy · 16. Mai 2006

Zitat

Original von eurofinder
Wenn das noch nicht reicht, dann bitte kurz mitteilen, welche Infos ihr noch braucht.

Standardfrage: Hast Du DMA bei der Festplatte aktiviert? Was ergibt hdparm /dev/hda
bzw.hdx entsprechend Deiner Konfiguration? Lass' auch mal ein top nebenbei laufen, um zu
sehen, wo die CPU Leistung bleibt.

eurofinder · 16. Mai 2006

Hilft das evntl. jemanden - ich kann nichts besonderes feststellen.

Burn-plugin wurde so gegen 14.30 Uhr gestartet - glaube ich.

Hier die Infos zu hdparm und top und df:
vdr01 ~ # hdparm /dev/hda

/dev/hda:
multcount = 16 (on)
IO_support = 1 (32-bit)
unmaskirq = 1 (on)
using_dma = 1 (on)
keepsettings = 0 (off)
readonly = 0 (off)
readahead = 256 (on)
geometry = 30401/255/63, sectors = 488397168, start = 0
vdr01 ~ # hdparm -Tt /dev/hda

/dev/hda:
Timing buffer-cache reads: 780 MB in 2.00 seconds = 389.86 MB/sec
Timing buffered disk reads: 154 MB in 3.02 seconds = 50.98 MB/sec
vdr01 ~ # hdparm -i /dev/hda

/dev/hda:

Model=SAMSUNG SP2514N, FwRev=VF100-33, SerialNo=S08BJ10Y928833
Config={ Fixed }
RawCHS=16383/16/63, TrkSize=34902, SectSize=554, ECCbytes=4
BuffType=DualPortCache, BuffSize=8192kB, MaxMultSect=16, MultSect=16
CurCHS=16383/16/63, CurSects=16514064, LBA=yes, LBAsects=268435455
IORDY=on/off, tPIO={min:240,w/IORDY:120}, tDMA={min:120,rec:120}
PIO modes: pio0 pio1 pio2 pio3 pio4
DMA modes: mdma0 mdma1 mdma2
UDMA modes: udma0 udma1 udma2 udma3 udma4 *udma5
AdvancedPM=no WriteCache=enabled

* signifies the current active mode

vdr01 ~ # df
Filesystem 1K-blocks Used Available Use% Mounted on
/dev/hda2 8064304 6354216 1300432 84% /
udev 127316 2612 124704 3% /dev
none 127316 0 127316 0% /dev/shm
/dev/hdb1 153826820 118063872 27948936 81% /mnt/hdb1
/dev/hda5 232013976 156352880 63875412 71% /mnt/hda5
/dev/hda1 23302 13118 8981 60% /boot
vdr01 ~ #

Cpu(s): 6.6% us, 73.8% sy, 16.6% ni, 0.0% id, 0.0% wa, 0.3% hi, 2.6% si
Mem: 254632k total, 250332k used, 4300k free, 1268k buffers
Swap: 265064k total, 126088k used, 138976k free, 95564k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2984 at 25 0 82732 34m 544 R 23.3 13.8 117:27.67 atd
609 root 39 19 14724 5408 1492 R 3.7 2.1 2:57.12 noad
18258 root 39 19 14612 5264 1492 R 3.7 2.1 2:07.39 noad
10874 root 39 19 21668 6388 1508 R 3.3 2.5 3:33.16 noad
10126 root 34 19 14668 5384 1492 R 3.3 2.1 1:12.44 noad
21602 root 35 19 34404 3644 372 R 2.7 1.4 0:22.23 tcrequant
1269 root 15 0 117m 46m 2500 S 1.7 18.5 0:14.16 vdr
1260 root 15 0 117m 46m 2500 S 1.3 18.5 0:17.38 vdr
1261 root 15 0 117m 46m 2500 S 1.3 18.5 0:13.43 vdr
2708 root 15 0 1480 564 468 S 1.0 0.2 8:57.14 metalog
6280 root 34 19 117m 46m 2500 R 1.0 18.5 2:19.76 vdr
6332 root 34 19 117m 46m 2500 R 1.0 18.5 3:27.55 vdr
22624 root 15 0 117m 46m 2500 S 1.0 18.5 0:18.03 vdr
2427 root 15 0 117m 46m 2500 S 0.7 18.5 1:44.36 vdr
1268 root 15 0 117m 46m 2500 S 0.7 18.5 0:11.15 vdr
12862 root 15 0 117m 46m 2500 S 0.3 18.5 7:06.25 vdr
10518 root 16 0 6148 1752 1428 R 0.3 0.7 0:00.06 sshd
7060 root 16 0 1916 1024 792 R 0.3 0.4 0:00.03 top
1 root 16 0 1396 440 420 S 0.0 0.2 0:00.46 init
2 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
3 root 10 -5 0 0 0 S 0.0 0.0 0:00.03 events/0
4 root 10 -5 0 0 0 S 0.0 0.0 0:00.01 khelper
5 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kthread
8 root 20 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid
7 root 10 -10 0 0 0 S 0.0 0.0 0:00.00 vesafb
82 root 10 -5 0 0 0 S 0.0 0.0 0:01.29 kblockd/0
85 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 khubd
140 root 15 0 0 0 0 S 0.0 0.0 0:02.99 pdflush
141 root 15 0 0 0 0 S 0.0 0.0 0:04.45 pdflush
143 root 18 -5 0 0 0 S 0.0 0.0 0:00.00 aio/0
142 root 15 0 0 0 0 S 0.0 0.0 0:06.21 kswapd0
144 root 15 0 0 0 0 S 0.0 0.0 0:00.00 cifsoplockd
145 root 25 0 0 0 0 S 0.0 0.0 0:00.00 jfsIO
146 root 25 0 0 0 0 S 0.0 0.0 0:00.00 jfsCommit
147 root 25 0 0 0 0 S 0.0 0.0 0:00.00 jfsSync
148 root 18 -5 0 0 0 S 0.0 0.0 0:00.00 xfslogd/0
149 root 18 -5 0 0 0 S 0.0 0.0 0:00.00 xfsdatad/0
150 root 15 0 0 0 0 S 0.0 0.0 0:00.44 xfsbufd
736 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kseriod
808 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 ata/0
842 root 16 0 0 0 0 S 0.0 0.0 0:02.84 kjournald
[2]+ Stopped top

Bin für jede Anregung und Idee offen.
/dev/hdb1 ist übrigens ein Festplatte, auf der "nur" vdr-Dateien lagern, die im /video-Verzeichnis verlinkt ist.

Gruß
Eurofinder

eurofinder · 17. Mai 2006

Moin,

noch mal eine Nachfrage. Wie lange dauert es denn bei euch eine DVD aus sagen wir mal zwei Serienaufnahmen von ZDF zu je 45 Minuten als DVD mit burn-plugin umzurechnen?

Gruß
Eurofinder

hellimat · 17. Mai 2006

Hallo,

schau Dir den top noch mal genau an, 73,8% Last system und 0% idle! Jetzt musst du nur noch rausfinden welcher Prozess diese Last erzeugt. Das wird auf jeden Fall die Ursache sein, da burn ja mit nem nice 19 läuft und nicht mehr zum Zuge kommt.

viele Grüße
Matthias

wofritz · 17. Mai 2006

Zitat

73,8% Last system

Sowas sieht man auch, wenn jemand das syslog zuspammt. Mach burn massenhaft Fehlermeldungen? Dann wird Dein Datenstrom nicht in Ordnung sein.

Wolfgang

kilroy · 17. Mai 2006

Zitat

Original von eurofinder

Code

Cpu(s):  6.6% us, 73.8% sy, 16.6% ni,  0.0% id,  0.0% wa,  0.3% hi,  2.6% si
Mem:    254632k total,   250332k used,     4300k free,     1268k buffers
Swap:   265064k total,   126088k used,   138976k free,    95564k cached


  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 2984 at        25   0 82732  34m  544 R 23.3 13.8 117:27.67 atd
  609 root      39  19 14724 5408 1492 R  3.7  2.1   2:57.12 noad
18258 root      39  19 14612 5264 1492 R  3.7  2.1   2:07.39 noad
10874 root      39  19 21668 6388 1508 R  3.3  2.5   3:33.16 noad
10126 root      34  19 14668 5384 1492 R  3.3  2.1   1:12.44 noad
21602 root      35  19 34404 3644  372 R  2.7  1.4   0:22.23 tcrequant

Alles anzeigen

Warum verbraucht Dein atd denn soviel Rechenzeit? Was steht dazu im (sys)log?

Weiter fällt mir auf, daß Du noad (dieses Werbeerkennungsdingens?) und tcrequant nutzt.
Beides dürfte die Bearbeitungszeit erhöhen.

Wenn ich für die Kids eine DVD mit 8 Folgen Chip&Chap erstelle (~3,5GB), dauert dies
ohne noad, ohne requantisieren, mit Erstellen eines ISOs unter einer Stunde (NFS).

PS. Bitte paste Systemausgaben bitte mit CODE-Tag. Das erhöht die Lesbarkeit.

eurofinder · 17. Mai 2006

kilroy:

Wo finde ich den das Log zu atd und wozu dient atd eigentlich?

top sieht übrigens genauso aus, auch wenn noad nicht läuft. Ich habe top nur gerade zu einem Zeitpunkt gemacht, wo noad mal was zu erledigen hatte und tcrequant gerade begonnen hat.

Ich kann mich hier nur wiederholen - ich habe am System nichts geändert - abgesehen jetzt mal davon, was ich oben bereits geschrieben habe. Die lange Laufzeit war ja vorher bei gleichen Einstellungen nicht zu verzeichnen.

Das dvd-log gibt nur wenige Meldungen aus.

Gruß
Eurofinder

foobar42 · 17. Mai 2006

Zitat

Original von hellimat
schau Dir den top noch mal genau an, 73,8% Last system und 0% idle! Jetzt

Hm, das kommt schon hin, wenn user- und nice-Prozesse addiert werden. In gehe mal davon aus, dass die nicht unter der sys-Last subsummiert sind.

Aber: Ich habe es nicht nachgerechnet, aber Pi*Daumen ist die Summe der in der Prozessliste auftauchenden Prozesse < 100% Last

Falls das stimmt, laufen offenbar noch versteckte Prozesse - das wäre mir verdächtig. Genauso wie dieser "hochgetaktete" atd, der eigentlich nur darauf wartet, zeitgesteuerte Prozesse anzuwerfen.

Falls mein Eindruck in Sachen Prozessliste mich getäuscht hat, bitte dieses Posting nach /dev/null entsorgen.

eurofinder · 17. Mai 2006

Hallöchen,

bin inzwischen einen Schritt weiter.
Das Verzeichnis /var/log/crond und /var/log/everything laufen bei mir permanent voll.
Hier mal ein Auszug
May 17 18:23:54 [atd] File a002cf01228557 is in wrong format - aborting
May 17 18:23:54 [atd] File a004590123440b is in wrong format - aborting
May 17 18:23:55 [atd] File a004b201236b4d is in wrong format - aborting
May 17 18:23:55 [atd] File a004d901237c87 is in wrong format - aborting
May 17 18:23:55 [atd] File a004de012380ba is in wrong format - aborting
May 17 18:23:55 [atd] File a004df012380ce is in wrong format - aborting
May 17 18:23:55 [atd] File a004e501238155 is in wrong format - aborting
May 17 18:23:55 [atd] File a004ec01238227 is in wrong format - aborting
May 17 18:23:55 [atd] File a00457012342fc is in wrong format - aborting
May 17 18:23:55 [atd] File a00458012343a2 is in wrong format - aborting
May 17 18:23:55 [atd] File a004b101236b02 is in wrong format - aborting
May 17 18:23:55 [atd] File a005020123916d is in wrong format - aborting
May 17 18:23:55 [atd] File a004d801237c6c is in wrong format - aborting
May 17 18:23:55 [atd] File a004e70123817d is in wrong format - aborting
May 17 18:23:55 [atd] File a002cf01228557 is in wrong format - aborting
May 17 18:23:55 [atd] File a004590123440b is in wrong format - aborting
May 17 18:23:55 [atd] File a004b201236b4d is in wrong format - aborting
May 17 18:23:55 [atd] File a004d901237c87 is in wrong format - aborting
May 17 18:23:55 [atd] File a004de012380ba is in wrong format - aborting
May 17 18:23:55 [atd] File a004df012380ce is in wrong format - aborting
May 17 18:23:55 [atd] File a004e501238155 is in wrong format - aborting
May 17 18:23:55 [atd] File a004ec01238227 is in wrong format - aborting
May 17 18:23:55 [atd] File a00457012342fc is in wrong format - aborting
May 17 18:23:55 [atd] File a00458012343a2 is in wrong format - aborting
May 17 18:23:55 [atd] File a004b101236b02 is in wrong format - aborting
May 17 18:23:55 [atd] File a005020123916d is in wrong format - aborting
May 17 18:23:55 [atd] File a004d801237c6c is in wrong format - aborting
May 17 18:23:55 [atd] File a004e70123817d is in wrong format - aborting
May 17 18:23:55 [atd] File a002cf01228557 is in wrong format - aborting
May 17 18:23:55 [atd] File a004590123440b is in wrong format - aborting
May 17 18:23:55 [atd] File a004b201236b4d is in wrong format - aborting
May 17 18:23:55 [atd] File a004d901237c87 is in wrong format - aborting
May 17 18:23:55 [atd] File a004de012380ba is in wrong format - aborting
May 17 18:23:55 [atd] File a004df012380ce is in wrong format - aborting
May 17 18:23:55 [atd] File a004e501238155 is in wrong format - aborting
May 17 18:23:55 [atd] File a004ec01238227 is in wrong format - aborting
May 17 18:23:55 [atd] File a00457012342fc is in wrong format - aborting
May 17 18:23:55 [atd] File a00458012343a2 is in wrong format - aborting

Kann damit jemand was anfangen? Wo kommt das her und wie schalte ich das ab?

Gruß
Eurofinder

kilroy · 17. Mai 2006

Sagt mir ad hoc nichts. Hast Du es mal bei Google eingeworfen?

eurofinder · 17. Mai 2006

Bin gerade dabei, ob ich etwas finde.
Gruß
Eurofinder

eurofinder · 17. Mai 2006

So,

habe das Rätsel hoffe ich gelöst.

in /var/spool/at/atjobs und /var/spool/at/atspool ware jede Menge Dateien enthalten, die auf nicht mehr vorhandene vdr-Files verwiesen. Habe diese mal kurzerhand gelöscht.

Jetzt läuft das hier auch wieder.

Gruß
Eurofinder

DVD erzegen dauert Stunden

Jetzt mitmachen!

Teilen