Bonjour,
Je vous sollicite pour tenter de résoudre un problème avec un service qui ne veut pas démarrer correctement au démarrage d'une machine.
Il s'agit d'une machine [virtuelle] en Debian 10 Buster. Le service en question est squid, fourni par le paquet éponyme en version 4.6-1+deb10u1.
En effet, au démarrage de la machine, SystemD tente de lancer le service squid bien trop tôt, avant que les systèmes de fichiers soient tous présents (et notamment la partition /var où il veut écrire : dans /var/run/squid.pid, et dans /var/log/squid/access.log.).
J'ai modifié le fichier squid.service fourni par la distribution qui me semblait déficient sur ces dépendances, de la manière suivante :
$ diff -u /lib/systemd/system/squid.service /etc/systemd/system/squid.service
--- /lib/systemd/system/squid.service 2019-02-19 06:29:20.000000000 +0100
+++ /etc/systemd/system/squid.service 2019-09-06 11:22:00.385894559 +0200
@@ -8,7 +8,8 @@
[Unit]
Description=Squid Web Proxy Server
Documentation=man:squid(8)
-After=network.target network-online.target nss-lookup.target
+Requires=var.mount network.target network-online.target nss-lookup.target
+After= var.mount network.target network-online.target nss-lookup.target
[Service]
Type=forking
En effet, la doc de SystemD indique bien que si on veut qu'un service soit lancé après un autre au démarrage de la machine, il faut à la fois le placer dans une règle de type After= et dans une autre de type Requires= (ou Wants=).
J'ai activé cette modif (systemctl daemon-reload) qui semble bien prise en compte, mais malgré tout, au démarrage suivant, SystemD démarre squid *avant* le montage de var !! Je peux le constater par exemple avec le journal du démarrage :
# journalctl -b -u squid.service -u var.mount
-- Logs begin at Fri 2019-09-06 11:15:46 CEST, end at Fri 2019-09-06 11:26:52 CEST.
sept. 06 11:15:47 Deve2m squid[427]: WARNING: Cannot write log file: /var/log/squid <- squid démarre ici, et /var/log/squid n'existe pas !
sept. 06 11:15:47 Deve2m squid[427]: /var/log/squid/cache.log: No such file or dire
sept. 06 11:15:47 Deve2m squid[427]: messages will be sent to 'stderr'.
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47| Created PID file (/var/ru
sept. 06 11:15:47 Deve2m squid[427]: Squid Parent: will start 1 kids
sept. 06 11:15:47 Deve2m squid[427]: Squid Parent: (squid-1) process 490 started
sept. 06 11:15:47 Deve2m squid[427]: WARNING: Cannot write log file: /var/log/squid
sept. 06 11:15:47 Deve2m squid[427]: /var/log/squid/cache.log: No such file or dire
sept. 06 11:15:47 Deve2m squid[427]: messages will be sent to 'stderr'.
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47 kid1| ERROR: cannot change
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47 kid1| Current Directory is
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47 kid1| Creating missing swa
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47 kid1| No cache_dir stores
sept. 06 11:15:47 Deve2m squid[427]: Squid Parent: squid-1 process 490 exited with
sept. 06 11:15:47 Deve2m squid[427]: 2019/09/06 11:15:47| Removing PID file (/var/r
sept. 06 11:15:47 Deve2m squid[525]: WARNING: Cannot write log file: /var/log/squid
sept. 06 11:15:47 Deve2m squid[525]: /var/log/squid/cache.log: No such file or dire
sept. 06 11:15:47 Deve2m squid[525]: messages will be sent to 'stderr'.
sept. 06 11:15:47 Deve2m systemd[1]: squid.service: Can't open PID file /run/squid.
sept. 06 11:15:47 Deve2m squid[535]: Created PID file (/var/run/squid.pid)
sept. 06 11:15:47 Deve2m squid[535]: Squid Parent: will start 1 kids
sept. 06 11:15:47 Deve2m squid[535]: Squid Parent: (squid-1) process 542 started
sept. 06 11:15:47 Deve2m squid[542]: ERROR: cannot change current directory to /var
sept. 06 11:15:47 Deve2m squid[542]: Current Directory is /
sept. 06 11:15:47 Deve2m squid[542]: Starting Squid Cache version 4.6 for x86_64-pc
sept. 06 11:15:47 Deve2m squid[542]: Service Name: squid
sept. 06 11:15:47 Deve2m squid[542]: Process ID 542
sept. 06 11:15:47 Deve2m squid[542]: Process Roles: worker
sept. 06 11:15:47 Deve2m squid[542]: With 1024 file descriptors available
sept. 06 11:15:47 Deve2m squid[542]: Initializing IP Cache...
sept. 06 11:15:47 Deve2m squid[542]: DNS Socket created at [::], FD 6
sept. 06 11:15:47 Deve2m squid[542]: DNS Socket created at 0.0.0.0, FD 7
sept. 06 11:15:47 Deve2m squid[542]: Warning: Could not find any nameservers. Tryin
sept. 06 11:15:47 Deve2m squid[542]: Please check your /etc/resolv.conf file
sept. 06 11:15:47 Deve2m squid[542]: or use the 'dns_nameservers' option in squid.c
sept. 06 11:15:47 Deve2m squid[542]: Logfile: opening log daemon:/var/log/squid/acc
sept. 06 11:15:47 Deve2m squid[542]: Logfile Daemon: opening log /var/log/squid/acc
sept. 06 11:15:47 Deve2m squid[542]: Local cache digest enabled; rebuild/rewrite ev
sept. 06 11:15:47 Deve2m squid[542]: Store logging disabled
sept. 06 11:15:47 Deve2m squid[542]: Swap maxSize 0 + 262144 KB, estimated 20164 ob
sept. 06 11:15:47 Deve2m squid[542]: Target number of buckets: 1008
sept. 06 11:15:47 Deve2m squid[542]: Using 8192 Store buckets
sept. 06 11:15:47 Deve2m squid[542]: Max Mem size: 262144 KB
sept. 06 11:15:47 Deve2m squid[542]: Max Swap size: 0 KB
sept. 06 11:15:47 Deve2m squid[542]: Using Least Load store dir selection
sept. 06 11:15:47 Deve2m squid[542]: ERROR: cannot change current directory to /var
sept. 06 11:15:47 Deve2m squid[542]: Current Directory is /
sept. 06 11:15:47 Deve2m squid[542]: Finished loading MIME types and icons.
sept. 06 11:15:47 Deve2m squid[542]: HTCP Disabled.
sept. 06 11:15:47 Deve2m squid[542]: Pinger socket opened on FD 12
sept. 06 11:15:47 Deve2m squid[542]: Squid plugin modules loaded: 0
sept. 06 11:15:47 Deve2m squid[542]: Adaptation support is off.
sept. 06 11:15:47 Deve2m squid[542]: Accepting HTTP Socket connections at local=[::
sept. 06 11:15:47 Deve2m systemd[1]: var.mount: Directory /var to mount over is not <- var.mount démarre ici !
sept. 06 11:15:47 Deve2m systemd[1]: Mounting /var...
sept. 06 11:15:47 Deve2m systemd[1]: Mounted /var.
sept. 06 11:15:47 Deve2m systemd[1]: squid.service: Unit cannot be reloaded because
sept. 06 11:15:48 Deve2m squid[542]: logfileHandleWrite: daemon:/var/log/squid/acce
sept. 06 11:15:48 Deve2m squid[542]: Closing HTTP(S) port [::]:3128
sept. 06 11:15:48 Deve2m squid[542]: storeDirWriteCleanLogs: Starting...
sept. 06 11:15:48 Deve2m squid[542]: Finished. Wrote 0 entries.
sept. 06 11:15:48 Deve2m squid[542]: Took 0.00 seconds ( 0.00 entries/sec).
sept. 06 11:15:48 Deve2m squid[542]: FATAL: I don't handle this error well!
sept. 06 11:15:48 Deve2m squid[542]: Squid Cache (Version 4.6): Terminated abnormal
sept. 06 11:15:48 Deve2m squid[542]: Closing Pinger socket on FD 12
sept. 06 11:15:48 Deve2m squid[535]: Squid Parent: squid-1 process 542 exited with
sept. 06 11:15:48 Deve2m squid[535]: Squid Parent: (squid-1) process 1107 started
sept. 06 11:15:48 Deve2m squid[1107]: Set Current Directory to /var/spool/squid
sept. 06 11:15:48 Deve2m squid[1107]: Starting Squid Cache version 4.6 for x86_64-p
sept. 06 11:15:48 Deve2m squid[1107]: Service Name: squid
etc.
Bref, les commandes qui permettent de vérifier les dépendances indiquent bien que le service squid dépend de var.mount, mais SystemD le démarre quand-même avant ?!? À noter que cela semble être la même chose pour l'accès au DNS, qui doit normalement être assuré par une dépendance à nss-lookup.target.
Est-ce que j'ai loupé quelque chose ? Ou est-ce un souci lié à SystemD ? Si vous avez une piste, cela m'intéresse !
Merci,
Fred.
This message contains information that may be privileged or confidential and is the property of the Capgemini Group. It is intended only for the person to whom it is addressed. If you are not the intended recipient, you are not authorized to read, print, retain, copy, disseminate, distribute, or use this message or any part thereof. If you receive this message in error, please notify the sender immediately and delete all copies of this message.
