Page History

Les fichiers de log du broker sont situés dans le dossier /var/log/shinken/. Pour plus d'informations, consultez la page Fichiers Logs.

Démarrage du broker

[XXXXXXXXXXYYYY-MM-DD HH:MM:SS] INFO   : [ broker-name ] Using the local log file '/var/log/shinken/brokerd.log'
[XXXXXXXXXX] INFO   YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] Printing stored debug messages prior to our daemonization
[XXXXXXXXXXYYYY-MM-DD HH:MM:SS] INFO   : [ broker-name ] System[ limitSYSTEM number of process/threads is set to maximum available: 22392/22392
[XXXXXXXXXX] INFO   : [broker] System limitresource number of open files is set to maximum available: 131070/131070
[XXXXXXXXXX] INFO   : [broker] Starting HTTP daemon
[XXXXXXXXXX  is set to (soft:131070     / hard:131070    ) (set at system max values)
[YYYY-MM-DD HH:MM:SS] INFO: [ broker] |-----------------name ] [ SYSTEM           ] System resource number of processes/threads is set to (soft:unlimited  / hard:unlimited ) (set at system max values)
[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] Starting HTTP daemon
[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] |--------------------------------------------------------------------------------------------------|
[XXXXXXXXXX] INFO: [brokerYYYY-MM-DD HH:MM:SS] INFO: [ broker-name ]                                                          broker is starting
[XXXXXXXXXXYYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] |--------------------------------------------------------------------------------------------------|

Avec affichage:

• du Du fichier de log défini dans sa configuration (broker.ini)
• du nombres Du nombre de processus/threads maximum autorisé par le système pour ce daemondémon
• du nombres Du nombre de fichiers ouverts maximum autorisé par le système

Chargement d'une configuration

Premier chargement de la configuration

Lorsque le Broker reçoit sa configuration pour la première fois deux logs INFO sont affichés.

• Le premier indiquant que nous rentrons dans la phase de chargement d'une nouvelle configuration.

  Code Block
  theme Emacs
  [

• YYYY-MM-DD HH:MM:SS] INFO : [ broker-

• name ] [ CONFIGURATION ]

• -----

Un tour de boucle

• Loading the new configuration from the arbiter

• Le deuxième indiquant que nous avons reçu la configuration de l'Arbiter.

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] INFO : [ broker-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 broker n'est pas de la même version que l'arbiter et que l'option *mismatch_version_error* est activé sur l'arbiter:

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] ERROR : [ broker-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 broker n'est pas de la même version que l'arbiter et que l'option *mismatch_version_error* est désactivé sur l'arbiter:

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] WARNING : [ broker-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].

Mise à jour de la configuration

Lorsque qu'il y a une mise à jour de la configuration, deux logs en INFO sont affichés.

• Le premier indiquant que nous rentrons dans la phase de chargement d'une nouvelle configuration.

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] INFO : [ broker-name   ] [ CONFIGURATION ] [ UPDATE ] ----- Loading a configuration update from the arbiter

• Le deuxième indiquant que nous avons reçu la nouvelle configuration de l'Arbiter.

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] INFO : [ broker-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 broker n'est pas de la même version que l'arbiter et que l'option *mismatch_version_error* est activé sur l'arbiter:

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] ERROR : [ broker-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 broker n'est pas de la même version que l'arbiter et que l'option *mismatch_version_error* est désactivé sur l'arbiter:

• Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS]

• WARNING : [ broker-

• name ]

• Incompatible

• daemon

• version

• :

• Your

• Arbiter

• daemon

• is

• in

Récupération des broks des schedulers et arbiters

• version [XX.XX.XX-release.fr culmulative-patch-YY] while this daemon is in version [XX.XX.XX-release.fr culmulative-patch-YY].

Cas d'un démon recevant un nouveau démon spare ou une assignation d'un démon master

Dans le cas où un master reçoit le nom de son démon spare, on aura

:

