Problème au démarrage avec systemd

Jean-Luc · Avril 26, 2016, 1:41pm

Bonjour,
Je tourne sous debian/sid.
Depuis quelques jours, le système, lors du démarrage et de l’énumération des périphériques USB a une grande respiration (90 secondes environ).

Il démarre, affiche les périphériques USB connecté et… plus rien.

Si je ne fais rien, il poursuit sa course normalement et tout se passe bien.
Si je retire un périphérique USB, alors, il poursuit son démarrage sans attendre.
J’ai tenté de supprimer tous les périphériques USB, même problème (et je n’ai pas de clavier, ni de souris)
J’ai réinitialisé le BIOS (on ne sait jamais).
Tout ça sans succès.

En regardant le journal de démarrage, je peux voir ceci :

[ 7.405270] usb 1-6: new high-speed USB device number 4 using xhci_hcd
[ 7.578858] usb 1-6: New USB device found, idVendor=0424, idProduct=2514
[ 7.579007] usb 1-6: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 7.579746] hub 1-6:1.0: USB hub found
[ 7.579939] hub 1-6:1.0: 2 ports detected
[ 7.858529] usb 1-6.1: new full-speed USB device number 5 using xhci_hcd
[ 7.957340] usb 1-6.1: New USB device found, idVendor=045e, idProduct=0745
[ 7.957489] usb 1-6.1: New USB device strings: Mfr=1, Product=2, SerialNumber
=0
[ 7.957661] usb 1-6.1: Product: Microsoft® 2.4GHz Transceiver v6.0
[ 7.957801] usb 1-6.1: Manufacturer: Microsoft
[ 93.198778] systemd[1]: system-generators terminated by signal ALRM.
[ 93.274495] systemd[1]: Listening on Journal Audit Socket.
[ 93.275318] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 93.276091] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[ 93.276835] systemd[1]: Listening on udev Control Socket.

Ce qui a retenu mon attention, c’est le message suivant, juste au moment où il reprend son démarrage :
systemd[1]: system-generators terminated by signal ALRM.

Je ne connais pas bien systemd et je n’ai jamais touché à cette partie du système. Il semble que les « generators » sont liés à des personnalisations… ce que je n’ai pas fait.

En désespoir de cause, j’ai réinstallé sysvinit et sysvinit.core… Ce qui a résolu le problème de démarrage, mais pas le problème avec systemd bien entendu.

Ce matin il y avait une mise à jour de systemd, je l’ai donc tentée en supprimant de nouveau. Le problème est toujours là. Je suis donc, de nouveau, revenu en arrière.

Merci d’avance à ceux qui auraient une expérience dans le domaine.

Jean-Luc

grandtoubab · Avril 26, 2016, 4:57pm

Salut,
j’ai fait quelques modifs pour minidlna et network manager (je suis passé à wicd) et je trouve ça dans dmesg

[    6.240644] systemd-sysv-generator[145]: Overwriting existing symlink /run/systemd/generator.late/minidlna.service with real service
[    6.905512] systemd[1]: Cannot add dependency job for unit NetworkManager.service, ignoring: Unit NetworkManager.service failed to load: No such file or directory.

ça ne me dérange absolument pas mais ça te donne une piste

root@desktop:/run/systemd/generator# ls -alrt
total 16
drwxr-xr-x  2 root root  60 avril 26 17:29 multi-user.target.wants
-rw-r--r--  1 root root 277 avril 26 17:29 -.mount
-rw-r--r--  1 root root 228 avril 26 17:29 media-cdrom0.mount
drwxr-xr-x  2 root root  80 avril 26 17:29 local-fs.target.requires
-rw-r--r--  1 root root 461 avril 26 17:29 home.mount
drwxr-xr-x  2 root root  80 avril 26 17:29 local-fs.target.wants
drwxr-xr-x  2 root root  60 avril 26 17:29 umountnfs.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 umountfs.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 sendsigs.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 rpcbind.target.d
drwxr-xr-x  2 root root  60 avril 26 17:29 rpcbind.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 remote-fs.target.d
drwxr-xr-x  2 root root  60 avril 26 17:29 networking.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 mountnfs.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 mountnfs-bootclean.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 mountall.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 mountall-bootclean.service.d
drwxr-xr-x  2 root root  60 avril 26 17:29 hwclock.service.d
drwxr-xr-x 17 root root 420 avril 26 17:29 .
drwxr-xr-x 16 root root 380 avril 26 17:30 ..


