Lange Boot-Zeit: "A start Job is running for linuxmuster" hält den Systemstart auf

hackbert · 18. Oktober 2023 um 10:17

Hallo,

in einem anderen issue auf github wurde von dorian vorgeschlagen, die Reihenfolge der systemd services beim boot zu ändern:

github.com/linuxmuster/linuxmuster-linuxclient7

Sysvol mount with computer account fails sometimes

offen 07:03AM - 20 Sep 22 UTC

kiarn

bug

Hello, I'm experiencing the following ; about 1/3 of the computers are not ab…le to mount sysvol at boot. As a consequence, the sysstart scripts can not be launched, but it does not block the login afterwards. Maybe that's why it's not really observed. It seems that the network is not started when linuxclient tries to mount sysvol : ``` Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] m108.linuxmuster.lan was changed to klz-01.linuxmuster.lan Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: message repeated 2 times: [ [DEBUG] m108.linuxmuster.lan was changed to klz-01.linuxmuster.lan] Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [INFO] Trying to overwrite /etc/krb5.keytab Sep 20 07:02:30 klz-01 onBoot[1020]: kinit: KDC für Realm »linuxmuster.lan« kann nicht gefunden werden bei Anfängliche Anmeldedaten werden geholt. Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] Calculating mountpoint of //dfgserver.linuxmuster.lan/sysvol Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [WARNING] Uid could not be found! Continuing anyway! Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] Trying to mount //dfgserver.linuxmuster.lan/sysvol to /srv/samba/KLZ-01$/sysvol Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] * Creating directory... Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] * Executing /usr/sbin/mount.cifs -o file_mode=0700,dir_mode=0700,sec=krb5,nodev,nosuid,mfsymlinks,nobrl,vers=3.0,user=KLZ-01$,domain=linuxmuster.lan //dfgserver.linuxmuster.lan/sysvol /srv/samba/KLZ-01$/sysvol Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [DEBUG] * Trying to mount... Sep 20 07:02:30 klz-01 onBoot[978]: * Error mounting share //dfgserver.linuxmuster.lan/sysvol to /srv/samba/KLZ-01$/sysvol! Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [FATAL] * Error mounting share //dfgserver.linuxmuster.lan/sysvol to /srv/samba/KLZ-01$/sysvol! Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [INFO] === Running local hook onBoot === Sep 20 07:02:30 klz-01 onBoot[1031]: id: »KLZ-01$“: Einen solchen Benutzer gibt es nicht Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [WARNING] Exception when querying groups of user KLZ-01$, it probaply does not exist Sep 20 07:02:30 klz-01 onBoot[1033]: id: »KLZ-01$“: Einen solchen Benutzer gibt es nicht Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [WARNING] Exception when querying groups of user KLZ-01$, it probaply does not exist Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [ERROR] Cloud not bind to ldap! Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [ERROR] === An exception occurred === Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [ERROR] {desc: "Cant contact LDAP server", errno: 11, info: Resource temporarily unavailable} Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [ERROR] === end exception === Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [ERROR] Cannot talk to LDAP Sep 20 07:02:30 klz-01 linuxmuster-linuxclient7: [INFO] == Executing script /etc/linuxmuster-linuxclient7/onBoot.d/00_example.sh == ``` And then 15s later : ``` Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.0987] device (eno1): carrier: link connected Sep 20 07:02:45 klz-01 kernel: [ 26.116090] e1000e 0000:00:19.0 eno1: NIC Link is Up 100 Mbps Full Duplex, Flow Control: None Sep 20 07:02:45 klz-01 kernel: [ 26.116100] e1000e 0000:00:19.0 eno1: 10/100 speed: disabling TSO Sep 20 07:02:45 klz-01 kernel: [ 26.116153] IPv6: ADDRCONF(NETDEV_CHANGE): eno1: link becomes ready Sep 20 07:02:45 klz-01 kernel: [ 26.116630] kauditd_printk_skb: 10 callbacks suppressed Sep 20 07:02:45 klz-01 kernel: [ 26.116641] audit: type=1400 audit(1663650165.094:64): apparmor="ALLOWED" operation="open" profile="/usr/sbin/sssd" name="/sys/devices/pci0000:00/0000:00:19.0/net/eno1/type" pid=1129 comm="sssd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.0994] device (eno1): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed') Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1006] policy: auto-activating connection 'Kabelgebundene Verbindung 1' (590442dd-4438-3e37-8ba9-3de248222ce6) Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1014] device (eno1): Activation: starting connection 'Kabelgebundene Verbindung 1' (590442dd-4438-3e37-8ba9-3de248222ce6) Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1016] device (eno1): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1021] manager: NetworkManager state is now CONNECTING Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1025] device (eno1): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1035] device (eno1): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Sep 20 07:02:45 klz-01 NetworkManager[753]: <info> [1663650165.1044] dhcp4 (eno1): activation: beginning transaction (timeout in 45 seconds) ``` So it's pretty obvious that the network is down when linuxclient starts. I tried to find a reason in the systemd direction and found this : https://github.com/systemd/systemd/issues/22360#issuecomment-1028665992 So I add : ``` Wants=network-online.target ``` in `/etc/systemd/system/linuxmuster-linuxclient7.service` and then reload systemd, but it doesn't seem to sufficient, because I still have the problem. It's not really an issue in linuxclient, more a convention problem of what "online" means for the network, but I think it's important to mention it here. I will update this topic if I find some hints. Arnaud

Wir haben damit sehr gute erste Erfahrungen gemacht, es scheint deutlich besser und stabiler zu funktionieren als Timeout oder exit(0). Wir hatten ohne diesen Fix auch Probleme damit, dass nicht immer alle Hookscripts von Linuxmuster ausgeführt wurden. Auch das scheint damit behoben. Falls jemand in fremden Netzen oder Offline Probleme mit den automatischen Proxy-Settings hatte ist das vermutlich die Ursache.

Was zum testen zu tun ist: Die Datei /etc/systemd/system/linuxmuster-linuxclient7.service sollte wie folgt angepasst werden:

[Unit]
Description=linuxmuster: switch local and remote home depending on ad server connection
After=sssd.service

[Service]
Type=oneshot
RemainAfterExit=true
ExecStart=/usr/share/linuxmuster-linuxclient7/scripts/onBoot
ExecStop=/usr/share/linuxmuster-linuxclient7/scripts/onShutdown
TimeoutSec=60

[Install]
WantedBy=multi-user.target
Alias=linuxmuster-linuxclient7.service

wichtig ist hier nur die Zeile:

After=sssd.service

Seit dieser Änderung haben wir keine Lags mehr beobachtet, den Timeout haben wir sicherheitshalber mal drinnen gelassen.

weiteres Topic mit diesem Problem:

Beste Grüße
Paul Kremser