Maj. nextcloud 15.0.5~ynh3 vers 15.0.12~ynh1 impossible (erreur fail2ban vraissemblablement)

Bonjour à tous.

J’utilise depuis plusieurs mois yunohost (dernière version) sur un serveur VPS OVH (tournant sur une debian 9 à jour), sans modification (les apps installées sont nextcloud, dokuwiki et phpmyadmin et rien d’autre)

Après avoir effectué une mise à jour système sans problème particulier, j’ai voulu mettre à jour nextcloud (15.0.5~ynh3 vers 15.0.12~ynh1).

Hélas, à la fermeture de fail2ban, il m’a été indiqué plusieurs erreurs et l’impossibilité d’accéder à certains logs (problème de droits ?). Après l’échec de la mise à jour de nextcloud, j’ai relancé yunohost qui est resté en carafe (heureusement j’ai pu immédiatement restaurer en ligne de commande une sauvegarde réalisées quelques minutes avant la maj de nextcloud).

J’ai retenté la mise à jour et j’ai eu exactement le même problème sinon que yunohost n’a pas planté au redémarrage. Je note que j’ai la même erreur fail2ban en tentant de mettre à jour dokuwiki. En revanche, la maj de phpmyadmin est passée comme une fleur).

Je me permets de poster les deux logs d’erreur, merci de votre aide :slight_smile: :

- Nextcloud:

2019-11-04 15:17:22,727: DEBUG - + local action
2019-11-04 15:17:22,727: DEBUG - + local line_match
2019-11-04 15:17:22,727: DEBUG - + local length
2019-11-04 15:17:22,727: DEBUG - + local log_**********
2019-11-04 15:17:22,728: DEBUG - + local timeout
2019-11-04 15:17:22,728: DEBUG - + ynh_handle_getopts_args --service_name=fail2ban --action=reload
2019-11-04 15:17:22,728: DEBUG - + set +x
2019-11-04 15:17:22,728: DEBUG - + local service_name=fail2ban
2019-11-04 15:17:22,728: DEBUG - + local action=reload
2019-11-04 15:17:22,728: DEBUG - + local log_**********=/var/log/fail2ban/fail2ban.log
2019-11-04 15:17:22,728: DEBUG - + local length=20
2019-11-04 15:17:22,729: DEBUG - + local timeout=300
2019-11-04 15:17:22,731: DEBUG - + [[ -n ‘’ ]]
2019-11-04 15:17:22,731: DEBUG - + ‘[’ reload == reload ‘]’
2019-11-04 15:17:22,731: DEBUG - + action=reload-or-restart
2019-11-04 15:17:22,731: DEBUG - + systemctl reload-or-restart fail2ban
2019-11-04 15:18:52,793: DEBUG - + journalctl --no-pager --lines=20 -u fail2ban
2019-11-04 15:18:52,795: WARNING - Job for fail2ban.service failed.
2019-11-04 15:18:52,796: DEBUG - + test -e /var/log/fail2ban/fail2ban.log
2019-11-04 15:18:52,797: WARNING - See “systemctl status fail2ban.service” and “journalctl -xe” for details.
2019-11-04 15:18:52,797: DEBUG - + false
2019-11-04 15:18:52,798: WARNING - – Logs begin at Sun 2019-11-03 11:02:01 CET, end at Mon 2019-11-04 15:18:52 CET. –
2019-11-04 15:18:52,798: DEBUG - + ynh_exit_properly
2019-11-04 15:18:52,799: WARNING - Nov 04 15:00:45 toto.ovh systemd[1]: Stopping Fail2Ban Service…
2019-11-04 15:18:52,799: DEBUG - + local exit_code=1
2019-11-04 15:18:52,800: WARNING - Nov 04 15:02:15 toto.ovh systemd[1]: fail2ban.service: Stopping timed out. Terminating.
2019-11-04 15:18:52,800: DEBUG - + ‘[’ 1 -eq 0 ‘]’
2019-11-04 15:18:52,801: WARNING - Nov 04 15:02:15 toto.ovh fail2ban-client[18421]: WARNING Caught signal 15. Exiting
2019-11-04 15:18:52,801: DEBUG - + trap ‘’ EXIT
2019-11-04 15:18:52,802: WARNING - Nov 04 15:02:16 toto.ovh systemd[1]: fail2ban.service: Control process exited, code=exited status=255
2019-11-04 15:18:52,802: DEBUG - + set +eu
2019-11-04 15:18:52,803: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: fail2ban.service: State ‘stop-sigterm’ timed out. Killing.
2019-11-04 15:18:52,803: DEBUG - + sleep 0.5
2019-11-04 15:18:52,804: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: fail2ban.service: Killing process 10490 (fail2ban-server) with signal SIGKILL.
2019-11-04 15:18:52,804: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: fail2ban.service: Main process exited, code=killed, status=9/KILL
2019-11-04 15:18:52,805: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: Stopped Fail2Ban Service.
2019-11-04 15:18:52,806: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: fail2ban.service: Unit entered failed state.
2019-11-04 15:18:52,806: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: fail2ban.service: Failed with result ‘timeout’.
2019-11-04 15:18:52,807: WARNING - Nov 04 15:03:46 toto.ovh systemd[1]: Starting Fail2Ban Service…
2019-11-04 15:18:52,807: WARNING - Nov 04 15:03:59 toto.ovh fail2ban-client[20912]: 2019-11-04 15:03:59,277 fail2ban.server [20913]: INFO Starting Fail2ban v0.9.6
2019-11-04 15:18:52,807: WARNING - Nov 04 15:03:59 toto.ovh fail2ban-client[20912]: 2019-11-04 15:03:59,279 fail2ban.server [20913]: INFO Starting in daemon mode
2019-11-04 15:18:52,808: WARNING - Nov 04 15:04:08 toto.ovh systemd[1]: Started Fail2Ban Service.
2019-11-04 15:18:52,808: WARNING - Nov 04 15:17:22 toto.ovh systemd[1]: Reloading Fail2Ban Service.
2019-11-04 15:18:52,808: WARNING - Nov 04 15:18:52 toto.ovh systemd[1]: fail2ban.service: Reload operation timed out. Killing reload process.
2019-11-04 15:18:52,809: WARNING - Nov 04 15:18:52 toto.ovh systemd[1]: Reload failed for Fail2Ban Service.
2019-11-04 15:18:53,311: DEBUG - + ynh_print_err ‘–message=!!\n nextcloud’’‘s script has encountered an error. Its execution was cancelled.\n!!’
2019-11-04 15:18:53,311: WARNING - /usr/share/yunohost/helpers.d/logging: line 90: args_array: readonly variable
2019-11-04 15:18:53,312: DEBUG - + local legacy_args=m
2019-11-04 15:18:53,313: DEBUG - + args_array=([m]=message=)
2019-11-04 15:18:53,464: ERROR - Impossible de mettre à jour nextcloud

