Upgrade Jessie auf Stretch danach lange Bootphase

[halo44]

Ich benötige Hilfe nach dem Upgrade.

Das Upgrade ist problemlos durchgelaufen und das System startet auch anschließend und ist nutzbar. Allerdings dauert der Bootvorgang deutlich länger als vorher unter Jessie.

Ich boote ohne die Optionen "quiet" und "splash", lasse mir also die Bootmeldungen anzeigen. Diese sind nach 27 Sekunden durchgelaufen und der Bildschirm wird jetzt schwarz für weitere 15 Sekunden bis die Passwortabfrage für den Benutzer-Login erscheint. Nach Eingabe des Passworts bleibt dieses Bild 17 Sekunden sichtbar, bevor wieder ein schwarzer Bildschirm gezeigt wird. Der Plasma-Arbeitsbereich erscheint nach weiteren 20 Sekunden Wartezeit. Danach startet Thunderbird aus dem Autostart und fragt nach dem Passwort für das Sicherheitsmodul. Dieses tippe ich ein, aber erst nach 11 Sekunden wird die erfolgte Eingabe akzeptiert und ich kann Enter betätigen. Das sind summa-summarum 90 Sekunden (ohne Passworteingabe).

Danach ist das System nutzbar und zeigt bisher keine anderen wesentlichen Fehler. Aber die deutlich verlängerte Startzeit gegenüber Jessie ist mir nicht geheuer.

Systemd-analyze zeigt bei Stretch bzw. Jessie

Code: Alles auswählen

Startup finished in 4.164s (kernel) + 34.275s (userspace) = 38.439s
Startup finished in 3.438s (kernel) + 18.114s (userspace) = 21.552s

Systemd-analyze critical-chain zeigt für Stretch

Code: Alles auswählen

graphical.target @34.267s
└─multi-user.target @34.267s
  └─postfix.service @34.264s +2ms
    └─postfix@-.service @26.845s +7.418s
      └─network-online.target @26.839s
        └─NetworkManager-wait-online.service @14.116s +12.722s
          └─NetworkManager.service @11.271s +2.843s
            └─dbus.service @10.160s
              └─basic.target @10.110s
                └─sockets.target @10.109s
                  └─cups.socket @10.108s
                    └─sysinit.target @10.052s
                      └─systemd-timesyncd.service @9.834s +217ms
                        └─systemd-tmpfiles-setup.service @9.183s +600ms
                          └─local-fs.target @9.160s
                            └─run-user-126.mount @26.492s
                              └─local-fs-pre.target @2.935s
                                └─systemd-tmpfiles-setup-dev.service @2.112s +823ms
                                  └─kmod-static-nodes.service @1.925s +185ms
                                    └─system.slice @1.903s
                                      └─-.slice @1.723s

Das sieht für mich nach irgendwelchen Netzwerkproblemen aus. Vor allem irritiert mich der NetworkManager-wait-online.service. Diesen finde ich beim Start meiner Jessie-Installation überhaupt nicht, auch nicht in der Auflistung von systemd-analyze blame.

Übrigens läuft auf meinem Notebook Stretch schon seit September vergangenen Jahre, regelmäßig aktualisiert, ohne Probleme und startet im Vergleich zum Desktoprechner mit diesen Werten

Code: Alles auswählen

Startup finished in 2.653s (kernel) + 8.830s (userspace) = 11.483s

Für jede Hilfe bin ich dankbar. Sollten weitere Informationen erforderlich sein, werde ich diese natürlich liefern.

Gruss H.

[scientific]

NetworkManager-wait-online.service tut nichts anderes als darauf warten, dass NetworkManager fertig eine Verbindung konfigurieren konnte.
Wenns da Probleme gibt, dauert das halt lange.

Versuche herauszufinden, warum NM so lange braucht, um die Verbindung aufzubauen.
Ev. Sind es andere Services, die NM verzögern. Bei mir war das z. B. Dropbox.

[halo44]

Danke für Deine Antwort.

Was mir schon aufgefallen war, ist diese Meldung im Journal

Code: Alles auswählen

Jun 20 17:50:38 dt-debian avahi-daemon[547]: Failed to open /etc/resolv.conf: Invalid argument

Ich habe dem aber keine besondere Bedeutung beigemessen, weil ich anschließend feststellte, daß die /etc/resolv.conf den korrekten Eintrag enthielt.

