J'avais jusqu'à présent eu aucune occasion de parler des upgrades de mon serveur Fedora ici, puisque jusqu'à présent il n'y avait pas grand chose à dire, même rien du tout. Depuis l'apparition de FedUp, en Fedora 17 si ma mémoire est bonne, j'ai upgradé successivement le système du serveur, avec soin et minutie, sans jamais rencontrer un seul pépin. Il faut dire que je le chouchoute, tous les jours il m'envoie son rapport journalier m'informant de diverses avaries rencontrées durant les dernières 24 heures, les réactions qu'il a eu pour corriger ces anomalies, et même lancer une fois par semaine des tests matériels.

On a quoi sur la table ?

Un Linux Apache Mariadb PHP Bind Postfix Dovecot NTP NFS Bittorrent Tor Jabber KVM (Bitcoin daemon est dans une VM), fraichement upgradé en F21, basé sur une installation minimale sans Environnement de Bureau. Deux disques durs pour un grand LVM, 23 volumes logiques (si si, pas moins), SELinux en mode targeted, SSH en mode authentification par clé, rapports de contrôle des fichiers avec la rpmdb, rapports des anomalies SELinux, des HIDS, etc...

Il s'est passé quoi ?

Une upgrade à première vue comme toutes les autres, le journal de FedUp est lisible ici pour le prouver (FedUp remplit le même fichier depuis F18, la partie qui nous concerne est tout en bas), sauf que le reboot suivant a déraillé. Au premier coup d'oeil le serveur NFS ne démarrait pas, son journal n'explique pas pourquoi. Le méta-moteur de recherche Seeks est aussi hors-service, sauf que lui on sait pourquoi : les dépendances du paquets F20 ne sont plus satisfaites, normal nous sommes en F21. NetworkManager quant à lui indique dans sont journal qu'il n'a plus du tout de mémoire disponible pour traiter de nouveaux événements.

janv. 22 15:31:30 lancaster rpc.statd[5232]: Version 1.3.1 starting
janv. 22 15:31:30 lancaster rpc.statd[5232]: Flags: TI-RPC
janv. 22 15:31:30 lancaster rpc.statd[5232]: failed to create RPC listeners, exiting
janv. 22 15:31:31 lancaster systemd[1]: rpc-statd.service: control process exited, code=exited status=1
janv. 22 15:31:31 lancaster systemd[1]: Failed to start NFS status monitor for NFSv2/3 locking..
janv. 22 15:31:31 lancaster systemd[1]: Unit rpc-statd.service entered failed state.
janv. 22 15:31:31 lancaster systemd[1]: rpc-statd.service failed.
janv. 22 15:31:31 lancaster rpc.mountd[5230]: Could not bind socket: (98) Address already in use
janv. 22 15:31:31 lancaster rpc.mountd[5230]: Could not bind socket: (98) Address already in use
janv. 22 15:31:31 lancaster rpc.mountd[5230]: Could not bind socket: (98) Address already in use
janv. 22 15:31:31 lancaster rpc.mountd[5230]: Could not bind socket: (98) Address already in use
janv. 22 15:31:31 lancaster rpc.mountd[5230]: mountd: No V2 or V3 listeners created!
janv. 22 15:31:31 lancaster rpc.mountd[5234]: Version 1.3.1 starting
janv. 22 15:31:31 lancaster rpc.nfsd[5237]: rpc.nfsd: writing fd to kernel failed: errno 111 (Connection refused)
janv. 22 15:31:31 lancaster kernel: svc: failed to register nfsdv3 RPC service (errno 111).
janv. 22 15:31:31 lancaster kernel: svc: failed to register nfsaclv3 RPC service (errno 111).
janv. 22 15:31:31 lancaster rpc.nfsd[5237]: rpc.nfsd: unable to set any sockets for nfsd
janv. 22 15:31:31 lancaster kernel: svc: failed to register nfsdv3 RPC service (errno 97).
janv. 22 15:31:31 lancaster kernel: svc: failed to register nfsaclv3 RPC service (errno 97).
janv. 22 15:31:31 lancaster systemd[1]: nfs-server.service: main process exited, code=exited, status=1/FAILURE
janv. 22 15:31:31 lancaster systemd[1]: Failed to start NFS server and services.
janv. 22 15:31:31 lancaster systemd[1]: Unit nfs-server.service entered failed state.
janv. 22 15:31:31 lancaster systemd[1]: nfs-server.service failed.

janv. 22 14:38:59 lancaster NetworkManager[958]: <error> [1421933939.450160] [platform/nm-linux-platform.c:3842] event_handler(): Failed to retrieve incoming events: Out of memory (-5)

Donc on fait quoi ?

Les pièces du puzzle sont en place, l'enquête va pouvoir commencer. Typiquement on commence par le plus petit pour aller vers le plus gros (problème), on dégrossi en quelques sortes. Seeks était pointé du doigt par la commande package-cleanup --problems, il apparait également dans le journal de FedUp. La meilleure solution pour lui en attendant la sortie du paquet F21 est bien de le retirer avec Yum. En lisant de près le journal du service nfs-server, on observe qu'en fait ce sont les services RPC dont NFS est dépendant, qui ne démarrent pas. J'ai remarqué aussi que NetworkManager a imprimé son erreur au même instant lorsque j'essayais de démarrer nfs-server, peut-être que les deux éléments sont liés.

J'ai donc fait plusieurs tests. J'ai commencé par supprimer le fichier /etc/sysctl.d/transmission.conf qui modifiait la mémoire maximum allouée à l'interface réseau. Ce hack (obsolète après test) résolvait une erreur dans le démon Transmission, puis j'ai stoppé le service Transmission pour voir s'il influençait NetworkManager, j'ai aussi essayé de démarrer plusieurs fois nfs-server pour voir si ça déclenchait l'erreur de NM. Aucun résultat à noter, nous avons bien à faire à un bug propre à NetworkManager. Si son bug n'est pas influencé par différents service réseau, est-ce que son bug affecte le démarrage des services RPC empèchant ainsi le démarrage de nfs-server ?

En regardant un peu sur le web, j'ai trouvé que le bug était connu sur EPEL7. Si le bug est connu quelque part, son fix est peut-être déjà arrivé dans le dépôt updates-testing. Erreur encore une fois, pas de mise à jour disponible pour le paquet NM. Le ticket du bug EPEL7 aidant, j'ai donc ouvert un ticket pour F21. Il ne reste plus que le cas des services RPC à traiter pour y voir plus clair dans l'affaire du serveur NFS.

Ironie du sort, en cherchant sur le Bugzilla je suis tombé par hasard sur ce ticket, dévoilant l'explication logique et rationnelle du pourquoi les services RPC ne démarraient pas. Les mots clés pour cette recherche furent : rpc.statd failed to create RPC listeners, exiting Qui eu crû que c'était parce que le service rpcbind.socket n'était ni activé ni démarré suite à l'upgrade ? Une fois ce socket activé, NFS ne démarra pas pour autant au boot de la machine. En effet, nfs.target est un reliquat du passé et n'existe plus sur F21. Il conviendra donc de désactiver puis réactiver ce service pour corriger les liens symboliques utilisés par systemd.

# systemctl disable nfs-server
Removed symlink /etc/systemd/system/nfs.target.wants/nfs-server.service.
# systemctl enable nfs-server
Created symlink from /etc/systemd/system/multi-user.target.wants/nfs-server.service to /usr/lib/systemd/system/nfs-server.service.

Le mystère est résolu

Élémentaire mon cher, lorsqu'on rencontre un problème avec NFS, c'est toute la pile RPC qu'il faut vérifier sur son système...