root@desktop:/run/systemd/generator.late# ls -alrt
total 100
lrwxrwxrwx  1 root root  18 avril 26 17:29 ifupdown.service -> networking.service
-rw-r--r--  1 root root 484 avril 26 17:29 wicd.service
-rw-r--r--  1 root root 387 avril 26 17:29 ufw.service
drwxr-xr-x  2 root root 240 avril 26 17:29 sysinit.target.wants
-rw-r--r--  1 root root 604 avril 26 17:29 speech-dispatcher.service
-rw-r--r--  1 root root 613 avril 26 17:29 smbd.service
-rw-r--r--  1 root root 571 avril 26 17:29 samba-ad-dc.service
drwxr-xr-x  2 root root 260 avril 26 17:29 runlevel5.target.wants
drwxr-xr-x  2 root root 260 avril 26 17:29 runlevel4.target.wants
drwxr-xr-x  2 root root 260 avril 26 17:29 runlevel3.target.wants
drwxr-xr-x  2 root root 260 avril 26 17:29 runlevel2.target.wants
-rw-r--r--  1 root root 503 avril 26 17:29 rpcbind.service
-rw-r--r--  1 root root 289 avril 26 17:29 rcS.service
-rw-r--r--  1 root root 286 avril 26 17:29 rc.service
-rw-r--r--  1 root root 504 avril 26 17:29 ntp.service
-rw-r--r--  1 root root 567 avril 26 17:29 nmbd.service
-rw-r--r--  1 root root 497 avril 26 17:29 nfs-common.service
-rw-r--r--  1 root root 538 avril 26 17:29 networking.service
-rw-r--r--  1 root root 567 avril 26 17:29 minidlna.service
-rw-r--r--  1 root root 445 avril 26 17:29 minidlna.save.service
-rw-r--r--  1 root root 439 avril 26 17:29 minidlna.ok.service
-rw-r--r--  1 root root 520 avril 26 17:29 live-tools.service
-rw-r--r--  1 root root 531 avril 26 17:29 keyboard-setup.service
-rw-r--r--  1 root root 389 avril 26 17:29 kbd.service
-rw-r--r--  1 root root 545 avril 26 17:29 irqbalance.service
-rw-r--r--  1 root root 456 avril 26 17:29 hdparm.service
-rw-r--r--  1 root root 576 avril 26 17:29 hddtemp.service
-rw-r--r--  1 root root 725 avril 26 17:29 exim4.service
-rw-r--r--  1 root root 510 avril 26 17:29 console-setup.service
-rw-r--r--  1 root root 548 avril 26 17:29 atop.service
-rw-r--r--  1 root root 451 avril 26 17:29 apparmor.service
drwxr-xr-x  7 root root 660 avril 26 17:29 .
drwxr-xr-x 16 root root 380 avril 26 17:30 ..

pour le temps de démarrage

root@desktop:/# systemd-analyze
Startup finished in 4.630s (kernel) + 35.437s (userspace) = 40.068s

pour voir l’état des services
root@desktop:/# systemctl --all

puis appuis sur la barre d’espace pour lister tous les services
q pour quitter

pour t’interesser a l’usb
systemctl --all | grep usb

Jean-Luc · Avril 26, 2016, 5:23pm

Bon, ça ne m’aide pas vraiment… Je connaissait les commandes en question.
Le problème est que tout fonctionne bien, mais que le système a une “grande respiration” lors du démarrage avec un arrêt d’environ une minute et demi… puis qu’il il attend on ne sait quoi et termine le démarrage sur dépassement de délai d’attente.

Ensuite, tout fonctionne normalement (sur l’USB, au démarrage, j’ai la souris et le clavier sans fil et l’onduleur). Si la souris ou le clavier posaient des problèmes ça se verrait vite…

Mais je progresse.

J’ai (pour vérifier ce qu’il y avait dans /run/systemd/generaror tel que dans votre message) supprimé de nouveau sysvinit et sysvinit-core.
Là, il a redémarré sans problème avec systemd.

La seule différence avec ma configuration “normale” qui marchait mais qui ne fonctionne plus depuis quelques jours et que je n’ai pas réinstallé systemd-cron mais j’ai laissé anacron et cron (dont sysvinit dépend).

Il semble donc que le problème soit lié à systemd-cron.

systemd-analyze
Startup finished in 3.075s (kernel) + 19.872s (userspace) = 22.947s

Nota : systemctl -all | grep usb ne donne rien du tout.

grandtoubab · Avril 26, 2016, 7:44pm

systemctl --all | grep usb

deux tirets

Jean-Luc · Avril 26, 2016, 8:30pm

Oui, oui, avec les deux tirets.

grandtoubab · Avril 27, 2016, 11:08am

tu dois avoir un problème