[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-master  ] [RECEIVE CONFIGURATION BROKS] [ arbiterMASTER ] My spare daemon is       ] [PERFnow "broker-spare"

Dans le cas où un spare reçoit le nom de son démon master, on aura:

[YYYY-MM-DD HH:MM:SS] INFO : [ broker-spare ] [ 0.000CONFIGURATION ]s -[ AddSPARE 1] I am now broksthe intospare INTERNAL queue (new size=18) and of the EXTERNALmaster queue (new size=18)
[YYYY-MM-DD HH:MM:SS] INFO   : [broker-master  ] [RECEIVE BROKS] [ arbiter            ]                   ----- 1    composed of: architecture_export_map=1

daemon "broker-master"

Par rapport au paramètre broker__manage_spare__spare_must_have_the_same_list_of_module_type , le démon va mettre dans le cas où le paramètre change:

• Dans le cas où désormais il en a besoin:

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] INFO : [ broker-master ] [ CONFIGURATION ] [ MASTER ] The spare daemon "broker-spare-useless" is now requiring the same modules types as the master

• Dans le cas où désormais le spare n'a pas besoin d'avoir les mêmes modules (s'affichera notamment au démarrage du démon si le paramètre est désactivé)

  Code Block
  theme Emacs
  [YYYY-MM-DD HH:MM:SS] INFO

• : [ broker-master

• ] [

• CONFIGURATION

• ] [

• MASTER

• ]

• The

• spare daemon "broker-spare-useless" is now NOT requiring the same modules types as the master

Mise à jour des liens vers d'autres démons

Lorsque que l'Arbiter détecte un changement de lien entre les démons quatre logs en INFO seront affichés.

• Les deux premiers logs affichent le(les) lien(s) du(des) démon(s) supprimé(s).

0.007 ]s - Add 16   broks into INTERNAL queue (new size=16) and the EXTERNAL queue (new size=16)
[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-master  ] [GET BROKSCONFIGURATION ] The arbiter ]asked [us scheduler-masterto remove daemons: 
[YYYY-MM-DD HH:MM:SS] INFO : [ broker-master ] [ CONFIGURATION ] - REMOVED scheduler        ----- 16   composed of: host_check_result=10, host_next_schedule=6

Avec pour les deux cas:

• affichage du nombre de broks récupérés sur le daemon, et affichage de la taille des files d'attentes une fois rajoutés
• affichage du type de broks récupérés, ainsi que leur nombre

Envoie des broks aux modules externes

Statut des files d'envoi

: [name=scheduler1-name] [shard_id= XXX] [uri=http://scheduler_address:port/] 

• Les deux premiers logs affichent le(les) lien(s) du(des) démon(s) ajouté(s).

[YYYY-MM-DD HH:MM:SS] INFO : [ broker-master  ] [MANAGE BROKSCONFIGURATION ] [ EXTERNAL MODULE ] => Number of "Broks Sets" not eaten in MODULE queues (WebUI5-ha): 11 (WebUI3-ha): 11 (WebUI7-ha): 11 (WebUI4-ha): 11 (WebUI8-ha): 11 (WebUI1-ha): 11 (WebUI2-ha): 11 (WebUI6-ha): 11

A chaque tour de boucle, le broker envoie 1 ensemble de broks à chaque WebUI. 1 ensemble est composé d'autant de broks qu'il a reçus dans le tour.

Si le nombre est plus gros que 1, c'est que les WebUIs mettent du temps à digérer les ensembles.

• C'est courant au démarrage car les broks initiaux sont longs à être digéré,
• mais cela ne devrait pas arriver après.

Préparation des Broks pour l'envoi

Application par le démon de la propriété satellitemap (remaping d'adresse pour gérer un VLan)

Quand un démon a un paramètre satellitemap, il va changer l’adresse d'un autre démon par une autre (pour par exemple gérer le cas où il tourne dans un vlan avec un plan d’adressage particulier). Cette application se voit via le log suivant:

[YYYY-MM-DD HH:MM:SS] INFO : [ broker-master  ] [MANAGE BROKSCONFIGURATION ] [ PREPARINGSATELLITEMAP BROKS] Replacing the daemon ] [PERF] [ 0.001 ]s, preparing broks lists for INTERNAL and EXTERNAL modules

Chaque tour de boucle le broker préparer les listes d'envoi avec les nouveaux broks reçus.

Envoi vers les modules externes

scheduler-secondary to address:port from localhost:8768 => 192.168.1.124:8768 as defined in our daemon .cfg file (satellitemap property)

Ici le Scheduler scheduler-secondary est passé de l'adresse localhost:8768 à 192.168.1.124:8768.

Un tour de boucle

Début d'un tour

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-master name ] [MANAGEBROKER BROKSTIME ] [ EXTERNAL=== MODULELoop start ===  ] - PUSHED   [ 0.331s, limit=5.000s ]s, EXTERNAL queue evolution: [   424 broks =>     0 broks remaining ] [   424 broks managed ] [ Push average speed =  1928 broks/s]

Le broker a envoyé 424 broks en 0.331s, et avait laissé une limite de temps de 5s pour cet envoi (calcul basé sur la vitesse moyenne des derniers envois, ici 1928broks/s, et une marge de sécurité).

A noter: si le nombre de broks remaining est différent de zéro, ceci signifie que le broker a reçu des broks pendant la phase d'envoi, et qu'il les enverra le prochain tour.

Envoie des broks aux modules internes (sans leur propre processus)

Récupération des broks des Schedulers et Arbiters

L'Arbiter envoie ses broks vers le broker:

[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-name ] [RECEIVE BROKS] [ arbiter            ] [PERF] [ 0.000 ]s - Add 1    broks into INTERNAL queue (new size=18) and the EXTERNAL queue (new size=18)

[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-mastername  ] [MANAGERECEIVE BROKS ] [ INTERNALarbiter MODULE    ] - EXECUTED [ 0.239 ]s, INTERNAL queue] evolution: [   424 broks =>   238 broks remaining ] [   424 broks managed ]
[YYYY-MM-DD HH:MM:SS] INFO: [broker-master  ] ----- 1    composed       of: architecture_export_map=1

