search

sni / mod_gearman

Distribute Naemon Host/Service Checks & Eventhandler with Gearman Queues. Host/Servicegroups affinity included.
http://www.mod-gearman.org
GNU General Public License v3.0
122 stars 42 forks source link

Server side multiple keys #132

Closed box293 closed 6 years ago

box293 commented 6 years ago

I was thinking about how MG is sometimes used in multi tenant scenarios. Currently my understanding is that the MG server can only have one key defined, hence all the workers need to use that one key.

When you have a central monitoring server with separate clients it might be useful if each client could use their own key. This would require the MG server to allow for multiple keys in it's configuration. This could also be enhanced by only allowing specific workers to connect using specific keys.

Instead of using a key, it might be advantageous if TLS certificates could be used instead.

On a side note, in relation to keys and encryption I could not easily identify what type of encryption method is used, is it documented somewhere?

sni commented 6 years ago

Newer libgearman supports TLS, but i never had time to have a deeper look into this. TLS support would indeed be great. Currently MG uses AES-256 encryption.

One workaround for multiple server keys would be to load the NEB module twice with different keys and different hostgroups.

box293 commented 6 years ago

Newer libgearman supports TLS, but i never had time to have a deeper look into this.

Do you have any pointers as to how I could play around with this in the configuration files?

One workaround for multiple server keys would be to load the NEB module twice with different keys and different hostgroups.

Thats a good idea, I'll look into doing this.

sni commented 6 years ago

No, sry, i have no pointer. There is nothing in the mod-gearman config files either because MG does not supprt that. I just said that newer gearmand and libgearman would support it in theory. I never tried it and its not implemented in MG. But of course, Pull Requests are welcome.

box293 commented 6 years ago

One workaround for multiple server keys would be to load the NEB module twice with different keys and different hostgroups.

I wanted to report back that I could not get this to work. From what I could tell only the first neb module is used when organising jobs / queues. For example the specific hostgroups and servicegroups that have been defined for queues, these jobs never reach these queues as they are defined in the second and more configs (hence the workers never get the checks).

Here are the nagios.cfg entries:

broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/nagios_core.conf eventhandler=no
broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_NEW_CLIENT.conf eventhandler=no
broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_ANOTHER_CLIENT.conf eventhandler=no

Here is nagios_core.conf:

debug=3
logfile=/var/log/mod_gearman2/mod_gearman_neb_core.log
server=localhost:4730
eventhandler=yes
services=yes
hosts=yes
do_hostchecks=yes
route_eventhandler_like_checks=no
encryption=yes
key=97ghRR76h-8jinf54_57bnmK6b
use_uniq_jobs=on
localhostgroups=
localservicegroups=
result_workers=1
perfdata=no
perfdata_mode=1
orphan_host_checks=yes
orphan_service_checks=yes
accept_clear_results=no

Here is module_NEW_CLIENT.conf:

debug=3
logfile=/var/log/mod_gearman2/mod_gearman_neb_nc.log
server=localhost:4730
eventhandler=yes
services=yes
hosts=yes
hostgroups=[NEW CLIENT]
servicegroups=[NEW CLIENT]
do_hostchecks=yes
route_eventhandler_like_checks=no
encryption=yes
key=HUGFKL_kkl28939823JMkjn
use_uniq_jobs=on
result_workers=1
perfdata=no
perfdata_mode=1
orphan_host_checks=yes
orphan_service_checks=yes
accept_clear_results=no

Here is module_ANOTHER_CLIENT.conf:

debug=3
logfile=/var/log/mod_gearman2/mod_gearman_neb_ac.log
server=localhost:4730
eventhandler=yes
services=yes
hosts=yes
hostgroups=[ANOTHER_CLIENT],[ANOTHER_CLIENT][ORACLE][PRODUCTION]
servicegroups=[ANOTHER_CLIENT]
do_hostchecks=yes
route_eventhandler_like_checks=no
encryption=yes
key=HUGFKL_kkl28939823JMkjnaaaaa
use_uniq_jobs=on
result_workers=1
perfdata=no
perfdata_mode=1
orphan_host_checks=yes
orphan_service_checks=yes
accept_clear_results=no

Then I run:

systemctl stop nagios; systemctl restart gearmand; systemctl start nagios

When tailing the three log files, they all display some initial information but after that only the first conf file shows the jobs being processed. If I change the order:

broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_NEW_CLIENT.conf eventhandler=no
broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_ANOTHER_CLIENT.conf eventhandler=no
broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/nagios_core.conf eventhandler=no

After restarting the server the first entry NEW_CLIENT is the one that you see entries in the list.

So unless you see something wrong in the configs perhaps MG won't allow multiple configs.

FYI I did have in module_NEW_CLIENT.conf module_ANOTHER_CLIENT.conf the lines:

services=no
hosts=no

I had changed them to yes for testing.

Nagios 4.2.4 and Mod Gearman 2.1.1

sni commented 6 years ago

The order of loading the NEB modules is very important. Could you try to set services/hosts=no again but load the nagios_core.conf as last one. Otherwise the catch all from that config will prevent further processing.

box293 commented 6 years ago

Thanks for the response. I just tried what you requested but I get the same response, only the first broker line in nagios.cfg seems to be the one that is used.

I also tried services/hosts=no in nagios_core.conf but same result.

Here's some log info: broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_NEW_CLIENT.conf eventhandler=no

[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][DEBUG] configuration:
[2018-10-16 03:55:12][30821][DEBUG] log level:                       3
[2018-10-16 03:55:12][30821][DEBUG] log mode:                        file (1)
[2018-10-16 03:55:12][30821][DEBUG] queue by cust var:               no
[2018-10-16 03:55:12][30821][DEBUG] debug result:                    no
[2018-10-16 03:55:12][30821][DEBUG] result_worker:                   1
[2018-10-16 03:55:12][30821][DEBUG] do_hostchecks:                   yes
[2018-10-16 03:55:12][30821][DEBUG] route_eventhandler_like_checks:  no
[2018-10-16 03:55:12][30821][DEBUG] result_queue:                    check_results
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] server:                          localhost:4730
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] perfdata:                        no
[2018-10-16 03:55:12][30821][DEBUG] perfdata mode:                   overwrite
[2018-10-16 03:55:12][30821][DEBUG] hosts:                           no
[2018-10-16 03:55:12][30821][DEBUG] services:                        no
[2018-10-16 03:55:12][30821][DEBUG] eventhandler:                    no
[2018-10-16 03:55:12][30821][DEBUG] hostgroups:                      [NEW CLIENT]
[2018-10-16 03:55:12][30821][DEBUG] servicegroups:                   [NEW CLIENT]
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] encryption:                      yes
[2018-10-16 03:55:12][30821][DEBUG] keyfile:                         no
[2018-10-16 03:55:12][30821][DEBUG] encryption key:                  set
[2018-10-16 03:55:12][30821][DEBUG] accept clear result:             no
[2018-10-16 03:55:12][30821][DEBUG] transport mode:                  aes-256+base64
[2018-10-16 03:55:12][30821][DEBUG] use uniq jobs:                   yes
[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][TRACE] create_client()
[2018-10-16 03:55:12][30821][DEBUG] finished initializing
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)
[2018-10-16 03:55:12][30821][TRACE] handle_process_events(0, data)

broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/module_ANOTHER_CLIENT.conf eventhandler=no

[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][DEBUG] configuration:
[2018-10-16 03:55:12][30821][DEBUG] log level:                       3
[2018-10-16 03:55:12][30821][DEBUG] log mode:                        file (1)
[2018-10-16 03:55:12][30821][DEBUG] queue by cust var:               no
[2018-10-16 03:55:12][30821][DEBUG] debug result:                    no
[2018-10-16 03:55:12][30821][DEBUG] result_worker:                   1
[2018-10-16 03:55:12][30821][DEBUG] do_hostchecks:                   yes
[2018-10-16 03:55:12][30821][DEBUG] route_eventhandler_like_checks:  no
[2018-10-16 03:55:12][30821][DEBUG] result_queue:                    check_results
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] server:                          localhost:4730
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] perfdata:                        no
[2018-10-16 03:55:12][30821][DEBUG] perfdata mode:                   overwrite
[2018-10-16 03:55:12][30821][DEBUG] hosts:                           no
[2018-10-16 03:55:12][30821][DEBUG] services:                        no
[2018-10-16 03:55:12][30821][DEBUG] eventhandler:                    no
[2018-10-16 03:55:12][30821][DEBUG] hostgroups:                      [ANOTHER_CLIENT]
[2018-10-16 03:55:12][30821][DEBUG] hostgroups:                      [ANOTHER_CLIENT][ORACLE][PRODUCTION]
[2018-10-16 03:55:12][30821][DEBUG] servicegroups:                   [ANOTHER_CLIENT]
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] encryption:                      yes
[2018-10-16 03:55:12][30821][DEBUG] keyfile:                         no
[2018-10-16 03:55:12][30821][DEBUG] encryption key:                  set
[2018-10-16 03:55:12][30821][DEBUG] accept clear result:             no
[2018-10-16 03:55:12][30821][DEBUG] transport mode:                  aes-256+base64
[2018-10-16 03:55:12][30821][DEBUG] use uniq jobs:                   yes
[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][TRACE] create_client()
[2018-10-16 03:55:12][30821][DEBUG] finished initializing

broker_module=/usr/lib64/mod_gearman2/mod_gearman2.o config=/usr/local/nagios/etc/mod_gearman/nagios_core.conf eventhandler=no

[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][DEBUG] configuration:
[2018-10-16 03:55:12][30821][DEBUG] log level:                       3
[2018-10-16 03:55:12][30821][DEBUG] log mode:                        file (1)
[2018-10-16 03:55:12][30821][DEBUG] queue by cust var:               no
[2018-10-16 03:55:12][30821][DEBUG] debug result:                    no
[2018-10-16 03:55:12][30821][DEBUG] result_worker:                   1
[2018-10-16 03:55:12][30821][DEBUG] do_hostchecks:                   yes
[2018-10-16 03:55:12][30821][DEBUG] route_eventhandler_like_checks:  no
[2018-10-16 03:55:12][30821][DEBUG] result_queue:                    check_results
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] server:                          localhost:4730
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] perfdata:                        no
[2018-10-16 03:55:12][30821][DEBUG] perfdata mode:                   overwrite
[2018-10-16 03:55:12][30821][DEBUG] hosts:                           yes
[2018-10-16 03:55:12][30821][DEBUG] services:                        yes
[2018-10-16 03:55:12][30821][DEBUG] eventhandler:                    no
[2018-10-16 03:55:12][30821][DEBUG]
[2018-10-16 03:55:12][30821][DEBUG] encryption:                      yes
[2018-10-16 03:55:12][30821][DEBUG] keyfile:                         no
[2018-10-16 03:55:12][30821][DEBUG] encryption key:                  set
[2018-10-16 03:55:12][30821][DEBUG] accept clear result:             no
[2018-10-16 03:55:12][30821][DEBUG] transport mode:                  aes-256+base64
[2018-10-16 03:55:12][30821][DEBUG] use uniq jobs:                   yes
[2018-10-16 03:55:12][30821][DEBUG] --------------------------------
[2018-10-16 03:55:12][30821][TRACE] create_client()
[2018-10-16 03:55:12][30821][DEBUG] finished initializing

Once I restart the services it's only the NEW_CLIENT log file I see information in after the initialisation is finished.

sni commented 6 years ago

thats interesting, is there anything useful in the debug.log? Does nagios run the callback on all 3 modules?

box293 commented 6 years ago

To try and produce the smallest log possible I changed my nagios configs so I just had 2 hosts and 2 services. I stopped nagios, deleted the debug log and then started nagios. I then forced an immediate check of the service and stopped nagios about 10 seconds later. Here is the full debug from that.

