Exécution du script bm_check_all.sh

Bonjour à tous !

Lorsque j’exécute le script bm_check_all.sh afin de vérifier que “tout fonctionne bien”, j’ai le retour suivant :

On check_core.sh... check_core.sh is OK. On check_dav.sh... check_dav.sh is OK. On check_disk_usage.sh... check_disk_usage.sh is OK. On check_eas.sh... check_eas.sh is OK. On check_es.sh... check_es.sh is OK. On check_hps.sh... check_hps.sh is OK. On check_imap.sh... check_imap.sh is OK. On check_ips.sh... check_ips.sh is OK. On check_lmtp.sh... Authentication failed. no mechanism available check_lmtp.sh is OK. On check_locator.sh... 92.222.104.236 check_locator.sh is OK. On check_milter.sh... check_milter.sh is OK. On check_mq.sh... check_mq.sh is OK. On check_node.sh... check_node.sh is OK. On check_smtp.sh... check_smtp.sh is OK. On check_tika.sh... check_tika.sh is OK. On check_tomcat.sh... check_tomcat.sh is OK. On check_xmpp.sh... check_xmpp.sh is OK. On check_ysnp.sh... check_ysnp.sh FAILED.

Il semblerait donc que seuls “check_lmtp.sh” & “check_ysnp.sh” pose problème. Dois-je m’inquiéter ?

Merci par avance

Guillaume

Pour le LMTP non, c’est le message Authentication failed. no mechanism available qui n’est pas correct. D’ailleurs la ligne du dessous indique bien:
check_lmtp.sh is OK..

Pour ysnp par contre.
Si vous exécutez la commande:

# /usr/share/bm-checks/check_ysnp.sh

Qu’avez-vous dans les logs du service ysnp, /var/log/ysnp/ysnp.log ?

Alors en exécutant la commande, le log ne se crée pas.

Mais voici ce qu’il y avait déjà à l’intérieur du log (uniquement la dernière ligne de type “ERROR” car il est très long…) :

2016-04-25 00:12:21,931 n.b.c.c.u.UserClient ERROR - validation failed for user: office@global.virt, origin: ysnp net.bluemind.core.api.fault.ServerFault: validation failed for user: office@global.virt, origin: ysnp at net.bluemind.core.client.impl.AbstractClientImpl.checkServerError(AbstractClientImpl.java:302) ~[net.bluemind.core.client_1.0.0.b13866.jar:na] at net.bluemind.core.client.impl.AbstractClientImpl.validate(AbstractClientImpl.java:203) ~[net.bluemind.core.client_1.0.0.b13866.jar:na] at net.bluemind.core.client.user.UserClient.validate(UserClient.java:178) [net.bluemind.core.client_1.0.0.b13866.jar:na] at net.bluemind.ysnp.bmcore.impl.CoreCredentialValidator.validate(CoreCredentialValidator.java:92) [net.bluemind.ysnp.bmcore_1.0.0.b13866.jar:na] at net.bluemind.ysnp.impl.ValidationPolicy.validate(ValidationPolicy.java:101) [net.bluemind.ysnp_1.0.0.b13866.jar:na] at net.bluemind.ysnp.impl.SaslauthdProtocol.check(SaslauthdProtocol.java:93) [net.bluemind.ysnp_1.0.0.b13866.jar:na] at net.bluemind.ysnp.impl.SaslauthdProtocol.execute(SaslauthdProtocol.java:77) [net.bluemind.ysnp_1.0.0.b13866.jar:na] at net.bluemind.ysnp.impl.AsyncExecutor.doAsyncAuthentificationDialog(AsyncExecutor.java:73) [net.bluemind.ysnp_1.0.0.b13866.jar:na] at net.bluemind.ysnp.impl.AsyncExecutor.run(AsyncExecutor.java:62) [net.bluemind.ysnp_1.0.0.b13866.jar:na]

Ce message est normal, l’utilisateur office@global.virt n’existe pas - il n’est pas possible de créer des utilisateurs dans le domaine glkobal.virt.

Arrivez-vous a consulter votre messagerie via le webmail ?

Oui, tout marche bien à ce niveau là.

Que donne la commande:

# testsaslauthd -u admin0@global.virt -p `cat /etc/bm/bm-core.tok`

Vous êtes sur le serveur BlueMind ou sur un satellite (noeud ldap-role ou autre par exemple) ?

Ceci :

0: OK "Success."

Sur le serveur BM direct.

La commande bm_check_all.sh vous indique toujours une erreur sur ce service ?

Ah non, ça y est !

On check_core.sh... check_core.sh is OK. On check_dav.sh... check_dav.sh is OK. On check_disk_usage.sh... check_disk_usage.sh is OK. On check_eas.sh... check_eas.sh is OK. On check_es.sh... check_es.sh is OK. On check_hps.sh... check_hps.sh is OK. On check_imap.sh... check_imap.sh is OK. On check_ips.sh... check_ips.sh is OK. On check_lmtp.sh... Authentication failed. no mechanism available check_lmtp.sh is OK. On check_locator.sh... 92.222.104.236 check_locator.sh is OK. On check_milter.sh... check_milter.sh is OK. On check_mq.sh... check_mq.sh is OK. On check_node.sh... check_node.sh is OK. On check_smtp.sh... check_smtp.sh is OK. On check_tika.sh... check_tika.sh is OK. On check_tomcat.sh... check_tomcat.sh is OK. On check_xmpp.sh... check_xmpp.sh is OK. On check_ysnp.sh... check_ysnp.sh is OK.

