Module chargés dans le Broker


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME    ] I correctly loaded the modules: [sla,Simple-log,WebUI,Livestatus,Graphite-Perfdata]


Initialisation du module SLA - CHAPITRE [ INITIALISATION ]

Sur le Broker

Création du module


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] =============          Starting module initialisation     ==============
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Creating new migration process named : BROKER_NAME [ - Module: sla - migration]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Creating new archive process named : BROKER_NAME [ - Module: sla - archive]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Creating a queue manager process for the module.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Reading module configuration
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Creating 1 workers


Paramètre de connexion à la base mongo


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] Creating connection to sla database [shinken]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] MongoDB parameters
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - database__name ————————————————————————————————————————————————— :〖 shinken 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - database__uri —————————————————————————————————————————————————— :〖 mongodb://192.168.1.69/?w=1&fsync=false 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - replica_set ———————————————————————————————————————————————————— :〖  〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - use_ssh_tunnel ————————————————————————————————————————————————— :〖 0 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - ssh_user ——————————————————————————————————————————————————————— :〖 shinken 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - ssh_keyfile ———————————————————————————————————————————————————— :〖 ~shinken/.ssh/id_rsa 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - ssh_tunnel_timeout ————————————————————————————————————————————— :〖 10 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] AutoReconnect Management
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - database__retry_connection_X_times_before_considering_an_error — :〖 4 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ]    - database__wait_X_seconds_before_reconnect —————————————————————— :〖 3 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] Try to open a Mongodb connection to mongodb://192.168.1.69/?w=1&fsync=false:shinken
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] Mongo connection established in 3.13ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] [ MONGO ] Ensure that the index is present in the database ( and create it if necessary ). Done in 80.84ms


Fin de l'initialisation du module


[YYYY-MM-DD HH:MM:SS] INFO : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] Load from collection 28 elements info in cache done in 0.84ms
[YYYY-MM-DD HH:MM:SS] INFO : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] Found first element monitoring at 17-06-2020 10:42:52
[YYYY-MM-DD HH:MM:SS] INFO : [ BROKER_NAME ] [ sla              ] [ INITIALISATION ] ============= Module initialized in 234.97ms ==============


Démarrage du processus de migration - chapitre "[ MIGRATION ]"


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] Sub process ready to work.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] Migration process BROKER_NAME [ - Module: sla-writer - migration] initialization 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] Parameter load for migrating
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - daily_clean_batch_size ————————————————— :〖 10000 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - daily_clean_pause_time ————————————————— :〖 2 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - broker_module_sla_migration_batch_size — :〖 1000 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - broker_module_sla_migration_pause_time — :〖 0 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - nb_stored_days ————————————————————————— :〖 -1 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ]    - time_when_delete_old_SLA ——————————————— :〖 03:02 〗 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] [ MONGO ] Creating connection to sla database [shinken]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] [ MONGO ] Try to open a Mongodb connection to mongodb://localhost/?w=1&fsync=false:shinken
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] [ MONGO ] Mongo connection established in 6.62ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] [ MONGO ] Ensure mongo index done in 4.18ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] Load from collection 28 elements info in cache done in 0.92ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:31197) ] [ INITIALISATION ] Migration process BROKER_NAME [ - Module: sla-writer - migration] initialized


Erreurs - La connexion au serveur Mongo n'est pas établie
Avec Tunnel SSH


[YYYY-MM-DD HH:MM:SS] ERROR : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Initialisation Module: Error : [ BROKER_NAME -sla ] [ SSH TUNNEL ] [ MONGODB          ]  - mongo connection failure : localhost:43577 ==(ssh tunnel)==> 192.168.1.87:22 ==(mongodb)==> 192.168.1.87:27017.


Sans Tunnel SSH


[YYYY-MM-DD HH:MM:SS] ERROR : [ BROKER_NAME   ] [ sla              ] [ INITIALISATION ] Initialisation Module: Error : [ BROKER_NAME  -sla ] [ MONGODB          ]   - mongo connection failure to 192.168.1.87:27017


Démarrage du processus d'archive - CHAPITRE "[ ARCHIVE ] "


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Sub process ready to work.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Starting initialization of archive process [BROKER_NAME [ - Module: sla-writer - archive]]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Reading configuration for sla archive writing 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - time_before_shinken_inactive —————————————————————————————————— :〖 30 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - minimal_time_before_an_element_become_missing_data ———————————— :〖 60 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - minimal_time_before_an_element_become_missing_data_at_startup — :〖 600 〗 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Parameter load for sla writing 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - size_chunk_to_archive ——— :〖 10000 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - time_between_two_chunks — :〖 0,1 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ]    - keep_raw_sla_day ———————— :〖 7 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] [ MONGO ] Creating connection to sla database [shinken]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] [ MONGO ] Try to open a Mongodb connection to mongodb://localhost/?w=1&fsync=false:shinken
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] [ MONGO ] Mongo connection established in 16.50ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] [ MONGO ] Ensure that the index is present in the database ( and create it if necessary ). Done in 5.01ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Load from collection 28 elements info in cache done in 0.79ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:31201) ] [ INITIALISATION ] Archive process BROKER_NAME [ - Module: sla-writer - archive] initialized in 51.06ms


