[systemd] démarrage long (partiellement résolu)

[Anghirrim]

Bonsoir,

Depuis que je suis passé à systemd, tout fonctionne bien, sauf le démarrage qui est long.

Avec systemd-analyze, j'ai pu identifier deux choses qui sont trop longues:

Le réseau (que ce soit avec dhcpcd, networkmanager ou wicd) met plusieurs dizaines de secondes à se lancer.
Ainsi que colord.service, c'est le dernier service à se lancer et il mets aussi trop de temps (des fois jusqu'à 10 secondes).

Voici la sortie de "systemd-analyze blame"

Code : Tout sélectionner

[thomas@archasus ~]$ systemd-analyze blame
 11856ms wicd.service
  3631ms systemd-logind.service
  2330ms colord.service
  1539ms systemd-vconsole-setup.service
  1161ms udisks2.service
  1052ms systemd-binfmt.service
  1045ms media-donnees.mount
  1010ms systemd-remount-fs.service
   913ms sys-kernel-debug.mount
   814ms media-systeme.mount
   804ms dev-mqueue.mount
   795ms systemd-modules-load.service
   789ms dev-hugepages.mount
   749ms lm_sensors.service
   731ms proc-sys-fs-binfmt_misc.mount
   655ms systemd-udevd.service
   591ms upower.service
   526ms systemd-udev-trigger.service
   476ms systemd-user-sessions.service
   284ms systemd-tmpfiles-setup.service
   268ms polkit.service
   215ms systemd-sysctl.service
    52ms tmp.mount
     1ms sys-fs-fuse-connections.mount

Le plot.svg montre bien que ce sont ces deux services qui ralentissent le tout.

Je fais le tri dans le "journalctl -b" et je poste le résultat.

[onyx67]

