Verzögerung beim Bootvorgang

Hast Du Probleme mit Hardware, die durch die anderen Foren nicht abgedeckt werden? Schau auch in den "Tipps und Tricks"-Bereich.
Antworten
Plobiop
Beiträge: 2
Registriert: 31.07.2020 12:13:26

Verzögerung beim Bootvorgang

Beitrag von Plobiop » 31.07.2020 13:02:20

Hi,

Der Systemstart dauert sehr lang und ich kann mir keinen wirklichen Reim darauf machen. Laut der Ausgabe von 'dmesg' (NoPaste-Eintrag41102) tritt die Verzögerung nach Zeile 709 auf. Ohne die Maus passiert genau das gleiche. Also wahrscheinlich die Platten?

Habt ihr eine Idee?

DeletedUserReAsG

Re: Verzögerung beim Bootvorgang

Beitrag von DeletedUserReAsG » 31.07.2020 13:07:22

Meine Idee wäre:

Code: Alles auswählen

[    2.080726] md: resync of RAID array md126 
[…]
[   92.180354] raid6: sse2x1   gen() 10256 MB/s
Ich würde also das Problem beim RAID suchen – 90s wäre ‘n recht übllicher Timeout-Wert, da würde ich auch mal schauen. Es steht in der Zeit nicht zufällig „A start job is running […]“ auf dem Bildschirm?

Dass der USB-Kram gerade zu der Zeit hochkommt und ins Log malt, dürfte eher Koinzidenz sein.

Benutzeravatar
MSfree
Beiträge: 10686
Registriert: 25.09.2007 19:59:30

Re: Verzögerung beim Bootvorgang

Beitrag von MSfree » 31.07.2020 13:29:50

Code: Alles auswählen

systemd-analyze blame
?

Plobiop
Beiträge: 2
Registriert: 31.07.2020 12:13:26

Re: Verzögerung beim Bootvorgang

Beitrag von Plobiop » 31.07.2020 23:20:12

niemand hat geschrieben: ↑ zum Beitrag ↑
31.07.2020 13:07:22
Es steht in der Zeit nicht zufällig „A start job is running […]“ auf dem Bildschirm?
Nein, der Cursor blinkt. Ansonsten ist der Bildschirm dunkel. Nach der Wartezeit wird /dev/sdc2: clean, usw. ausgegeben. Ich hätte ansonsten auch keinen Grund anzunehmen, dass das RAID nicht so funktioniert wie es sollte.

systemd-analyze blame spuckt folgendes aus:

Code: Alles auswählen

          1.011s alsa-restore.service
           862ms udisks2.service
           767ms user@1000.service
           697ms systemd-logind.service
           438ms ModemManager.service
           436ms dev-sdc2.device
           425ms systemd-fsck@dev-disk-by\x2duuid-7103545c\x2d2b0c\x2d4919\x2d9f02\x2d265cffea837f.service
           315ms accounts-daemon.service
           246ms wpa_supplicant.service
           242ms NetworkManager.service
           241ms avahi-daemon.service
           239ms rsyslog.service
           235ms pppd-dns.service
           234ms home.mount
           204ms systemd-timesyncd.service
           204ms upower.service
           132ms keyboard-setup.service
           128ms systemd-udevd.service
           119ms apparmor.service
           119ms systemd-journald.service
            82ms systemd-udev-trigger.service
            75ms colord.service
            74ms dev-disk-by\x2duuid-1b14a4df\x2dae64\x2d436c\x2d8801\x2d9b5c58ccd4fb.swap
            67ms systemd-modules-load.service
            62ms polkit.service
            59ms systemd-tmpfiles-setup.service
            57ms packagekit.service
            43ms systemd-remount-fs.service
            40ms plymouth-quit-wait.service
            40ms plymouth-quit.service
            38ms dev-hugepages.mount
            38ms sys-kernel-debug.mount
            33ms dev-mqueue.mount
            30ms systemd-sysusers.service
            28ms networking.service
            22ms systemd-update-utmp.service
            19ms sddm.service
            18ms kmod-static-nodes.service
            18ms systemd-journal-flush.service
            17ms systemd-sysctl.service
            16ms plymouth-read-write.service
            16ms mdmon@md127.service
            16ms rtkit-daemon.service
            14ms systemd-tmpfiles-setup-dev.service
            13ms plymouth-start.service
            11ms user-runtime-dir@1000.service
             8ms systemd-random-seed.service
             8ms systemd-update-utmp-runlevel.service
             8ms systemd-user-sessions.service
             5ms ifupdown-pre.service
             5ms console-setup.service

DeletedUserReAsG

Re: Verzögerung beim Bootvorgang

Beitrag von DeletedUserReAsG » 01.08.2020 09:15:01

Plobiop hat geschrieben: ↑ zum Beitrag ↑
31.07.2020 23:20:12
Ich hätte ansonsten auch keinen Grund anzunehmen, dass das RAID nicht so funktioniert wie es sollte.
Ich hingegen hätte angesichts des Logs genau dort nochmal genauer geschaut.