- Dokuwiki:

2019-11-04 15:58:45,384: DEBUG - + python -
2019-11-04 15:58:45,484: DEBUG - + ‘[’ -n ‘’ ‘]’
2019-11-04 15:58:45,484: DEBUG - + unset backup_file_checksum
2019-11-04 15:58:45,485: DEBUG - + ynh_systemd_action --service_name=fail2ban --action=reload
2019-11-04 15:58:45,485: DEBUG - + local legacy_args=nalpte
2019-11-04 15:58:45,485: DEBUG - + args_array=([n]=service_name= [a]=action= [l]=line_match= [p]=log_= [t]=timeout= [e]=length=)
2019-11-04 15:58:45,485: DEBUG - + declare -Ar args_array
2019-11-04 15:58:45,485: DEBUG - + local service_name
2019-11-04 15:58:45,485: DEBUG - + local action
2019-11-04 15:58:45,485: DEBUG - + local line_match
2019-11-04 15:58:45,485: DEBUG - + local length
2019-11-04 15:58:45,486: DEBUG - + local log_

2019-11-04 15:58:45,486: DEBUG - + local timeout
2019-11-04 15:58:45,486: DEBUG - + ynh_handle_getopts_args --service_name=fail2ban --action=reload
2019-11-04 15:58:45,486: DEBUG - + set +x
2019-11-04 15:58:45,486: DEBUG - + local service_name=fail2ban
2019-11-04 15:58:45,486: DEBUG - + local action=reload
2019-11-04 15:58:45,486: DEBUG - + local log_**********=/var/log/fail2ban/fail2ban.log
2019-11-04 15:58:45,486: DEBUG - + local length=20
2019-11-04 15:58:45,486: DEBUG - + local timeout=300
2019-11-04 15:58:45,487: DEBUG - + [[ -n ‘’ ]]
2019-11-04 15:58:45,487: DEBUG - + ‘[’ reload == reload ‘]’
2019-11-04 15:58:45,487: DEBUG - + action=reload-or-restart
2019-11-04 15:58:45,487: DEBUG - + systemctl reload-or-restart fail2ban
2019-11-04 16:00:15,703: DEBUG - + journalctl --no-pager --lines=20 -u fail2ban
2019-11-04 16:00:15,705: WARNING - Job for fail2ban.service failed.
2019-11-04 16:00:15,705: DEBUG - + test -e /var/log/fail2ban/fail2ban.log
2019-11-04 16:00:15,706: WARNING - See “systemctl status fail2ban.service” and “journalctl -xe” for details.
2019-11-04 16:00:15,707: DEBUG - + false
2019-11-04 16:00:15,707: WARNING - – Logs begin at Mon 2019-11-04 15:45:27 CET, end at Mon 2019-11-04 16:00:15 CET. –
2019-11-04 16:00:15,708: DEBUG - + ynh_exit_properly
2019-11-04 16:00:15,708: WARNING - Nov 04 15:45:49 toto.ovh systemd[1]: Starting Fail2Ban Service…
2019-11-04 16:00:15,708: DEBUG - + local exit_code=1
2019-11-04 16:00:15,708: WARNING - Nov 04 15:45:54 toto.ovh fail2ban-client[870]: 2019-11-04 15:45:54,112 fail2ban.server [1168]: INFO Starting Fail2ban v0.9.6
2019-11-04 16:00:15,711: DEBUG - + ‘[’ 1 -eq 0 ‘]’
2019-11-04 16:00:15,711: WARNING - Nov 04 15:45:54 toto.ovh fail2ban-client[870]: 2019-11-04 15:45:54,114 fail2ban.server [1168]: INFO Starting in daemon mode
2019-11-04 16:00:15,711: DEBUG - + trap ‘’ EXIT
2019-11-04 16:00:15,712: WARNING - Nov 04 15:45:58 toto.ovh systemd[1]: Started Fail2Ban Service.
2019-11-04 16:00:15,713: DEBUG - + set +eu
2019-11-04 16:00:15,713: WARNING - Nov 04 15:46:00 toto.ovh systemd[1]: Reloading Fail2Ban Service.
2019-11-04 16:00:15,714: DEBUG - + sleep 0.5
2019-11-04 16:00:15,715: WARNING - Nov 04 15:46:07 toto.ovh systemd[1]: Reloaded Fail2Ban Service.
2019-11-04 16:00:15,716: WARNING - Nov 04 15:58:45 toto.ovh systemd[1]: Reloading Fail2Ban Service.
2019-11-04 16:00:15,718: WARNING - Nov 04 16:00:15 toto.ovh systemd[1]: fail2ban.service: Reload operation timed out. Killing reload process.
2019-11-04 16:00:15,718: WARNING - Nov 04 16:00:15 toto.ovh systemd[1]: Reload failed for Fail2Ban Service.
2019-11-04 16:00:16,220: DEBUG - + ynh_print_err ‘–message=!!\n dokuwiki’’‘s script has encountered an error. Its execution was cancelled.\n!!’
2019-11-04 16:00:16,220: WARNING - /usr/share/yunohost/helpers.d/logging: line 90: args_array: readonly variable
2019-11-04 16:00:16,221: DEBUG - + local legacy_args=m
2019-11-04 16:00:16,221: DEBUG - + args_array=([m]=message=)
2019-11-04 16:00:16,332: ERROR - Impossible de mettre à jour dokuwiki