Salut,
J'ai un peu le même type de soucis, pas dans les mêmes proportions, certes, mais ce qui m'intriguent c'est que dhcpcd@eth0.service semble de plus en plus long a démarré: 10 sec en moyenne aujourd'hui, contre seulement 5 voir 4 sec il y a 3 ou 4 mois et ce sur mes deux PC bureaux (ce qui est encore très raisonnable, j'en convient, mais quand même, je me pose la question du pourquoi)
Ce que j'ai cru comprendre via des posts similaires, c'est que dhcpcd n'est pas forcément en cause. Mais je ne maîtrise pas encore suffisamment systemd pour optimiser le démarrage en fonction de mes besoins réels.

[Anghirrim]

Salut,

Pour moi c'est en effet aléatoire. En moyenne, ça met 10 à 11 secondes pour démarrer. La je suis tombé sur un démarrage "cas décole".

J'ai ce comportement pour wicd, networkmanager et dhcpcd.

Voici le journalctl pour la partie Wicd / eth0 (trois derniers boot):

Code : Tout sélectionner

[thomas@archasus ~]$ journalctl -u wicd
janv. 25 18:01:17 archasus wicd[341]: dhcpcd[582]: dhcpcd not running
janv. 25 18:01:17 archasus dhcpcd[582]: dhcpcd not running
janv. 25 18:01:18 archasus wicd[341]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:01:18 archasus wicd[341]: dhcpcd[612]: dhcpcd not running
janv. 25 18:01:18 archasus wicd[341]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:01:18 archasus wicd[341]: dhcpcd[620]: dhcpcd not running
janv. 25 18:01:18 archasus wicd[341]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:01:20 archasus dhcpcd[651]: version 5.6.4 starting
janv. 25 18:01:20 archasus dhcpcd[651]: eth0: sending IPv6 Router Solicitation
janv. 25 18:01:20 archasus dhcpcd[651]: eth0: rebinding lease of 192.168.1.27
janv. 25 18:01:20 archasus dhcpcd[651]: eth0: acknowledged 192.168.1.27 from 192.168.1.1
janv. 25 18:01:20 archasus dhcpcd[651]: eth0: checking for 192.168.1.27
janv. 25 18:01:24 archasus dhcpcd[651]: eth0: sending IPv6 Router Solicitation
janv. 25 18:01:26 archasus dhcpcd[651]: eth0: leased 192.168.1.27 for 86400 seconds
janv. 25 18:01:26 archasus dhcpcd[651]: forked to background, child pid 700
janv. 25 18:01:28 archasus dhcpcd[700]: eth0: sending IPv6 Router Solicitation
janv. 25 18:01:32 archasus dhcpcd[700]: eth0: sending IPv6 Router Solicitation
janv. 25 18:01:32 archasus dhcpcd[700]: eth0: no IPv6 Routers available
janv. 25 18:11:51 archasus dhcpcd[700]: received SIGTERM, stopping
janv. 25 18:11:51 archasus dhcpcd[700]: eth0: removing interface
-- Reboot --
janv. 25 18:15:29 archasus wicd[345]: dhcpcd[615]: dhcpcd not running
janv. 25 18:15:30 archasus wicd[345]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:15:30 archasus wicd[345]: dhcpcd[637]: dhcpcd not running
janv. 25 18:15:30 archasus wicd[345]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:15:30 archasus wicd[345]: dhcpcd[646]: dhcpcd not running
janv. 25 18:15:30 archasus dhcpcd[646]: dhcpcd not running
janv. 25 18:15:30 archasus wicd[345]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:15:32 archasus dhcpcd[654]: version 5.6.4 starting
janv. 25 18:15:32 archasus dhcpcd[654]: eth0: sending IPv6 Router Solicitation
janv. 25 18:15:32 archasus dhcpcd[654]: eth0: rebinding lease of 192.168.1.27
janv. 25 18:15:32 archasus dhcpcd[654]: eth0: acknowledged 192.168.1.27 from 192.168.1.1
janv. 25 18:15:32 archasus dhcpcd[654]: eth0: checking for 192.168.1.27
janv. 25 18:15:36 archasus dhcpcd[654]: eth0: sending IPv6 Router Solicitation
janv. 25 18:15:37 archasus dhcpcd[654]: eth0: leased 192.168.1.27 for 86400 seconds
janv. 25 18:15:37 archasus dhcpcd[654]: forked to background, child pid 702
janv. 25 18:15:40 archasus dhcpcd[702]: eth0: sending IPv6 Router Solicitation
janv. 25 18:15:44 archasus dhcpcd[702]: eth0: sending IPv6 Router Solicitation
janv. 25 18:15:44 archasus dhcpcd[702]: eth0: no IPv6 Routers available
-- Reboot --
janv. 25 18:24:50 archasus wicd[348]: dhcpcd[591]: dhcpcd not running
janv. 25 18:24:52 archasus wicd[348]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:24:52 archasus wicd[348]: dhcpcd[633]: dhcpcd not running
janv. 25 18:24:52 archasus wicd[348]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:24:53 archasus wicd[348]: dhcpcd[653]: dhcpcd not running
janv. 25 18:24:53 archasus wicd[348]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 18:24:55 archasus dhcpcd[661]: version 5.6.4 starting
janv. 25 18:24:55 archasus dhcpcd[661]: eth0: sending IPv6 Router Solicitation
janv. 25 18:24:55 archasus dhcpcd[661]: eth0: rebinding lease of 192.168.1.27
janv. 25 18:24:55 archasus dhcpcd[661]: eth0: acknowledged 192.168.1.27 from 192.168.1.1
janv. 25 18:24:55 archasus dhcpcd[661]: eth0: checking for 192.168.1.27
janv. 25 18:24:59 archasus dhcpcd[661]: eth0: sending IPv6 Router Solicitation
janv. 25 18:25:00 archasus dhcpcd[661]: eth0: leased 192.168.1.27 for 86400 seconds
janv. 25 18:25:03 archasus dhcpcd[722]: eth0: sending IPv6 Router Solicitation
janv. 25 18:25:07 archasus dhcpcd[722]: eth0: sending IPv6 Router Solicitation
janv. 25 18:25:07 archasus dhcpcd[722]: eth0: no IPv6 Routers available

Et pour colord.service:

Code : Tout sélectionner

[thomas@archasus ~]$ journalctl -b
janv. 25 18:24:35 archasus dbus[354]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service'
janv. 25 18:24:37 archasus dbus[354]: [system] Successfully activated service 'org.freedesktop.ColorManager'
...
janv. 25 18:24:41 archasus systemd[1]: Got D-Bus activation request for colord.service
janv. 25 18:24:41 archasus systemd[1]: Trying to enqueue job colord.service/start/replace
janv. 25 18:24:41 archasus systemd[1]: Installed new job colord.service/start as 133
janv. 25 18:24:41 archasus systemd[1]: Enqueued job colord.service/start as 133
janv. 25 18:24:41 archasus systemd[1]: Starting Manage, Install and Generate Color Profiles...
janv. 25 18:24:41 archasus systemd[1]: About to execute /usr/lib/colord/colord
janv. 25 18:24:41 archasus systemd[1]: Forked /usr/lib/colord/colord as 374
janv. 25 18:24:41 archasus systemd[1]: colord.service changed dead -> start
janv. 25 18:24:41 archasus systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
janv. 25 18:24:41 archasus systemd[1]: Running GC...
janv. 25 18:24:41 archasus systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
janv. 25 18:24:41 archasus systemd[1]: colord.service's D-Bus name org.freedesktop.ColorManager now registered by :1.3
janv. 25 18:24:41 archasus systemd[1]: colord.service changed start -> running
janv. 25 18:24:41 archasus systemd[1]: Job colord.service/start finished, result=done

Bizarrement, pour l'un comme pour l'autre, pas d'erreur....

En revanche, comment cela se fait-il que dhcpcd se lance alors que j'ai annulé le service? C'est wicd qui le lance? Si oui, est-ce le fautif?

[Ypnose]

Apparemment dhcpcd prends du temps au niveau de l'IPv6. Pourquoi ne pas le désactiver?

[Anghirrim]

Il n'est pas activé à ce que je sache....

Le contenu de mon /etc/modprobe.d/modprobe.conf:

Code : Tout sélectionner

alias net-pf-10 off
# Desactiver le chargement automatique de IPv6
options ipv6 disable=1

Mais ça semble n'avoir aucun effet, dhcpcd essaie quand même...

[Ypnose]

On ne peut plus le désactiver de cette manière depuis un moment (3.4) car il est activé par défaut dans le kernel (en non plus en module).
Tu peux le désactiver en ajoutant ipv6.disable=1 dans ton bootloader (sur la ligne correspondante).

[Anghirrim]

Cool, ça a marché!!!! Merci!!!

Code : Tout sélectionner

janv. 25 21:03:23 archasus wicd[325]: dhcpcd[587]: dhcpcd not running
janv. 25 21:03:23 archasus wicd[325]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 21:03:23 archasus wicd[325]: dhcpcd[612]: dhcpcd not running
janv. 25 21:03:23 archasus wicd[325]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 21:03:23 archasus wicd[325]: dhcpcd[634]: dhcpcd not running
janv. 25 21:03:23 archasus wicd[325]: Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
janv. 25 21:03:25 archasus dhcpcd[645]: version 5.6.4 starting
janv. 25 21:03:25 archasus dhcpcd[645]: all: configured as a router, not a host
janv. 25 21:03:26 archasus dhcpcd[645]: eth0: rebinding lease of 192.168.1.27
janv. 25 21:03:26 archasus dhcpcd[645]: eth0: acknowledged 192.168.1.27 from 192.168.1.1
janv. 25 21:03:26 archasus dhcpcd[645]: eth0: checking for 192.168.1.27
janv. 25 21:03:30 archasus dhcpcd[645]: eth0: leased 192.168.1.27 for 86400 seconds

Comment dégager les parties dhcpcd et wpa_supplicant? Sont-elles nécessaires, faut-il que j'installe wpa_supplicant aussi? C'est pour les connexions cryptées non?

[Anghirrim]

J'ai édité le Wiki, vous pouvez checker au cas où il y a une coquille? Partie désactivation de la fonctionnalité.

ipv6 Wiki

[Ypnose]

À partir du moment où tu utilises wicd et que tu te connectes à une box en DHCP, tu auras forcément besoin de dhcpcd. wpa_supplicant est installé en tant que dépendances de wicd.
Donc la partie dhcpcd est nécessaire. Cependant, je ne sais pas pourquoi il y a un soucis avec wpa_supplicant sachant que tu sembles te connecter en filaire...
En tout cas, tu dois déjà avoir gagné quelques secondes lors du boot.

[Anghirrim]

Yep, deux à 3 secondes, ce qui est bon (20 à 25% de gain sur Wicd, pas négligeable!).

Pour dhcpcd et wpa_supplicant, ça n'est pas trop grave, tout se passe sur la même seconde, c'est ridicule par rapport au temps de connexion au réseau filaire. Je laisse ça tranquille.

Je vais continuer à fouiller pour colord maintenant. Merci de ton aide.