Le broker récupère les broks depuis un Scheduler:

[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-name ] [GET BROKS    ] [ scheduler-master   ] [PERF] [ 0.007 ]s - Add 16   broks into INTERNAL  ----- Details of INTERNAL modules execution time: (Graphite-Perfdata=0.071s), (Simple-log=0.010s), (sla=0.086s)

Le broker a fourni 424 broks aux modules internes (ceux qui n'ont pas leur propre processus), en 0.239s au total. Ici le nombre de broks remaining est différent de zéro, ceci signifie que le broker a reçu des broks pendant la phase d'envoi, et qu'il les enverra le prochain tour.

Il fourni ensuite le détail de temps de chaque module interne.

queue (new size=16) and the EXTERNAL queue (new size=16)
[YYYY-MM-DD HH:MM:SS] INFO   : [ broker-name ] [GET BROKS    ] [ scheduler-master   ]                   ----- 16   composed of: host_check_result=10, host_next_schedule=6

Avec pour les deux cas:

• Affichage du nombre de broks récupérés sur le démon, et affichage de la taille des files d'attente une fois rajoutés
• Affichage du type de broks récupérés, ainsi que leur nombre

Quand on a une erreur de transfert qui faisait perdre des broks dans le passé, on a cette entrée dans les logs:

[YYYY-MM-DD HH:MM:SS] INFOWARNING: [ broker-mastername  ] [MODULES GIVE   BROKS  ] [ EXTERNAL COMMANDS  broker-master ] [PERF]Did [fail 0.001 ]s Did read 0 external commands (like recheck, set acknowledge, etc) from modules

Le broker récupère les commandes (comme une création de downtime, etc) et le temps que ceci lui a demandé.

Appel au modules internes chaque seconde

to transfer broks from the scheduler "scheduler-master": [[Connexion error to https://192.80.10.220:7768/ : Operation timed out after 120000 milliseconds with 802816 out of 22791250 bytes received]. THESES BROKS ARE LOST AND CANNOT BE RETRIEVED

Elle disparaitra quand on aura bien testé le mécanisme de reprise sur erreur dans une future version.

Envoie des broks aux modules externes

Statut des files d'envoi

Chaque fin de tour, un appel est lancé vers les modules internes afin qu'ils puissent faire des actions spécifiques (par exemple vérifier un cache, vider leur éléments pas encore envoyés, etc)

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-mastername  ] [MODULESMANAGE BROKS ] [ EXTERNAL MODULE ] [=> TIMENumber INof BROKER"Broks Sets" not eaten in ]MODULE [PERF] [ 0.025 ]s All modules "ticks" are done. Execution times by modules: (Graphite-Perfdata=0.001s), (sla=0.024s)

Avec:

• le temps total
• le temps passé par chaque module

Fin d'un tour

queues (WebUI5-ha): 11 (WebUI3-ha): 11 (WebUI7-ha): 11 (WebUI4-ha): 11 (WebUI8-ha): 11 (WebUI1-ha): 11 (WebUI2-ha): 11 (WebUI6-ha): 11

À chaque tour de boucle, le broker envoie 1 ensemble de broks à chaque WebUI. 1 ensemble est composé d'autant de broks qu'il a reçus dans le tour.

Si le nombre est plus gros que 1, c'est que les WebUIs mettent du temps à digérer les ensembles.

• C'est courant au démarrage, car les broks initiaux sont longs à être traités
• Mais cela ne devrait pas arriver après

Préparation des Broks pour l'envoi

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-mastername  ] [BROKERMANAGE TIMEBROKS ] [ PREPARING ===BROKS Loop stop === ] [PERF] [ 0.397001 ]s

Le broker donne le temps qu'il a passé sur ce tour de boucle. Ce dernier doit rester sous la seconde sauf pendant la phase de reception d'une nouvelle configuration où il peux dépasser ce temps.

Surcharge serveur en activité disque, ralentissant l'écriture des logs

, preparing broks lists for INTERNAL and EXTERNAL modules

Chaque tour de boucle le broker préparer les listes d'envoi avec les nouveaux broks reçus.

Envoi vers les modules externes

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] [MANAGE BROKS ] [ EXTERNAL MODULE    ] - PUSHED   [ 0.331s, limit=5.000s ]s, EXTERNAL queue evolution: [   424 broks =>     0 broks remaining ] [   424 broks managed ] [ Push average speed =  1928 broks/s]