[1539678499.756959] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757007] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757032] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757048] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757063] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757079] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.757106] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.761597] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.761696] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.761734] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.763611] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.766444] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.766485] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.766493] [064.0] [pid=46364] Module '/usr/lib64/mod_gearman2/mod_gearman2.o' loaded with return code of '0'
[1539678499.766499] [064.0] [pid=46364] nebmodule_deinit() found
[1539678499.767111] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.767134] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.767140] [064.0] [pid=46364] Module '/usr/lib64/mod_gearman2/mod_gearman2.o' loaded with return code of '0'
[1539678499.767145] [064.0] [pid=46364] nebmodule_deinit() found
[1539678499.767977] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.767999] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768005] [064.0] [pid=46364] Module '/usr/lib64/mod_gearman2/mod_gearman2.o' loaded with return code of '0'
[1539678499.768009] [064.0] [pid=46364] nebmodule_deinit() found
[1539678499.768386] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768865] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768883] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768899] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768917] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.768933] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768943] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.768956] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768964] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.768978] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.768987] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769001] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769010] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769024] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769033] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769049] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769058] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769072] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769081] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769093] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769101] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769113] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769121] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769135] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769143] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769156] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769166] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769180] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769190] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769204] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769213] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769226] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769234] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769320] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769338] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769358] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769370] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769397] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769411] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769430] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769443] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769459] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769470] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769486] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769499] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769517] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769529] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769548] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.769561] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.769570] [064.0] [pid=46364] Module '/usr/local/nagios/bin/ndomod.o' loaded with return code of '0'
[1539678499.769576] [064.0] [pid=46364] nebmodule_deinit() found
[1539678499.769582] [064.1] [pid=46364] Making callbacks (type 0)...
[1539678499.769600] [064.2] [pid=46364] Callback #1 (type 0) return code = 0
[1539678499.769612] [064.2] [pid=46364] Callback #2 (type 0) return code = 0
[1539678499.769623] [064.2] [pid=46364] Callback #3 (type 0) return code = 0
[1539678499.769640] [064.2] [pid=46364] Callback #4 (type 0) return code = 0
[1539678499.773024] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.773041] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.773060] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.773070] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.773085] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.773096] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.775045] [064.1] [pid=46364] Making callbacks (type 0)...
[1539678499.775066] [064.2] [pid=46364] Callback #1 (type 0) return code = 0
[1539678499.775075] [064.2] [pid=46364] Callback #2 (type 0) return code = 0
[1539678499.775083] [064.2] [pid=46364] Callback #3 (type 0) return code = 0
[1539678499.775828] [064.2] [pid=46364] Callback #4 (type 0) return code = 0
[1539678499.775857] [001.0] [pid=46364] initialize_downtime_data()
[1539678499.775952] [064.1] [pid=46364] Making callbacks (type 19)...
[1539678499.775965] [064.2] [pid=46364] Callback #1 (type 19) return code = 0
[1539678499.775971] [001.0] [pid=46364] xrddefault_read_state_information() start
[1539678499.776573] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.776628] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.776714] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.776742] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.776793] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.776818] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.776863] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.776889] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.776933] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.776959] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.777014] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678499.777039] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678499.777085] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678499.777111] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678499.777123] [064.1] [pid=46364] Making callbacks (type 24)...
[1539678499.777137] [064.2] [pid=46364] Callback #1 (type 24) return code = 0
[1539678499.777148] [064.1] [pid=46364] Making callbacks (type 24)...
[1539678499.777164] [064.2] [pid=46364] Callback #1 (type 24) return code = 0
[1539678499.777176] [064.1] [pid=46364] Making callbacks (type 24)...
[1539678499.777187] [064.2] [pid=46364] Callback #1 (type 24) return code = 0
[1539678499.777208] [001.0] [pid=46364] sort_downtime()
[1539678499.777214] [064.1] [pid=46364] Making callbacks (type 19)...
[1539678499.789894] [064.2] [pid=46364] Callback #1 (type 19) return code = 0
[1539678499.789932] [001.0] [pid=46364] schedule_new_event()
[1539678499.789941] [008.0] [pid=46364] New Event Details:
[1539678499.789945] [008.0] [pid=46364]  Type:                       EVENT_USER_FUNCTION
[1539678499.789950] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.789955] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:34
[1539678499.789959] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.789963] [008.0] [pid=46364]  Event Interval:             15
[1539678499.789967] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.789971] [008.0] [pid=46364]  Event Options:              0
[1539678499.789976] [008.0] [pid=46364]  Event ID:                   0x2398ac0
[1539678499.789980] [001.0] [pid=46364] add_event()
[1539678499.789985] [001.0] [pid=46364] schedule_new_event()
[1539678499.789990] [008.0] [pid=46364] New Event Details:
[1539678499.789994] [008.0] [pid=46364]  Type:                       EVENT_USER_FUNCTION
[1539678499.789998] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.790002] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:34
[1539678499.790006] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.790010] [008.0] [pid=46364]  Event Interval:             15
[1539678499.790014] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.790018] [008.0] [pid=46364]  Event Options:              0
[1539678499.790021] [008.0] [pid=46364]  Event ID:                   0x2399710
[1539678499.790025] [001.0] [pid=46364] add_event()
[1539678499.790031] [001.0] [pid=46364] init_timing_loop() start
[1539678499.790040] [001.0] [pid=46364] check_time_against_period()
[1539678499.790118] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790139] [001.0] [pid=46364] check_time_against_period()
[1539678499.790154] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790169] [001.0] [pid=46364] check_time_against_period()
[1539678499.790183] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790197] [001.0] [pid=46364] check_time_against_period()
[1539678499.790210] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790222] [001.0] [pid=46364] check_time_against_period()
[1539678499.790235] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790309] [001.0] [pid=46364] check_time_against_period()
[1539678499.790328] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790345] [001.0] [pid=46364] check_time_against_period()
[1539678499.790362] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790379] [008.2] [pid=46364] Determining service scheduling parameters...
[1539678499.790385] [008.1] [pid=46364] Total scheduled service checks:  2
[1539678499.790390] [008.1] [pid=46364] Average service check interval:  210.00 sec
[1539678499.790398] [008.1] [pid=46364] Service inter-check delay:       105.00 sec
[1539678499.790406] [008.1] [pid=46364] Total scheduled service checks: 2
[1539678499.790411] [008.1] [pid=46364] Total hosts:                    5
[1539678499.790416] [008.1] [pid=46364] Service Interleave factor:      1
[1539678499.790425] [008.1] [pid=46364] Total scheduled services: 2
[1539678499.790430] [008.1] [pid=46364] Service Interleave factor: 1
[1539678499.790435] [008.1] [pid=46364] Total service interleave blocks: 2
[1539678499.790441] [008.1] [pid=46364] Service inter-check delay: 105.0
[1539678499.790447] [008.2] [pid=46364] Scheduling service checks...
[1539678499.790452] [008.2] [pid=46364] Current Interleave Block: 0
[1539678499.790459] [008.2] [pid=46364] Service 'Oracle - Check connection-time' on host 'another client test'
[1539678499.790474] [008.2] [pid=46364] CIB: 0, IBI: 1, TIB: 2, SIF: 1
[1539678499.790481] [008.2] [pid=46364] Mult factor: 2
[1539678499.790487] [008.0] [pid=46364]   Fixing check time 90 secs too far away
[1539678499.790494] [008.0] [pid=46364]   New check offset: 22
[1539678499.790520] [008.2] [pid=46364] Preferred Check Time: 1539678521 --> Tue Oct 16 04:28:41 2018

[1539678499.790527] [001.0] [pid=46364] check_time_against_period()
[1539678499.790547] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790575] [008.2] [pid=46364] Actual Check Time: 1539678521 --> Tue Oct 16 04:28:41 2018

[1539678499.790582] [008.2] [pid=46364] Current Interleave Block: 1
[1539678499.790587] [008.2] [pid=46364] Service 'PING' on host 'localhost'
[1539678499.790593] [008.2] [pid=46364] CIB: 1, IBI: 1, TIB: 2, SIF: 1
[1539678499.790598] [008.2] [pid=46364] Mult factor: 3
[1539678499.790604] [008.0] [pid=46364]   Fixing check time 15 secs too far away
[1539678499.790609] [008.0] [pid=46364]   New check offset: 177
[1539678499.790631] [008.2] [pid=46364] Preferred Check Time: 1539678676 --> Tue Oct 16 04:31:16 2018

[1539678499.790636] [001.0] [pid=46364] check_time_against_period()
[1539678499.790669] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790693] [008.2] [pid=46364] Actual Check Time: 1539678676 --> Tue Oct 16 04:31:16 2018

[1539678499.790698] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678499.790728] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678499.790735] [001.0] [pid=46364] schedule_new_event()
[1539678499.790741] [008.0] [pid=46364] New Event Details:
[1539678499.790745] [008.0] [pid=46364]  Type:                       EVENT_SERVICE_CHECK
[1539678499.790750] [008.0] [pid=46364]  High Priority:              No
[1539678499.790754] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:41
[1539678499.790757] [008.0] [pid=46364]  Recurring:                  No
[1539678499.790761] [008.0] [pid=46364]  Event Interval:             0
[1539678499.790765] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.790768] [008.0] [pid=46364]  Event Options:              0
[1539678499.790773] [008.0] [pid=46364]  Event ID:                   0x23998b0
[1539678499.790777] [001.0] [pid=46364] add_event()
[1539678499.790781] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678499.790807] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678499.790813] [001.0] [pid=46364] schedule_new_event()
[1539678499.790818] [008.0] [pid=46364] New Event Details:
[1539678499.790822] [008.0] [pid=46364]  Type:                       EVENT_SERVICE_CHECK
[1539678499.790825] [008.0] [pid=46364]  High Priority:              No
[1539678499.790829] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:31:16
[1539678499.790833] [008.0] [pid=46364]  Recurring:                  No
[1539678499.790836] [008.0] [pid=46364]  Event Interval:             0
[1539678499.790840] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.790844] [008.0] [pid=46364]  Event Options:              0
[1539678499.790848] [008.0] [pid=46364]  Event ID:                   0x2394e70
[1539678499.790852] [001.0] [pid=46364] add_event()
[1539678499.790856] [008.2] [pid=46364] Determining host scheduling parameters...
[1539678499.790860] [008.2] [pid=46364] Total scheduled host checks:  5
[1539678499.790863] [008.2] [pid=46364] Host check interval total:    1500
[1539678499.790867] [008.2] [pid=46364] Average host check interval:  300.00 sec
[1539678499.790872] [008.2] [pid=46364] Host inter-check delay:       60.00 sec
[1539678499.790876] [008.2] [pid=46364] Scheduling host checks...
[1539678499.790879] [008.2] [pid=46364] Host '[ANOTHER_CLIENT][WORKER][10.20.4.5]'
[1539678499.790898] [008.2] [pid=46364] Preferred Check Time: 1539678499 --> Tue Oct 16 04:28:19 2018
[1539678499.790903] [001.0] [pid=46364] check_time_against_period()
[1539678499.790916] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.790937] [008.2] [pid=46364] Actual Check Time: 1539678499 --> Tue Oct 16 04:28:19 2018

[1539678499.790947] [008.2] [pid=46364] Host '[NEW CLIENT][WORKER][10.20.4.5]'
[1539678499.790968] [008.2] [pid=46364] Preferred Check Time: 1539678559 --> Tue Oct 16 04:29:19 2018
[1539678499.790973] [001.0] [pid=46364] check_time_against_period()
[1539678499.790988] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.791012] [008.2] [pid=46364] Actual Check Time: 1539678559 --> Tue Oct 16 04:29:19 2018

[1539678499.791017] [008.2] [pid=46364] Host '[NEW CLIENT][WORKER][10.90.4.5]'
[1539678499.791032] [008.2] [pid=46364] Preferred Check Time: 1539678619 --> Tue Oct 16 04:30:19 2018
[1539678499.791036] [001.0] [pid=46364] check_time_against_period()
[1539678499.791050] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.791072] [008.2] [pid=46364] Actual Check Time: 1539678619 --> Tue Oct 16 04:30:19 2018

[1539678499.791077] [008.2] [pid=46364] Host 'another client test'
[1539678499.791092] [008.2] [pid=46364] Preferred Check Time: 1539678679 --> Tue Oct 16 04:31:19 2018
[1539678499.791096] [001.0] [pid=46364] check_time_against_period()
[1539678499.791106] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.791127] [008.2] [pid=46364] Actual Check Time: 1539678679 --> Tue Oct 16 04:31:19 2018

[1539678499.791131] [008.2] [pid=46364] Host 'localhost'
[1539678499.791145] [008.2] [pid=46364] Preferred Check Time: 1539678739 --> Tue Oct 16 04:32:19 2018
[1539678499.791150] [001.0] [pid=46364] check_time_against_period()
[1539678499.791165] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.791191] [008.2] [pid=46364] Actual Check Time: 1539678739 --> Tue Oct 16 04:32:19 2018

