View Source

Chargement des broks initiaux par un regenerator ( créateur d'objets des modules de broker ) et vérifier que c'est bien la même configuration charger entre les regenerators / Scheduler / Arbiter

Les logs suivants permettent 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ée 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 partie de configuration gérée par le Scheduler (unique par Scheduler)
scheduler_name: nom du Scheduler qui 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ée par l'Arbiter
creation_date: date du démarrage de l'Arbiter
arbiter_name: nom de l'Arbiter qui a créé cette configuration

[YYYY-MM-DD HH:MM:SS] 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 rejette une configuration :

Dans le cas où la configuration d'un Scheduler est déjà gérée par un regenerator ( cas qui arrive si par exemple un module crash ) on redemande les broks initiaux. Tous les modules vont recevoir la nouvelle configuration, mais ceux qui la gère déjà ne vont pas la recharger et vont loguer :

[YYYY-MM-DD HH:MM:SS] 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 partie de configuration gérée par le Scheduler (unique par Scheduler)
scheduler_name: nom du Scheduler qui 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ée par l'Arbiter
creation_date: date du démarrage de l'Arbiter
arbiter_name: nom de l'Arbiter qui a créé cette configuration

[YYYY-MM-DD HH:MM:SS] 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 ]

Temps de locks trop long entre la consommation des Broks ( Ecriture ) et les requêtes des utilisateurs ( lecture )

Actuellement on ne sait pas consommer les broks et répondre aux utilisateurs en même temps. On a donc une concurrence entre deux parties:

Récupération et consommation des broks depuis le broker, et mise à jour des hôtes/checks/clusters (et tous les autres objets) depuis les informations des broks
Réponses aux requêtes des utilisateurs (parcours des hôtes, checks, clusters, ...)

Un des principal risque est une famine d'un des deux groupes d'actions:

si on ne fait qu'avaler des broks et ne jamais répondre aux utilisateurs, ceci va poser problème
symétriquement, si on ne fait que répondre aux utilisateurs, et jamais avaler des broks, on va avoir des informations périmées, voir on ne finira jamais de consommer de nouvelles configurations

Le gestionnaire de lock essaie de partager au mieux le temps d'exécution entre les deux groupes, en cas de forte charge, des logs vont remonter les lenteurs observées

Quand on a trop de requêtes de lectures, et qu'elles ne rendent pas la main pendant plus de 30s aux broks, on aura un log suivant ( Brok BLOQUE par les requêtes ):

ERROR: [ ITEMS ACCESS ORDONNANCER ] [ LONG LOCK ] Broks management are waiting (1 thread) since 30s (> log error limit=30s) because HTTP resquests (20 threads) has the LOCK

Quand on a trop de consommation de Broks, et que les requêtes sont bloquées (Requêtes utilisateurs BLOQUÉES par les Broks)

ERROR: [ ITEMS ACCESS ORDONNANCER ] [ LONG LOCK ] HTTP resquests are waiting (5 threads) since 30s (> log error limit=30s) because Broks management (1 thread) has the LOCK

Quand les requêtes en lecture mettent trop de temps à rendre la main au consommateur de Broks et que d'autres requêtes en lecture attendent de pouvoir s'exécuter depuis trop longtemps :

ERROR: [ ITEMS ACCESS ORDONNANCER ] [ LONG LOCK ] Still have 9 running tasks ongoing (HTTP resquests). => ( 1 ) Broks management and then ( 11 ) HTTP resquests are waiting since 30s (>= log error limit:30s)

Quand la consommation de Broks met trop de temps à rendre la main pour la gestion de requêtes en lecture, et que d'autres consommateurs attendent de s'exécuter depuis trop longtemps (cas théorique, n'est pas supposé survenir en fonctionnement normal) :

ERROR: [ ITEMS ACCESS ORDONNANCER ] [ LONG LOCK ] Still have 1 running tasks ongoing (Broks management). => ( 12 ) HTTP requests then ( 1 ) Broks management are waiting since 30s (>= log error limit:30s)

L'absorption des broks a pris du retard

Activation du rattrapage des broks en retard, on prend un brok set supplémentaire à traiter, on affiche :

le nombre de broks dans le brok set
le temps passé pour récupérer le brok set sur la queue
le nombre actuel de broks à traiter
le nombre maximal de broks qu'on peut récupérer avant de les traiter
le nombre de brok set encore en attente

[AAAA-MM-DD hh:mm:ss] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF] [LATE BROKS SETS]  Getting brok set with XX broks in 0.000s [time for read queue size=0.000s]. Total broks to process= XXX/max:XXXX. Broks sets in queue: X.

Rattrapage des broks en retard en cours, on a atteint/dépassé le nombre maximal de broks à récupérer, on les traite :

[AAAA-MM-DD hh:mm:ss] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF] [LATE BROKS SETS] Late brok taken => limit reach : XX / limit: XXXXXX.

Des broks on été traités, affichage de statistiques :

nombre de broks traités
temps d'attente du premier brok set
nombre de brok set en retard récupérés, et le temps que ça a pris de les récupérer
temps passé à dé-sérialiser les broks
temps d'attente du lock avant de traiter les broks
temps passé pour traiter les broks
temps total

[AAAA-MM-DD hh:mm:ss] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF]  [ XXXX broks ] [ wait and get first set on queue=0.000s ] [ get 0 late sets on=0.000s ] [ unserialize=0.000s ] [ wait write lock=0.000s ] [ manage broks=0.000s ] [ total=0.000s ]

Affichage du type des broks à traités

[AAAA-MM-DD hh:mm:ss] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF]                  => manage broks types : [brok_type_1=XXXX] [brok_type_2=XX] [...]

Exemple de log

[2021-01-25 19:00:34] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF]                  => manage broks types : [initial_command_status=1374] [initial_hostgroup_status=657] [service_next_schedule=2677] [update_program_status=21] [program_status=3] [host_check_result=568] [clean_all_my_instance_id=3] [initial_service_status=67969] [initial_contactgroup_status=24] [initial_timeperiod_status=15] [initial_broks_done=3] [initial_contact_status=1644] [initial_host_status=1960] [host_next_schedule=508] [log_monitoring=36] [update_service_status=2] [service_check_result=3271] [proxy_items_graph=3]

Après avoir traiter des broks, il reste trop de brok set en attente, on garde le lock et on continue l'absorption des broks en retard

[AAAA-MM-DD hh:mm:ss] INFO   : [ WebUI-6         ] [ MANAGE BROKS ] [PERF] Broks sets in queue after manage broks is XX. We keep the lock and continue the brok managing.