Le broker a envoyé 424 broks en 0.331s , et avait laissé une limite de temps de 5s  pour cet envoi (calcul basé sur la vitesse moyenne des derniers envois, ici 1928 broks/s , et une marge de sécurité).

À noter: si le nombre de broks remaining est différent de zéro, ceci signifie que le broker a reçu des broks pendant la phase d'envoi, et qu'il les enverra le prochain tour.

Envoie des broks aux modules internes (sans leur propre processus)

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] [MANAGE BROKS ] [ INTERNAL MODULE    ] - EXECUTED [ 0.239 ]s, INTERNAL queue evolution: [   424 broks =>   238 broks remaining ] [   424 broks managed ]
[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ]                                        ----- Details of INTERNAL brok deserialization time:0.010s modules execution time: (Graphite-Perfdata=0.071s), (Simple-log=0.010s), (sla=0.086s)

Le broker a fourni  424 broks aux modules internes (ceux qui n'ont pas leur propre processus), en  0.239s  au total. Ici le nombre de broks remaining est différent de zéro, ceci signifie que le broker a reçu des broks pendant la phase d'envoi, et qu'il les enverra le prochain tour.

Il fournit ensuite le temps passé à désérialiser les broks ainsi que le détail de temps de chaque module interne.

Récupération des commandes (demande de prise en compte, demande pour relancer une vérification, etc)

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] [MODULES      ] [ BUS COMMANDS  ] [PERF] [ 0.001 ]s Did read 0 internal commands (like recheck, set acknowledge, etc) from modules

Le broker récupère les commandes (comme une création de périodes de maintenance, etc.) et le temps que ceci lui a demandé.

Cas d'erreur

Si le broker ne parvient pas à récupérer les commandes d'un de ses modules, le log suivant est produit :

[YYYY-MM-DD HH:MM:SS] WARNING: [ broker-name ] [MODULES      ] [ BUS COMMANDS       ] Cannot read shinken internal commands (like recheck, set acknowledge, etc) from module [MODULE-NAME]. We will retry it.

Appel au modules internes chaque seconde

Chaque fin de tour, un appel est lancé vers les modules internes afin qu'ils puissent faire des actions spécifiques (par exemple vérifier un cache, vider leurs éléments pas encore envoyés, etc.)

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] [MODULES      ] [ TIME IN BROKER     ] [PERF] [ 0.025 ]s All modules "ticks" are done. Execution times by modules: (Graphite-Perfdata=0.001s), (sla=0.024s)

Avec:

• Le temps total
• Le temps passé par chaque module