L’aviez-vous lancé juste après un boot ou un bmctl restart ?

Non, après avoir lu votre documentation : https://forge.bluemind.net/confluence/display/BM35/Monitoring

J’ai programmé une crontask quotidienne pour exécuter le script et recevoir le retour par mail pour m’assurer que tout aille bien. Et depuis, j’ai cette “erreur”.

Quelle est la fréquence d’exécution de cette cron ?
L’erreur est systématique ?

Quel utilisateur exécute cette cron ?

Chaque jour à 5h00.
Oui, mais cela fait seulement 2 jours que la crontask est en place.

root

Trouvez-vous l’échec d’authentification d’admin0 vers 5h du matin dans le fichier /var/log/ysnp/ysnp.log ?

Je n’ai pas d’échec d’authentification. Voici ce que j’ai vers les 5h :

2016-04-25 04:58:21,285 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 04:58:21,286 n.b.y.i.ValidationPolicy INFO - Access to imap granted from token cache for gsoub@XXXX.fr 2016-04-25 04:58:47,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28795, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 04:59:17,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28795, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 04:59:47,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28795, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:00:17,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28795, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:00:21,285 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 05:00:21,285 n.b.y.i.ValidationPolicy INFO - Access to imap granted from token cache for gsoub@XXXX.fr 2016-04-25 05:00:47,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:01:17,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:01:47,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:02:17,859 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35462, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11053} 2016-04-25 05:02:21,336 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 05:02:21,342 n.b.y.i.ValidationPolicy INFO - Access to service imap granted to gsoub with 'bm-core' validator in 6ms. 2016-04-25 05:02:47,860 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35463, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11054} 2016-04-25 05:03:17,860 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28796, missCount=35463, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11054}

Attention, les heures dans les logs des services java sont en UTC, actuellement il faut enlever 2h.

Pardon, voici à 3h :

2016-04-25 02:56:21,176 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 02:56:21,176 n.b.y.i.ValidationPolicy INFO - Access to imap granted from token cache for gsoub@XXXX.fr 2016-04-25 02:56:47,843 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28755, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:57:17,843 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28755, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:57:47,843 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28755, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:58:17,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28755, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:58:21,139 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 02:58:21,139 n.b.y.i.ValidationPolicy INFO - Access to imap granted from token cache for gsoub@XXXX.fr 2016-04-25 02:58:47,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28756, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:59:17,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28756, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 02:59:47,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28756, missCount=35410, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 03:00:01,353 n.b.y.i.SaslauthdProtocol INFO - Attempting login: admin0 service: imap realm: 2016-04-25 03:00:01,369 n.b.y.i.ValidationPolicy INFO - Access to service imap granted to admin0 with 'bm-core' validator in 16ms. 2016-04-25 03:00:01,422 n.b.y.i.SaslauthdProtocol INFO - Attempting login: admin0 service: imap realm: 2016-04-25 03:00:01,424 n.b.y.i.ValidationPolicy INFO - Access to service imap granted to admin0 with 'bm-core' validator in 2ms. 2016-04-25 03:00:01,493 n.b.y.i.SaslauthdProtocol INFO - Attempting login: admin0 service: smtp realm: 2016-04-25 03:00:01,493 n.b.y.i.ValidationPolicy INFO - Access to smtp granted from token cache for admin0@ 2016-04-25 03:00:17,845 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28757, missCount=35412, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11009} 2016-04-25 03:00:21,509 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 03:00:21,512 n.b.y.i.ValidationPolicy INFO - Access to service imap granted to gsoub with 'bm-core' validator in 3ms. 2016-04-25 03:00:47,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28757, missCount=35413, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11010} 2016-04-25 03:01:17,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28757, missCount=35413, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11010} 2016-04-25 03:01:47,844 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28757, missCount=35413, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11010} 2016-04-25 03:02:17,845 n.b.y.i.ValidationPolicy INFO - CacheStats{hitCount=28757, missCount=35413, loadSuccessCount=0, loadExceptionCount=0, totalLoadTime=0, evictionCount=11012} 2016-04-25 03:02:21,184 n.b.y.i.SaslauthdProtocol INFO - Attempting login: gsoub service: imap realm: XXXX.fr 2016-04-25 03:02:21,184 n.b.y.i.ValidationPolicy INFO - Access to imap granted from token cache for gsoub@XXXX.fr

Comment avez-vous déclaré cette cron (via crontab -e exécuté en tant que root, un fichier dans /etc/cron*…) ?

via crontab -e exécuté en tant que root

Il semblerait que la commande:

testsaslauthd -u admin0@global.virt -p `cat /etc/bm/bm-core.tok`

retourne un code erreur différent de 0 lors de son exécution par la cron, mais si ce service n’était réellement pas actif, il ne serait pas possible de faire des accès à sa messagerie (webmail, Activesync et/ou IMAP).

Que donne:

# crontab -l

J’ai pensé à un éventuel problème de droit qui ne permettrait pas d’accèder au socket unix de ce service, mais si le script a les droits root il n’y a pas de raisons.
Vous n’utilisez pas SELinux ou autre ?