Bonjour,
Sur les logs fail2ban, 2 sujets peuvent peut-être t’aider :



En revanche, je ne suis pas sûr qu’il s’agisse du même problème !

Merci pour ta contribution mais effectivement il ne s’agit pas du même problème: dans les deux cas évoqués dans tes liens, fail2ban ne se relance pas à la suite d’une mise à jour (ou d’une désinstallation) d’une application car il ne trouve pas les logs de l’application “Shaarli”.

Je n’ai pas cette application et surtout mes logs ne montrent pas que fail2ban plante car il ne trouve pas les logs ou une prison d’une application.

En revanche, je note une incohérence, il veut accéder à “/var/log/fail2ban/fail2ban.log” qui n’existe pas (même pas le répertoire):

2019-11-04 15:58:45,486: DEBUG - + local log_**********=/var/log/fail2ban/fail2ban.log
[…]
2019-11-04 16:00:15,705: DEBUG - + test -e /var/log/fail2ban/fail2ban.log

C’est peut-être une piste mais je ne sais pas quoi chercher maintenant sachant que journalctl me donne pas grand chose :confused:

root@toto:/usr/share# journalctl -u fail2ban --since yesterday
– Logs begin at Mon 2019-11-04 16:27:41 CET, end at Mon 2019-11-04 18:43:36 CET. –
Nov 04 16:28:02 toto.ovh systemd[1]: Starting Fail2Ban Service…
Nov 04 16:28:07 toto.ovh fail2ban-client[879]: 2019-11-04 16:28:07,109 fail2ban.server [1146]: INFO Starting Fail2ban v0.9.6
Nov 04 16:28:07 toto.ovh fail2ban-client[879]: 2019-11-04 16:28:07,109 fail2ban.server [1146]: INFO Starting in daemon mode
Nov 04 16:28:10 toto.ovh systemd[1]: Started Fail2Ban Service.
Nov 04 16:28:12 toto.ovh systemd[1]: Reloading Fail2Ban Service.
Nov 04 16:28:26 toto.ovh systemd[1]: Reloaded Fail2Ban Service.
Nov 04 18:22:49 toto.ovh systemd[1]: Reloading Fail2Ban Service.
Nov 04 18:24:19 toto.ovh systemd[1]: fail2ban.service: Reload operation timed out. Killing reload process.
Nov 04 18:24:19 toto.ovh systemd[1]: Reload failed for Fail2Ban Service.

