sni / lmd

Livestatus Multitool Daemon - Create livestatus federation from multiple sources
https://labs.consol.de/omd/packages/lmd/
GNU General Public License v3.0
42 stars 31 forks source link

Pass through requests directly to a backend if the backend is online, but its cache is not fresh #106

Closed steffen-poulsen closed 3 years ago

steffen-poulsen commented 3 years ago

We have two backend types that are unfortunately not a hand-in-glove fit for the current implementation of LMD.

One type is our Icinga backends, which appear to be bad at signaling that they have fresh data for the LMD. This means that they will only get refreshed every 5 minutes, even if they have new data to offer every second.

Another type is our huge Nagios backends (100.000s of checks), that can take up to 10 minutes or more for the LMD to refresh. These Nagios backends do have the advantage over the Icinga backends, that once they have been refreshed, the delta update works fast.

Unfortunately, we have a very busy environment with a lot of changes coming in. Therefore we would like to reload the backends often, for the configuration updates to reflect as quickly as possible. The Nagios reload in itself does not present a problem for this to happen, as it reloads fast, typically in 30s. But, the 10m LMD refresh is a challenge, as we would like to reload more often than the 30m that we feel is possible for now - a reload every 30m leaves 20m of responsive GUI time with the Nagios backends.

This 10m delay time while waiting for the LMD to refresh the backend means that we are often left with stale check results in our console. And worse, with no visibility of acknowledgements and comments that we have added. The check results will be updated eventually, and acknowledgements and comments will show up eventually (after 10m), so the LMD functionality is ok. Just, delayed.

We love the LMD very much, and we would like to investigate options for bringing interactions and responses more "online", even with these two badly behaving backend types that we have.

An idea that we would like to propose, is to add an option to pass requests directly through to the backend, if the backend is online, but its cache is not fresh.

The LMD cache would still be refreshing in the background as it currently does. And whenever the cache is fresh, the LMD will use the cache as its source (putting less CPU load on our Nagios backends). And, whenever the LMD cache is not fresh but the backend is up, the LMD will use the backend as source (making our Icinga backends responsive to work with, even if the LMD cache would seldom be used).

I was playing around with a sequence diagram, I am attaching it just to show my current understanding of how things currently work with the LMD.

We don't know if this kind of change is possible at all, but we would love to hear your thoughts.

Thruk-LMD-Backends-sequence-diagram

sni commented 3 years ago

Interesting idea. But i am really wondering why the refresh takes up to 10min. I've seen big sites that take up to 1minute. But 10 minutes really sounds like something is wrong (unless this is a super small connection). And if its a low bandwidth connection, then passing queries through would make the initial sync even slower. LMD show a detailed list how long each table takes to sync (when debug log is enabled). Is there anything suspicious? Maybe synchronization after a reload could be improved by not loading everything and do a smarter sync. Fetching everything was just the easiest option and so far it was sufficient for all sites.

steffen-poulsen commented 3 years ago

So far we have not been able to identify any bottlenecks or suspicious activity. We believe bandwidth and CPU are adequate.

The backend refresh times appears to be directly proportional to the number of service checks in the backend.

A few figures:

We will do a full debug run covering a restart of the NCE-4 backend and attach the results first chance.

If a smarter or quicker sync would be possible, I believe this would be a great solution for our Nagios backends. I can see how this would reduce the waiting time for the Thruk GUI to be updated after a Nagios backend restart.

However, for our Icinga backends I expect some kind of passthrough option would still be helpful, as these backends never get into a "online" status at all. Even if they might sync faster after a restart with a smarter sync solution, they would still only be refreshing every 5m in their normal state.

Perhaps a setting for the Icinga backends that would make the LMD force a sync similar to the smarter after-restart sync at a set interval (say, every 30s) could be a way forward.

Anyway, thanks for considering this, Sven. Any reduction in the Thruk GUI update waiting time is highly appreciated.


Top "objects created" times:

$ grep "objects created in" /var/log/lmd.log | egrep -e " 5m| 6m| 7m"
[2020-12-14 11:00:04.166][Info][peer.go:807] [NCE-4] objects created in: 5m13.331929052s
[2020-12-14 14:22:27.939][Info][peer.go:807] [NCE-4] objects created in: 5m7.953010251s
[2020-12-14 17:07:03.742][Info][peer.go:807] [NCE-4] objects created in: 5m52.392832923s
[2020-12-14 21:58:18.401][Info][peer.go:807] [NCE-4] objects created in: 5m50.582067528s
[2020-12-14 21:58:25.058][Info][peer.go:807] [MED-2] objects created in: 5m57.239626548s
[2020-12-15 13:20:41.763][Info][peer.go:807] [NCE-4] objects created in: 5m26.223263113s
[2020-12-15 22:34:46.990][Info][peer.go:807] [NCE-4] objects created in: 5m39.933306279s
[2020-12-16 10:19:03.240][Info][peer.go:807] [NCE-4] objects created in: 6m15.568314856s
[2020-12-16 10:40:09.544][Info][peer.go:807] [NCE-4] objects created in: 5m36.084450345s
[2020-12-16 13:49:29.951][Info][peer.go:807] [NCE-4] objects created in: 5m47.954903793s
[2020-12-16 14:59:46.639][Info][peer.go:807] [NCE-4] objects created in: 6m12.619429478s
[2020-12-16 14:59:57.931][Info][peer.go:807] [MED-2] objects created in: 6m23.911676069s
[2020-12-16 16:45:25.187][Info][peer.go:807] [NCE-4] objects created in: 5m6.064754365s
[2020-12-16 17:33:17.165][Info][peer.go:807] [NCE-4] objects created in: 5m50.582093063s
[2020-12-16 18:35:44.526][Info][peer.go:807] [NCE-4] objects created in: 5m32.8021218s
[2020-12-16 19:10:38.727][Info][peer.go:807] [MED-2] objects created in: 5m39.892146324s
[2020-12-16 20:12:31.307][Info][peer.go:807] [NCE-4] objects created in: 5m3.343073399s
[2020-12-16 20:19:31.618][Info][peer.go:807] [MED-2] objects created in: 5m38.27781166s
[2020-12-16 20:19:36.171][Info][peer.go:807] [NCE-4] objects created in: 5m42.830349544s
[2020-12-16 21:16:13.102][Info][peer.go:807] [MED-2] objects created in: 6m31.462786458s
[2020-12-16 21:17:37.068][Info][peer.go:807] [NCE-4] objects created in: 7m55.428672598s
[2020-12-16 21:36:18.276][Info][peer.go:807] [NCE-4] objects created in: 5m11.835190209s
[2020-12-16 21:48:23.666][Info][peer.go:807] [MED-2] objects created in: 6m52.138772169s
[2020-12-16 22:17:55.887][Info][peer.go:807] [NCE-4] objects created in: 5m0.945910334s
[2020-12-16 22:18:24.303][Info][peer.go:807] [MED-2] objects created in: 5m29.361093092s
[2020-12-16 22:47:40.484][Info][peer.go:807] [NCE-4] objects created in: 6m9.375931243s
[2020-12-16 22:47:48.683][Info][peer.go:807] [MED-2] objects created in: 6m17.574771392s
[2020-12-16 22:56:40.603][Info][peer.go:807] [NCE-4] objects created in: 6m25.926474944s
[2020-12-16 23:31:44.440][Info][peer.go:807] [NCE-4] objects created in: 5m41.156880452s
[2020-12-17 01:35:07.748][Info][peer.go:807] [NCE-4] objects created in: 5m24.751820596s
[2020-12-17 01:36:44.376][Info][peer.go:807] [MED-2] objects created in: 7m1.378596197s
[2020-12-17 02:05:45.650][Info][peer.go:807] [NCE-4] objects created in: 5m46.93183009s
[2020-12-17 02:07:15.718][Info][peer.go:807] [MED-2] objects created in: 7m16.999873119s
[2020-12-17 02:41:03.443][Info][peer.go:807] [NCE-4] objects created in: 5m52.071784245s
[2020-12-17 03:16:02.985][Info][peer.go:807] [NCE-4] objects created in: 5m52.669341398s
[2020-12-17 03:16:33.821][Info][peer.go:807] [MED-2] objects created in: 6m23.504995809s
[2020-12-17 05:00:04.736][Info][peer.go:807] [NCE-4] objects created in: 5m8.480890448s
[2020-12-17 05:30:22.891][Info][peer.go:807] [NCE-4] objects created in: 5m2.018266365s
[2020-12-17 06:05:38.983][Info][peer.go:807] [NCE-4] objects created in: 5m47.444463769s
[2020-12-17 06:39:41.828][Info][peer.go:807] [MED-2] objects created in: 5m4.990781587s
[2020-12-17 06:39:59.693][Info][peer.go:807] [NCE-4] objects created in: 5m22.855014664s
[2020-12-17 08:25:30.541][Info][peer.go:807] [NCE-4] objects created in: 5m8.24242191s
[2020-12-17 10:32:02.050][Info][peer.go:807] [NCE-4] objects created in: 5m7.861214224s
[2020-12-17 11:43:47.805][Info][peer.go:807] [NCE-4] objects created in: 5m33.193898012s
[2020-12-17 15:06:33.924][Info][peer.go:807] [MED-2] objects created in: 6m25.805145677s
[2020-12-17 17:41:09.471][Info][peer.go:807] [NCE-4] objects created in: 7m13.974859359s
[2020-12-17 22:55:38.261][Info][peer.go:807] [MED-1] objects created in: 5m0.574759113s
[2020-12-17 22:55:53.446][Info][peer.go:807] [NCE-4] objects created in: 5m15.75871821s
[2020-12-17 22:56:49.438][Info][peer.go:807] [MED-2] objects created in: 6m11.750422138s
[2020-12-18 23:13:25.976][Info][peer.go:807] [NCE-4] objects created in: 7m58.694000403s

