Après avoir installé et configuré logrotate sur son serveur il peut arriver de recevoir des courriels de cron
contenant le message (visiblement d'erreur) suivant :
/etc/cron.daily/logrotate:
gzip: stdin: file size changed while zipping
N'arrivant pas à chaque fois et sans vraiment plus d'informations que ça : on recevra ce message encore quelques fois avant de se décider à faire quelque chose...
Le sujet du courriel "test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )" nous indique que c'est un script présent dans /etc/cron.daily
qui a rencontré/soulevé le problème, mais si on regarde le corps on a même mieux : le script quotidien de logrotate
est en cause.
Le message en lui même semble indiquer qu'un flux (stdin
) en cours de compression par gzip
a changé de taille (file size changed while zipping) et que ça ne lui a pas plus (et on le comprends).
Dis m'en plus
Le problème est que le courriel ne contient que ce qui a été "affiché" (STDIN
) par le script /etc/cron.daily/logrotate
lors de son exécution par run-parts
et c'est pas beaucoup.
On va donc le forcer à nous en dire plus en modifiant le script qui est actuellement (version 3.8.1-4) comme suit :
#!/bin/sh test -x /usr/sbin/logrotate || exit 0 /usr/sbin/logrotate /etc/logrotate.conf
On voit que le gros du procédé est fait par /usr/sbin/logrotate
qui, heureusement pour nous, accepte un paramètre "--verbose" le rendant plus prolixe :
#!/bin/sh test -x /usr/sbin/logrotate || exit 0 /usr/sbin/logrotate --verbose /etc/logrotate.conf
A partir de cet instant, notre script quotidien de rotation de journaux indiquera pas à pas ses actions et avec un peu de chance, le problème se reproduira la prochaine fois nous permettant de le localiser :
/etc/cron.daily/logrotate:Bingo : on retrouve notre "file size changed while zipping", c'est donc avec les journaux de
reading config file /etc/logrotate.conf
including /etc/logrotate.d
[...]
reading config file samba
Handling 15 logs
rotating pattern: /var/log/apache2/*.log
weekly (52 rotations)
[...]
rotating pattern: /var/log/samba/log.nmbd weekly (7 rotations)
empty log files are not rotated, old logs are removed
considering log /var/log/samba/log.nmbd
log needs rotating
rotating log /var/log/samba/log.nmbd, log->rotateCount is 7
dateext suffix '-20130915'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/samba/log.nmbd.7.gz to /var/log/samba/log.nmbd.8.gz (rotatecount 7, logstart 1, i 7),
renaming /var/log/samba/log.nmbd.6.gz to /var/log/samba/log.nmbd.7.gz (rotatecount 7, logstart 1, i 6),
renaming /var/log/samba/log.nmbd.5.gz to /var/log/samba/log.nmbd.6.gz (rotatecount 7, logstart 1, i 5),
renaming /var/log/samba/log.nmbd.4.gz to /var/log/samba/log.nmbd.5.gz (rotatecount 7, logstart 1, i 4),
renaming /var/log/samba/log.nmbd.3.gz to /var/log/samba/log.nmbd.4.gz (rotatecount 7, logstart 1, i 3),
renaming /var/log/samba/log.nmbd.2.gz to /var/log/samba/log.nmbd.3.gz (rotatecount 7, logstart 1, i 2),
renaming /var/log/samba/log.nmbd.1.gz to /var/log/samba/log.nmbd.2.gz (rotatecount 7, logstart 1, i 1),
renaming /var/log/samba/log.nmbd.0.gz to /var/log/samba/log.nmbd.1.gz (rotatecount 7, logstart 1, i 0),
old log /var/log/samba/log.nmbd.0.gz does not exist
renaming /var/log/samba/log.nmbd to /var/log/samba/log.nmbd.1
creating new /var/log/samba/log.nmbd mode = 0644 uid = 0 gid = 0
running postrotate script
compressing log with: /bin/gzip
gzip: stdin: file size changed while zipping
removing old log /var/log/samba/log.nmbd.8.gz
[...]
samba
(dans mon cas) que le problème se pose.
Connu ?
En cherchant un peu sur Internet, je suis tombé sur un article de distrosfaqs "Logrotate: File Size Changed While Zipping" citant à la fois logrotate
, la compression et samba mais ne donnait pas vraiment de reponse.
Finalement je suis tombé sur ce bugreport Debian "logrotate: file size changed while zipping" qui, bien que concernant Prosody, m'a conduit dans la bonne direction :
Le producteur de journaux serait encore en train d'écrire dedans alors queLooks like Prosody does not immediately close the old log file before it is compressed.
Upstream recently added delaycompress option to logrotate:
http://hg.prosody.im/debian/rev/b3998cd5c1b9
logrotate
le compresse : Ça colle avec ce qu'on avait trouvé plus haut.Mais il y a mieux : Le bugreport indique que l'author de Prosody a corrigé son script pour y ajouter l'option logrotate
delaycompress
:
diff -r 7ead6ae15c3c -r b3998cd5c1b9 prosody.logrotate --- a/prosody.logrotate Sat May 04 19:50:19 2013 +0100 +++ b/prosody.logrotate Tue May 28 21:11:51 2013 +0200 @@ -2,6 +2,7 @@ daily rotate 14 compress + delaycompress create 640 prosody adm postrotate /etc/init.d/prosody reload > /dev/nullRenseignement pris (grâce à
man logrotate
) delaycompress
, permet de :
Postpone compression of the previous log file to the next rotation cycle. This only has effect when used in combination with compress. It can be used when some program cannot be told to close its logfile and thus might continue writing to the previous log file for some time.Retarder la compression est une fonctionnalité proposée par
logrotate
qui pouvoir résoudre le problème (laissant environ 24 heures au programme pour arrêter d'écrire dans le fichier de log)
Correction du problème
Après vérifications le script gérant les journaux de samba (/etc/logrotate.d/samba
) n'utilise pas l'option delaycompress
, tout comme (/etc/logrotate.d/munin-update
d'ailleurs.
Il suffit juste de le rajouter (en dessous de compress
) et d'attendre pour constater que le problème ne se reproduit plus (et que les journaux continuent bien d'être "tournés" : très important ça) 🙂
La commande suivante, devrait vous lister tous les scripts de rotation qui compressent (compress
présent) mais sans faire retarder (pas de delaycompress
) :
grep -l -R -E "\Wcompress" . | xargs grep -L "delaycompress"Sans prétentions elle n'est clairement pas à l'abri de problèmes puisqu'un fichier de rotation peut contenir plusieurs blocs de configuration différents (et l'un peut présenter
compress
+delaycompress
tandis que l'autre uniquement compress
) mais ça permet de dégrossir un peu.
12 avril 2016 11:42
Toujours très utile tout ça, merci.
19 avril 2016 13:23
Très beau résumé. J'ai beaucoup appris de logrotate et de sa configuration à cette occasion. Peut-être serait-il bon de préciser que la dernière commande présuppose d'être dans le bon répertoire (mais on le voit vite si ce n'est pas le bon)