Wie gesagt: 1m30s ist eine typische Timeout-Zeit, und die Meldungen unmittelbar davor und danach beziehen sich auf das RAID-System – ich würd’s so interpretieren, dass auf was gewartet wird, das nicht eintritt. Das würde ich nun suchen und abstellen. Könnte ’ne falsche UUID irgendwo sein, auf deren Auftauchen vergeblich gewartet wird, oder was anderes.

TomL

Re: Verzögerung beim Bootvorgang

Beitrag von TomL » 01.08.2020 10:59:00

Ich habe gerade auch mal einen Blick aufs Log geworfen und hab dazu mal ne Frage:

Code: Alles auswählen

[    2.322704] input: Acrox AmazonBasics gaming mouse as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/0003:3938:1110.0003/input/input6
[    2.322894] hid-generic 0003:3938:1110.0003: input,hidraw2: USB HID v1.11 Mouse [Acrox AmazonBasics gaming mouse] on usb-0000:00:14.0-2/input0
[    2.325054] input: Acrox AmazonBasics gaming mouse Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.1/0003:3938:1110.0004/input/input7
[    2.388725] input: Acrox AmazonBasics gaming mouse Consumer Control as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.1/0003:3938:1110.0004/input/input8
[    2.388778] input: Acrox AmazonBasics gaming mouse as /devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.1/0003:3938:1110.0004/input/input9
[    2.389076] hid-generic 0003:3938:1110.0004: input,hiddev0,hidraw3: USB HID v1.11 Keyboard [Acrox AmazonBasics gaming mouse] on usb-0000:00:14.0-2/input1
[   92.180354] raid6: sse2x1   gen() 10256 MB/s
[   92.248358] raid6: sse2x1   xor()  8101 MB/s
Ich interpretiere das so, dass der Timeout vor dem Raid passiert... also das die Jobs vor dem Raid irgendwie hängen, hier ist scheinbar was mit der Mouse. Ist das falsch interpretiert?

Benutzeravatar
MSfree
Beiträge: 10686
Registriert: 25.09.2007 19:59:30

Re: Verzögerung beim Bootvorgang

Beitrag von MSfree » 01.08.2020 11:08:27

Ich habe die Meldungen aus der dmesg-Ausgabe mal nach md126 gefiltert:

Code: Alles auswählen

[    2.074412] md/raid1:md126: not clean -- starting background reconstruction
[    2.074413] md/raid1:md126: active with 2 out of 2 mirrors
[    2.074424] md126: detected capacity change from 0 to 1825361100800
[    2.080726] md: resync of RAID array md126
[   98.460244] EXT4-fs (md126): mounted filesystem with ordered data mode. Opts: (null)
So ganz verstehe ich die Ausgabe nicht, kann das hier aber nicht nachvollziehen. Meine Kiste hat ein Raid5, und dort sieht die Ausgabe so aus:

Code: Alles auswählen

[    6.154979] md/raid:md0: not clean -- starting background reconstruction
[    6.154986] md/raid:md0: device sdd operational as raid disk 3
[    6.154987] md/raid:md0: device sdb operational as raid disk 1
[    6.154987] md/raid:md0: device sdc operational as raid disk 2
[    6.154987] md/raid:md0: device sda operational as raid disk 0
[    6.155176] md/raid:md0: raid level 5 active with 4 out of 4 devices, algorithm 2
[    6.204006] md0: detected capacity change from 0 to 6000790732800
[   11.687278] md: resync of RAID array md0
[   14.459608] EXT4-fs (md0): mounted filesystem with ordered data mode. Opts: user_xattr,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0,acl
Im Gegensatz zu deiner Ausgabe werden bei mir die Devices, die zum Raid gehören, gelistet (sda-sdd). Bei mir vergehen zwischen "resync" und "mounted" rund 3s, bei dir sind es 96s.

Warum bei dir 96s vergehen, kann ich mir nicht wirklich erklären. Das ist zu kurz für eine volle Rekonstruktion, die in deinem Fall um die 5 Stunden benötigen müßte. Es ist aber zu lang für eine einfach Prüfung, ob das Raid sauber ist, was in meinem Fall um die 8s dauert.

Wie ist denn dein Raid aufgebaut?

Code: Alles auswählen

lsblk
?

Ist da eventuell eine Rekonstruktion im Gange?

Code: Alles auswählen

cat /proc/mdstat
?

DeletedUserReAsG

Re: Verzögerung beim Bootvorgang

Beitrag von DeletedUserReAsG » 01.08.2020 11:49:47

TomL hat geschrieben: ↑ zum Beitrag ↑
01.08.2020 10:59:00
Ich interpretiere das so, dass der Timeout vor dem Raid passiert... also das die Jobs vor dem Raid irgendwie hängen, hier ist scheinbar was mit der Mouse. Ist das falsch interpretiert?
Ja, siehe auch die Beiträge oben: die Maus taucht nur zufällig in dem Zeitraum auf, die zusammenhängenden Meldungen betreffend das RAID-Subsystem.

Wie geschrieben: ich würde mit den dafür vorgesehenen Werkzeugen schauen, ob da was zu finden ist – und das beheben.

Antworten