@desktop:~$ systemctl --all | grep usb
  dev-disk-by\x2did-usb\x2dGeneric_USB_CF_Reader_2004888\x2d0:1.device                                       loaded    active   plugged   USB_CF_Reader
  dev-disk-by\x2did-usb\x2dGeneric_USB_MS_Reader_2004888\x2d0:3.device                                       loaded    active   plugged   USB_MS_Reader
  dev-disk-by\x2did-usb\x2dGeneric_USB_SD_Reader_2004888\x2d0:0.device                                       loaded    active   plugged   USB_SD_Reader
  dev-disk-by\x2did-usb\x2dGeneric_USB_SM_Reader_2004888\x2d0:2.device                                       loaded    active   plugged   USB_SM_Reader
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.2\x2dusb\x2d0:1:1.0\x2dscsi\x2d0:0:0:0.device                        loaded    active   plugged   USB_SD_Reader
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.2\x2dusb\x2d0:1:1.0\x2dscsi\x2d0:0:0:1.device                        loaded    active   plugged   USB_CF_Reader
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.2\x2dusb\x2d0:1:1.0\x2dscsi\x2d0:0:0:2.device                        loaded    active   plugged   USB_SM_Reader
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.2\x2dusb\x2d0:1:1.0\x2dscsi\x2d0:0:0:3.device                        loaded    active   plugged   USB_MS_Reader
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.3\x2dusb\x2d0:4:1.0\x2dscsi\x2d0:0:0:0.device                        loaded    active   plugged   WDC_WD10EADX-00TDHB0
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.3\x2dusb\x2d0:4:1.0\x2dscsi\x2d0:0:0:0\x2dpart1.device               loaded    active   plugged   WDC_WD10EADX-00TDHB0 Elements
  dev-disk-by\x2dpath-pci\x2d0000:00:1c.3\x2dusb\x2d0:4:1.0\x2dscsi\x2d0:0:0:0\x2dpart2.device               loaded    active   plugged   WDC_WD10EADX-00TDHB0 2
  sys-devices-pci0000:00-0000:00:1c.2-usb4-4\x2d1-4\x2d1:1.0-host7-target7:0:0-7:0:0:0-block-sdc.device      loaded    active   plugged   USB_SD_Reader
  sys-devices-pci0000:00-0000:00:1c.2-usb4-4\x2d1-4\x2d1:1.0-host7-target7:0:0-7:0:0:1-block-sdd.device      loaded    active   plugged   USB_CF_Reader
  sys-devices-pci0000:00-0000:00:1c.2-usb4-4\x2d1-4\x2d1:1.0-host7-target7:0:0-7:0:0:2-block-sde.device      loaded    active   plugged   USB_SM_Reader
  sys-devices-pci0000:00-0000:00:1c.2-usb4-4\x2d1-4\x2d1:1.0-host7-target7:0:0-7:0:0:3-block-sdf.device      loaded    active   plugged   USB_MS_Reader
  sys-devices-pci0000:00-0000:00:1c.3-usb1-1\x2d3-1\x2d3:1.0-net-wlan0.device                                loaded    active   plugged   RTL8192CU 802.11n WLAN Adapter
  sys-devices-pci0000:00-0000:00:1c.3-usb1-1\x2d4-1\x2d4:1.0-host6-target6:0:0-6:0:0:0-block-sdb-sdb1.device loaded    active   plugged   WDC_WD10EADX-00TDHB0 Elements
  sys-devices-pci0000:00-0000:00:1c.3-usb1-1\x2d4-1\x2d4:1.0-host6-target6:0:0-6:0:0:0-block-sdb-sdb2.device loaded    active   plugged   WDC_WD10EADX-00TDHB0 2
  sys-devices-pci0000:00-0000:00:1c.3-usb1-1\x2d4-1\x2d4:1.0-host6-target6:0:0-6:0:0:0-block-sdb.device      loaded    active   plugged   WDC_WD10EADX-00TDHB0

Jean-Luc · Avril 27, 2016, 1:00pm

Ben non, les hid (clavier/souris et, dans mon cas, l’onduleur qui est vu comme hid) ne sont pas pris en compte, et c’est normal.

Mais si je branche un disque USB ou un clé USB, je les retrouve bien :

