Les fichiers de log du Poller sont situés dans le dossier /var/log/shinken/. Pour plus d'informations, consultez la page Fichiers Logs.
Au démarrage et tous les jours à minuit, en plus des logs communs à tous les démons, le Poller indique l'état du logger optionnel d'exécution :
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ START-DAEMON ] [ LOGGERS CONFIGURATION ] --------------------------------------------------------- [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ START-DAEMON ] [ LOGGERS CONFIGURATION ] Optional loggers activation : [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ START-DAEMON ] [ LOGGERS CONFIGURATION ] - DISABLED : [ CHECK EXECUTION ] [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ START-DAEMON ] [ LOGGERS CONFIGURATION ] --------------------------------------------------------- |
Ce logger peut être activé pour suivre l'exécution des commandes de vérification ( voir la section Logs d'exécution des commandes de vérification ).
Au démarrage du démon, les lignes suivantes indiquent les limites systèmes qui sont appliquées :
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ SYSTEM ] System resource number of open files is set to (soft:1024 / hard:1024 ) (from parameter max_file_descriptor_limit) [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ SYSTEM ] System resource number of processes/threads is set to (soft:unlimited / hard:unlimited ) (set at system max values) |
Avec comme informations principales:
Lorsque le Poller reçoit sa configuration pour la première fois, deux logs INFO sont affichés.
Le premier indiquant que le Poller rentre dans la phase de chargement d'une nouvelle configuration.
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] ----- Loading the new configuration from the arbiter |
Le deuxième indiquant que le Poller a reçu la configuration de l'Arbiter.
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] The arbiter send us a new configuration: [configuration_uuid=configuration-uuid, arbiter=arbiter-name, architecture=architecture-name, date=YYYY-MM-DD HH:MM:SS] |
Dans le cas où le Poller n'est pas de la même version que l'Arbiter et que l'option *mismatch_version_error* est activée sur l'Arbiter:
[YYYY-MM-DD HH:MM:SS] ERROR : [ poller-name ] Incompatible daemon version : Your Arbiter daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY] while this daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY]. Refusing this configuration. |
Dans le cas où le Poller n'est pas de la même version que l'Arbiter et que l'option *mismatch_version_error* est désactivée sur l'Arbiter:
[YYYY-MM-DD HH:MM:SS] WARNING : [ poller-name ] Incompatible daemon version : Your Arbiter daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY] while this daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY]. |
Lorsqu'il y a une mise à jour de la configuration, deux logs en INFO sont affichés.
Le premier indiquant que le Poller rentre dans la phase de chargement d'une nouvelle configuration.
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] [ UPDATE ] ----- Loading a configuration update from the arbiter |
Le deuxième indiquant que le Poller a reçu la configuration de l'Arbiter.
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] [ UPDATE ] The arbiter send us a new configuration: [configuration_uuid=configuration-uuid, arbiter=arbiter-name, architecture=architecture-name, date=YYYY-MM-DD HH:MM:SS] |
Dans le cas où le Poller n'est pas de la même version que l'Arbiter et que l'option *mismatch_version_error* est activée sur l'Arbiter:
[YYYY-MM-DD HH:MM:SS] ERROR : [ poller-name ] Incompatible daemon version : Your Arbiter daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY] while this daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY]. Refusing this configuration. |
Dans le cas où le Poller n'est pas de la même version que l'Arbiter et que l'option *mismatch_version_error* est désactivée sur l'Arbiter:
[YYYY-MM-DD HH:MM:SS] WARNING : [ poller-name ] Incompatible daemon version : Your Arbiter daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY] while this daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY]. |
Lorsque l'Arbiter détecte un changement de lien entre les démons, quatre logs en INFO seront affichés.
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] The arbiter asked us to remove daemons: [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] - REMOVED scheduler : [name=scheduler1-name] [shard_id= XXX] [uri=http://scheduler_address:port/] |
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] The arbiter send us new daemons: [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CONFIGURATION ] + ADDED scheduler : [name=scheduler2-name] [shard_id= XXX] [uri=http://scheduler_address:port/] |
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CHECKS ] [ scheduler-master ] [ GET ] Requesting checks todo from this scheduler for 2.000s cpu time [received=3 check(s) for 0.039s cpu time] |
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CHECKS ] [ scheduler-master ] [ RECEIVED ] We received checks todo from this scheduler for 2.000s cpu time [received=1 check(s) for 0.317s cpu time] |
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CHECKS RESULTS ] [scheduler-master] [ PUSHED ] 1 check's result(s) sends to this scheduler in [0.043]s |
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ CHECKS RESULTS ] [scheduler-master] [ GIVEN ] 1 check's result(s) given to answer scheduler request |
Si le serveur hébergeant le démon est surchargé en termes d'IO disques sur le volume qui héberge le fichier de log, alors ce dernier va mettre du temps à s'écrire et va ralentir tout le démon. Il faut alors si c'est faisable isoler le volume des disques sur un disque moins chargé pour ne pas ralentir le démon.
En cas de soucis, il sera écrit les lignes suivantes :
[YYYY-MM-DD HH:MM:SS] WARNING : [ LOGGER ] [YYYY-MM-DD HH:MM:SS] WARNING : [ LOGGER ] ---------------------------------------------------------------------------------------------------- [YYYY-MM-DD HH:MM:SS] WARNING : [ LOGGER ] [ WRITING ] The log write times is very high (1.87s). Please look at your log disk performance. [YYYY-MM-DD HH:MM:SS] WARNING : [ LOGGER ] ---------------------------------------------------------------------------------------------------- [YYYY-MM-DD HH:MM:SS] WARNING : [ LOGGER ] |
Quand un check de supervision du démon est fait, on va avoir plusieurs entrées dans les logs qui concernent des données que le démon garde sur diverses statistiques.
Un log permet d'avoir le temps pris sur le calcul des dernières commandes en timeout:
[YYYY-MM-DD HH:MM:SS] DEBUG : [ poller-name ] [ STATS ] Compute "Checks in timeouts" stats : 0.000s in a total of 2048 commands in timeouts |
Un log permet d'avoir le temps de calcul concernant les ranges d'exécution des checks/notifications en fonction du temps (<100ms, <400ms, etc):
[YYYY-MM-DD HH:MM:SS] DEBUG : [ poller-name ] [ STATS ] Compute "Checks per CPU running time" : 0.000s (on a total of 2048 checks) |
Un log permet d'avoir le temps de calcul pour avoir les 5 commandes les plus longues en temps CPU:
[YYYY-MM-DD HH:MM:SS] DEBUG : [ poller-name ] [ STATS ] top5 execution time 0.003s (loop over 1 ranges and 343 elements) |
Un dernier log permet d'avoir le temps complet du calcul des statistiques du démon:
[YYYY-MM-DD HH:MM:SS] DEBUG : [ poller-name ] [ STATS ] Daemon stats were computed in 0.020s (0.001 for daemon common part, 0.020 for poller part) |
En cas d'affichage INFO on met un petit morceau en plus sur comment gérer le niveau de log:
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ STATS ] Daemon stats were computed in 0.004s (0.000 for daemon common part, 0.004 for poller part) (NOTE: log is displayed in INFO because 0.004 is higher than display_statistics_compute_time_if_higher=1ms in the daemon cfg) |
Le démon nettoie ses structures de statistiques toutes les 5minutes, ce qui sera vu par la ligne de log suivante:
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ STATS ] Clean checks in timeouts structure in 0.000s (before clean: 0 commands in timeouts, after clean: 0) |
On peut savoir si les workers manquent de disponibilité CPU/RAM/Load average en suivant les logs.
Si on a manqué de performance ce tour (CPU, RAM ou load average trop élevé, indiqué), alors on aura le log suivant:
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ ALL WORKERS ] [ MISSING RESSOURCE ] Must launch: 2 checks ( Expected CPU Time: 1.318s ) => Launched: 1/2 checks => Wait 0.530s CPU/Memory availability |
Sinon ils ont pu tout lancer, on aura le log suivant:
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ ALL WORKERS ] Launched all 2/2 checks ( Expected CPU Time: 1.318s ) |
Si le worker n'a pas réussi à lancer de check pendant plus de 5 seconds on aura le log suivant:
[YYYY-MM-DD HH:MM:SS] WARNING : [ poller-name ] [worker-fork] [WORKER_ID] is full since 〖X〗. It has 〖Y〗 checks pending. |
ou :
On peut suivre les sondes au sein du Poller via le log suivant, pour les checks provenant des Schedulers & Synchronizers (cumulés, pour l'instant on n’a pas l'information sur toute la chaine du Poller):
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ FOR SCHEDULERS/SYNCHRONIZERS ] [ THIS TURN ] [ Daemon ] [ Waiting to be push to workers ] 8 checks, Expected CPU Time: 1.06s [YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ THIS TURN ] => [ Workers ] [ New launch = 9 checks, Expected CPU Time: 1.10s ] [ Executing = 6 checks, Expected CPU Time: 1.601s ] [ Just finished = 7 checks, Consumed CPU Time: 0.62s, +0.03s from Expected CPU Time ] [YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ THIS TURN ] [ Daemon ] [ Waiting to be returned ] 6 checks, Consumed CPU Time: 1.06s |
Avec:
Et les mêmes informations, mais sur une moyenne d'une minute glissantes:
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ FOR SCHEDULERS/SYNCHRONIZERS ] [ 1min AVERAGE ] [ Daemon ] [ Waiting to be push to workers ] 14.42 checks/s, Expected CPU Time: 2.11s [YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ 1min AVERAGE ] => [ Workers ] [ New launch = 5.98 checks/s, Expected CPU Time: 0.91s ] [ Executing = 5.10 checks/s, Expected CPU Time: 0.933s ] [ Just finished = 5.78 checks/s, Consumed CPU Time (total): 1.35s, +0.00s from Expected CPU Time ] [YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ PERFS ] [ 1min AVERAGE ] [ Daemon ] [ Waiting to be returned ] 5.80 checks/s, Consumed CPU Time: 0.88s |
Note: on doit avoir des valeurs sensiblement équivalentes entre les valeurs suivantes:
Et ils représentent le débit du Poller.
Les démons ont une phase de chargement des modules qui est décrite dans la page GLOBAL - Les logs de gestion des modules - chapitre [ MODULES-MANAGER ]
Le log suivant indique
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [ STATS ] action in main daemon to be dispatched to workers: [ XX ], distribution by worker [ WORKER XX: XX done this turn / XX total pending ] [ WORKER XX: XX done this turn / XX total pending ] total: [ XX ] |
Le log suivant indique le nombre d'actions présentes dans le Worker, ainsi qu'une estimation du temps CPU nécessaire à leur exécution
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-master ] [WORKER XX][COMMAND TO PROCESS] Worker load_todo_actions : X.XXX nb_action : XX |
Si un worker est surchargé, le log WARNING suivant sera généré, indiquant qu'il met trop de temps à retourner ses résultats :
[YYYY-MM-DD HH:MM:SS] WARNING : [ poller-name ] The worker 2 reception did fail this turn (IOError), skip to the next turn to receive more. |
Les logs suivants permettent de suivre le temps d'exécution de la boucle principale du Poller
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ POLLER TIME ] [ === Loop start === ] [ Loop number=XXX ] ===-===-===-===-===-===-===-===-===-===-===-===-=== [YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ POLLER TIME ] [ === Loop stop === ] [ Loop number=XXX ] [PERF] [ X.XXX ]s |
Le log suivant permet de suivre l'activité de chaque Worker et de s'assurer que chacun continue de tourner
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ POLLER TIME ] [ WORKERS ] Last activity [ WORKER X: X.XXXs ago, WORKER Y: Y.YYYs ago] |
Quand le tour de boucle d'un Worker n'a pas fini avant un certain délai, le log suivant signale la lenteur observée
[YYYY-MM-DD HH:MM:SS] WARNING : [ poller-name ] [ POLLER TIME ] [ WORKER X ] is slow, last tick was X.XXXs ago, over limit of X.XXXs |
Quand le tour de boucle d'un Worker prend beaucoup trop de temps, le log suivant signale le retard observé
[YYYY-MM-DD HH:MM:SS] ERROR : [ poller-name ] [ POLLER TIME ] [ WORKER X ] is late, last tick was X.XXXs ago, over limit of X.XXXs |
L'activation ou la désactivation du logger optionnel se fait via l'utilisation d'une commande curl depuis le shell.
Les paramètres requis sont :
Le résultat de cette commande renvoie un document JSON.
Suivant l'activité du Poller, l'activation de ce logger peut générer un gros volume de données. Sur un site de production, il est conseillé de limiter l'activation de ce logger sur de courtes périodes ( par exemple une heure au plus ), afin de limiter le surplus d'occupation disque engendré. |
curl -s -k "POLLER_PROTOCOLE://POLLER_IP:POLLER_PORT/set_log_enable?logger_id=LOGGER_ID&enable=1" |
curl -s -k "http://localhost:7771/set_log_enable?logger_id=CHECK_EXECUTION&enable=1" |
La commande doit renvoyer la sortie :
{"message": "logger [Shinken] [CHECK EXECUTION CONTROL] is enabled"} |
Quand le logger est activé, le log suivant est généré :
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ INFO-DAEMON ] [ LOGGERS CONFIGURATION ] - ENABLING : [ XXXX EXECUTION ] |
[2025-11-06 16:45:36] INFO : [ poller-master ] [ INFO-DAEMON ] [ LOGGERS CONFIGURATION ] - ENABLING : [ CHECK EXECUTION ] |
curl -s -k "POLLER_PROTOCOLE://POLLER_IP:POLLER_PORT/set_log_enable?logger_id=LOGGER_ID&enable=0" |
curl -s -k "http://localhost:7771/set_log_enable?logger_id=CHECK_EXECUTION&enable=0" |
La commande doit renvoyer la sortie :
{"message": "logger [Shinken] [CHECK EXECUTION CONTROL] is disabled"} |
Quand le logger est désactivé, le log suivant est généré :
[YYYY-MM-DD HH:MM:SS] INFO : [ poller-name ] [ INFO-DAEMON ] [ LOGGERS CONFIGURATION ] - DISABLING : [ XXXX EXECUTION ] |
[2025-11-06 16:58:23] INFO : [ poller-master ] [ INFO-DAEMON ] [ LOGGERS CONFIGURATION ] - DISABLING : [ CHECK EXECUTION ] |
curl -s -k "POLLER_PROTOCOLE://POLLER_IP:POLLER_PORT/get_log_info?logger_id=LOGGER_ID" |
curl -s -k "http://localhost:7771/get_log_info?logger_id=CHECK_EXECUTION" |
La commande doit renvoyer une sortie du style :
[{"id": "CHECK_EXECUTION", "name": "[Shinken] [CHECK EXECUTION CONTROL]", "enable": true}] |
Lorsqu'une commande s'exécute, et que le logger d'exécution a été activé, les logs suivants sont générés.
Si la commande termine avec un code de terminaison compris entre 1 et 3 ( inclus ), Shinken considère que la commande a fonctionné correctement ( voir la page Les Sondes, section "Code retour" ).
[YYYY-MM-DD HH:MM:SS] INFO : [ WORKER X ] [ XXXXX EXECUTION ] [ DONE ] [ UUID ] [ COMMAND ] : CHEMIN_DE_LA_COMMANDE ... [YYYY-MM-DD HH:MM:SS] INFO : [ WORKER X ] [ XXXXX EXECUTION ] [ DONE ] [ UUID ] [ STATUS ] : RESULTAT D'EXÉCUTION [YYYY-MM-DD HH:MM:SS] INFO : [ WORKER X ] [ XXXXX EXECUTION ] [ DONE ] [ UUID ] [ RESULT ] : SORTIE GÉNÉRÉE LIGNE 1 [YYYY-MM-DD HH:MM:SS] INFO : [ WORKER X ] [ XXXXX EXECUTION ] [ DONE ] [ UUID ] [ RESULT ] : SORTIE GÉNÉRÉE LIGNE 2 |
[2025-11-06 18:15:29] INFO : [ WORKER 4 ] [ CHECK EXECUTION ] [ DONE ] [ 5e38b68a4e8845fd8dfbf47090b01424 ] [ COMMAND ] : /var/lib/shinken-user/libexec/uss-nautilus/nautilus_commande ... [2025-11-06 18:15:29] INFO : [ WORKER 4 ] [ CHECK EXECUTION ] [ DONE ] [ 5e38b68a4e8845fd8dfbf47090b01424 ] [ STATUS ] : 1 (WARNING) [2025-11-06 18:15:29] INFO : [ WORKER 4 ] [ CHECK EXECUTION ] [ DONE ] [ 5e38b68a4e8845fd8dfbf47090b01424 ] [ RESULT ] : output by uss-nautilus [2025-11-06 18:15:29] INFO : [ WORKER 4 ] [ CHECK EXECUTION ] [ DONE ] [ 5e38b68a4e8845fd8dfbf47090b01424 ] [ RESULT ] : | |
Les commandes de vérification dont le code de terminaison n'est pas compris entre 0 et 3 ( inclus ) sont considérées comme non fonctionnelles ( voir la page Les Sondes, section "Code retour" ).
[YYYY-MM-DD HH:MM:SS] ERROR : [ WORKER X ] [ XXXXX EXECUTION ] [ ERROR ] [ UUID ] [ COMMAND ] : CHEMIN_DE_LA_COMMANDE ... [YYYY-MM-DD HH:MM:SS] ERROR : [ WORKER X ] [ XXXXX EXECUTION ] [ ERROR ] [ UUID ] [ STATUS ] : RESULTAT D'EXÉCUTION [YYYY-MM-DD HH:MM:SS] ERROR : [ WORKER X ] [ XXXXX EXECUTION ] [ ERROR ] [ UUID ] [ RESULT ] : SORTIE GÉNÉRÉE LIGNE 1 [YYYY-MM-DD HH:MM:SS] ERROR : [ WORKER X ] [ XXXXX EXECUTION ] [ ERROR ] [ UUID ] [ RESULT ] : SORTIE GÉNÉRÉE LIGNE 2 |
[2025-11-06 18:12:03] ERROR : [ WORKER 2 ] [ CHECK EXECUTION ] [ ERROR ] [ 16049b9c632040b7822b80cb934c36ff ] [ COMMAND ] : /usr/bin/bash ... [2025-11-06 18:12:03] ERROR : [ WORKER 2 ] [ CHECK EXECUTION ] [ ERROR ] [ 16049b9c632040b7822b80cb934c36ff ] [ STATUS ] : 8 (ERROR) [2025-11-06 18:12:03] ERROR : [ WORKER 2 ] [ CHECK EXECUTION ] [ ERROR ] [ 16049b9c632040b7822b80cb934c36ff ] [ RESULT ] : failed to [2025-11-06 18:12:03] ERROR : [ WORKER 2 ] [ CHECK EXECUTION ] [ ERROR ] [ 16049b9c632040b7822b80cb934c36ff ] [ RESULT ] : execute on this system |