[1539678499.791196] [008.0] [pid=46364] Fixed scheduling for 0 hosts and 2 services
[1539678499.791201] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.791231] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.791250] [001.0] [pid=46364] schedule_new_event()
[1539678499.791302] [008.0] [pid=46364] New Event Details:
[1539678499.791308] [008.0] [pid=46364]  Type:                       EVENT_HOST_CHECK
[1539678499.791314] [008.0] [pid=46364]  High Priority:              No
[1539678499.791319] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:19
[1539678499.791324] [008.0] [pid=46364]  Recurring:                  No
[1539678499.791329] [008.0] [pid=46364]  Event Interval:             0
[1539678499.791335] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791340] [008.0] [pid=46364]  Event Options:              0
[1539678499.791345] [008.0] [pid=46364]  Event ID:                   0x2394fd0
[1539678499.791350] [001.0] [pid=46364] add_event()
[1539678499.791356] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.791395] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.791403] [001.0] [pid=46364] schedule_new_event()
[1539678499.791410] [008.0] [pid=46364] New Event Details:
[1539678499.791415] [008.0] [pid=46364]  Type:                       EVENT_HOST_CHECK
[1539678499.791420] [008.0] [pid=46364]  High Priority:              No
[1539678499.791425] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:29:19
[1539678499.791430] [008.0] [pid=46364]  Recurring:                  No
[1539678499.791436] [008.0] [pid=46364]  Event Interval:             0
[1539678499.791441] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791446] [008.0] [pid=46364]  Event Options:              0
[1539678499.791451] [008.0] [pid=46364]  Event ID:                   0x2395050
[1539678499.791457] [001.0] [pid=46364] add_event()
[1539678499.791464] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.791501] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.791509] [001.0] [pid=46364] schedule_new_event()
[1539678499.791516] [008.0] [pid=46364] New Event Details:
[1539678499.791521] [008.0] [pid=46364]  Type:                       EVENT_HOST_CHECK
[1539678499.791526] [008.0] [pid=46364]  High Priority:              No
[1539678499.791531] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:30:19
[1539678499.791546] [008.0] [pid=46364]  Recurring:                  No
[1539678499.791552] [008.0] [pid=46364]  Event Interval:             0
[1539678499.791558] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791563] [008.0] [pid=46364]  Event Options:              0
[1539678499.791569] [008.0] [pid=46364]  Event ID:                   0x2395150
[1539678499.791574] [001.0] [pid=46364] add_event()
[1539678499.791580] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.791632] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.791655] [001.0] [pid=46364] schedule_new_event()
[1539678499.791660] [008.0] [pid=46364] New Event Details:
[1539678499.791664] [008.0] [pid=46364]  Type:                       EVENT_HOST_CHECK
[1539678499.791667] [008.0] [pid=46364]  High Priority:              No
[1539678499.791671] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:31:19
[1539678499.791675] [008.0] [pid=46364]  Recurring:                  No
[1539678499.791679] [008.0] [pid=46364]  Event Interval:             0
[1539678499.791682] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791686] [008.0] [pid=46364]  Event Options:              0
[1539678499.791689] [008.0] [pid=46364]  Event ID:                   0x2396190
[1539678499.791693] [001.0] [pid=46364] add_event()
[1539678499.791697] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.791723] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.791728] [001.0] [pid=46364] schedule_new_event()
[1539678499.791733] [008.0] [pid=46364] New Event Details:
[1539678499.791737] [008.0] [pid=46364]  Type:                       EVENT_HOST_CHECK
[1539678499.791740] [008.0] [pid=46364]  High Priority:              No
[1539678499.791744] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:32:19
[1539678499.791748] [008.0] [pid=46364]  Recurring:                  No
[1539678499.791754] [008.0] [pid=46364]  Event Interval:             0
[1539678499.791757] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791761] [008.0] [pid=46364]  Event Options:              0
[1539678499.791765] [008.0] [pid=46364]  Event ID:                   0x2396d50
[1539678499.791770] [001.0] [pid=46364] add_event()
[1539678499.791776] [001.0] [pid=46364] schedule_new_event()
[1539678499.791782] [008.0] [pid=46364] New Event Details:
[1539678499.791786] [008.0] [pid=46364]  Type:                       EVENT_RESCHEDULE_CHECKS
[1539678499.791790] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.791795] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:49
[1539678499.791799] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.791803] [008.0] [pid=46364]  Event Interval:             30
[1539678499.791807] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791811] [008.0] [pid=46364]  Event Options:              0
[1539678499.791815] [008.0] [pid=46364]  Event ID:                   0x2396ed0
[1539678499.791819] [001.0] [pid=46364] add_event()
[1539678499.791823] [001.0] [pid=46364] schedule_new_event()
[1539678499.791828] [008.0] [pid=46364] New Event Details:
[1539678499.791832] [008.0] [pid=46364]  Type:                       EVENT_CHECK_REAPER
[1539678499.791835] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.791839] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:29
[1539678499.791843] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.791847] [008.0] [pid=46364]  Event Interval:             10
[1539678499.791851] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791855] [008.0] [pid=46364]  Event Options:              0
[1539678499.791859] [008.0] [pid=46364]  Event ID:                   0x23973c0
[1539678499.791862] [001.0] [pid=46364] add_event()
[1539678499.791867] [001.0] [pid=46364] schedule_new_event()
[1539678499.791872] [008.0] [pid=46364] New Event Details:
[1539678499.791875] [008.0] [pid=46364]  Type:                       EVENT_ORPHAN_CHECK
[1539678499.791885] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.791889] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:29:19
[1539678499.791893] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.791896] [008.0] [pid=46364]  Event Interval:             60
[1539678499.791902] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791906] [008.0] [pid=46364]  Event Options:              0
[1539678499.791910] [008.0] [pid=46364]  Event ID:                   0x23993e0
[1539678499.791914] [001.0] [pid=46364] add_event()
[1539678499.791918] [001.0] [pid=46364] schedule_new_event()
[1539678499.791922] [008.0] [pid=46364] New Event Details:
[1539678499.791925] [008.0] [pid=46364]  Type:                       EVENT_SFRESHNESS_CHECK
[1539678499.791929] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.791932] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:29:19
[1539678499.791936] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.791940] [008.0] [pid=46364]  Event Interval:             60
[1539678499.791943] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791947] [008.0] [pid=46364]  Event Options:              0
[1539678499.791951] [008.0] [pid=46364]  Event ID:                   0x2399ba0
[1539678499.791955] [001.0] [pid=46364] add_event()
[1539678499.791959] [001.0] [pid=46364] schedule_new_event()
[1539678499.791964] [008.0] [pid=46364] New Event Details:
[1539678499.791968] [008.0] [pid=46364]  Type:                       EVENT_STATUS_SAVE
[1539678499.791971] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.791975] [008.0] [pid=46364]  Run Time:                   10-16-2018 04:28:29
[1539678499.791979] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.791984] [008.0] [pid=46364]  Event Interval:             10
[1539678499.791989] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.791993] [008.0] [pid=46364]  Event Options:              0
[1539678499.791997] [008.0] [pid=46364]  Event ID:                   0x2398ed0
[1539678499.792001] [001.0] [pid=46364] add_event()
[1539678499.792024] [001.0] [pid=46364] schedule_new_event()
[1539678499.792030] [008.0] [pid=46364] New Event Details:
[1539678499.792034] [008.0] [pid=46364]  Type:                       EVENT_LOG_ROTATION
[1539678499.792038] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.792041] [008.0] [pid=46364]  Run Time:                   10-17-2018 00:00:00
[1539678499.792045] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.792049] [008.0] [pid=46364]  Event Interval:             0
[1539678499.792052] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.792056] [008.0] [pid=46364]  Event Options:              0
[1539678499.792060] [008.0] [pid=46364]  Event ID:                   0x239cb60
[1539678499.792064] [001.0] [pid=46364] add_event()
[1539678499.792068] [001.0] [pid=46364] schedule_new_event()
[1539678499.792073] [008.0] [pid=46364] New Event Details:
[1539678499.792076] [008.0] [pid=46364]  Type:                       EVENT_RETENTION_SAVE
[1539678499.792080] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.792084] [008.0] [pid=46364]  Run Time:                   10-16-2018 05:28:19
[1539678499.792088] [008.0] [pid=46364]  Recurring:                  Yes
[1539678499.792092] [008.0] [pid=46364]  Event Interval:             3600
[1539678499.792095] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.792098] [008.0] [pid=46364]  Event Options:              0
[1539678499.792102] [008.0] [pid=46364]  Event ID:                   0x2399550
[1539678499.792105] [001.0] [pid=46364] add_event()
[1539678499.792109] [001.0] [pid=46364] init_timing_loop() end
[1539678499.792118] [001.0] [pid=46364] schedule_new_event()
[1539678499.792123] [008.0] [pid=46364] New Event Details:
[1539678499.792126] [008.0] [pid=46364]  Type:                       EVENT_CHECK_PROGRAM_UPDATE
[1539678499.792130] [008.0] [pid=46364]  High Priority:              Yes
[1539678499.792138] [008.0] [pid=46364]  Run Time:                   10-16-2018 19:21:50
[1539678499.792143] [008.0] [pid=46364]  Recurring:                  No
[1539678499.792147] [008.0] [pid=46364]  Event Interval:             79200
[1539678499.792150] [008.0] [pid=46364]  Compensate for Time Change: Yes
[1539678499.792154] [008.0] [pid=46364]  Event Options:              0
[1539678499.792158] [008.0] [pid=46364]  Event ID:                   0x23af080
[1539678499.792162] [001.0] [pid=46364] add_event()
[1539678499.792166] [064.1] [pid=46364] Making callbacks (type 18)...
[1539678499.792178] [064.2] [pid=46364] Callback #1 (type 18) return code = 0
[1539678499.792185] [001.0] [pid=46364] save_status_data()
[1539678499.792190] [004.2] [pid=46364] Writing status data to temp file '/usr/local/nagios/var/nagios.tmpXXXXXX'
[1539678499.891844] [064.1] [pid=46364] Making callbacks (type 18)...
[1539678499.891868] [064.2] [pid=46364] Callback #1 (type 18) return code = 0
[1539678499.892109] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678499.892136] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678499.892142] [064.1] [pid=46364] Making callbacks (type 0)...
[1539678499.892230] [064.2] [pid=46364] Callback #1 (type 0) return code = 0
[1539678499.892300] [064.2] [pid=46364] Callback #2 (type 0) return code = 0
[1539678499.892323] [064.2] [pid=46364] Callback #3 (type 0) return code = 0
[1539678499.892390] [064.2] [pid=46364] Callback #4 (type 0) return code = 0
[1539678499.892412] [001.0] [pid=46364] event_execution_loop() start
[1539678499.892424] [064.1] [pid=46364] Making callbacks (type 11)...
[1539678499.892447] [064.2] [pid=46364] Callback #1 (type 11) return code = 0
[1539678499.892454] [008.1] [pid=46364] ** Event Check Loop
[1539678499.892485] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:19 2018
[1539678499.892492] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678499.892499] [12288.1] [pid=46364] ## Polling 0ms; sockets=6; events=17; iobs=0x22b4140
[1539678499.892507] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678499.892513] [001.0] [pid=46364] handle_timed_event() start
[1539678499.892518] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678499.892526] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678499.892532] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678499.892537] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678499.892558] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_HOST_CHECK, Run Time: Tue Oct 16 04:28:19 2018
[1539678499.892564] [008.0] [pid=46364] ** Host Check Event ==> Host: '[ANOTHER_CLIENT][WORKER][10.20.4.5]', Options: 0, Latency: 0.101209 sec
[1539678499.892575] [001.0] [pid=46364] run_scheduled_host_check()
[1539678499.892581] [016.0] [pid=46364] Attempting to run scheduled check of host '[ANOTHER_CLIENT][WORKER][10.20.4.5]': check options=0, latency=0.101209
[1539678499.892596] [001.0] [pid=46364] run_async_host_check([ANOTHER_CLIENT][WORKER][10.20.4.5] ...)
[1539678499.892601] [016.0] [pid=46364] ** Running async check of host '[ANOTHER_CLIENT][WORKER][10.20.4.5]'...
[1539678499.892607] [016.0] [pid=46364] Host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' passed first hurdle (caching/execution)
[1539678499.892612] [001.0] [pid=46364] check_host_check_viability()
[1539678499.892634] [001.0] [pid=46364] check_time_against_period()
[1539678499.892652] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.892670] [001.0] [pid=46364] check_host_dependencies()
[1539678499.892677] [064.1] [pid=46364] Making callbacks (type 7)...
[1539678499.892712] [064.2] [pid=46364] Callback #1 (type 7) return code = 0
[1539678499.892728] [064.2] [pid=46364] Callback #2 (type 7) return code = 0
[1539678499.892744] [064.2] [pid=46364] Callback #3 (type 7) return code = 0
[1539678499.892749] [016.0] [pid=46364] Checking host '[ANOTHER_CLIENT][WORKER][10.20.4.5]'...
[1539678499.892753] [001.0] [pid=46364] adjust_host_check_attempt()
[1539678499.892757] [016.2] [pid=46364] Adjusting check attempt number for host '[ANOTHER_CLIENT][WORKER][10.20.4.5]': current attempt=1/3, state=0, state type=1
[1539678499.892767] [016.2] [pid=46364] New check attempt number = 1
[1539678499.892777] [001.0] [pid=46364] get_raw_command_line_r()
[1539678499.892784] [2320.2] [pid=46364] Raw Command Input: $USER1$/check_ssh $ARG1$ $HOSTADDRESS$
[1539678499.892790] [001.0] [pid=46364] process_macros_r()
[1539678499.892794] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678499.892798] [2048.1] [pid=46364] Processing: '-p $_HOSTSSH_PORT$'
[1539678499.892802] [2048.2] [pid=46364]   Processing part: '-p '
[1539678499.892812] [2048.2] [pid=46364]   Not currently in macro.  Running output (3): '-p '
[1539678499.892817] [2048.2] [pid=46364]   Processing part: '_HOSTSSH_PORT'
[1539678499.892825] [2048.2] [pid=46364]   Processed '_HOSTSSH_PORT', Free: 0
[1539678499.892829] [2048.2] [pid=46364]   Processed '_HOSTSSH_PORT', Free: 0,  Cleaning options: 3
[1539678499.892834] [2048.2] [pid=46364]   Uncleaned macro.  Running output (5): '-p 22'
[1539678499.892838] [2048.2] [pid=46364]   Just finished macro.  Running output (5): '-p 22'
[1539678499.892842] [2048.2] [pid=46364]   Processing part: ''
[1539678499.892846] [2048.2] [pid=46364]   Not currently in macro.  Running output (5): '-p 22'
[1539678499.892850] [2048.1] [pid=46364]   Done.  Final output: '-p 22'
[1539678499.892854] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678499.892857] [2320.2] [pid=46364] Expanded Command Output: $USER1$/check_ssh $ARG1$ $HOSTADDRESS$
[1539678499.892862] [001.0] [pid=46364] process_macros_r()
[1539678499.892866] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678499.892871] [2048.1] [pid=46364] Processing: '$USER1$/check_ssh $ARG1$ $HOSTADDRESS$'
[1539678499.892876] [2048.2] [pid=46364]   Processing part: ''
[1539678499.892881] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678499.892885] [2048.2] [pid=46364]   Processing part: 'USER1'
[1539678499.892890] [2048.2] [pid=46364]   Processed 'USER1', Free: 0
[1539678499.892894] [2048.2] [pid=46364]   Processed 'USER1', Free: 0,  Cleaning options: 3
[1539678499.892899] [2048.2] [pid=46364]   Uncleaned macro.  Running output (25): '/usr/local/nagios/libexec'
[1539678499.892904] [2048.2] [pid=46364]   Just finished macro.  Running output (25): '/usr/local/nagios/libexec'
[1539678499.892908] [2048.2] [pid=46364]   Processing part: '/check_ssh '
[1539678499.892917] [2048.2] [pid=46364]   Not currently in macro.  Running output (36): '/usr/local/nagios/libexec/check_ssh '
[1539678499.892921] [2048.2] [pid=46364]   Processing part: 'ARG1'
[1539678499.892925] [2048.2] [pid=46364]   Processed 'ARG1', Free: 0
[1539678499.892929] [2048.2] [pid=46364]   Processed 'ARG1', Free: 0,  Cleaning options: 3
[1539678499.892933] [2048.2] [pid=46364]   Uncleaned macro.  Running output (41): '/usr/local/nagios/libexec/check_ssh -p 22'
[1539678499.892937] [2048.2] [pid=46364]   Just finished macro.  Running output (41): '/usr/local/nagios/libexec/check_ssh -p 22'
[1539678499.892941] [2048.2] [pid=46364]   Processing part: ' '
[1539678499.892945] [2048.2] [pid=46364]   Not currently in macro.  Running output (42): '/usr/local/nagios/libexec/check_ssh -p 22 '
[1539678499.892949] [2048.2] [pid=46364]   Processing part: 'HOSTADDRESS'
[1539678499.892953] [2048.2] [pid=46364]   Processed 'HOSTADDRESS', Free: 0
[1539678499.892957] [2048.2] [pid=46364]   Processed 'HOSTADDRESS', Free: 0,  Cleaning options: 3
[1539678499.892961] [2048.2] [pid=46364]   Uncleaned macro.  Running output (51): '/usr/local/nagios/libexec/check_ssh -p 22 10.20.4.5'
[1539678499.892965] [2048.2] [pid=46364]   Just finished macro.  Running output (51): '/usr/local/nagios/libexec/check_ssh -p 22 10.20.4.5'
[1539678499.892969] [2048.2] [pid=46364]   Processing part: ''
[1539678499.892973] [2048.2] [pid=46364]   Not currently in macro.  Running output (51): '/usr/local/nagios/libexec/check_ssh -p 22 10.20.4.5'
[1539678499.892977] [2048.1] [pid=46364]   Done.  Final output: '/usr/local/nagios/libexec/check_ssh -p 22 10.20.4.5'
[1539678499.892986] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678499.892992] [064.1] [pid=46364] Making callbacks (type 7)...
[1539678499.893008] [064.2] [pid=46364] Callback #1 (type 7) return code = 0
[1539678499.893020] [064.2] [pid=46364] Callback #2 (type 7) return code = 0
[1539678499.893033] [064.2] [pid=46364] Callback #3 (type 7) return code = 0
[1539678499.893056] [001.0] [pid=46364] macros_to_kvv()
[1539678499.893073] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678499.893079] [001.0] [pid=46364] handle_timed_event() end
[1539678499.893083] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678499.893087] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678499.893091] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678499.893095] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678499.893111] [008.1] [pid=46364] ** Event Check Loop
[1539678499.893133] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:29 2018
[1539678499.893138] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678499.893143] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=16; iobs=0x22b4140
[1539678499.893763] [001.0] [pid=46389] clear_volatile_macros_r()
[1539678499.906938] [016.2] [pid=46364] Processing check result for host '[ANOTHER_CLIENT][WORKER][10.20.4.5]'
[1539678499.906954] [001.0] [pid=46364] handle_async_host_check_result([ANOTHER_CLIENT][WORKER][10.20.4.5] ...)
[1539678499.906978] [016.1] [pid=46364] ** Handling async check result for host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' from 'Core Worker 46366'...
[1539678499.906983] [016.2] [pid=46364]         Check Type:         Active
[1539678499.906990] [016.2] [pid=46364]         Check Options:      0
[1539678499.906994] [016.2] [pid=46364]         Scheduled Check?:   Yes
[1539678499.906999] [016.2] [pid=46364]         Reschedule Check?:  Yes
[1539678499.907004] [016.2] [pid=46364]         Exited OK?:         Yes
[1539678499.907009] [016.2] [pid=46364]         Exec Time:          0.012
[1539678499.907023] [016.2] [pid=46364]         Latency:            0.344
[1539678499.907028] [016.2] [pid=46364]         Return Status:      0
[1539678499.907033] [016.2] [pid=46364]         Output:             SSH OK - OpenSSH_7.4 (protocol 2.0) | time=0.010249s;;;0.000000;10.000000