Jetzt aber habe ich mir aus den weiteren auf dem Rechner installierten OS (Jessie und PCLinuxOS) mal für alle drei den Inhalt der Datei anzeigen lassen. Jessie und PCLinuxOS zeigen den richtigen Nameserver. Aber Stretch verweist (aus den anderen OS betrachtet) auf /var/run/NetworkManager/resolv.conf und hat eine Dateigröße von 0 Byte.

Erst nach fertigem Systemstart zeigt die Datei den richtigen Nameserver und auch der Zeitstempel der Datei ist der vom erfolgten Start.

Nach Runterfahren von Stretch und Start eines der anderen OS finde ich für die Stretch-Version wieder eine Größe von 0 Byte.

Vielleicht kann dies zur Aufklärung beitragen?

Gruss H.

[rallygion]

Kann es sein, dass einfach die Bootreihenfolge geändert wurde?
Seit dem Upgrade dauert es bei mir auch etwas länger.
Nur bei mir wars bisher immer so, dass das Aufbauen der Netzwerkverbindung etwas länger dauerte (liegt an der Firmware für den Intel 7260 AC Chip), die GUI aber schon gestartet war.
Dann hatte ich oben in der Statusleiste eben drei Punkte anstatt dem Netzwerksymbol.
Seit dem Upgrade wird evtl vor dem gdm3 die Netzwerkverbindung aufgebaut und dann erst gmd3 gestartet.
Oder bin ich da auf dem falschen Dampfer?

[halo44]

Leider komme ich erst jetzt dazu mich weiter mit dem Problem zu beschäftigen. Heute z.B. erfahre ich:

Code: Alles auswählen

Startup finished in 4.446s (kernel) + 1min 22.542s (userspace) = 1min 26.988s

und

Code: Alles auswählen

graphical.target @31.060s
└─multi-user.target @31.060s
  └─postfix.service @31.057s +2ms
    └─postfix@-.service @24.564s +6.492s
      └─network-online.target @24.560s
        └─NetworkManager-wait-online.service @13.008s +11.551s
          └─NetworkManager.service @11.225s +1.779s
            └─network-pre.target @11.223s
              └─ebtables.service @8.533s +2.687s
                └─local-fs.target @8.532s
                  └─run-user-1000.mount @50.977s
                    └─local-fs-pre.target @3.928s
                      └─lvm2-monitor.service @1.674s +2.253s
                        └─lvm2-lvmetad.service @2.182s
                          └─lvm2-lvmetad.socket @1.669s
                            └─-.mount @1.420s
                              └─system.slice @1.587s
                                └─-.slice @1.420s

Zwar nimmt sich auch hier der Dienst NetworkManager-wait-online seine Zeit, aber im Journal des Bootvorgangs finde ich

Code: Alles auswählen

Jun 29 10:29:00 dt-debian NetworkManager[483]: <info>  [1498724940.5347] manager: startup complete
Jun 29 10:29:00 dt-debian systemd[1]: Started Network Manager Wait Online.
Jun 29 10:29:00 dt-debian systemd[1]: Reached target Network is Online.

Das heisst für mich der Networkmanager ist komplett gestartet, aber warum und zu welchem Zweck startet unmittelbar nach dieser Meldung noch Network Manager Wait Online?

Erst 27 Sekunden später ist die Nutzeranmeldung erfolgt, worin etwa 4-5 Sekunden für die Eingabe des Passworts enthalten sind:

Code: Alles auswählen

Jun 29 10:29:27 dt-debian sddm-helper[1936]: pam_unix(sddm:session): session opened for user halo44 by (uid=0)

Weiter hinten im Journal finde ich etwa 90 Meldungen zu kscreen, ein Paket, welches ich unter Jessie nicht kenne. Es soll wohl die Handhabung mehrerer Monitore ermöglichen. Ich habe nur einen Monitor, wozu ist das Paket dann beim Upgrade neu installiert worden?

Das System meldet den erfolgreichen Start

Code: Alles auswählen

Jun 29 10:29:59 dt-debian systemd[1]: Startup finished in 4.446s (kernel) + 1min 22.542s (userspace) = 1min 26.988s.

lässt aber erst Tastatur und Mausaktionen weitere 23 Sekunden später zu. Der ganze Bootvorgang dauert von 10:28:37 bis ab 10:30:22 Eingaben möglich sind.

