Distribution EOLE

informations remontées par Karim à ce sujet (et au sujet de problèmes avec zephir-client) :

petit info sur le plantage du service Zéphir qui semble sévir sur quelques serveurs si je ne me trompe pas.

comme tu le sais j'ai 2 serveurs Zéphir, ce matin j'ai trouvé l'un des 2 avec zéphir planté et comme je m'en doutais depuis le départ c'est au moment de la rotation des logs qu'il ne se relance pas.

j'ai donc jeté un oeil à l'autre zéphir :

la rotation s'était effectuée j'avais bien les fichiers zephir_backend.info.log.1 et zephir_backend.info.log
le service s'était relancé :

root     20611 22.1 30.0 2540500 1836240 ?     Sl   06:26  53:46 /usr/bin/python /usr/bin/twistd --syslog --pidfile /var/run/zephir_backend.pid --reactor epoll -no zephir_backend
nobody   20968  0.0  0.6 142924 38972 ?        S    06:26   0:07 /usr/bin/python /usr/bin/twistd --syslog --pidfile /var/run/zephir_web.pid --reactor epoll -no zephir_web

et pourtant le service écrivait encore dans le fichier zephir_backend.info.log.1 !!

je décide de relancer zephir, et la 1ère fois j'ai un échec :

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# service zephir restart
 * Arret du système Zephir...                                                                                   [ OK ]
 * Demarrage du système Zephir...                                                                                    
 Le système Zephir est déja lancé                                                                                [fail]

le pid est toujours présent dans /var/run/

je relance encore une fois zéphir, cette fois-ci cela fonctionne :

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# service zephir restart
 * Arret du système Zephir...                                                                                          Le système Zephir est déjà arreté                                                                               [ OK ]
 * Demarrage du système Zephir...                                                                               [ OK ]

je regarde les logs, et je m'aperçoit qu'il continue de loguer dans zephir_backend.info.log.1.

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# tailf zephir_backend.info.log.1
Mar  1 10:45:15 zephir23-1 zephir_backend: [HTTPChannel,39383,109.0.146.117] connexion du serveur 1025
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] Received SIGTERM, shutting down.
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] (Port 7081 Closed)
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] (Port 8090 Closed)
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] Stopping factory <twisted.web.server.Site instance at 0x30fdea8>
Mar  1 10:45:16 zephir23-1 zephir_backend: [twisted.web.server.Site] (Port 7080 Closed)
Mar  1 10:45:16 zephir23-1 zephir_backend: [twisted.web.server.Site] Stopping factory <twisted.web.server.Site instance at 0x30fae60>
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] Main loop terminated.
Mar  1 10:45:16 zephir23-1 zephir_backend: [-] Server Shut Down.
Mar  1 10:45:21 zephir23-1 zephir_backend: [HTTPChannel,1,194.199.77.31] connexion du serveur 813
Mar  1 10:45:22 zephir23-1 zephir_backend: [-] debsums : pas de dernière mesure disponible.
Mar  1 10:45:22 zephir23-1 zephir_backend: [-] RootDebsums : pas de dernière mesure disponible.
Mar  1 10:45:22 zephir23-1 zephir_backend: [-] RRDtool warning: This RRD was created on another architecture
Mar  1 10:45:22 zephir23-1 zephir_backend: last message repeated 3 times
Mar  1 10:45:22 zephir23-1 zephir_backend: [HTTPChannel,8,193.51.226.119] connexion du serveur 12

Mar  1 10:45:23 zephir23-1 zephir_backend: [HTTPChannel,9,194.199.117.101] connexion du serveur 651
Mar  1 10:45:25 zephir23-1 zephir_backend: [HTTPChannel,13,80.14.44.202] connexion du serveur 938

je décide alors de relancer rsyslog :

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# service rsyslog restart
rsyslog start/running, process 6404
root@zephir23-1:/var/log/rsyslog/local/zephir_backend#