[1539678499.907048] [016.2] [pid=46364] Parsing check output...
[1539678499.907052] [016.2] [pid=46364] Short Output: SSH OK - OpenSSH_7.4 (protocol 2.0)
[1539678499.907057] [016.2] [pid=46364] Long Output:  NULL
[1539678499.907061] [016.2] [pid=46364] Perf Data:    time=0.010249s;;;0.000000;10.000000
[1539678499.907065] [001.0] [pid=46364] get_host_check_return_code()
[1539678499.907088] [001.0] [pid=46364] process_host_check_result()
[1539678499.907092] [016.1] [pid=46364] HOST: [ANOTHER_CLIENT][WORKER][10.20.4.5], ATTEMPT=1/3, CHECK TYPE=ACTIVE, STATE TYPE=HARD, OLD STATE=0, NEW STATE=0
[1539678499.907113] [016.1] [pid=46364] Host was UP.
[1539678499.907117] [016.1] [pid=46364] Host is still UP.
[1539678499.907121] [016.1] [pid=46364] Pre-handle_host_state() Host: [ANOTHER_CLIENT][WORKER][10.20.4.5], Attempt=1/3, Type=HARD, Final State=0 (UP)
[1539678499.907126] [001.0] [pid=46364] handle_host_state()
[1539678499.907149] [001.0] [pid=46364] obsessive_compulsive_host_check_processor()
[1539678499.907156] [001.0] [pid=46364] process_macros_r()
[1539678499.907165] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678499.907168] [2048.1] [pid=46364] Processing: '-p $_HOSTSSH_PORT$'
[1539678499.907173] [2048.2] [pid=46364]   Processing part: '-p '
[1539678499.907177] [2048.2] [pid=46364]   Not currently in macro.  Running output (3): '-p '
[1539678499.907181] [2048.2] [pid=46364]   Processing part: '_HOSTSSH_PORT'
[1539678499.907187] [2048.2] [pid=46364]   Processed '_HOSTSSH_PORT', Free: 0
[1539678499.907191] [2048.2] [pid=46364]   Processed '_HOSTSSH_PORT', Free: 0,  Cleaning options: 3
[1539678499.907195] [2048.2] [pid=46364]   Uncleaned macro.  Running output (5): '-p 22'
[1539678499.907199] [2048.2] [pid=46364]   Just finished macro.  Running output (5): '-p 22'
[1539678499.907208] [2048.2] [pid=46364]   Processing part: ''
[1539678499.907213] [2048.2] [pid=46364]   Not currently in macro.  Running output (5): '-p 22'
[1539678499.907217] [2048.1] [pid=46364]   Done.  Final output: '-p 22'
[1539678499.907221] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678499.907225] [001.0] [pid=46364] run_host_performance_data_command()
[1539678499.907229] [001.0] [pid=46364] update_host_performance_data_file()
[1539678499.907248] [016.2] [pid=46364] Raw host performance file output: DATATYPE::HOSTPERFDATA        TIMET::$TIMET$  HOSTNAME::$HOSTNAME$    HOSTPERFDATA::$HOSTPERFDATA$    HOSTCHECKCOMMAND::$HOSTCHECKCOMMAND$  HOSTSTATE::$HOSTSTATE$  HOSTSTATETYPE::$HOSTSTATETYPE$  HOSTOUTPUT::$HOSTOUTPUT$        LONGHOSTOUTPUT::$LONGHOSTOUTPUT$
[1539678499.907258] [001.0] [pid=46364] process_macros_r()
[1539678499.907278] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678499.907300] [2048.1] [pid=46364] Processing: 'DATATYPE::HOSTPERFDATA    TIMET::$TIMET$  HOSTNAME::$HOSTNAME$    HOSTPERFDATA::$HOSTPERFDATA$    HOSTCHECKCOMMAND::$HOSTCHECKCOMMAND$    HOSTSTATE::$HOSTSTATE$        HOSTSTATETYPE::$HOSTSTATETYPE$  HOSTOUTPUT::$HOSTOUTPUT$        LONGHOSTOUTPUT::$LONGHOSTOUTPUT$'
[1539678499.907306] [2048.2] [pid=46364]   Processing part: 'DATATYPE::HOSTPERFDATA     TIMET::'
[1539678499.907313] [2048.2] [pid=46364]   Not currently in macro.  Running output (30): 'DATATYPE::HOSTPERFDATA        TIMET::'
[1539678499.907318] [2048.2] [pid=46364]   Processing part: 'TIMET'
[1539678499.907374] [2048.2] [pid=46364]   macros[11] (TIMET) match.
[1539678499.907387] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0
[1539678499.907393] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0,  Cleaning options: 0
[1539678499.907399] [2048.2] [pid=46364]   Uncleaned macro.  Running output (40): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499'
[1539678499.907405] [2048.2] [pid=46364]   Just finished macro.  Running output (40): 'DATATYPE::HOSTPERFDATA   TIMET::1539678499'
[1539678499.907411] [2048.2] [pid=46364]   Processing part: '   HOSTNAME::'
[1539678499.907416] [2048.2] [pid=46364]   Not currently in macro.  Running output (51): 'DATATYPE::HOSTPERFDATA        TIMET::1539678499       HOSTNAME::'
[1539678499.907422] [2048.2] [pid=46364]   Processing part: 'HOSTNAME'
[1539678499.907428] [2048.2] [pid=46364]   macros[0] (HOSTNAME) match.
[1539678499.907435] [2048.2] [pid=46364]   Processed 'HOSTNAME', Free: 0
[1539678499.907441] [2048.2] [pid=46364]   Processed 'HOSTNAME', Free: 0,  Cleaning options: 0
[1539678499.907447] [2048.2] [pid=46364]   Uncleaned macro.  Running output (86): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]'
[1539678499.907453] [2048.2] [pid=46364]   Just finished macro.  Running output (86): 'DATATYPE::HOSTPERFDATA   TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]'
[1539678499.907458] [2048.2] [pid=46364]   Processing part: '   HOSTPERFDATA::'
[1539678499.907464] [2048.2] [pid=46364]   Not currently in macro.  Running output (101): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::'
[1539678499.907470] [2048.2] [pid=46364]   Processing part: 'HOSTPERFDATA'
[1539678499.907476] [2048.2] [pid=46364]   macros[18] (HOSTPERFDATA) match.
[1539678499.907482] [2048.2] [pid=46364]   Processed 'HOSTPERFDATA', Free: 0
[1539678499.907487] [2048.2] [pid=46364]   Processed 'HOSTPERFDATA', Free: 0,  Cleaning options: 0
[1539678499.907493] [2048.2] [pid=46364]   Uncleaned macro.  Running output (136): 'DATATYPE::HOSTPERFDATA      TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000'
[1539678499.907499] [2048.2] [pid=46364]   Just finished macro.  Running output (136): 'DATATYPE::HOSTPERFDATA  TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000'
[1539678499.907504] [2048.2] [pid=46364]   Processing part: '   HOSTCHECKCOMMAND::'
[1539678499.907510] [2048.2] [pid=46364]   Not currently in macro.  Running output (155): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::'
[1539678499.907526] [2048.2] [pid=46364]   Processing part: 'HOSTCHECKCOMMAND'
[1539678499.907533] [2048.2] [pid=46364]   macros[61] (HOSTCHECKCOMMAND) match.
[1539678499.907539] [2048.2] [pid=46364]   Processed 'HOSTCHECKCOMMAND', Free: 0
[1539678499.907545] [2048.2] [pid=46364]   Processed 'HOSTCHECKCOMMAND', Free: 0,  Cleaning options: 0
[1539678499.907554] [2048.2] [pid=46364]   Uncleaned macro.  Running output (183): 'DATATYPE::HOSTPERFDATA      TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$'
[1539678499.907560] [2048.2] [pid=46364]   Just finished macro.  Running output (183): 'DATATYPE::HOSTPERFDATA  TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$'
[1539678499.907566] [2048.2] [pid=46364]   Processing part: '   HOSTSTATE::'
[1539678499.907572] [2048.2] [pid=46364]   Not currently in macro.  Running output (195): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::'
[1539678499.907578] [2048.2] [pid=46364]   Processing part: 'HOSTSTATE'
[1539678499.907584] [2048.2] [pid=46364]   macros[26] (HOSTSTATE) match.
[1539678499.907590] [2048.2] [pid=46364]   Processed 'HOSTSTATE', Free: 0
[1539678499.907595] [2048.2] [pid=46364]   Processed 'HOSTSTATE', Free: 0,  Cleaning options: 0
[1539678499.907601] [2048.2] [pid=46364]   Uncleaned macro.  Running output (197): 'DATATYPE::HOSTPERFDATA      TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP'
[1539678499.907608] [2048.2] [pid=46364]   Just finished macro.  Running output (197): 'DATATYPE::HOSTPERFDATA  TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP'
[1539678499.907614] [2048.2] [pid=46364]   Processing part: '   HOSTSTATETYPE::'
[1539678499.907640] [2048.2] [pid=46364]   Not currently in macro.  Running output (213): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::'
[1539678499.907645] [2048.2] [pid=46364]   Processing part: 'HOSTSTATETYPE'
[1539678499.907651] [2048.2] [pid=46364]   macros[41] (HOSTSTATETYPE) match.
[1539678499.907672] [2048.2] [pid=46364]   Processed 'HOSTSTATETYPE', Free: 0
[1539678499.907677] [2048.2] [pid=46364]   Processed 'HOSTSTATETYPE', Free: 0,  Cleaning options: 0
[1539678499.907682] [2048.2] [pid=46364]   Uncleaned macro.  Running output (217): 'DATATYPE::HOSTPERFDATA      TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD'
[1539678499.907687] [2048.2] [pid=46364]   Just finished macro.  Running output (217): 'DATATYPE::HOSTPERFDATA  TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD'
[1539678499.907692] [2048.2] [pid=46364]   Processing part: '   HOSTOUTPUT::'
[1539678499.907697] [2048.2] [pid=46364]   Not currently in macro.  Running output (230): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::'
[1539678499.907702] [2048.2] [pid=46364]   Processing part: 'HOSTOUTPUT'
[1539678499.907712] [2048.2] [pid=46364]   macros[16] (HOSTOUTPUT) match.
[1539678499.907717] [2048.2] [pid=46364]   Processed 'HOSTOUTPUT', Free: 0
[1539678499.907722] [2048.2] [pid=46364]   Processed 'HOSTOUTPUT', Free: 0,  Cleaning options: 0
[1539678499.907728] [2048.2] [pid=46364]   Uncleaned macro.  Running output (265): 'DATATYPE::HOSTPERFDATA      TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0)'
[1539678499.907750] [2048.2] [pid=46364]   Just finished macro.  Running output (265): 'DATATYPE::HOSTPERFDATA  TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0)'
[1539678499.907755] [2048.2] [pid=46364]   Processing part: '   LONGHOSTOUTPUT::'
[1539678499.907760] [2048.2] [pid=46364]   Not currently in macro.  Running output (282): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0) LONGHOSTOUTPUT::'
[1539678499.907781] [2048.2] [pid=46364]   Processing part: 'LONGHOSTOUTPUT'
[1539678499.907786] [2048.2] [pid=46364]   macros[99] (LONGHOSTOUTPUT) match.
[1539678499.907790] [2048.2] [pid=46364]   Processed 'LONGHOSTOUTPUT', Free: 0
[1539678499.907795] [2048.2] [pid=46364]   Processing part: ''
[1539678499.907800] [2048.2] [pid=46364]   Not currently in macro.  Running output (282): 'DATATYPE::HOSTPERFDATA       TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0) LONGHOSTOUTPUT::'
[1539678499.907822] [2048.1] [pid=46364]   Done.  Final output: 'DATATYPE::HOSTPERFDATA TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0) LONGHOSTOUTPUT::'
[1539678499.907827] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678499.907831] [016.2] [pid=46364] Processed host performance data file output: DATATYPE::HOSTPERFDATA     TIMET::1539678499       HOSTNAME::[ANOTHER_CLIENT][WORKER][10.20.4.5]   HOSTPERFDATA::time=0.010249s;;;0.000000;10.000000     HOSTCHECKCOMMAND::check_ssh!-p $_HOSTSSH_PORT$  HOSTSTATE::UP   HOSTSTATETYPE::HARD     HOSTOUTPUT::SSH OK - OpenSSH_7.4 (protocol 2.0) LONGHOSTOUTPUT::
[1539678499.907853] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678499.907860] [016.1] [pid=46364] Post-handle_host_state() Host: [ANOTHER_CLIENT][WORKER][10.20.4.5], Attempt=1/3, Type=HARD, Final State=0 (UP)
[1539678499.907869] [001.0] [pid=46364] check_for_host_flapping()
[1539678499.907874] [016.1] [pid=46364] Checking host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' for flapping...
[1539678499.907879] [016.2] [pid=46364] LFT=5.00, HFT=20.00, CPC=9.87, PSC=9.87%
[1539678499.907906] [016.1] [pid=46364] Rescheduling next check of host at Tue Oct 16 04:33:19 2018
[1539678499.907929] [001.0] [pid=46364] get_next_valid_time()
[1539678499.907946] [001.0] [pid=46364] _get_matching_timerange()
[1539678499.907963] [001.0] [pid=46364] schedule_host_check()
[1539678499.907980] [016.0] [pid=46364] Scheduling a non-forced, active check of host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' @ Tue Oct 16 04:33:19 2018
[1539678499.907985] [016.2] [pid=46364] Scheduling new host check event.
[1539678499.907990] [001.0] [pid=46364] add_event()
[1539678499.907995] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.908058] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.908064] [064.1] [pid=46364] Making callbacks (type 12)...
[1539678499.908097] [064.2] [pid=46364] Callback #1 (type 12) return code = 0
[1539678499.908104] [016.1] [pid=46364] ** Async check result for host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' handled: new state=0
[1539678499.908110] [064.1] [pid=46364] Making callbacks (type 7)...
[1539678499.908130] [064.2] [pid=46364] Callback #1 (type 7) return code = 0
[1539678499.908144] [064.2] [pid=46364] Callback #2 (type 7) return code = 0
[1539678499.908158] [064.2] [pid=46364] Callback #3 (type 7) return code = 0
[1539678499.908164] [4096.2] [pid=46364] ## 1 descriptors had input
[1539678499.908169] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678501.411256] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678501.411277] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678502.912855] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678502.912874] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678504.414495] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678504.414519] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678505.310163] [256.2] [pid=46364] Read 101 bytes from command worker
[1539678505.310187] [256.1] [pid=46364] Read raw external command '[1539678505] SCHEDULE_FORCED_SVC_CHECK;another client test;Oracle - Check connection-time;1539678502'
[1539678505.310196] [001.0] [pid=46364] process_external_command1()
[1539678505.310200] [128.2] [pid=46364] Raw command entry: [1539678505] SCHEDULE_FORCED_SVC_CHECK;another client test;Oracle - Check connection-time;1539678502
[1539678505.310214] [064.1] [pid=46364] Making callbacks (type 17)...
[1539678505.310255] [064.2] [pid=46364] Callback #1 (type 17) return code = 0
[1539678505.310266] [001.0] [pid=46364] process_external_command2()
[1539678505.310270] [128.1] [pid=46364] External Command Type: 54
[1539678505.310274] [128.1] [pid=46364] Command Entry Time: 1539678505
[1539678505.310278] [128.1] [pid=46364] Command Arguments: another client test;Oracle - Check connection-time;1539678502
[1539678505.310289] [001.0] [pid=46364] schedule_service_check()
[1539678505.310434] [016.0] [pid=46364] Scheduling a forced, active check of service 'Oracle - Check connection-time' on host 'another client test' @ Tue Oct 16 04:28:22 2018
[1539678505.310461] [016.2] [pid=46364] Found another service check event for this service @ Tue Oct 16 04:28:41 2018
[1539678505.310467] [016.2] [pid=46364] New service check event is forced, so it will be used instead of the existing event.
[1539678505.310472] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678505.310477] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678505.310503] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678505.310509] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678505.310516] [016.2] [pid=46364] Scheduling new service check event.
[1539678505.310521] [001.0] [pid=46364] add_event()
[1539678505.310532] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678505.310591] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678505.310598] [064.1] [pid=46364] Making callbacks (type 17)...
[1539678505.310611] [064.2] [pid=46364] Callback #1 (type 17) return code = 0
[1539678505.310617] [4096.2] [pid=46364] ## 1 descriptors had input
[1539678505.310624] [064.1] [pid=46364] Making callbacks (type 11)...
[1539678505.310642] [064.2] [pid=46364] Callback #1 (type 11) return code = 0
[1539678505.310647] [008.1] [pid=46364] ** Event Check Loop
[1539678505.310672] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:22 2018
[1539678505.310678] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678505.310684] [12288.1] [pid=46364] ## Polling 0ms; sockets=6; events=17; iobs=0x22b4140
[1539678505.310691] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678505.310697] [001.0] [pid=46364] handle_timed_event() start
[1539678505.310702] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678505.310718] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678505.310723] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678505.310728] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678505.310764] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_SERVICE_CHECK, Run Time: Tue Oct 16 04:28:22 2018
[1539678505.310769] [008.0] [pid=46364] ** Service Check Event ==> Host: 'another client test', Service: 'Oracle - Check connection-time', Options: 1, Latency: 0.000241 sec
[1539678505.310774] [001.0] [pid=46364] run_scheduled_service_check() start
[1539678505.310778] [016.0] [pid=46364] Attempting to run scheduled check of service 'Oracle - Check connection-time' on host 'another client test': check options=1, latency=0.000241
[1539678505.310782] [001.0] [pid=46364] run_async_service_check()
[1539678505.310785] [001.0] [pid=46364] check_service_check_viability()
[1539678505.310789] [001.0] [pid=46364] check_service_parents()
[1539678505.310794] [064.1] [pid=46364] Making callbacks (type 6)...
[1539678505.310820] [064.2] [pid=46364] Callback #1 (type 6) return code = 0
[1539678505.310831] [064.2] [pid=46364] Callback #2 (type 6) return code = 0
[1539678505.310842] [064.2] [pid=46364] Callback #3 (type 6) return code = 0
[1539678505.310846] [016.0] [pid=46364] Checking service 'Oracle - Check connection-time' on host 'another client test'...
[1539678505.310853] [001.0] [pid=46364] get_raw_command_line_r()
[1539678505.310858] [2320.2] [pid=46364] Raw Command Input: $USER1$/check_dummy $ARG1$ $ARG2$
[1539678505.310862] [001.0] [pid=46364] process_macros_r()
[1539678505.310867] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310871] [2048.1] [pid=46364] Processing: '0'
[1539678505.310875] [2048.2] [pid=46364]   Processing part: '0'
[1539678505.310879] [2048.2] [pid=46364]   Not currently in macro.  Running output (1): '0'
[1539678505.310883] [2048.1] [pid=46364]   Done.  Final output: '0'
[1539678505.310886] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.310889] [001.0] [pid=46364] process_macros_r()
[1539678505.310893] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310896] [2048.1] [pid=46364] Processing: ''ALL OK''
[1539678505.310900] [2048.2] [pid=46364]   Processing part: ''ALL OK''
[1539678505.310903] [2048.2] [pid=46364]   Not currently in macro.  Running output (8): ''ALL OK''
[1539678505.310907] [2048.1] [pid=46364]   Done.  Final output: ''ALL OK''
[1539678505.310910] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.310913] [001.0] [pid=46364] process_macros_r()
[1539678505.310916] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310920] [2048.1] [pid=46364] Processing: ''
[1539678505.310923] [2048.2] [pid=46364]   Processing part: ''
[1539678505.310927] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.310930] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.310933] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.310937] [001.0] [pid=46364] process_macros_r()
[1539678505.310940] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310943] [2048.1] [pid=46364] Processing: ''
[1539678505.310946] [2048.2] [pid=46364]   Processing part: ''
[1539678505.310950] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.310953] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.310957] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.310960] [001.0] [pid=46364] process_macros_r()
[1539678505.310964] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310967] [2048.1] [pid=46364] Processing: ''
[1539678505.310972] [2048.2] [pid=46364]   Processing part: ''
[1539678505.310975] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.310979] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.310982] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.310990] [001.0] [pid=46364] process_macros_r()
[1539678505.310994] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.310997] [2048.1] [pid=46364] Processing: ''
[1539678505.311001] [2048.2] [pid=46364]   Processing part: ''
[1539678505.311004] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.311008] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.311011] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.311014] [001.0] [pid=46364] process_macros_r()
[1539678505.311018] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.311021] [2048.1] [pid=46364] Processing: ''
[1539678505.311025] [2048.2] [pid=46364]   Processing part: ''
[1539678505.311028] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.311032] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.311035] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.311038] [001.0] [pid=46364] process_macros_r()
[1539678505.311041] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.311044] [2048.1] [pid=46364] Processing: ''
[1539678505.311048] [2048.2] [pid=46364]   Processing part: ''
[1539678505.311052] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.311055] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.311058] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.311062] [2320.2] [pid=46364] Expanded Command Output: $USER1$/check_dummy $ARG1$ $ARG2$
[1539678505.311065] [001.0] [pid=46364] process_macros_r()
[1539678505.311069] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.311072] [2048.1] [pid=46364] Processing: '$USER1$/check_dummy $ARG1$ $ARG2$'
[1539678505.311076] [2048.2] [pid=46364]   Processing part: ''
[1539678505.311080] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.311083] [2048.2] [pid=46364]   Processing part: 'USER1'
[1539678505.311087] [2048.2] [pid=46364]   Processed 'USER1', Free: 0
[1539678505.311091] [2048.2] [pid=46364]   Processed 'USER1', Free: 0,  Cleaning options: 3
[1539678505.311095] [2048.2] [pid=46364]   Uncleaned macro.  Running output (25): '/usr/local/nagios/libexec'
[1539678505.311099] [2048.2] [pid=46364]   Just finished macro.  Running output (25): '/usr/local/nagios/libexec'
[1539678505.311103] [2048.2] [pid=46364]   Processing part: '/check_dummy '
[1539678505.311106] [2048.2] [pid=46364]   Not currently in macro.  Running output (38): '/usr/local/nagios/libexec/check_dummy '
[1539678505.311110] [2048.2] [pid=46364]   Processing part: 'ARG1'
[1539678505.311113] [2048.2] [pid=46364]   Processed 'ARG1', Free: 0
[1539678505.311116] [2048.2] [pid=46364]   Processed 'ARG1', Free: 0,  Cleaning options: 3
[1539678505.311120] [2048.2] [pid=46364]   Uncleaned macro.  Running output (39): '/usr/local/nagios/libexec/check_dummy 0'
[1539678505.311124] [2048.2] [pid=46364]   Just finished macro.  Running output (39): '/usr/local/nagios/libexec/check_dummy 0'
[1539678505.311127] [2048.2] [pid=46364]   Processing part: ' '
[1539678505.311131] [2048.2] [pid=46364]   Not currently in macro.  Running output (40): '/usr/local/nagios/libexec/check_dummy 0 '
[1539678505.311134] [2048.2] [pid=46364]   Processing part: 'ARG2'
[1539678505.311138] [2048.2] [pid=46364]   Processed 'ARG2', Free: 0
[1539678505.311141] [2048.2] [pid=46364]   Processed 'ARG2', Free: 0,  Cleaning options: 3
[1539678505.311145] [2048.2] [pid=46364]   Uncleaned macro.  Running output (48): '/usr/local/nagios/libexec/check_dummy 0 'ALL OK''
[1539678505.311149] [2048.2] [pid=46364]   Just finished macro.  Running output (48): '/usr/local/nagios/libexec/check_dummy 0 'ALL OK''
[1539678505.311152] [2048.2] [pid=46364]   Processing part: ''
[1539678505.311155] [2048.2] [pid=46364]   Not currently in macro.  Running output (48): '/usr/local/nagios/libexec/check_dummy 0 'ALL OK''
[1539678505.311159] [2048.1] [pid=46364]   Done.  Final output: '/usr/local/nagios/libexec/check_dummy 0 'ALL OK''
[1539678505.311169] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.311176] [064.1] [pid=46364] Making callbacks (type 6)...
[1539678505.311185] [064.2] [pid=46364] Callback #1 (type 6) return code = 0
[1539678505.311193] [064.2] [pid=46364] Callback #2 (type 6) return code = 0
[1539678505.311199] [064.2] [pid=46364] Callback #3 (type 6) return code = 0
[1539678505.311213] [001.0] [pid=46364] macros_to_kvv()
[1539678505.311227] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678505.311232] [001.0] [pid=46364] handle_timed_event() end
[1539678505.311236] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678505.311254] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678505.311258] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678505.311261] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678505.311266] [008.1] [pid=46364] ** Event Check Loop
[1539678505.311286] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:29 2018
[1539678505.311290] [008.1] [pid=46364] Current/Max Service Checks: 1/0 (inf% saturation)
[1539678505.311294] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=16; iobs=0x22b4140
[1539678505.313884] [016.2] [pid=46364] Processing check result for service 'Oracle - Check connection-time' on host 'another client test'
[1539678505.313898] [001.0] [pid=46364] handle_async_service_check_result()
[1539678505.313908] [016.0] [pid=46364] ** Handling check result for service 'Oracle - Check connection-time' on host 'another client test' from 'Core Worker 46367'...
[1539678505.313911] [016.1] [pid=46364] HOST: another client test, SERVICE: Oracle - Check connection-time, CHECK TYPE: Active, OPTIONS: 1, SCHEDULED: Yes, RESCHEDULE: Yes, EXITED OK: Yes, RETURN CODE: 0, OUTPUT: OK: ALL OK