Entscheidend aber scheint mir doch erstmal die Zeit zu sein, die sich der "Network Manager Wait Online" nimmt. Kann mir bitte jemand raten, wie ich dies Problem angehen sollte.

Gruss H.

[scientific]

NetworkManager-wait-online.service "nimmt" sich nicht die Zeit. Die nimmt sich ein anderer Prozess... oder braucht sie. Den herauszufinden ist in der Tat nicht einfach. NetworkManager-wait-online.service wartet nur ab, bis alle Abhängigkeite nm-online erfolgreich "online" zurückgibt.

Schau in den Skripten in
/etc/NetworkManager/dispatcher.d/pre-up und /etc/network/pre-up und up ob da etwas drinnen ist, das den Hänger verursacht.
NetworkManager geht nämlich erst weiter, wenn die pre-up Skripte mit exit 0 beendet wurden.

[scientific]

Ich habe auch immer wieder mal das Phänomen, dass gnome die Shortcuts des Keyboards erst nach 1,5 Minuten erkannte. Das hing mit einer falschen Abhängigkeit zusammen,, die ich mit einem selbst geschriebenen Skript + systemd-unit verbrochen hatte...

[halo44]

... Schau in den Skripten in /etc/NetworkManager/dispatcher.d/pre-up und /etc/network/pre-up und up ob da etwas drinnen ist, das den Hänger verursacht ...

In /etc/NetworkManager/dispatcher.d findet sich nur ein Ordner pre-up.d, der aber leer ist. In /etc/network findet sich nur der Ordner if-pre-up.d mit 3 Elementen: bridge, ethtool und wpasupplicant. Weiter findet sich ein Ordner if-up.d mit den Elementen avahi-daemon clamav-freshclam-ifupdown ethtool mountnfs ntpdate openssh-server openvpn postfix upstart wpasupplicant. Diese finden sich aber auch in der Jessie-Installation.

Was die Analyse der Skripte hinsichtlich einer eventuellen Ursache für den Hänger angeht, so übersteigt das meine Fähigkeiten.

Gruss H.

[scientific]

Trenne mal das Netzwerk und stoppe all diese Dienste. Und dann starte sie einzeln direkt ohne netz und beobachte, welches davon so lanfe braucht.

[halo44]

Habe ich gemacht. Beim Stoppen von avahi-daemon erhielt ich die Warnung

Warning: Stopping avahi-daemon.service, but it can still be activated by: avahi-daemon.socket

Der Dienst war auch prompt wieder aktiviert.

Bei den Diensten clamav-freshclam-ifupdown ethtool ntpdate openssh-server upstart und wpasupplicant wurde mir jeweils gemeldet "service not found".

Der Start der Dienste openvpn und postfix erfolgte sofort ohne Verzögerung.

Allerdings erhielt ich beim Startversuch für den Dienst mountnfs den Hinweis

Failed to start mountnfs.service: Unit mountnfs.service is masked.

Gruss H.

[scientific]

Ich glaub, ich hab mich unklar ausgedrückt.
Starte die Skripte direkt aus pre-up. Also das, was NetworkManager auch tun würde.

[halo44]

Ich glaub, ich hab mich unklar ausgedrückt.
Starte die Skripte direkt aus pre-up. Also das, was NetworkManager auch tun würde.

Es liegt eher nicht daran, daß Du Dich falsch ausgedrückt hast. Ich verstehe wohl nicht, was ich tun soll.

Beim ersten Mal habe ich das Netzkabel gezogen und die Dienste über systemctl gestoppt, soweit sie gefunden wurden. Danach den Startversuch wieder über systemctl. Ergebnis siehe meinen Beitrag von 15:09.

Bei zweiten Mal habe ich die Skripte aus /etc/network/if-up.d mit Rootrechten und dem Kommando sh aufgerufen. Alle wurden ohne Zeitverzögerung ausgeführt.

Wenn ich wüßte, wie der NetworkManager was auch tun würde, könnte ich es vielleicht so machen, wie Du möchtest. Bitte setze bei mir nicht zuviel Hintergrundwissen zu Netzwerkfragen und erst recht nicht zu systemd und sein Unit-Handling voraus.

Trotzdem bedanke ich mich für Deine Hilfe.

Gruss H.