Fin d'un tour

[YYYY-MM-DD HH:MM:SS] INFO: [ broker-name ] [BROKER TIME ] [ === Loop stop === ] [ Loop number=XX ] [PERF] [ 0.397 ]s

Le broker donne le temps qu'il a passé sur ce tour de boucle. Ce dernier doit rester sous la seconde sauf pendant la phase de réception d'une nouvelle configuration où il peut dépasser ce temps.

Surcharge serveur en activité disque, ralentissant l'écriture des logs

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 dans la mesure du possible, isoler le volume des disques sur un disque moins chargé pour ne pas ralentir le démon.

En cas de soucis, vous aurez dans les lots l'entrée suivante:

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 writes time 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 ]

Arrêt d'un module

Quand le broker doit éteindre un de ses modules, le log suivant est généré :

[YYYY-MM-DD HH:MM:SS] INFO : [ BROKER-NAME ] [MODULES ] [MODULE-NAME] Stopping module process pid=6505

Chargement des broks initiaux par un regenerator (créateur d'objets des modules de broker) permettant de vérifier que c'est bien la même configuration chargée entre les regenerators - schedulers - arbiters

Les logs suivants permet de suivre le chargement de la configuration de supervision entre l'arbiter les schedulers jusqu'aux interfaces : webui / livestatus / livedata

Il existe 2 types d'identifiants de configuration ( représentation de la configuration )

• configuration_uuid -> uuid de configuration totale générés par l'Arbiter
• configuration_part_id -> id de la partie de configuration géré par un Scheduler

Quand un module de broker avec un regenerator charge une nouvelle configuration :

[2020-05-15 16:29:49] INFO : [WebUI3] [ CONFIGURATION ] [ NEW ] [ REGENERATOR ] configuration part retrieved: [ configuration_part_id=configuration_part_id, scheduler=scheduler_name configuration_uuid=configuration_uuid, arbiter=arbiter_name date=creation_date ]

• configuration_part_id -> id de la partit de configuration gérée par le Scheduler (unique par Scheduler)
• scheduler_name ->nom du scheduler gère cette partie de la configuration
• configuration_uuid -> uuid crée lors du démarrage de l'Arbiter qui correspond donc à l'id de la configuration géré par l'Arbiter
• creation_date -> date du démarrage de l'Arbiter
• arbiter_name ->nom de l'Arbiter qui a créé cette configuration

[2020-05-15 16:29:49] INFO   : [WebUI3] [ CONFIGURATION ] [ NEW ] [ REGENERATOR ] configuration part retrieved : [ configuration_part_id=8, scheduler=scheduler-master configuration_uuid=fe5982b29bfb48cdadb35523799f7cec, arbiter=arbiter-master1 date=15-05-2020 16:13:40 ]

Quand un module de broker avec un regenerator rejet une configuration :

Dans le cas ou la configuration d'un Scheduler est déjà géré par un regenerator cas qui arrive si par exemple :
un module crash on redemande les broks initiaux donc tous les modules vont recevoir la nouvelle configuration, mais ceux qui la gère déjà ne vont pas la recharger et vont log :

[2020-05-15 16:41:40] INFO : [WebUI3] [ CONFIGURATION ] [ NEW ] [ REGENERATOR ] No need to reload the configuration part because I already handle it [ configuration_part_id=configuration_part_id, scheduler=scheduler_name configuration_uuid=configuration_uuid, arbiter=arbiter_name date=creation_date ]

• configuration_part_id -> id de la partit de configuration géré par le Scheduler (unique par Scheduler)
• scheduler_name ->nom du scheduler gère cette partie de la configuration
• configuration_uuid -> uuid crée lors du démarrage de l'Arbiter qui correspond donc à l'id de la configuration géré par l'Arbiter
• creation_date -> date du démarrage de l'Arbiter
• arbiter_name ->nom de l'Arbiter qui a créé cette configuration

[2020-05-15 16:41:40] WARNING: [WebUI3] [ CONFIGURATION ] [ NEW ] [ REGENERATOR ] No need to reload the configuration part because I already handle it [ configuration_part_id=8, scheduler=scheduler-master configuration_uuid=fe5982b29bfb48cdadb35523799f7cec, arbiter=arbiter-master1 date=15-05-2020 16:13:40 ]