[1539678505.313916] [001.0] [pid=46364] get_service_check_return_code()
[1539678505.313919] [016.2] [pid=46364] Parsing check output...
[1539678505.313922] [016.2] [pid=46364] Short Output: OK: ALL OK
[1539678505.313924] [016.2] [pid=46364] Long Output:  NULL
[1539678505.313927] [016.2] [pid=46364] Perf Data:    NULL
[1539678505.313930] [016.2] [pid=46364] ST: HARD  CA: 1  MA: 5  CS: 0  LS: 0  LHS: 0
[1539678505.313934] [016.1] [pid=46364] Service is OK.
[1539678505.313936] [016.1] [pid=46364] Service did not change state.
[1539678505.313956] [016.1] [pid=46364] Rescheduling next check of service at Tue Oct 16 04:30:25 2018
[1539678505.313960] [001.0] [pid=46364] get_next_valid_time()
[1539678505.313970] [001.0] [pid=46364] _get_matching_timerange()
[1539678505.313979] [001.0] [pid=46364] schedule_service_check()
[1539678505.313988] [016.0] [pid=46364] Scheduling a non-forced, active check of service 'Oracle - Check connection-time' on host 'another client test' @ Tue Oct 16 04:30:25 2018
[1539678505.313992] [016.2] [pid=46364] Scheduling new service check event.
[1539678505.313995] [001.0] [pid=46364] add_event()
[1539678505.313998] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678505.314029] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678505.314036] [064.1] [pid=46364] Making callbacks (type 6)...
[1539678505.314051] [064.2] [pid=46364] Callback #1 (type 6) return code = 0
[1539678505.314060] [064.2] [pid=46364] Callback #2 (type 6) return code = 0
[1539678505.314069] [064.2] [pid=46364] Callback #3 (type 6) return code = 0
[1539678505.314075] [064.1] [pid=46364] Making callbacks (type 13)...
[1539678505.314105] [064.2] [pid=46364] Callback #1 (type 13) return code = 0
[1539678505.314111] [001.0] [pid=46364] check_for_service_flapping()
[1539678505.314116] [016.1] [pid=46364] Checking service 'Oracle - Check connection-time' on host 'another client test' for flapping...
[1539678505.314121] [016.2] [pid=46364] LFT=5.00, HFT=20.00, CPC=0.00, PSC=0.00%
[1539678505.314128] [016.1] [pid=46364] Service is not flapping (0.00% state change).
[1539678505.314133] [001.0] [pid=46364] check_for_host_flapping()
[1539678505.314138] [016.1] [pid=46364] Checking host 'another client test' for flapping...
[1539678505.314150] [016.2] [pid=46364] LFT=5.00, HFT=20.00, CPC=0.00, PSC=0.00%
[1539678505.314157] [016.1] [pid=46364] Host is not flapping (0.00% state change).
[1539678505.314164] [001.0] [pid=46364] process_macros_r()
[1539678505.314185] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314190] [2048.1] [pid=46364] Processing: '0'
[1539678505.314194] [2048.2] [pid=46364]   Processing part: '0'
[1539678505.314200] [2048.2] [pid=46364]   Not currently in macro.  Running output (1): '0'
[1539678505.314204] [2048.1] [pid=46364]   Done.  Final output: '0'
[1539678505.314209] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314213] [001.0] [pid=46364] process_macros_r()
[1539678505.314217] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314221] [2048.1] [pid=46364] Processing: ''ALL OK''
[1539678505.314226] [2048.2] [pid=46364]   Processing part: ''ALL OK''
[1539678505.314231] [2048.2] [pid=46364]   Not currently in macro.  Running output (8): ''ALL OK''
[1539678505.314235] [2048.1] [pid=46364]   Done.  Final output: ''ALL OK''
[1539678505.314255] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314260] [001.0] [pid=46364] process_macros_r()
[1539678505.314264] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314268] [2048.1] [pid=46364] Processing: ''
[1539678505.314271] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314275] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314279] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314283] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314286] [001.0] [pid=46364] process_macros_r()
[1539678505.314290] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314294] [2048.1] [pid=46364] Processing: ''
[1539678505.314298] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314303] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314307] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314311] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314314] [001.0] [pid=46364] process_macros_r()
[1539678505.314318] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314321] [2048.1] [pid=46364] Processing: ''
[1539678505.314325] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314329] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314333] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314336] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314340] [001.0] [pid=46364] process_macros_r()
[1539678505.314344] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314347] [2048.1] [pid=46364] Processing: ''
[1539678505.314351] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314355] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314430] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314437] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314442] [001.0] [pid=46364] process_macros_r()
[1539678505.314447] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314452] [2048.1] [pid=46364] Processing: ''
[1539678505.314457] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314463] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314468] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314473] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314478] [001.0] [pid=46364] process_macros_r()
[1539678505.314483] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314488] [2048.1] [pid=46364] Processing: ''
[1539678505.314493] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314498] [2048.2] [pid=46364]   Not currently in macro.  Running output (0): ''
[1539678505.314504] [2048.1] [pid=46364]   Done.  Final output: ''
[1539678505.314514] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314520] [001.0] [pid=46364] run_service_performance_data_command()
[1539678505.314526] [001.0] [pid=46364] update_service_performance_data_file()
[1539678505.314532] [016.2] [pid=46364] Raw service performance data file output: DATATYPE::SERVICEPERFDATA     TIMET::$TIMET$  HOSTNAME::$HOSTNAME$    SERVICEDESC::$SERVICEDESC$      SERVICEPERFDATA::$SERVICEPERFDATA$    SERVICECHECKCOMMAND::$SERVICECHECKCOMMAND$      HOSTSTATE::$HOSTSTATE$  HOSTSTATETYPE::$HOSTSTATETYPE$  SERVICESTATE::$SERVICESTATE$    SERVICESTATETYPE::$SERVICESTATETYPE$    SERVICEOUTPUT::$SERVICEOUTPUT$        LONGSERVICEOUTPUT::$LONGSERVICEOUTPUT$
[1539678505.314538] [001.0] [pid=46364] process_macros_r()
[1539678505.314543] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678505.314548] [2048.1] [pid=46364] Processing: 'DATATYPE::SERVICEPERFDATA TIMET::$TIMET$  HOSTNAME::$HOSTNAME$    SERVICEDESC::$SERVICEDESC$      SERVICEPERFDATA::$SERVICEPERFDATA$      SERVICECHECKCOMMAND::$SERVICECHECKCOMMAND$    HOSTSTATE::$HOSTSTATE$  HOSTSTATETYPE::$HOSTSTATETYPE$  SERVICESTATE::$SERVICESTATE$    SERVICESTATETYPE::$SERVICESTATETYPE$    SERVICEOUTPUT::$SERVICEOUTPUT$  LONGSERVICEOUTPUT::$LONGSERVICEOUTPUT$'
[1539678505.314554] [2048.2] [pid=46364]   Processing part: 'DATATYPE::SERVICEPERFDATA  TIMET::'
[1539678505.314560] [2048.2] [pid=46364]   Not currently in macro.  Running output (33): 'DATATYPE::SERVICEPERFDATA     TIMET::'
[1539678505.314566] [2048.2] [pid=46364]   Processing part: 'TIMET'
[1539678505.314573] [2048.2] [pid=46364]   macros[11] (TIMET) match.
[1539678505.314580] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0
[1539678505.314585] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0,  Cleaning options: 0
[1539678505.314591] [2048.2] [pid=46364]   Uncleaned macro.  Running output (43): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505'
[1539678505.314596] [2048.2] [pid=46364]   Just finished macro.  Running output (43): 'DATATYPE::SERVICEPERFDATA        TIMET::1539678505'
[1539678505.314602] [2048.2] [pid=46364]   Processing part: '   HOSTNAME::'
[1539678505.314607] [2048.2] [pid=46364]   Not currently in macro.  Running output (54): 'DATATYPE::SERVICEPERFDATA     TIMET::1539678505       HOSTNAME::'
[1539678505.314613] [2048.2] [pid=46364]   Processing part: 'HOSTNAME'
[1539678505.314619] [2048.2] [pid=46364]   macros[0] (HOSTNAME) match.
[1539678505.314626] [2048.2] [pid=46364]   Processed 'HOSTNAME', Free: 0
[1539678505.314632] [2048.2] [pid=46364]   Processed 'HOSTNAME', Free: 0,  Cleaning options: 0
[1539678505.314639] [2048.2] [pid=46364]   Uncleaned macro.  Running output (73): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test'
[1539678505.314644] [2048.2] [pid=46364]   Just finished macro.  Running output (73): 'DATATYPE::SERVICEPERFDATA        TIMET::1539678505       HOSTNAME::another client test'
[1539678505.314650] [2048.2] [pid=46364]   Processing part: '   SERVICEDESC::'
[1539678505.314656] [2048.2] [pid=46364]   Not currently in macro.  Running output (87): 'DATATYPE::SERVICEPERFDATA     TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::'
[1539678505.314662] [2048.2] [pid=46364]   Processing part: 'SERVICEDESC'
[1539678505.314668] [2048.2] [pid=46364]   macros[3] (SERVICEDESC) match.
[1539678505.314674] [2048.2] [pid=46364]   Processed 'SERVICEDESC', Free: 0
[1539678505.314680] [2048.2] [pid=46364]   Processed 'SERVICEDESC', Free: 0,  Cleaning options: 0
[1539678505.314686] [2048.2] [pid=46364]   Uncleaned macro.  Running output (117): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time'
[1539678505.314693] [2048.2] [pid=46364]   Just finished macro.  Running output (117): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time'
[1539678505.314698] [2048.2] [pid=46364]   Processing part: '   SERVICEPERFDATA::'
[1539678505.314705] [2048.2] [pid=46364]   Not currently in macro.  Running output (135): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::'
[1539678505.314715] [2048.2] [pid=46364]   Processing part: 'SERVICEPERFDATA'
[1539678505.314723] [2048.2] [pid=46364]   macros[19] (SERVICEPERFDATA) match.
[1539678505.314729] [2048.2] [pid=46364]   Processed 'SERVICEPERFDATA', Free: 0
[1539678505.314750] [2048.2] [pid=46364]   Processing part: '   SERVICECHECKCOMMAND::'
[1539678505.314755] [2048.2] [pid=46364]   Not currently in macro.  Running output (157): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::'
[1539678505.314759] [2048.2] [pid=46364]   Processing part: 'SERVICECHECKCOMMAND'
[1539678505.314765] [2048.2] [pid=46364]   macros[60] (SERVICECHECKCOMMAND) match.
[1539678505.314771] [2048.2] [pid=46364]   Processed 'SERVICECHECKCOMMAND', Free: 0
[1539678505.314776] [2048.2] [pid=46364]   Processed 'SERVICECHECKCOMMAND', Free: 0,  Cleaning options: 0
[1539678505.314780] [2048.2] [pid=46364]   Uncleaned macro.  Running output (185): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!'
[1539678505.314784] [2048.2] [pid=46364]   Just finished macro.  Running output (185): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!'
[1539678505.314794] [2048.2] [pid=46364]   Processing part: '   HOSTSTATE::'
[1539678505.314797] [2048.2] [pid=46364]   Not currently in macro.  Running output (197): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::'
[1539678505.314800] [2048.2] [pid=46364]   Processing part: 'HOSTSTATE'
[1539678505.314804] [2048.2] [pid=46364]   macros[26] (HOSTSTATE) match.
[1539678505.314807] [2048.2] [pid=46364]   Processed 'HOSTSTATE', Free: 0
[1539678505.314810] [2048.2] [pid=46364]   Processed 'HOSTSTATE', Free: 0,  Cleaning options: 0
[1539678505.314813] [2048.2] [pid=46364]   Uncleaned macro.  Running output (199): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP'
[1539678505.314816] [2048.2] [pid=46364]   Just finished macro.  Running output (199): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP'
[1539678505.314819] [2048.2] [pid=46364]   Processing part: '   HOSTSTATETYPE::'
[1539678505.314822] [2048.2] [pid=46364]   Not currently in macro.  Running output (215): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::'
[1539678505.314825] [2048.2] [pid=46364]   Processing part: 'HOSTSTATETYPE'
[1539678505.314828] [2048.2] [pid=46364]   macros[41] (HOSTSTATETYPE) match.
[1539678505.314831] [2048.2] [pid=46364]   Processed 'HOSTSTATETYPE', Free: 0
[1539678505.314834] [2048.2] [pid=46364]   Processed 'HOSTSTATETYPE', Free: 0,  Cleaning options: 0
[1539678505.314837] [2048.2] [pid=46364]   Uncleaned macro.  Running output (219): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD'
[1539678505.314840] [2048.2] [pid=46364]   Just finished macro.  Running output (219): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD'
[1539678505.314844] [2048.2] [pid=46364]   Processing part: '   SERVICESTATE::'
[1539678505.314848] [2048.2] [pid=46364]   Not currently in macro.  Running output (234): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::'
[1539678505.314851] [2048.2] [pid=46364]   Processing part: 'SERVICESTATE'
[1539678505.314854] [2048.2] [pid=46364]   macros[4] (SERVICESTATE) match.
[1539678505.314857] [2048.2] [pid=46364]   Processed 'SERVICESTATE', Free: 0
[1539678505.314860] [2048.2] [pid=46364]   Processed 'SERVICESTATE', Free: 0,  Cleaning options: 0
[1539678505.314863] [2048.2] [pid=46364]   Uncleaned macro.  Running output (236): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK'
[1539678505.314866] [2048.2] [pid=46364]   Just finished macro.  Running output (236): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK'
[1539678505.314869] [2048.2] [pid=46364]   Processing part: '   SERVICESTATETYPE::'
[1539678505.314872] [2048.2] [pid=46364]   Not currently in macro.  Running output (255): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::'
[1539678505.314875] [2048.2] [pid=46364]   Processing part: 'SERVICESTATETYPE'
[1539678505.314878] [2048.2] [pid=46364]   macros[42] (SERVICESTATETYPE) match.
[1539678505.314881] [2048.2] [pid=46364]   Processed 'SERVICESTATETYPE', Free: 0
[1539678505.314883] [2048.2] [pid=46364]   Processed 'SERVICESTATETYPE', Free: 0,  Cleaning options: 0
[1539678505.314886] [2048.2] [pid=46364]   Uncleaned macro.  Running output (259): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD'
[1539678505.314889] [2048.2] [pid=46364]   Just finished macro.  Running output (259): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD'
[1539678505.314892] [2048.2] [pid=46364]   Processing part: '   SERVICEOUTPUT::'
[1539678505.314896] [2048.2] [pid=46364]   Not currently in macro.  Running output (275): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::'
[1539678505.314899] [2048.2] [pid=46364]   Processing part: 'SERVICEOUTPUT'
[1539678505.314902] [2048.2] [pid=46364]   macros[17] (SERVICEOUTPUT) match.
[1539678505.314904] [2048.2] [pid=46364]   Processed 'SERVICEOUTPUT', Free: 0
[1539678505.314907] [2048.2] [pid=46364]   Processed 'SERVICEOUTPUT', Free: 0,  Cleaning options: 0
[1539678505.314910] [2048.2] [pid=46364]   Uncleaned macro.  Running output (285): 'DATATYPE::SERVICEPERFDATA   TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK'
[1539678505.314913] [2048.2] [pid=46364]   Just finished macro.  Running output (285): 'DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK'
[1539678505.314917] [2048.2] [pid=46364]   Processing part: '   LONGSERVICEOUTPUT::'
[1539678505.314921] [2048.2] [pid=46364]   Not currently in macro.  Running output (305): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK     LONGSERVICEOUTPUT::'
[1539678505.314924] [2048.2] [pid=46364]   Processing part: 'LONGSERVICEOUTPUT'
[1539678505.314927] [2048.2] [pid=46364]   macros[100] (LONGSERVICEOUTPUT) match.
[1539678505.314930] [2048.2] [pid=46364]   Processed 'LONGSERVICEOUTPUT', Free: 0
[1539678505.314933] [2048.2] [pid=46364]   Processing part: ''
[1539678505.314936] [2048.2] [pid=46364]   Not currently in macro.  Running output (305): 'DATATYPE::SERVICEPERFDATA    TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK     LONGSERVICEOUTPUT::'
[1539678505.314939] [2048.1] [pid=46364]   Done.  Final output: 'DATATYPE::SERVICEPERFDATA      TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time     SERVICEPERFDATA::     SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK       LONGSERVICEOUTPUT::'
[1539678505.314942] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678505.314945] [016.2] [pid=46364] Processed service performance data file output: DATATYPE::SERVICEPERFDATA       TIMET::1539678505       HOSTNAME::another client test   SERVICEDESC::Oracle - Check connection-time   SERVICEPERFDATA::       SERVICECHECKCOMMAND::check_dummy!0!'ALL OK'!!!!!!       HOSTSTATE::UP   HOSTSTATETYPE::HARD     SERVICESTATE::OK        SERVICESTATETYPE::HARD  SERVICEOUTPUT::OK: ALL OK     LONGSERVICEOUTPUT::
[1539678505.314964] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678505.314969] [4096.2] [pid=46364] ## 1 descriptors had input
[1539678505.314972] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678506.816523] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678506.816547] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678508.318099] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678508.318136] [12288.1] [pid=46364] ## Polling 656ms; sockets=6; events=17; iobs=0x22b4140
[1539678508.974945] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678508.974991] [001.0] [pid=46364] handle_timed_event() start
[1539678508.975002] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678508.975053] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678508.975073] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678508.975090] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678508.975157] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_CHECK_REAPER, Run Time: Tue Oct 16 04:28:29 2018
[1539678508.975167] [008.0] [pid=46364] ** Check Result Reaper. Latency: 0.000s
[1539678508.975181] [001.0] [pid=46364] reap_check_results() start
[1539678508.975189] [016.0] [pid=46364] Starting to reap check results.
[1539678508.975268] [016.1] [pid=46364] Starting to read check result queue '/var/nagiosramdisk/spool/checkresults'...
[1539678508.975283] [016.0] [pid=46364] Finished reaping 0 check results
[1539678508.975287] [001.0] [pid=46364] reap_check_results() end
[1539678508.975291] [001.0] [pid=46364] handle_timed_event() end
[1539678508.975295] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678508.975311] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678508.975322] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678508.975330] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678508.975335] [001.0] [pid=46364] reschedule_event()
[1539678508.975339] [001.0] [pid=46364] add_event()
[1539678508.975344] [008.1] [pid=46364] ** Event Check Loop
[1539678508.975365] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:29 2018
[1539678508.975369] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678508.975374] [12288.1] [pid=46364] ## Polling 0ms; sockets=6; events=17; iobs=0x22b4140
[1539678508.975380] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678508.975384] [001.0] [pid=46364] handle_timed_event() start
[1539678508.975388] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678508.975392] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678508.975395] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678508.975399] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678508.975412] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_STATUS_SAVE, Run Time: Tue Oct 16 04:28:29 2018
[1539678508.975416] [008.0] [pid=46364] ** Status Data Save Event. Latency: 0.000s
[1539678508.975421] [064.1] [pid=46364] Making callbacks (type 18)...
[1539678508.975454] [064.2] [pid=46364] Callback #1 (type 18) return code = 0
[1539678508.975462] [001.0] [pid=46364] save_status_data()
[1539678508.975469] [004.2] [pid=46364] Writing status data to temp file '/usr/local/nagios/var/nagios.tmpXXXXXX'
[1539678508.996505] [064.1] [pid=46364] Making callbacks (type 18)...
[1539678508.996533] [064.2] [pid=46364] Callback #1 (type 18) return code = 0
[1539678508.996539] [001.0] [pid=46364] handle_timed_event() end
[1539678508.996543] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678508.996547] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678508.996552] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678508.996557] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678508.996562] [001.0] [pid=46364] reschedule_event()
[1539678508.996566] [001.0] [pid=46364] add_event()
[1539678508.996572] [008.1] [pid=46364] ** Event Check Loop
[1539678508.996595] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:34 2018
[1539678508.996601] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678508.996607] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678510.498264] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678510.498300] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678511.999856] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678511.999896] [064.1] [pid=46364] Making callbacks (type 11)...
[1539678511.999935] [064.2] [pid=46364] Callback #1 (type 11) return code = 0
[1539678511.999944] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678513.501256] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678513.501279] [12288.1] [pid=46364] ## Polling 473ms; sockets=6; events=17; iobs=0x22b4140
[1539678513.974792] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678513.974818] [001.0] [pid=46364] handle_timed_event() start
[1539678513.974823] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678513.974828] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678513.974832] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678513.974836] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678513.974878] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_USER_FUNCTION, Run Time: Tue Oct 16 04:28:34 2018
[1539678513.974883] [008.0] [pid=46364] ** User Function Event. Latency: 0.000s
[1539678513.974892] [001.0] [pid=46364] process_host_perfdata_file()
[1539678513.974898] [001.0] [pid=46364] get_raw_command_line_r()
[1539678513.974903] [2320.2] [pid=46364] Raw Command Input: /bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.host
[1539678513.974914] [2320.2] [pid=46364] Expanded Command Output: /bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.host
[1539678513.974918] [016.2] [pid=46364] Raw host performance data file processing command line: /bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.host
[1539678513.974923] [001.0] [pid=46364] process_macros_r()
[1539678513.974927] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678513.974930] [2048.1] [pid=46364] Processing: '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.host'
[1539678513.974935] [2048.2] [pid=46364]   Processing part: '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/'
[1539678513.974940] [2048.2] [pid=46364]   Not currently in macro.  Running output (72): '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/'
[1539678513.974944] [2048.2] [pid=46364]   Processing part: 'TIMET'
[1539678513.974949] [2048.2] [pid=46364]   macros[11] (TIMET) match.
[1539678513.974955] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0
[1539678513.974958] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0,  Cleaning options: 3
[1539678513.974963] [2048.2] [pid=46364]   Uncleaned macro.  Running output (82): '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513'
[1539678513.974967] [2048.2] [pid=46364]   Just finished macro.  Running output (82): '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513'
[1539678513.974971] [2048.2] [pid=46364]   Processing part: '.perfdata.host'
[1539678513.974975] [2048.2] [pid=46364]   Not currently in macro.  Running output (96): '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.host'
[1539678513.974979] [2048.1] [pid=46364]   Done.  Final output: '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.host'
[1539678513.974983] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678513.974987] [016.2] [pid=46364] Processed host performance data file processing command line: /bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.host
[1539678513.975005] [001.0] [pid=46364] my_system_r()
[1539678513.975009] [256.1] [pid=46364] Running command '/bin/mv /var/nagiosramdisk/host-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.host'...
[1539678513.975026] [064.1] [pid=46364] Making callbacks (type 3)...
[1539678513.975114] [064.2] [pid=46364] Callback #1 (type 3) return code = 0
[1539678513.980191] [256.1] [pid=46364] Execution time=0.005 sec, early timeout=0, result=0, output=(null)
[1539678513.980210] [064.1] [pid=46364] Making callbacks (type 3)...
[1539678513.980247] [064.2] [pid=46364] Callback #1 (type 3) return code = 0
[1539678513.980264] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678513.980337] [001.0] [pid=46364] handle_timed_event() end
[1539678513.980344] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678513.980349] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678513.980353] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678513.980357] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678513.980370] [001.0] [pid=46364] reschedule_event()
[1539678513.980375] [001.0] [pid=46364] add_event()
[1539678513.980381] [008.1] [pid=46364] ** Event Check Loop
[1539678513.980409] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:34 2018
[1539678513.980414] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678513.980419] [12288.1] [pid=46364] ## Polling 0ms; sockets=6; events=17; iobs=0x22b4140
[1539678513.980425] [4096.2] [pid=46364] ## 0 descriptors had input
[1539678513.980429] [001.0] [pid=46364] handle_timed_event() start
[1539678513.980433] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678513.980437] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678513.980441] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678513.980449] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678513.980472] [008.0] [pid=46364] ** Timed Event ** Type: EVENT_USER_FUNCTION, Run Time: Tue Oct 16 04:28:34 2018
[1539678513.980478] [008.0] [pid=46364] ** User Function Event. Latency: 0.000s
[1539678513.980483] [001.0] [pid=46364] process_service_perfdata_file()
[1539678513.980490] [001.0] [pid=46364] get_raw_command_line_r()
[1539678513.980495] [2320.2] [pid=46364] Raw Command Input: /bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.service
[1539678513.980504] [2320.2] [pid=46364] Expanded Command Output: /bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.service
[1539678513.980508] [016.2] [pid=46364] Raw service performance data file processing command line: /bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.service
[1539678513.980512] [001.0] [pid=46364] process_macros_r()
[1539678513.980518] [2048.1] [pid=46364] **** BEGIN MACRO PROCESSING ***********
[1539678513.980522] [2048.1] [pid=46364] Processing: '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/$TIMET$.perfdata.service'
[1539678513.980528] [2048.2] [pid=46364]   Processing part: '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/'
[1539678513.980533] [2048.2] [pid=46364]   Not currently in macro.  Running output (75): '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/'
[1539678513.980539] [2048.2] [pid=46364]   Processing part: 'TIMET'
[1539678513.980546] [2048.2] [pid=46364]   macros[11] (TIMET) match.
[1539678513.980632] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0
[1539678513.980658] [2048.2] [pid=46364]   Processed 'TIMET', Free: 0,  Cleaning options: 3
[1539678513.980664] [2048.2] [pid=46364]   Uncleaned macro.  Running output (85): '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513'
[1539678513.980669] [2048.2] [pid=46364]   Just finished macro.  Running output (85): '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513'
[1539678513.980673] [2048.2] [pid=46364]   Processing part: '.perfdata.service'
[1539678513.980677] [2048.2] [pid=46364]   Not currently in macro.  Running output (102): '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.service'
[1539678513.980681] [2048.1] [pid=46364]   Done.  Final output: '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.service'
[1539678513.980685] [2048.1] [pid=46364] **** END MACRO PROCESSING *************
[1539678513.980689] [016.2] [pid=46364] Processed service performance data file processing command line: /bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.service
[1539678513.980707] [001.0] [pid=46364] my_system_r()
[1539678513.980711] [256.1] [pid=46364] Running command '/bin/mv /var/nagiosramdisk/service-perfdata /var/nagiosramdisk/spool/xidpe/1539678513.perfdata.service'...
[1539678513.980723] [064.1] [pid=46364] Making callbacks (type 3)...
[1539678513.980757] [064.2] [pid=46364] Callback #1 (type 3) return code = 0
[1539678513.984860] [256.1] [pid=46364] Execution time=0.004 sec, early timeout=0, result=0, output=(null)
[1539678513.984883] [064.1] [pid=46364] Making callbacks (type 3)...
[1539678513.984921] [064.2] [pid=46364] Callback #1 (type 3) return code = 0
[1539678513.984997] [001.0] [pid=46364] clear_volatile_macros_r()
[1539678513.985013] [001.0] [pid=46364] handle_timed_event() end
[1539678513.985020] [064.1] [pid=46364] Making callbacks (type 1)...
[1539678513.985026] [064.2] [pid=46364] Callback #1 (type 1) return code = 0
[1539678513.985033] [064.2] [pid=46364] Callback #2 (type 1) return code = 0
[1539678513.985039] [064.2] [pid=46364] Callback #3 (type 1) return code = 0
[1539678513.985057] [001.0] [pid=46364] reschedule_event()
[1539678513.985069] [001.0] [pid=46364] add_event()
[1539678513.985076] [008.1] [pid=46364] ** Event Check Loop
[1539678513.985109] [008.1] [pid=46364] Next Event Time: Tue Oct 16 04:28:39 2018
[1539678513.985117] [008.1] [pid=46364] Current/Max Service Checks: 0/0 (-nan% saturation)
[1539678513.985123] [12288.1] [pid=46364] ## Polling 1500ms; sockets=6; events=17; iobs=0x22b4140
[1539678514.476687] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678514.476719] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678514.476729] [4096.2] [pid=46364] ## -3 descriptors had input
[1539678514.476735] [001.0] [pid=46364] event_execution_loop() end
[1539678514.476797] [064.1] [pid=46364] Making callbacks (type 0)...
[1539678514.476832] [064.2] [pid=46364] Callback #1 (type 0) return code = 0
[1539678514.476845] [064.2] [pid=46364] Callback #2 (type 0) return code = 0
[1539678514.476855] [064.2] [pid=46364] Callback #3 (type 0) return code = 0
[1539678514.476875] [064.2] [pid=46364] Callback #4 (type 0) return code = 0
[1539678514.476882] [064.1] [pid=46364] Making callbacks (type 0)...
[1539678514.476893] [064.2] [pid=46364] Callback #1 (type 0) return code = 0
[1539678514.476905] [064.2] [pid=46364] Callback #2 (type 0) return code = 0
[1539678514.476916] [064.2] [pid=46364] Callback #3 (type 0) return code = 0
[1539678514.476945] [064.2] [pid=46364] Callback #4 (type 0) return code = 0
[1539678514.476951] [064.1] [pid=46364] Making callbacks (type 19)...
[1539678514.476976] [064.2] [pid=46364] Callback #1 (type 19) return code = 0
[1539678514.476981] [001.0] [pid=46364] xrddefault_save_state_information()
[1539678514.477091] [004.2] [pid=46364] Writing retention data to temp file '/usr/local/nagios/var/nagios.tmpPvpzmm'
[1539678514.491627] [064.1] [pid=46364] Making callbacks (type 19)...
[1539678514.491662] [064.2] [pid=46364] Callback #1 (type 19) return code = 0
[1539678514.491911] [064.1] [pid=46364] Making callbacks (type 2)...
[1539678514.491928] [064.2] [pid=46364] Callback #1 (type 2) return code = 0
[1539678514.491958] [064.0] [pid=46364] Attempting to unload module 'NERD': flags=1, reason=1
[1539678514.491964] [064.0] [pid=46364] Module 'NERD' unloaded successfully.
[1539678514.491987] [064.0] [pid=46364] Attempting to unload module '/usr/lib64/mod_gearman2/mod_gearman2.o': flags=1, reason=1
[1539678514.494681] [064.0] [pid=46364] Module '/usr/lib64/mod_gearman2/mod_gearman2.o' unloaded successfully.
[1539678514.494724] [064.0] [pid=46364] Attempting to unload module '/usr/lib64/mod_gearman2/mod_gearman2.o': flags=1, reason=1