Démarrage des workers - CHAPITRE "[ WORKER]"


[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER MANAGER ] Starting worker 0
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER MANAGER ] The worker 0 is now started as pid:29585

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] Sub process ready to work.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] Staring new worker.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] [ MONGO ] Creating connection to sla database [shinken]
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] [ MONGO ] Try to open a Mongodb connection to mongodb://localhost/?w=1&fsync=false:shinken
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] [ MONGO ] Mongo connection established in 5.85ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] [ MONGO ] Ensure that the index is present in the database ( and create it if necessary ). Done in 5.01ms
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] Load previous state of 28 elements done in 466.86ms.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] Parameter load for build raw sla 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ]    - store_output ——————————————————————————————————————— :〖 1 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ]    - store_long_output —————————————————————————————————— :〖 1 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ]    - list_of_stored_output_status ——————————————————————— :〖 set([]) 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ]    - minimal_time_before_an_element_become_missing_data — :〖 60 〗
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ]    - time_before_shinken_inactive ——————————————————————— :〖 30 〗 
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] [ INITIALISATION ] New worker start in 468.01ms.
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ WORKER: 0 (pid:31252) ] Now running..


Fonctionnement du module - chapitre [ ARCHIVING ]

Cas de 2 modules qui archive le même jour en base


[YYYY-MM-DD HH:MM:SS] ERROR  : [ BROKER_NAME   ] [ sla              ] [ ARCHIVE  (pid:1434)    ] [ ARCHIVING ] Fail to archive collection 150_2020 (for date 29-05-2020) because it was lock by [broker-int-13 sla2 archive (pid:23460)] and i am [broker-int-13 sla2 archive (pid:23058)] (an other process try to archive this day)

Dans le cas où 2 modules SLA écrivent dans la même base, les 2 modules vont tenter de faire l'archive du jour en même temps. C'est pourquoi nous avons mis un lock afin d'éviter les doublons dans les entrées SLA.

Si vous avez ce log, vérifiez votre configuration si vous n’avez pas 2 modules SLA ou 2 brokers qui écrivent dans la même base Mongo.

Fonctionnement du module - chapitre [ RUNNING ]

Ecriture des états futurs ( les états qu'on reporte sur les jours d'après )

Lors de l'écriture des états futurs, on a le log suivant :

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ WORKER: 0 (pid:10277) ] [ RUNNING ] Save future states in [2.88ms]. Found [4] entries in base in [1.42ms]. Saving [1] new entries in [1.34ms]. Update [0] entries in [0.04ms]

Une fois par jour, le module nettoie aussi les états futurs à supprimer

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME ] [ sla              ] [ WORKER: 0 (pid:10277) ] [ RUNNING ] The clean of future states found [1] entries to delete. There was deleted in [2.28ms (1.28ms for found entries, 1.03ms for delete entries)].


Log de migration des données SLA

A chaque démarrage du module, le module fait une recherche des données à migrer :

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Need to migrate 931144 archives

Puis si il y a des données à migrer on log la progression : 

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Migrating in progress 1000/931144 archives
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Migrating in progress 2000/931144 archives
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Migrating in progress 3000/931144 archives
[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Migrating in progress 4000/931144 archives

Puis enfin :

Si il y a eu une migration :

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:32233) ] Migrate 931144 archive done in:7m 0.14s.

Sinon:

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MIGRATION (pid:10878) ] No archive need migration. Check done in:1.09ms.


Fonctionnement du module - chapitre [ MONGO ]

Log de gestion de l'AutoReconnect

L'AutoReconnect est une erreur du driver MongoDB qui survient quand :

  • Un nouveau PRIMARY est élu dans un Cluster MongoDB
  • Le driver trouve une erreur réseau, comme un timeout de 20s lors de l'établissement de la connexion à la base.

Dans ce cas Shinken tente de refaire une connexion à la base.

Voir Configuration du Module SLA

Tentative en cours :

[YYYY-MM-DD HH:MM:SS] INFO   : [ BROKER_NAME   ] [ sla              ] [ MONGO ] Mongo asked an AutoReconnect on the operation OPERATION_NAME on COLLECTION_NAME. Operation failed : X/Y

Toutes les tentatives on échouées :

[YYYY-MM-DD HH:MM:SS] ERROR  : [ BROKER_NAME   ] [ sla              ] [ MONGO ] Mongo asked an AutoReconnect on the operation OPERATION_NAME on COLLECTION_NAME. Operation failed : X/Y. We tried Y time but it kept failing.


  • X : est le nombre de fois où l'opération a été tenté 
  • Y : est le nombre de tentative maximal de l'opération
  • OPERATION_NAME : nom de l'opération. Exemple : find, find_one, list_name_collections, save ...
  • COLLECTION_NAME : nom de la collection MongoDB