Full service fetch from NCE-4 is around 15s (116k checks, 55kB):

$ egrep -e "Debug|NCE-4" /var/log/lmd.log | grep -i table | head -20
[2020-12-17 06:58:21.235][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      2ms - insert:     29ms - count:        1 - size:        0 kB
[2020-12-17 06:58:21.444][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:      6ms - insert:    196ms - count:        0 - size:        0 kB
[2020-12-17 06:58:37.344][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:  14.501s - insert:    328ms - count:   116099 - size:    55156 kB
[2020-12-17 06:58:37.494][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      9ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-17 06:58:38.448][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:    567ms - insert:    173ms - count:    18473 - size:     9880 kB
[2020-12-17 06:58:38.495][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     45ms - insert:       0s - count:       35 - size:       13 kB
[2020-12-17 06:58:44.062][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      2ms - insert:   1.865s - count:        1 - size:        0 kB
[2020-12-17 06:58:44.100][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     10ms - insert:     19ms - count:        0 - size:        0 kB
[2020-12-17 06:58:44.269][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     40ms - insert:    127ms - count:        0 - size:        0 kB
[2020-12-17 06:58:47.255][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      6ms - insert:      6ms - count:        1 - size:        0 kB
[2020-12-17 06:58:47.387][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     57ms - insert:     26ms - count:        3 - size:        1 kB
[2020-12-17 06:58:47.503][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     94ms - insert:     15ms - count:      113 - size:       43 kB
[2020-12-17 06:58:55.236][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      2ms - insert:   3.039s - count:        1 - size:        0 kB
[2020-12-17 06:58:55.344][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:      8ms - insert:     97ms - count:       26 - size:       13 kB
[2020-12-17 06:59:01.072][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     46ms - insert:   5.675s - count:      432 - size:      214 kB
[2020-12-17 06:59:01.510][Debug][datastoreset.go:687] [NCE-4] updated table:     timeperiods - fetch:    124ms - insert:    254ms - count:        6 - size:        0 kB
[2020-12-17 06:59:01.959][Debug][datastoreset.go:687] [NCE-4] updated table:      hostgroups - fetch:    261ms - insert:    182ms - count:     3819 - size:      132 kB
[2020-12-17 06:59:02.225][Debug][datastoreset.go:687] [NCE-4] updated table:   servicegroups - fetch:     24ms - insert:    237ms - count:        0 - size:        0 kB

The load for the Thruk/LMD server appears to be not alarming:

$ top -n1 | head -11
top - 20:10:59 up 36 days, 10:22,  1 user,  load average: 1.57, 1.96, 2.39
Tasks: 427 total,   1 running, 426 sleeping,   0 stopped,   0 zombie
Cpu(s):  4.6%us,  0.7%sy,  0.0%ni, 94.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  66108116k total, 26334252k used, 39773864k free,   401252k buffers
Swap: 16596984k total,   301752k used, 16295232k free, 11138384k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
25269 apache    20   0 11.6g 8.2g 3748 S 31.2 13.0   2543:42 lmd
27630 apache    20   0 2550m 2.4g 4140 S 23.2  3.8   0:58.88 perl
 2473 mysql     20   0 8359m  32m 2700 S 22.2  0.1  42662:13 mysqld
18233 apache    20   0  280m 209m 2900 S  6.6  0.3   1:06.57 thruk_fastcgi.p
steffen-poulsen commented 3 years ago

This is our LMD debug output for a NCE-4 restart, the initial timings for the table updates are like this:

[2020-12-20 07:18:18.985][Debug][datastoreset.go:146] [NCE-4] update failed: site has been restarted, recreating objects (program_start: 1608445083, pid: 10704)
[2020-12-20 07:18:18.987][Debug][datastoreset.go:92] [NCE-4] updated table:          status - fetch:      2ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:18:19.040][Debug][datastoreset.go:92] [NCE-4] updated table:     timeperiods - fetch:     11ms - insert:       0s - count:        6 - size:        0 kB
[2020-12-20 07:18:19.056][Debug][datastoreset.go:92] [NCE-4] updated table:        contacts - fetch:      5ms - insert:      5ms - count:     1589 - size:      114 kB
[2020-12-20 07:18:30.425][Debug][datastoreset.go:92] [NCE-4] updated table:   contactgroups - fetch:  10.511s - insert:    493ms - count:     3701 - size:    20223 kB
[2020-12-20 07:18:30.436][Debug][datastoreset.go:92] [NCE-4] updated table:        commands - fetch:      9ms - insert:       0s - count:      371 - size:       50 kB
[2020-12-20 07:20:22.139][Debug][datastoreset.go:92] [NCE-4] updated table:           hosts - fetch: 1m44.071s - insert:   4.054s - count:    18476 - size:   179938 kB
[2020-12-20 07:20:22.567][Debug][datastoreset.go:92] [NCE-4] updated table:      hostgroups - fetch:    342ms - insert:     56ms - count:     3820 - size:     1808 kB
[2020-12-20 07:23:07.085][Debug][datastoreset.go:92] [NCE-4] updated table:        services - fetch: 2m28.515s - insert:  10.044s - count:   116515 - size:   350909 kB
[2020-12-20 07:23:07.089][Debug][datastoreset.go:92] [NCE-4] updated table:   servicegroups - fetch:      2ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:07.382][Debug][datastoreset.go:92] [NCE-4] updated table:        comments - fetch:    134ms - insert:     96ms - count:    24593 - size:     4251 kB
[2020-12-20 07:23:07.398][Debug][datastoreset.go:92] [NCE-4] updated table:       downtimes - fetch:      2ms - insert:       0s - count:       66 - size:       10 kB
[2020-12-20 07:23:07.398][Info][peer.go:807] [NCE-4] objects created in: 4m48.413206181s

As can be seen, the reported fetch time for the hosts table is stated as 1m44s (180MB), and the fetch time for the services table is 2m28s (350MB).

The reported insert times are stated as 4 and 10 seconds, so I guess they are negligible in this regard.


A little more debug output including the normal NCE-4 state, before and after:

$ cat /var/log/lmd.log | grep NCE-4 | grep "failed" -B 10 -A 50
[2020-12-20 07:17:43.236][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 165.583462ms
[2020-12-20 07:17:48.073][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      1ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:17:48.086][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     11ms - insert:       0s - count:       36 - size:       19 kB
[2020-12-20 07:17:48.133][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     44ms - insert:       0s - count:      145 - size:       53 kB
[2020-12-20 07:17:48.206][Debug][datastoreset.go:568] [NCE-4] updated comments
[2020-12-20 07:17:48.210][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 139.122078ms
[2020-12-20 07:17:53.074][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      2ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:17:53.091][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     10ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:17:53.314][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     40ms - insert:    178ms - count:        0 - size:        0 kB
[2020-12-20 07:17:53.329][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 258.792173ms
[2020-12-20 07:17:58.074][Debug][peer.go:881] [NCE-4] sending data/query failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:17:58.074][Debug][peer.go:1232] [NCE-4] connection error 172.26.66.59:6557: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:17:58.075][Debug][peer.go:1266] [NCE-4] last online: 2020-12-20 07:17:53 +0100 CET
[2020-12-20 07:17:58.075][Debug][datastoreset.go:146] [NCE-4] update failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:17:58.075][Info][peer.go:376] [NCE-4] updating objects failed after: 504.313233ms: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:00.074][Debug][peer.go:881] [NCE-4] sending data/query failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:00.074][Debug][peer.go:1232] [NCE-4] connection error 172.26.66.59:6557: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:00.074][Debug][peer.go:1266] [NCE-4] last online: 2020-12-20 07:17:53 +0100 CET
[2020-12-20 07:18:00.074][Debug][datastoreset.go:146] [NCE-4] update failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:00.075][Debug][peer.go:408] [NCE-4] updating timeperiods and host/servicegroup statistics completed (2ms)
[2020-12-20 07:18:00.075][Debug][peer.go:379] [NCE-4] updating objects failed after: 503.849532ms: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:03.074][Debug][peer.go:881] [NCE-4] sending data/query failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:03.074][Debug][peer.go:1232] [NCE-4] connection error 172.26.66.59:6557: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:03.074][Debug][peer.go:1266] [NCE-4] last online: 2020-12-20 07:17:53 +0100 CET
[2020-12-20 07:18:03.074][Debug][datastoreset.go:146] [NCE-4] update failed: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:03.074][Debug][peer.go:379] [NCE-4] updating objects failed after: 500.667505ms: No UNIX socket /usr/local/nagios/var/rw/live existing
[2020-12-20 07:18:18.985][Info][datastoreset.go:680] [NCE-4] site has been restarted, recreating objects (program_start: 1608445083, pid: 10704)
[2020-12-20 07:18:18.985][Debug][datastoreset.go:146] [NCE-4] update failed: site has been restarted, recreating objects (program_start: 1608445083, pid: 10704)
[2020-12-20 07:18:18.987][Debug][datastoreset.go:92] [NCE-4] updated table:          status - fetch:      2ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:18:19.040][Debug][datastoreset.go:92] [NCE-4] updated table:     timeperiods - fetch:     11ms - insert:       0s - count:        6 - size:        0 kB
[2020-12-20 07:18:19.056][Debug][datastoreset.go:92] [NCE-4] updated table:        contacts - fetch:      5ms - insert:      5ms - count:     1589 - size:      114 kB
[2020-12-20 07:18:30.425][Debug][datastoreset.go:92] [NCE-4] updated table:   contactgroups - fetch:  10.511s - insert:    493ms - count:     3701 - size:    20223 kB
[2020-12-20 07:18:30.436][Debug][datastoreset.go:92] [NCE-4] updated table:        commands - fetch:      9ms - insert:       0s - count:      371 - size:       50 kB
[2020-12-20 07:20:22.139][Debug][datastoreset.go:92] [NCE-4] updated table:           hosts - fetch: 1m44.071s - insert:   4.054s - count:    18476 - size:   179938 kB
[2020-12-20 07:20:22.567][Debug][datastoreset.go:92] [NCE-4] updated table:      hostgroups - fetch:    342ms - insert:     56ms - count:     3820 - size:     1808 kB
[2020-12-20 07:23:07.085][Debug][datastoreset.go:92] [NCE-4] updated table:        services - fetch: 2m28.515s - insert:  10.044s - count:   116515 - size:   350909 kB
[2020-12-20 07:23:07.089][Debug][datastoreset.go:92] [NCE-4] updated table:   servicegroups - fetch:      2ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:07.382][Debug][datastoreset.go:92] [NCE-4] updated table:        comments - fetch:    134ms - insert:     96ms - count:    24593 - size:     4251 kB
[2020-12-20 07:23:07.398][Debug][datastoreset.go:92] [NCE-4] updated table:       downtimes - fetch:      2ms - insert:       0s - count:       66 - size:       10 kB
[2020-12-20 07:23:07.398][Info][peer.go:807] [NCE-4] objects created in: 4m48.413206181s
[2020-12-20 07:23:07.401][Debug][datastoreset.go:687] [NCE-4] updated table:     timeperiods - fetch:      2ms - insert:       0s - count:        6 - size:        0 kB
[2020-12-20 07:23:07.620][Debug][datastoreset.go:687] [NCE-4] updated table:      hostgroups - fetch:    213ms - insert:       0s - count:     3820 - size:      132 kB
[2020-12-20 07:23:07.623][Debug][datastoreset.go:687] [NCE-4] updated table:   servicegroups - fetch:      2ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:07.623][Debug][peer.go:408] [NCE-4] updating timeperiods and host/servicegroup statistics completed (225ms)
[2020-12-20 07:23:12.107][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      4ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:23:13.389][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:    843ms - insert:     73ms - count:    18476 - size:     9897 kB
[2020-12-20 07:23:26.094][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:  10.922s - insert:    474ms - count:   116378 - size:    56322 kB
[2020-12-20 07:23:26.124][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 14.053045754s
[2020-12-20 07:23:26.174][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      1ms - insert:     47ms - count:        1 - size:        0 kB
[2020-12-20 07:23:26.365][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     10ms - insert:    180ms - count:       23 - size:       12 kB
[2020-12-20 07:23:27.084][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:    291ms - insert:    394ms - count:       24 - size:        8 kB
[2020-12-20 07:23:27.431][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 1.307037336s
[2020-12-20 07:23:31.174][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      2ms - insert:     99ms - count:        1 - size:        0 kB
[2020-12-20 07:23:31.213][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:      7ms - insert:     30ms - count:        0 - size:        0 kB
[2020-12-20 07:23:31.370][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     42ms - insert:    113ms - count:        0 - size:        0 kB
[2020-12-20 07:23:31.395][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 324.002382ms
[2020-12-20 07:23:36.155][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:     78ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:23:36.249][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     70ms - insert:       0s - count:       18 - size:        9 kB
[2020-12-20 07:23:36.327][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     77ms - insert:       0s - count:       17 - size:        6 kB
[2020-12-20 07:23:36.421][Debug][datastoreset.go:568] [NCE-4] updated comments
[2020-12-20 07:23:36.435][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 364.186917ms
[2020-12-20 07:23:41.280][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      4ms - insert:    195ms - count:        1 - size:        0 kB
[2020-12-20 07:23:41.288][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:      7ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:41.492][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     31ms - insert:    169ms - count:        0 - size:        0 kB
[2020-12-20 07:23:41.513][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 434.567859ms
[2020-12-20 07:23:46.083][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      3ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:23:47.018][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:    687ms - insert:     37ms - count:    18476 - size:     9895 kB
[2020-12-20 07:23:47.148][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     88ms - insert:       0s - count:       47 - size:       17 kB
[2020-12-20 07:23:47.266][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 1.195191671s
[2020-12-20 07:23:51.075][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      1ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:23:51.082][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:      6ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:51.109][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:     26ms - insert:       0s - count:        0 - size:        0 kB
[2020-12-20 07:23:51.121][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 50.403302ms
[2020-12-20 07:23:56.114][Debug][datastoreset.go:687] [NCE-4] updated table:          status - fetch:      3ms - insert:     38ms - count:        1 - size:        0 kB
[2020-12-20 07:23:56.572][Debug][datastoreset.go:307] [NCE-4] updated table:           hosts - fetch:     22ms - insert:    434ms - count:       10 - size:        5 kB
[2020-12-20 07:24:09.333][Debug][datastoreset.go:307] [NCE-4] updated table:        services - fetch:  11.429s - insert:    172ms - count:   116515 - size:    56374 kB
[2020-12-20 07:24:09.348][Debug][datastoreset.go:190] [NCE-4] delta update complete in: 13.277220026s
[2020-12-20 07:24:09.350][Debug][datastoreset.go:687] [NCE-4] updated table:     timeperiods - fetch:      1ms - insert:       0s - count:        6 - size:        0 kB
steffen-poulsen commented 3 years ago

Now that we have Debug enabled anyway, I am looking at the delta updates for the Icinga backend, "Master".

It appears the LMD actually has short periods (~30s) where it is able to retrieve updates from the Master backend every 5 seconds. This is what the LMD is able to always do with the Nagios backends in their normal state.

What mainly happens in the rest of a 5-7m cycle, is a slow services fetch get that takes around 5m.

I wonder what is the cause of this.

As there appears to be no LMD errors, it seems likely that this is related to the way Icinga livestatus interface exposes data.

Even if it appears that this pattern is probably not related to the LMD, I will just share the findings anyway. If nothing else, for future reference :-)


Every 5-7 minutes there is a slow delta update - but there are faster ones in between:

$ cat /var/log/lmd.log | grep Master | grep delta | tail -20
[2020-12-20 07:44:02.410][Debug][datastoreset.go:190] [Master] delta update complete in: 4.064986393s
[2020-12-20 07:44:03.448][Debug][datastoreset.go:190] [Master] delta update complete in: 155.261513ms
[2020-12-20 07:44:08.468][Debug][datastoreset.go:190] [Master] delta update complete in: 175.2933ms
[2020-12-20 07:44:13.434][Debug][datastoreset.go:190] [Master] delta update complete in: 141.311304ms
[2020-12-20 07:44:18.412][Debug][datastoreset.go:190] [Master] delta update complete in: 119.765381ms
[2020-12-20 07:44:23.432][Debug][datastoreset.go:190] [Master] delta update complete in: 139.721324ms
[2020-12-20 07:50:01.720][Debug][datastoreset.go:190] [Master] delta update complete in: 5m33.427098019s
[2020-12-20 07:50:06.182][Debug][datastoreset.go:190] [Master] delta update complete in: 4.288491672s
[2020-12-20 07:50:06.328][Debug][datastoreset.go:190] [Master] delta update complete in: 145.891187ms
[2020-12-20 07:50:11.885][Debug][datastoreset.go:190] [Master] delta update complete in: 592.139606ms
[2020-12-20 07:50:16.427][Debug][datastoreset.go:190] [Master] delta update complete in: 134.410727ms
[2020-12-20 07:50:21.429][Debug][datastoreset.go:190] [Master] delta update complete in: 135.659986ms
[2020-12-20 07:50:26.671][Debug][datastoreset.go:190] [Master] delta update complete in: 377.979874ms
[2020-12-20 07:55:20.289][Debug][datastoreset.go:190] [Master] delta update complete in: 4m48.996771052s
[2020-12-20 07:55:26.917][Debug][datastoreset.go:190] [Master] delta update complete in: 6.478754731s
[2020-12-20 07:55:27.237][Debug][datastoreset.go:190] [Master] delta update complete in: 319.991544ms
[2020-12-20 07:55:31.443][Debug][datastoreset.go:190] [Master] delta update complete in: 150.762215ms
[2020-12-20 07:55:36.453][Debug][datastoreset.go:190] [Master] delta update complete in: 159.737648ms
[2020-12-20 07:55:41.472][Debug][datastoreset.go:190] [Master] delta update complete in: 179.066883ms
[2020-12-20 07:55:46.493][Debug][datastoreset.go:190] [Master] delta update complete in: 200.07957ms

The 5m delta update time appears to be due to a 5m services fetch time.

$ cat /var/log/lmd.log | grep Master | grep "delta update complete in: 5m33.427098019s" -B 15 -A 10
[2020-12-20 07:44:13.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:13.346][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     41ms - insert:      3ms - count:      331 - size:      274 kB
[2020-12-20 07:44:13.423][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      4ms - count:      131 - size:      224 kB
[2020-12-20 07:44:13.434][Debug][datastoreset.go:190] [Master] delta update complete in: 141.311304ms
[2020-12-20 07:44:18.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:18.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      3ms - count:      356 - size:      295 kB
[2020-12-20 07:44:18.410][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      2ms - count:      129 - size:      130 kB
[2020-12-20 07:44:18.412][Debug][datastoreset.go:190] [Master] delta update complete in: 119.765381ms
[2020-12-20 07:44:23.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:23.354][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     45ms - insert:      4ms - count:      329 - size:      274 kB
[2020-12-20 07:44:23.429][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      3ms - count:      133 - size:      151 kB
[2020-12-20 07:44:23.432][Debug][datastoreset.go:190] [Master] delta update complete in: 139.721324ms
[2020-12-20 07:44:28.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:28.343][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      4ms - count:      347 - size:      287 kB
[2020-12-20 07:50:01.713][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m31.916s - insert:    593ms - count:    35530 - size:    33762 kB
[2020-12-20 07:50:01.720][Debug][datastoreset.go:190] [Master] delta update complete in: 5m33.427098019s
[2020-12-20 07:50:01.721][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:50:01.891][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    136ms - insert:     17ms - count:     3824 - size:      251 kB
[2020-12-20 07:50:01.893][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:50:01.894][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (173ms)
[2020-12-20 07:50:01.894][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:06.068][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   4.036s - insert:     29ms - count:     4649 - size:     3747 kB
[2020-12-20 07:50:06.179][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     96ms - insert:      9ms - count:      267 - size:      496 kB
[2020-12-20 07:50:06.182][Debug][datastoreset.go:190] [Master] delta update complete in: 4.288491672s
[2020-12-20 07:50:06.183][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:06.234][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     45ms - insert:       0s - count:      331 - size:      274 kB

There appears to be a consistent pattern to this, repeating every 5-7m:

$ cat /var/log/lmd.log | grep Master | grep "conf:" -A 500 | grep -v ms
[2020-12-20 07:16:48.657][Debug][main.go:878] conf:       "Name": "Master",
[2020-12-20 07:20:02.657][Debug][datastoreset.go:190] [Master] delta update complete in: 5m13.36427791s
[2020-12-20 07:20:06.765][Debug][datastoreset.go:190] [Master] delta update complete in: 3.711098375s
[2020-12-20 07:20:07.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:12.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:22.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:27.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:32.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:22.525][Debug][datastoreset.go:190] [Master] delta update complete in: 5m50.230303098s
[2020-12-20 07:26:22.525][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:26:22.653][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:28.846][Debug][datastoreset.go:190] [Master] delta update complete in: 6.1940887s
[2020-12-20 07:26:28.847][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:33.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:38.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:43.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:48.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:53.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:33:54.646][Debug][datastoreset.go:190] [Master] delta update complete in: 7m1.353884511s
[2020-12-20 07:33:54.647][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:33:54.760][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:00.010][Debug][datastoreset.go:190] [Master] delta update complete in: 5.250937378s
[2020-12-20 07:34:00.011][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:34:00.151][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:05.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:10.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB

The above 5-7m pattern in more detail:

$ cat /var/log/lmd.log | grep Master | grep "conf:" -A 500
[2020-12-20 07:16:48.657][Debug][main.go:878] conf:       "Name": "Master",
[2020-12-20 07:20:02.649][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m11.901s - insert:    574ms - count:    35530 - size:    33765 kB
[2020-12-20 07:20:02.657][Debug][datastoreset.go:190] [Master] delta update complete in: 5m13.36427791s
[2020-12-20 07:20:02.842][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:    184ms - count:        3 - size:        0 kB
[2020-12-20 07:20:03.040][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    137ms - insert:     39ms - count:     3824 - size:      251 kB
[2020-12-20 07:20:03.054][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      2ms - insert:     11ms - count:        7 - size:        0 kB
[2020-12-20 07:20:03.054][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (397ms)
[2020-12-20 07:20:03.084][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:      3ms - insert:     23ms - count:        1 - size:        0 kB
[2020-12-20 07:20:06.663][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   3.438s - insert:     35ms - count:     4649 - size:     3747 kB
[2020-12-20 07:20:06.762][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     82ms - insert:     10ms - count:      264 - size:      454 kB
[2020-12-20 07:20:06.765][Debug][datastoreset.go:190] [Master] delta update complete in: 3.711098375s
[2020-12-20 07:20:07.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:07.338][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      2ms - count:      339 - size:      280 kB
[2020-12-20 07:20:07.421][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     76ms - insert:      2ms - count:      151 - size:      219 kB
[2020-12-20 07:20:07.424][Debug][datastoreset.go:190] [Master] delta update complete in: 131.222379ms
[2020-12-20 07:20:12.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:12.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      3ms - count:      315 - size:      260 kB
[2020-12-20 07:20:12.437][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     96ms - insert:      1ms - count:      144 - size:       97 kB
[2020-12-20 07:20:12.439][Debug][datastoreset.go:190] [Master] delta update complete in: 146.734727ms
[2020-12-20 07:20:17.447][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:    148ms - count:        1 - size:        0 kB
[2020-12-20 07:20:17.529][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     53ms - insert:      9ms - count:      357 - size:      295 kB
[2020-12-20 07:20:17.632][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     92ms - insert:      6ms - count:      147 - size:      178 kB
[2020-12-20 07:20:17.636][Debug][datastoreset.go:190] [Master] delta update complete in: 338.797849ms
[2020-12-20 07:20:22.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:22.342][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     38ms - insert:      3ms - count:      332 - size:      275 kB
[2020-12-20 07:20:22.420][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     71ms - insert:      3ms - count:      178 - size:      143 kB
[2020-12-20 07:20:22.423][Debug][datastoreset.go:190] [Master] delta update complete in: 130.61521ms
[2020-12-20 07:20:27.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:27.353][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:     15ms - count:      343 - size:      284 kB
[2020-12-20 07:20:27.593][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    108ms - insert:    117ms - count:      173 - size:      195 kB
[2020-12-20 07:20:27.597][Debug][datastoreset.go:190] [Master] delta update complete in: 303.921318ms
[2020-12-20 07:20:32.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:20:32.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      3ms - count:      328 - size:      272 kB
[2020-12-20 07:26:22.521][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m48.729s - insert:    792ms - count:    35530 - size:    33766 kB
[2020-12-20 07:26:22.525][Debug][datastoreset.go:190] [Master] delta update complete in: 5m50.230303098s
[2020-12-20 07:26:22.525][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:26:22.650][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    108ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 07:26:22.652][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:26:22.652][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (127ms)
[2020-12-20 07:26:22.653][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:28.705][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   5.919s - insert:     28ms - count:     4649 - size:     3747 kB
[2020-12-20 07:26:28.843][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    115ms - insert:     15ms - count:      428 - size:      643 kB
[2020-12-20 07:26:28.846][Debug][datastoreset.go:190] [Master] delta update complete in: 6.1940887s
[2020-12-20 07:26:28.847][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:28.892][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      1ms - count:      373 - size:      308 kB
[2020-12-20 07:26:28.991][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     94ms - insert:       0s - count:      156 - size:      177 kB
[2020-12-20 07:26:28.993][Debug][datastoreset.go:190] [Master] delta update complete in: 147.277065ms
[2020-12-20 07:26:33.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:33.345][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     42ms - insert:      3ms - count:      350 - size:      289 kB
[2020-12-20 07:26:33.439][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     87ms - insert:      3ms - count:      138 - size:      131 kB
[2020-12-20 07:26:33.442][Debug][datastoreset.go:190] [Master] delta update complete in: 149.047839ms
[2020-12-20 07:26:38.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:38.345][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      5ms - count:      332 - size:      275 kB
[2020-12-20 07:26:38.447][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     94ms - insert:      4ms - count:      155 - size:      113 kB
[2020-12-20 07:26:38.450][Debug][datastoreset.go:190] [Master] delta update complete in: 157.395209ms
[2020-12-20 07:26:43.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:43.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      3ms - count:      342 - size:      283 kB
[2020-12-20 07:26:43.438][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     91ms - insert:      2ms - count:      162 - size:      134 kB
[2020-12-20 07:26:43.441][Debug][datastoreset.go:190] [Master] delta update complete in: 148.223753ms
[2020-12-20 07:26:48.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:48.338][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      327 - size:      272 kB
[2020-12-20 07:26:48.439][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     94ms - insert:      4ms - count:      131 - size:      139 kB
[2020-12-20 07:26:48.441][Debug][datastoreset.go:190] [Master] delta update complete in: 148.918512ms
[2020-12-20 07:26:53.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:26:53.350][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     46ms - insert:      2ms - count:      324 - size:      268 kB
[2020-12-20 07:33:54.644][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 6m59.901s - insert:    550ms - count:    35530 - size:    33764 kB
[2020-12-20 07:33:54.646][Debug][datastoreset.go:190] [Master] delta update complete in: 7m1.353884511s
[2020-12-20 07:33:54.647][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:33:54.758][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:     99ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 07:33:54.760][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:33:54.760][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (113ms)
[2020-12-20 07:33:54.760][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:33:59.905][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   5.008s - insert:     35ms - count:     4649 - size:     3747 kB
[2020-12-20 07:34:00.008][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     87ms - insert:     10ms - count:      301 - size:      399 kB
[2020-12-20 07:34:00.010][Debug][datastoreset.go:190] [Master] delta update complete in: 5.250937378s
[2020-12-20 07:34:00.011][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:34:00.148][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    125ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 07:34:00.150][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:34:00.150][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (139ms)
[2020-12-20 07:34:00.151][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:00.207][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     44ms - insert:      1ms - count:      319 - size:      263 kB
[2020-12-20 07:34:00.296][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     85ms - insert:       0s - count:      124 - size:      141 kB
[2020-12-20 07:34:00.298][Debug][datastoreset.go:190] [Master] delta update complete in: 147.862345ms
[2020-12-20 07:34:05.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:05.342][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     39ms - insert:      3ms - count:      312 - size:      258 kB
[2020-12-20 07:34:05.418][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      3ms - count:       88 - size:      128 kB
[2020-12-20 07:34:05.424][Debug][datastoreset.go:190] [Master] delta update complete in: 130.938073ms
[2020-12-20 07:34:10.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:10.340][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      3ms - count:      335 - size:      278 kB
[2020-12-20 07:34:10.424][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     74ms - insert:      5ms - count:      151 - size:      254 kB
[2020-12-20 07:34:10.427][Debug][datastoreset.go:190] [Master] delta update complete in: 134.105107ms
[2020-12-20 07:34:15.299][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:      5ms - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:15.345][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      4ms - count:      330 - size:      274 kB
[2020-12-20 07:34:15.425][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     75ms - insert:      2ms - count:      107 - size:      156 kB
[2020-12-20 07:34:15.427][Debug][datastoreset.go:190] [Master] delta update complete in: 134.697701ms
[2020-12-20 07:34:20.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:20.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     38ms - insert:      3ms - count:      361 - size:      299 kB
[2020-12-20 07:34:20.418][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      3ms - count:      155 - size:      140 kB
[2020-12-20 07:34:20.421][Debug][datastoreset.go:190] [Master] delta update complete in: 128.269762ms
[2020-12-20 07:34:25.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:34:25.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      3ms - count:      345 - size:      286 kB
[2020-12-20 07:39:00.695][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 4m34.173s - insert:    529ms - count:    35530 - size:    33758 kB
[2020-12-20 07:39:00.698][Debug][datastoreset.go:190] [Master] delta update complete in: 4m35.405403916s
[2020-12-20 07:39:00.698][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:39:00.826][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    112ms - insert:      4ms - count:     3824 - size:      251 kB
[2020-12-20 07:39:00.829][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      2ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:39:00.829][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (130ms)
[2020-12-20 07:39:00.830][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:04.912][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   3.892s - insert:     79ms - count:     4649 - size:     3747 kB
[2020-12-20 07:39:05.108][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     91ms - insert:     99ms - count:      228 - size:      268 kB
[2020-12-20 07:39:05.111][Debug][datastoreset.go:190] [Master] delta update complete in: 4.282083369s
[2020-12-20 07:39:05.112][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:05.245][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     31ms - insert:     93ms - count:      305 - size:      252 kB
[2020-12-20 07:39:05.319][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     71ms - insert:       0s - count:      100 - size:       98 kB
[2020-12-20 07:39:05.322][Debug][datastoreset.go:190] [Master] delta update complete in: 211.13542ms
[2020-12-20 07:39:10.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:10.355][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     51ms - insert:      3ms - count:      341 - size:      283 kB
[2020-12-20 07:39:10.436][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     75ms - insert:      4ms - count:      135 - size:      134 kB
[2020-12-20 07:39:10.439][Debug][datastoreset.go:190] [Master] delta update complete in: 146.633389ms
[2020-12-20 07:39:15.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:15.337][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     34ms - insert:      3ms - count:      346 - size:      286 kB
[2020-12-20 07:39:15.423][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     77ms - insert:      5ms - count:      112 - size:      203 kB
[2020-12-20 07:39:15.425][Debug][datastoreset.go:190] [Master] delta update complete in: 132.26164ms
[2020-12-20 07:39:20.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:20.353][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     49ms - insert:      3ms - count:      343 - size:      284 kB
[2020-12-20 07:39:20.584][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     89ms - insert:    138ms - count:      180 - size:      179 kB
[2020-12-20 07:39:20.588][Debug][datastoreset.go:190] [Master] delta update complete in: 295.684902ms
[2020-12-20 07:39:25.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:25.338][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      344 - size:      285 kB
[2020-12-20 07:39:25.476][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:     65ms - count:      134 - size:      112 kB
[2020-12-20 07:39:25.479][Debug][datastoreset.go:190] [Master] delta update complete in: 187.034443ms
[2020-12-20 07:39:30.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:39:30.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      4ms - count:      319 - size:      263 kB
[2020-12-20 07:43:58.232][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 4m26.663s - insert:    359ms - count:    35530 - size:    33758 kB
[2020-12-20 07:43:58.235][Debug][datastoreset.go:190] [Master] delta update complete in: 4m27.94229291s
[2020-12-20 07:43:58.235][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:43:58.343][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:     96ms - insert:      1ms - count:     3824 - size:      251 kB
[2020-12-20 07:43:58.345][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:43:58.345][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (110ms)
[2020-12-20 07:43:58.346][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:02.303][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   3.831s - insert:     27ms - count:     4649 - size:     3747 kB
[2020-12-20 07:44:02.407][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     92ms - insert:      6ms - count:      239 - size:      280 kB
[2020-12-20 07:44:02.410][Debug][datastoreset.go:190] [Master] delta update complete in: 4.064986393s
[2020-12-20 07:44:02.411][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:44:02.523][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    101ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 07:44:02.526][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:44:02.526][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (115ms)
[2020-12-20 07:44:03.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:03.338][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      1ms - count:      338 - size:      280 kB
[2020-12-20 07:44:03.446][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    105ms - insert:      1ms - count:      103 - size:      138 kB
[2020-12-20 07:44:03.448][Debug][datastoreset.go:190] [Master] delta update complete in: 155.261513ms
[2020-12-20 07:44:08.314][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:     19ms - count:        1 - size:        0 kB
[2020-12-20 07:44:08.356][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      3ms - count:      350 - size:      289 kB
[2020-12-20 07:44:08.456][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     89ms - insert:      7ms - count:      175 - size:      247 kB
[2020-12-20 07:44:08.468][Debug][datastoreset.go:190] [Master] delta update complete in: 175.2933ms
[2020-12-20 07:44:13.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:13.346][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     41ms - insert:      3ms - count:      331 - size:      274 kB
[2020-12-20 07:44:13.423][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      4ms - count:      131 - size:      224 kB
[2020-12-20 07:44:13.434][Debug][datastoreset.go:190] [Master] delta update complete in: 141.311304ms
[2020-12-20 07:44:18.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:18.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      3ms - count:      356 - size:      295 kB
[2020-12-20 07:44:18.410][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      2ms - count:      129 - size:      130 kB
[2020-12-20 07:44:18.412][Debug][datastoreset.go:190] [Master] delta update complete in: 119.765381ms
[2020-12-20 07:44:23.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:23.354][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     45ms - insert:      4ms - count:      329 - size:      274 kB
[2020-12-20 07:44:23.429][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      3ms - count:      133 - size:      151 kB
[2020-12-20 07:44:23.432][Debug][datastoreset.go:190] [Master] delta update complete in: 139.721324ms
[2020-12-20 07:44:28.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:44:28.343][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      4ms - count:      347 - size:      287 kB
[2020-12-20 07:50:01.713][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m31.916s - insert:    593ms - count:    35530 - size:    33762 kB
[2020-12-20 07:50:01.720][Debug][datastoreset.go:190] [Master] delta update complete in: 5m33.427098019s
[2020-12-20 07:50:01.721][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:50:01.891][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    136ms - insert:     17ms - count:     3824 - size:      251 kB
[2020-12-20 07:50:01.893][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:50:01.894][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (173ms)
[2020-12-20 07:50:01.894][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:06.068][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   4.036s - insert:     29ms - count:     4649 - size:     3747 kB
[2020-12-20 07:50:06.179][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     96ms - insert:      9ms - count:      267 - size:      496 kB
[2020-12-20 07:50:06.182][Debug][datastoreset.go:190] [Master] delta update complete in: 4.288491672s
[2020-12-20 07:50:06.183][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:06.234][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     45ms - insert:       0s - count:      331 - size:      274 kB
[2020-12-20 07:50:06.324][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     85ms - insert:       0s - count:      127 - size:      212 kB
[2020-12-20 07:50:06.328][Debug][datastoreset.go:190] [Master] delta update complete in: 145.891187ms
[2020-12-20 07:50:11.748][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:    453ms - count:        1 - size:        0 kB
[2020-12-20 07:50:11.803][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     42ms - insert:      3ms - count:      375 - size:      311 kB
[2020-12-20 07:50:11.882][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     73ms - insert:      3ms - count:      149 - size:      116 kB
[2020-12-20 07:50:11.885][Debug][datastoreset.go:190] [Master] delta update complete in: 592.139606ms
[2020-12-20 07:50:16.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:16.345][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      5ms - count:      357 - size:      296 kB
[2020-12-20 07:50:16.424][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     73ms - insert:      3ms - count:      131 - size:      153 kB
[2020-12-20 07:50:16.427][Debug][datastoreset.go:190] [Master] delta update complete in: 134.410727ms
[2020-12-20 07:50:21.299][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:      4ms - count:        1 - size:        0 kB
[2020-12-20 07:50:21.348][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     39ms - insert:      3ms - count:      331 - size:      274 kB
[2020-12-20 07:50:21.426][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      4ms - count:      151 - size:      162 kB
[2020-12-20 07:50:21.429][Debug][datastoreset.go:190] [Master] delta update complete in: 135.659986ms
[2020-12-20 07:50:26.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:26.473][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     36ms - insert:    134ms - count:      349 - size:      289 kB
[2020-12-20 07:50:26.668][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    102ms - insert:     88ms - count:      160 - size:      159 kB
[2020-12-20 07:50:26.671][Debug][datastoreset.go:190] [Master] delta update complete in: 377.979874ms
[2020-12-20 07:50:31.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:50:31.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      3ms - count:      325 - size:      269 kB
[2020-12-20 07:55:20.286][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 4m47.968s - insert:    376ms - count:    35530 - size:    33762 kB
[2020-12-20 07:55:20.289][Debug][datastoreset.go:190] [Master] delta update complete in: 4m48.996771052s
[2020-12-20 07:55:20.290][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 07:55:20.436][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    134ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 07:55:20.438][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 07:55:20.438][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (148ms)
[2020-12-20 07:55:20.439][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:26.571][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   5.939s - insert:     66ms - count:     4649 - size:     3747 kB
[2020-12-20 07:55:26.913][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    120ms - insert:    217ms - count:      394 - size:      449 kB
[2020-12-20 07:55:26.917][Debug][datastoreset.go:190] [Master] delta update complete in: 6.478754731s
[2020-12-20 07:55:26.918][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:26.967][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     39ms - insert:      1ms - count:      409 - size:      338 kB
[2020-12-20 07:55:27.234][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    116ms - insert:    146ms - count:      157 - size:      155 kB
[2020-12-20 07:55:27.237][Debug][datastoreset.go:190] [Master] delta update complete in: 319.991544ms
[2020-12-20 07:55:31.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:31.343][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     39ms - insert:      4ms - count:      334 - size:      276 kB
[2020-12-20 07:55:31.441][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     92ms - insert:      3ms - count:       99 - size:      161 kB
[2020-12-20 07:55:31.443][Debug][datastoreset.go:190] [Master] delta update complete in: 150.762215ms
[2020-12-20 07:55:36.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:36.339][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      337 - size:      279 kB
[2020-12-20 07:55:36.450][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    104ms - insert:      4ms - count:      136 - size:      172 kB
[2020-12-20 07:55:36.453][Debug][datastoreset.go:190] [Master] delta update complete in: 159.737648ms
[2020-12-20 07:55:41.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:41.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     38ms - insert:      3ms - count:      328 - size:      273 kB
[2020-12-20 07:55:41.468][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    117ms - insert:      6ms - count:      150 - size:      198 kB
[2020-12-20 07:55:41.472][Debug][datastoreset.go:190] [Master] delta update complete in: 179.066883ms
[2020-12-20 07:55:46.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:46.351][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     46ms - insert:      3ms - count:      327 - size:      271 kB
[2020-12-20 07:55:46.489][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    123ms - insert:     11ms - count:      165 - size:      359 kB
[2020-12-20 07:55:46.493][Debug][datastoreset.go:190] [Master] delta update complete in: 200.07957ms
[2020-12-20 07:55:51.295][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 07:55:51.339][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      2ms - count:      328 - size:      272 kB
[2020-12-20 08:03:13.231][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 7m20.701s - insert:    574ms - count:    35530 - size:    33755 kB
[2020-12-20 08:03:13.234][Debug][datastoreset.go:190] [Master] delta update complete in: 7m21.940579745s
[2020-12-20 08:03:13.235][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 08:03:13.362][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    116ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 08:03:13.364][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:03:13.364][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (129ms)
[2020-12-20 08:03:13.365][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:03:17.616][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   3.876s - insert:    100ms - count:     4649 - size:     3747 kB
[2020-12-20 08:03:17.716][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     83ms - insert:      8ms - count:      280 - size:      381 kB
[2020-12-20 08:03:17.719][Debug][datastoreset.go:190] [Master] delta update complete in: 4.354778782s
[2020-12-20 08:03:18.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:03:18.351][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     44ms - insert:      2ms - count:      344 - size:      284 kB
[2020-12-20 08:03:18.452][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     96ms - insert:      2ms - count:      126 - size:      167 kB
[2020-12-20 08:03:18.455][Debug][datastoreset.go:190] [Master] delta update complete in: 161.76775ms
[2020-12-20 08:03:23.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:03:23.340][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     34ms - insert:      3ms - count:      355 - size:      294 kB
[2020-12-20 08:03:23.427][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     77ms - insert:      6ms - count:      177 - size:      183 kB
[2020-12-20 08:03:23.430][Debug][datastoreset.go:190] [Master] delta update complete in: 137.755895ms
[2020-12-20 08:03:28.391][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:     97ms - count:        1 - size:        0 kB
[2020-12-20 08:03:28.438][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      3ms - count:      341 - size:      281 kB
[2020-12-20 08:03:28.520][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     75ms - insert:      3ms - count:      169 - size:      157 kB
[2020-12-20 08:03:28.522][Debug][datastoreset.go:190] [Master] delta update complete in: 229.909028ms
[2020-12-20 08:03:33.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:03:33.335][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     31ms - insert:      3ms - count:      335 - size:      277 kB
[2020-12-20 08:03:33.415][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     72ms - insert:      4ms - count:      112 - size:      138 kB
[2020-12-20 08:03:33.418][Debug][datastoreset.go:190] [Master] delta update complete in: 124.566338ms
[2020-12-20 08:03:38.651][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:    358ms - count:        1 - size:        0 kB
[2020-12-20 08:03:38.713][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     48ms - insert:      3ms - count:      374 - size:      311 kB
[2020-12-20 08:03:38.797][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     75ms - insert:      5ms - count:      162 - size:      225 kB
[2020-12-20 08:03:38.800][Debug][datastoreset.go:190] [Master] delta update complete in: 507.697169ms
[2020-12-20 08:03:43.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:03:43.351][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     43ms - insert:      4ms - count:      316 - size:      261 kB
[2020-12-20 08:08:45.954][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m1.358s - insert:    491ms - count:    35530 - size:    33757 kB
[2020-12-20 08:08:45.957][Debug][datastoreset.go:190] [Master] delta update complete in: 5m2.664658001s
[2020-12-20 08:08:45.958][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 08:08:46.078][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    108ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 08:08:46.080][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:08:46.080][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (122ms)
[2020-12-20 08:08:46.081][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:08:50.624][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   4.398s - insert:     31ms - count:     4649 - size:     3747 kB
[2020-12-20 08:08:50.722][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     82ms - insert:     10ms - count:      364 - size:      478 kB
[2020-12-20 08:08:50.725][Debug][datastoreset.go:190] [Master] delta update complete in: 4.645478098s
[2020-12-20 08:08:50.726][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:08:50.779][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     45ms - insert:      1ms - count:      367 - size:      304 kB
[2020-12-20 08:08:50.863][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     81ms - insert:       0s - count:      183 - size:      208 kB
[2020-12-20 08:08:50.866][Debug][datastoreset.go:190] [Master] delta update complete in: 140.308269ms
[2020-12-20 08:08:55.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:08:55.336][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:      3ms - count:      333 - size:      274 kB
[2020-12-20 08:08:55.434][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     93ms - insert:      3ms - count:      142 - size:      115 kB
[2020-12-20 08:08:55.437][Debug][datastoreset.go:190] [Master] delta update complete in: 143.990362ms
[2020-12-20 08:09:00.388][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:     94ms - count:        3 - size:        0 kB
[2020-12-20 08:09:00.599][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:     97ms - insert:    103ms - count:     3824 - size:      251 kB
[2020-12-20 08:09:00.602][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:09:00.602][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (308ms)
[2020-12-20 08:09:00.602][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:09:00.646][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     34ms - insert:      3ms - count:      354 - size:      293 kB
[2020-12-20 08:09:00.720][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      2ms - count:       99 - size:      133 kB
[2020-12-20 08:09:00.723][Debug][datastoreset.go:190] [Master] delta update complete in: 120.902161ms
[2020-12-20 08:09:05.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:09:05.450][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     32ms - insert:    115ms - count:      332 - size:      275 kB
[2020-12-20 08:09:05.524][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      2ms - count:      112 - size:      111 kB
[2020-12-20 08:09:05.527][Debug][datastoreset.go:190] [Master] delta update complete in: 234.334249ms
[2020-12-20 08:09:10.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:09:10.339][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      2ms - count:      333 - size:      276 kB
[2020-12-20 08:09:10.414][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     69ms - insert:      3ms - count:      132 - size:      133 kB
[2020-12-20 08:09:10.417][Debug][datastoreset.go:190] [Master] delta update complete in: 124.146086ms
[2020-12-20 08:09:15.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:09:15.345][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     42ms - insert:      3ms - count:      336 - size:      278 kB
[2020-12-20 08:14:18.888][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m2.288s - insert:    642ms - count:    35530 - size:    33762 kB
[2020-12-20 08:14:18.891][Debug][datastoreset.go:190] [Master] delta update complete in: 5m3.59857639s
[2020-12-20 08:14:18.892][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 08:14:19.001][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:     97ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 08:14:19.003][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:14:19.003][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (112ms)
[2020-12-20 08:14:19.004][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:22.898][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:    3.77s - insert:     26ms - count:     4649 - size:     3746 kB
[2020-12-20 08:14:22.993][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     82ms - insert:      7ms - count:      332 - size:      296 kB
[2020-12-20 08:14:22.995][Debug][datastoreset.go:190] [Master] delta update complete in: 3.992107502s
[2020-12-20 08:14:23.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:23.335][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      1ms - count:      320 - size:      265 kB
[2020-12-20 08:14:23.418][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     80ms - insert:       0s - count:      143 - size:      158 kB
[2020-12-20 08:14:23.425][Debug][datastoreset.go:190] [Master] delta update complete in: 132.000366ms
[2020-12-20 08:14:28.304][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:28.368][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     41ms - insert:      5ms - count:      314 - size:      259 kB
[2020-12-20 08:14:28.464][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     71ms - insert:      8ms - count:      161 - size:      152 kB
[2020-12-20 08:14:28.467][Debug][datastoreset.go:190] [Master] delta update complete in: 163.967517ms
[2020-12-20 08:14:33.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:33.340][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      322 - size:      266 kB
[2020-12-20 08:14:33.415][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     70ms - insert:      2ms - count:      106 - size:      126 kB
[2020-12-20 08:14:33.417][Debug][datastoreset.go:190] [Master] delta update complete in: 125.005629ms
[2020-12-20 08:14:38.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:38.340][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      2ms - count:      326 - size:      270 kB
[2020-12-20 08:14:38.438][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     88ms - insert:      5ms - count:      124 - size:      194 kB
[2020-12-20 08:14:38.440][Debug][datastoreset.go:190] [Master] delta update complete in: 147.101445ms
[2020-12-20 08:14:43.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:43.339][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      365 - size:      302 kB
[2020-12-20 08:14:43.460][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    113ms - insert:      4ms - count:      140 - size:      189 kB
[2020-12-20 08:14:43.463][Debug][datastoreset.go:190] [Master] delta update complete in: 169.393887ms
[2020-12-20 08:14:48.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:14:48.338][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      334 - size:      277 kB
[2020-12-20 08:19:34.641][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 4m45.035s - insert:    631ms - count:    35530 - size:    33765 kB
[2020-12-20 08:19:34.644][Debug][datastoreset.go:190] [Master] delta update complete in: 4m46.351749241s
[2020-12-20 08:19:34.714][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:     69ms - count:        3 - size:        0 kB
[2020-12-20 08:19:34.822][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:     95ms - insert:       0s - count:     3824 - size:      251 kB
[2020-12-20 08:19:34.824][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:19:34.824][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (179ms)
[2020-12-20 08:19:34.825][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:19:39.028][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   4.072s - insert:     28ms - count:     4649 - size:     3747 kB
[2020-12-20 08:19:39.127][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     85ms - insert:      7ms - count:      274 - size:      264 kB
[2020-12-20 08:19:39.130][Debug][datastoreset.go:190] [Master] delta update complete in: 4.30570957s
[2020-12-20 08:19:39.130][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:19:39.186][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     49ms - insert:      1ms - count:      334 - size:      276 kB
[2020-12-20 08:19:39.269][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     79ms - insert:       0s - count:      131 - size:      105 kB
[2020-12-20 08:19:39.271][Debug][datastoreset.go:190] [Master] delta update complete in: 141.485197ms
[2020-12-20 08:19:44.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:19:44.339][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      4ms - count:      347 - size:      286 kB
[2020-12-20 08:19:44.424][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     77ms - insert:      3ms - count:      135 - size:      120 kB
[2020-12-20 08:19:44.426][Debug][datastoreset.go:190] [Master] delta update complete in: 133.138858ms
[2020-12-20 08:19:49.399][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:    106ms - count:        1 - size:        0 kB
[2020-12-20 08:19:49.448][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     38ms - insert:      3ms - count:      355 - size:      293 kB
[2020-12-20 08:19:49.535][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     73ms - insert:     11ms - count:      158 - size:      148 kB
[2020-12-20 08:19:49.538][Debug][datastoreset.go:190] [Master] delta update complete in: 245.134597ms
[2020-12-20 08:19:54.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:19:54.340][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     36ms - insert:      3ms - count:      346 - size:      286 kB
[2020-12-20 08:19:54.426][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     78ms - insert:      3ms - count:      180 - size:      161 kB
[2020-12-20 08:19:54.430][Debug][datastoreset.go:190] [Master] delta update complete in: 136.376232ms
[2020-12-20 08:19:59.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:19:59.333][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     30ms - insert:      2ms - count:      313 - size:      259 kB
[2020-12-20 08:19:59.411][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     71ms - insert:      4ms - count:      131 - size:      189 kB
[2020-12-20 08:19:59.414][Debug][datastoreset.go:190] [Master] delta update complete in: 121.710181ms
[2020-12-20 08:20:00.294][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 08:20:00.422][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    114ms - insert:      1ms - count:     3824 - size:      251 kB
[2020-12-20 08:20:00.425][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      2ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:20:00.425][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (132ms)
[2020-12-20 08:20:04.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:20:04.390][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     42ms - insert:     47ms - count:      360 - size:      298 kB
[2020-12-20 08:25:19.236][Debug][datastoreset.go:307] [Master] updated table:        services - fetch: 5m13.776s - insert:    436ms - count:    35530 - size:    33766 kB
[2020-12-20 08:25:19.239][Debug][datastoreset.go:190] [Master] delta update complete in: 5m14.946752378s
[2020-12-20 08:25:19.240][Debug][datastoreset.go:687] [Master] updated table:     timeperiods - fetch:       0s - insert:       0s - count:        3 - size:        0 kB
[2020-12-20 08:25:19.369][Debug][datastoreset.go:687] [Master] updated table:      hostgroups - fetch:    105ms - insert:      1ms - count:     3824 - size:      251 kB
[2020-12-20 08:25:19.372][Debug][datastoreset.go:687] [Master] updated table:   servicegroups - fetch:      1ms - insert:       0s - count:        7 - size:        0 kB
[2020-12-20 08:25:19.372][Debug][peer.go:408] [Master] updating timeperiods and host/servicegroup statistics completed (133ms)
[2020-12-20 08:25:19.373][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:25.914][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:   6.385s - insert:     41ms - count:     4649 - size:     3747 kB
[2020-12-20 08:25:26.033][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:    100ms - insert:     11ms - count:      410 - size:      474 kB
[2020-12-20 08:25:26.036][Debug][datastoreset.go:190] [Master] delta update complete in: 6.663278698s
[2020-12-20 08:25:26.036][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:26.081][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      1ms - count:      319 - size:      264 kB
[2020-12-20 08:25:26.290][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     89ms - insert:    117ms - count:      122 - size:      108 kB
[2020-12-20 08:25:26.294][Debug][datastoreset.go:190] [Master] delta update complete in: 258.206676ms
[2020-12-20 08:25:31.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:31.337][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     34ms - insert:      3ms - count:      322 - size:      266 kB
[2020-12-20 08:25:31.432][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     90ms - insert:      2ms - count:       88 - size:      147 kB
[2020-12-20 08:25:31.436][Debug][datastoreset.go:190] [Master] delta update complete in: 143.03656ms
[2020-12-20 08:25:36.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:36.347][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     44ms - insert:      3ms - count:      352 - size:      290 kB
[2020-12-20 08:25:36.445][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     91ms - insert:      3ms - count:      137 - size:      172 kB
[2020-12-20 08:25:36.447][Debug][datastoreset.go:190] [Master] delta update complete in: 155.027846ms
[2020-12-20 08:25:41.297][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:41.342][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     35ms - insert:      3ms - count:      345 - size:      286 kB
[2020-12-20 08:25:41.449][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     98ms - insert:      5ms - count:      150 - size:      202 kB
[2020-12-20 08:25:41.451][Debug][datastoreset.go:190] [Master] delta update complete in: 156.019656ms
[2020-12-20 08:25:46.294][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:46.337][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     33ms - insert:      3ms - count:      316 - size:      262 kB
[2020-12-20 08:25:46.549][Debug][datastoreset.go:307] [Master] updated table:        services - fetch:     93ms - insert:    116ms - count:      161 - size:      297 kB
[2020-12-20 08:25:46.560][Debug][datastoreset.go:190] [Master] delta update complete in: 266.836919ms
[2020-12-20 08:25:51.293][Debug][datastoreset.go:687] [Master] updated table:          status - fetch:       0s - insert:       0s - count:        1 - size:        0 kB
[2020-12-20 08:25:51.341][Debug][datastoreset.go:307] [Master] updated table:           hosts - fetch:     37ms - insert:      3ms - count:      339 - size:      280 kB
steffen-poulsen commented 3 years ago

I want to share a detail on the bandwidth pattern at restart time between the LMD and our NCE-4 backend also.

There seems to be this pattern:

Btw, I don't know if it might be useful to have a figure for this initial "wait time" in the LMD debug log as well. This would be the time spent in the request before receiving the first byte of the reply. If this is possible, perhaps it could assist in identifying bandwidth issues early.

image

sni commented 3 years ago

The 5m pattern may be a "full refresh" set by the FullUpdateInterval. Is this enabled in your setup? Which versions of Icinga / Nagios do you use, are all of them slow?

sni commented 3 years ago

should be fixed with e0e8ea1e2d651d6ff22d4b9ec29426d0a8865575