Here is the nagios.log entries for for period:

[1539678499] Nagios 4.2.4 starting... (PID=46364)
[1539678499] Local time is Tue Oct 16 04:28:19 EDT 2018
[1539678499] LOG VERSION: 2.0
[1539678499] qh: Socket '/usr/local/nagios/var/rw/nagios.qh' successfully initialized
[1539678499] qh: core query handler registered
[1539678499] nerd: Channel hostchecks registered successfully
[1539678499] nerd: Channel servicechecks registered successfully
[1539678499] nerd: Channel opathchecks registered successfully
[1539678499] nerd: Fully initialized and ready to rock!
[1539678499] wproc: Successfully registered manager as @wproc with query handler
[1539678499] wproc: Registry request: name=Core Worker 46366;pid=46366
[1539678499] wproc: Registry request: name=Core Worker 46367;pid=46367
[1539678499] wproc: Registry request: name=Core Worker 46369;pid=46369
[1539678499] wproc: Registry request: name=Core Worker 46368;pid=46368
[1539678499] mod_gearman: initialized version 2.1.1 (libgearman 0.33)
[1539678499] Event broker module '/usr/lib64/mod_gearman2/mod_gearman2.o' initialized successfully.
[1539678499] mod_gearman: initialized version 2.1.1 (libgearman 0.33)
[1539678499] Event broker module '/usr/lib64/mod_gearman2/mod_gearman2.o' initialized successfully.
[1539678499] mod_gearman: initialized version 2.1.1 (libgearman 0.33)
[1539678499] Event broker module '/usr/lib64/mod_gearman2/mod_gearman2.o' initialized successfully.
[1539678499] ndomod: NDOMOD 2.1.2 (11-14-2016) Copyright (c) 2009 Nagios Core Development Team and Community Contributors
[1539678499] ndomod: Successfully connected to data sink.  0 queued items to flush.
[1539678499] ndomod registered for process data
[1539678499] ndomod registered for log data'
[1539678499] ndomod registered for system command data'
[1539678499] ndomod registered for event handler data'
[1539678499] ndomod registered for notification data'
[1539678499] ndomod registered for comment data'
[1539678499] ndomod registered for downtime data'
[1539678499] ndomod registered for flapping data'
[1539678499] ndomod registered for program status data'
[1539678499] ndomod registered for host status data'
[1539678499] ndomod registered for service status data'
[1539678499] ndomod registered for adaptive program data'
[1539678499] ndomod registered for adaptive host data'
[1539678499] ndomod registered for adaptive service data'
[1539678499] ndomod registered for external command data'
[1539678499] ndomod registered for aggregated status data'
[1539678499] ndomod registered for retention data'
[1539678499] ndomod registered for contact data'
[1539678499] ndomod registered for contact notification data'
[1539678499] ndomod registered for acknowledgement data'
[1539678499] ndomod registered for state change data'
[1539678499] ndomod registered for contact status data'
[1539678499] ndomod registered for adaptive contact data'
[1539678499] Event broker module '/usr/local/nagios/bin/ndomod.o' initialized successfully.
[1539678499] Warning: Host '[ANOTHER_CLIENT][WORKER][10.20.4.5]' has no default contacts or contactgroups defined!
[1539678499] Warning: Host '[NEW CLIENT][WORKER][10.20.4.5]' has no default contacts or contactgroups defined!
[1539678499] Warning: Host '[NEW CLIENT][WORKER][10.90.4.5]' has no default contacts or contactgroups defined!
[1539678499] Successfully launched command file worker with pid 46389
[1539678514] Caught SIGTERM, shutting down...
[1539678514] Successfully shutdown... (PID=46364)
[1539678514] Event broker module 'NERD' deinitialized successfully.
[1539678514] Event broker module '/usr/lib64/mod_gearman2/mod_gearman2.o' deinitialized successfully.