systemctl -all | grep usb
dev-disk-by\x2did-usb\x2dSanDisk_Cruzer_Edge_2004452773119AF2C50C\x2d0:0.device loaded active plugged Cruzer_Edge
dev-disk-by\x2did-usb\x2dSanDisk_Cruzer_Edge_2004452773119AF2C50C\x2d0:0\x2dpart1.device loaded active plugged Cruzer_Edge PKBACK#_001
dev-disk-by\x2dpath-pci\x2d0000:00:14.0\x2dusb\x2d0:7:1.0\x2dscsi\x2d0:0:0:0.device loaded active plugged SAMSUNG_HM502JX
dev-disk-by\x2dpath-pci\x2d0000:00:14.0\x2dusb\x2d0:7:1.0\x2dscsi\x2d0:0:0:0\x2dpart1.device loaded active plugged SAMSUNG_HM502JX SAMSUNG
dev-disk-by\x2dpath-pci\x2d0000:00:14.0\x2dusb\x2d0:8:1.0\x2dscsi\x2d0:0:0:0.device loaded active plugged Cruzer_Edge
dev-disk-by\x2dpath-pci\x2d0000:00:14.0\x2dusb\x2d0:8:1.0\x2dscsi\x2d0:0:0:0\x2dpart1.device loaded active plugged Cruzer_Edge PKBACK#_001
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d7-1\x2d7:1.0-host6-target6:0:0-6:0:0:0-block-sdc-sdc1.device loaded active plugged SAMSUNG_HM502JX SAMSUNG
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d7-1\x2d7:1.0-host6-target6:0:0-6:0:0:0-block-sdc.device loaded active plugged SAMSUNG_HM502JX
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d8-1\x2d8:1.0-host7-target7:0:0-7:0:0:0-block-sdd-sdd1.device loaded active plugged Cruzer_Edge PKBACK#_001
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d8-1\x2d8:1.0-host7-target7:0:0-7:0:0:0-block-sdd.device loaded active plugged Cruzer_Edge

Non, ce n’est pas là que se trouve le problème.

pdm · Mai 3, 2016, 2:15pm

Bonjour Jean-Luc

Je rencontre un problème similaire (boot de 90 secondes et message “systemd[1]: system-generators terminated by signal ALRM”) depuis que j’ai remplacé le hdd par un ssd.
Dans mon cas, il semblerait que ce soit dû à une question d’entropie. Si je tape des touches du clavier au hasard pendant le boot, je raccourci le délai à 10 ou 15 secondes (en fonction de la vitesse à laquelle je tape). Dans les logs, au moment où d’habitude cela coince, j’ai le message :
[ +4,090525] random: nonblocking pool is initialized
Dans l’exemple ici, le délai est de 4 secondes (j’ai tapé assez vite). Et le reste du boot va très vite.

Je ne suis pas allé beaucoup plus loin.

La page Wikipépia de /dev/random indique “When the entropy pool is empty, reads from /dev/random will block until additional environmental noise is gathered”. Ce qui pourrait expliquer le SIGALRM.

Mon interprétation du phénomène : le boot va vite et avec un ssd, il y a peu d’entropie générée, un des system-generators a besoin de lire dans /dev/random (pour les partitions chiffrées ?) mais le noyau l’en empêche. Et comme à ce moment là il ne se passe rien de plus (côté périphériques qui pourraient générer de l’entropie), rien ne bouge jusqu’à un time-out propre à systemd.

Dans ton cas, vu qu’au moment où cela bloque, les périphériques USB sont déjà énumérés (je comprends que tu as un clavier USB), tu peux essayer également de taper sur les touches du clavier pour voir si cela a une influence.

Ceci étant ce n’est pas une solution durable, mais je n’ai pas trouvé d’autres pistes à ce jour.

Très cordialement

Pascal

Jean-Luc · Mai 3, 2016, 7:54pm

Merci pour votre retour Pascal,

Oui, c’est possible que ce soit un problème d’entropie. Mais je ne vois pas pourquoi cela s’appliquerait à systemd et pas à sysvinit.
Et, pire encore, que la suppression de systemd-cron — tout en gardant systemd — résolve aussi le problème.

Je démarre aussi sur un ssd mais je l’avais déjà avant.

J’ai même changé de machine sans réinstaller quoi que ce soit. Tout fonctionnait bien jusqu’à la semaine dernière.

J’ai donc laissé systemd et viré systemd-cron (qui semble pas mal impliqué dans l’affaire puisque tout va bien lorsqu’il n’est pas là…).

Pour l’instant, ça tourne comme ça et je n’ai plus fait d’autres investigations.

Je vais attendre de trouver la motivation pour ouvrir un bogue sur le BTS : il y en a plus de 300 sus systemd et uniquement quelques uns sur systemd-cron. Mais cron est peut-être un effet “collatéral”.

Jean-Luc

Jean-Luc · Mai 3, 2016, 8:17pm

Bon, j’ai ouvert un bogue.