et là il log bien dans le nouveau log zephir_backend.info.log

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# tailf zephir_backend.info.log
Mar  1 10:48:07 zephir23-1 zephir_backend: last message repeated 3 times
Mar  1 10:48:07 zephir23-1 zephir_backend: [HTTPChannel,160,193.51.226.125] connexion du serveur 530
Mar  1 10:48:07 zephir23-1 zephir_backend: [HTTPChannel,161,88.173.76.197] connexion du serveur 911
Mar  1 10:48:07 zephir23-1 zephir_backend: [HTTPChannel,162,194.199.77.57] connexion du serveur 909
Mar  1 10:48:08 zephir23-1 zephir_backend: [HTTPChannel,166,194.199.77.45] connexion du serveur 868
Mar  1 10:48:10 zephir23-1 zephir_backend: [HTTPChannel,170,193.51.226.81] connexion du serveur 673
Mar  1 10:48:10 zephir23-1 zephir_backend: [HTTPChannel,171,194.199.117.113] connexion du serveur 462
Mar  1 10:48:11 zephir23-1 zephir_backend: [HTTPChannel,172,194.199.117.20] connexion du serveur 296
Mar  1 10:48:12 zephir23-1 zephir_backend: [HTTPChannel,173,194.199.75.71] connexion du serveur 57
Mar  1 10:48:14 zephir23-1 zephir_backend: [HTTPChannel,176,193.51.226.101] connexion du serveur 733
Mar  1 10:48:18 zephir23-1 zephir_backend: [-] Mise en cache des configurations : 150/872 effectué
Mar  1 10:48:21 zephir23-1 zephir_backend: [HTTPChannel,199,194.57.173.197] connexion du serveur 271
^C
root@zephir23-1:/var/log/rsyslog/local/zephir_backend#

pour ce problème je pense qu'il faudrait peut-être recharger rsyslog après la rotation.

------------------

pour le problème du service zephir qui ne se relance pas, je pense qu'il y a un soucis avec la suppression du .pid par moment il ne parvient pas à le supprimer.

d'ailleurs j'ai remarqué que le numéro de process présent dans le .pid et celui renvoyé par un ps n'est pas toujours identique d'où le test dans le script d'init :

/bin/kill -SIGTERM $pid >/dev/null 2>&1 || rm -f $PIDFILE

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# cat /var/run/zephir_backend.pid ; echo "" 
18082

root@zephir23-1:/var/log/rsyslog/local/zephir_backend# ps aux |grep zephir_backend
root      8982  105 23.1 2050348 1414112 pts/19 Sl  11:31   6:27 /usr/bin/python /usr/bin/twistd --syslog --pidfile /var/run/zephir_backend.pid --reactor epoll -no zephir_backend

dans le script d'init :

quand les numéros de process sont diffèrents :

 printf ' '
 + '[' -f /var/run/zephir_backend.pid ']'
++ cat /var/run/zephir_backend.pid
+ pid=25070
+ /bin/kill -SIGTERM 25070
+ rm -f /var/run/zephir_backend.pid  #ici il est supprimé à la bourrin car le numéro de process est diffèrent
+ rm -f /var/lock/zephir_backend
+ rm -f /var/spool/uucp/lock

dans ce cas de figure cela fonctionne très bien.

par contre ce qui ne marche pas à tous les coups :

 printf ' '
 + '[' -f /var/run/zephir_backend.pid ']'
++ cat /var/run/zephir_backend.pid
+ pid=10423
+ /bin/kill -SIGTERM 10423
+ rm -f /var/lock/zephir_backend
+ rm -f /var/spool/uucp/lock

je pense que lorsque les numéros de process sont identiques le kill -SIGTERM ne fait pas toujours son taf de supprimer le zephir_backend.pid

Après étude avec Benjamin, j'ai envoyé un patch à Karim avec les modifications pour recharger rsyslog après rotation des logs.

Pour les autres pb, il y aura d'autres demandes.