Pas plus que le log de fail2ban (/var/log/fail2ban.log):

2019-11-04 18:24:32,847 fail2ban.actions        [1257]: NOTICE  [recidive] Unban xxx
2019-11-04 18:24:33,059 fail2ban.actions        [1257]: NOTICE  [recidive] Unban xxx
2019-11-04 18:24:33,271 fail2ban.actions        [1257]: NOTICE  [recidive] Unban xxx
2019-11-04 18:24:33,588 fail2ban.jail           [1257]: INFO    Jail 'recidive' stopped
2019-11-04 18:24:34,513 fail2ban.jail           [1257]: INFO    Jail 'sshd-ddos' stopped
2019-11-04 18:24:34,908 fail2ban.filter         [1257]: INFO    [pam-generic] Found yyy
2019-11-04 18:24:34,928 fail2ban.jail           [1257]: INFO    Jail 'postfix-sasl' stopped
2019-11-04 18:24:35,490 fail2ban.jail           [1257]: INFO    Jail 'nginx-http-auth' stopped
2019-11-04 18:24:36,495 fail2ban.jail           [1257]: INFO    Jail 'yunohost' stopped
2019-11-04 18:24:37,082 fail2ban.jail           [1257]: INFO    Jail 'pam-generic' stopped
2019-11-04 18:24:37,197 fail2ban.jail           [1257]: INFO    Jail 'dokuwiki' stopped
2019-11-04 18:24:37,720 fail2ban.jail           [1257]: INFO    Jail 'dovecot' stopped

Peut-être tout simplement le créer !

Bon, on touche à l’irrationnel là ^^

N’ayant aucune piste dans les logs de fail2ban j’ai regardé par acquis de conscience les logs de nginx et sans que j’en trouve la cause, j’avais une liste longue comme le bras d’erreur de résolution de letsencrypt.org retournant “Operation timed out”.

J’ai manuellement renouvelé le certificat letsencrypt (dans l’interface web) alors qu’il restait de mémoire 23 jours avant son expiration (et devant donc se renouveler automatiquement dans peu de temps).

Sans vraiment y croire, j’ai relancé la mise à jour de dokuwiki, qui est passée à la vitesse de l’éclair!

En revanche, celle de nextcloud veut toujours pas passer et alors même que les logs d’erreur des deux applications sont (étaient) similaires.

J’admets ne pas comprendre, aussi bien le fait que la maj de dokuwiki passe après le renouvellement du certificat letsencrypt, que le fait que celle de nextcloud ne passe toujours pas ?!? :crazy_face:

(Uh nope, faut mieux pas faire ça … ce truc apparait dans les logs juste parce que le helper de apps derrière ça essaye des trucs chelou pour regarder si un service quelconque demarre bien en supposant que son log est dans /var/log/{service}/{service}.log … mais en vrai à part nginx je connais pas 1000 services pour lesquels c’est vraiment le cas … )

Bon j’ai compris et le caractère aléatoire du passage de la mise à jour entre dokuwiki et nextcloud m’a mis sur la piste.

Le timeout pour fermer, reconfigurer et relancer fail2ban n’est pas lié à une erreur du script de mise à jour, mais bien au délai de réponse pour effectuer les différentes opérations.

Ceci est d’ailleurs évoqué dans cette conversation s’agissant d’etherpad:

En purgeant dans fail2ban les ip à bannir:
sqlite> DELETE FROM bans ;
sqlite> .quit

La mise à jour de nextcloud est passée comme une fleur ! Bon à savoir ! :grinning:

1 Like