Node in Cluster loses connection #5513

darmagan · 2017-08-16T13:29:47Z

Summary

There are two master nodes m1 and m2. M2 waits for m1, m1 on the other side does a sync, where m2 cuts the connection at that time 'cause m1 reached the timeout of 60sec with:

[2017-08-15 16:32:11 +0200] critical/ApiListener: Error while syncing endpoint 'master02': Error: Tried to read/write from a closed socket.

Infos

Master01:

[2017-08-15 16:30:55 +0200] information/ApiListener: New client connection for identity 'master02' from [xxx]:2084
[2017-08-15 16:30:55 +0200] information/ApiListener: Sending config updates for endpoint 'master02'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'master02'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Syncing configuration files for zone 'cloudsat' to endpoint 'master02'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Applying config update from endpoint 'master02' of zone 'master'.
[2017-08-15 16:30:56 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'master02'.
[2017-08-15 16:30:56 +0200] information/ApiListener: Syncing configuration files for zone 'oobsat' to endpoint 'master02'.
[2017-08-15 16:30:56 +0200] information/ApiListener: Syncing configuration files for zone 'netsat' to endpoint 'master02'.
[2017-08-15 16:30:57 +0200] information/ApiListener: Syncing runtime objects to endpoint 'master02'.
[2017-08-15 16:31:03 +0200] information/WorkQueue: #6 (ApiListener, SyncQueue) items: 0, rate: 0.0166667/s (1/min 9/5min 9/15min);
[2017-08-15 16:31:03 +0200] information/WorkQueue: #7 (IdoMysqlConnection, ido-mysql) items: 0, rate: 749.067/s (44944/min 260970/5min 260970/15min);
...
[2017-08-15 16:31:45 +0200] information/WorkQueue: #19 (JsonRpcConnection, #9) items: 0, rate: 0.266667/s (16/min 16/5min 16/15min);
[2017-08-15 16:31:45 +0200] information/WorkQueue: #21 (JsonRpcConnection, #11) items: 0, rate: 0/s (0/min 0/5min 0/15min);
[2017-08-15 16:31:45 +0200] information/WorkQueue: #5 (ApiListener, RelayQueue) items: 1, rate: 1646.35/s (98781/min 417533/5min 586134/15min);
[2017-08-15 16:31:45 +0200] information/WorkQueue: #17 (JsonRpcConnection, #7) items: 0, rate: 0.333333/s (20/min 22/5min 22/15min);
[2017-08-15 16:32:11 +0200] warning/JsonRpcConnection: API client disconnected for identity 'master02'
[2017-08-15 16:32:11 +0200] warning/ApiListener: Removing API client for endpoint 'master02'. 0 API clients left.
[2017-08-15 16:32:11 +0200] critical/ApiListener: Error while syncing endpoint 'master02': Error: Tried to read/write from a closed socket.

(0) libbase.so.2.7.0: <unknown function> (+0xa1c4a) [0x7fb908491c4a]
(1) libbase.so.2.7.0: icinga::SocketEventEngineEpoll::ChangeEvents(icinga::SocketEvents*, int) (+0x147) [0x7fb9084950a7]
(2) libbase.so.2.7.0: icinga::TlsStream::Write(void const*, unsigned long) (+0x50) [0x7fb90849f2a0]
(3) libbase.so.2.7.0: icinga::NetString::WriteStringToStream(boost::intrusive_ptr<icinga::Stream> const&, icinga::String const&) (+0x75) [0x7fb908487ef5]
(4) libremote.so.2.7.0: icinga::JsonRpc::SendMessage(boost::intrusive_ptr<icinga::Stream> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0x42) [0x7fb907c14e72]
(5) libremote.so.2.7.0: icinga::ApiListener::UpdateConfigObject(boost::intrusive_ptr<icinga::ConfigObject> const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0xdb8) [0x7fb907c33788]
(6) libremote.so.2.7.0: icinga::ApiListener::SendRuntimeConfigObjects(boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0x1ba) [0x7fb907c3432a]
(7) libremote.so.2.7.0: icinga::ApiListener::SyncClient(boost::intrusive_ptr<icinga::JsonRpcConnection> const&, boost::intrusive_ptr<icinga::Endpoint> const&, bool) (+0x146) [0x7fb907c346b6]
(8) libbase.so.2.7.0: icinga::WorkQueue::WorkerThreadProc() (+0x4df) [0x7fb9084babff]
(9) libboost_thread.so.1.54.0: <unknown function> (+0xcc0a) [0x7fb908f14c0a]
(10) libpthread.so.0: <unknown function> (+0x80a4) [0x7fb905bc70a4]
(11) libc.so.6: clone (+0x6d) [0x7fb9058fc02d]


[2017-08-15 16:32:12 +0200] information/WorkQueue: #10 (JsonRpcConnection, #0) items: 5, rate: 1068.57/s (64114/min 203971/5min 278477/15min);

On the same time on master02

[2017-08-15 16:30:55 +0200] information/ApiListener: Sending config updates for endpoint 'master01'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Syncing runtime objects to endpoint 'master01'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'master01'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Finished sending config updates for endpoint 'master01'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Sending replay log for endpoint 'master01'.
[2017-08-15 16:30:55 +0200] information/ApiListener: Finished sending replay log for endpoint 'master01'.
[2017-08-15 16:32:11 +0200] information/JsonRpcConnection: No messages for identity 'master01' have been received in the last 60 seconds.
[2017-08-15 16:32:11 +0200] warning/JsonRpcConnection: API client disconnected for identity 'master01'
[2017-08-15 16:32:11 +0200] warning/JsonRpcConnection: API client disconnected for identity 'master01'
[2017-08-15 16:32:11 +0200] warning/ApiListener: Removing API client for endpoint 'master01'. 0 API clients left.
[2017-08-15 16:32:11 +0200] warning/ApiListener: Removing API client for endpoint 'master01'. 0 API clients left.
[2017-08-15 16:32:26 +0200] information/ApiListener: New client connection for identity 'master01' from [153.95.26.186]:34462
[2017-08-15 16:32:26 +0200] information/ApiListener: Sending config updates for endpoint 'master01'.
[2017-08-15 16:32:26 +0200] information/ApiListener: Syncing runtime objects to endpoint 'master01'.
[2017-08-15 16:32:26 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'master01'.
[2017-08-15 16:32:26 +0200] information/ApiListener: Finished sending config updates for endpoint 'master01'.
[2017-08-15 16:32:26 +0200] information/ApiListener: Sending replay log for endpoint 'master01'.
[2017-08-15 16:32:26 +0200] information/ApiListener: Finished sending replay log for endpoint 'master01'.

Your Environment

Version used (icinga2 --version):

icinga2 - The Icinga 2 network monitoring daemon (version: r2.7.0-1)

Copyright (c) 2012-2017 Icinga Development Team (https://www.icinga.com/)
License GPLv2+: GNU GPL version 2 or later <http://gnu.org/licenses/gpl2.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Application information:
  Installation root: /usr
  Sysconf directory: /etc
  Run directory: /run
  Local state directory: /var
  Package data directory: /usr/share/icinga2
  State path: /var/lib/icinga2/icinga2.state
  Modified attributes path: /var/lib/icinga2/modified-attributes.conf
  Objects path: /var/cache/icinga2/icinga2.debug
  Vars path: /var/cache/icinga2/icinga2.vars
  PID path: /run/icinga2/icinga2.pid

System information:
  Platform: SLES
  Platform version: 12-SP1
  Kernel: Linux
  Kernel version: 3.12.74-60.64.40-default
  Architecture: x86_64

Build information:
  Compiler: GNU 4.8.5
  Build host: 1464b364519d

Operating System and version:

NAME="SLES"
VERSION="12-SP1"
VERSION_ID="12.1"
PRETTY_NAME="SUSE Linux Enterprise Server 12 SP1"
ID="sles"
ANSI_COLOR="0;32"
CPE_NAME="cpe:/o:suse:sles:12:sp1"

Enabled features (icinga2 feature list):

Disabled features: compatlog debuglog gelf graphite influxdb notification opentsdb statusdata syslog
Enabled features: api checker command ido-mysql livestatus mainlog perfdata

Config validation (icinga2 daemon -C):

information/cli: Icinga application loader (version: r2.7.0-1)
information/cli: Loading configuration file(s).
information/ConfigItem: Committing config item(s).
information/ApiListener: My API identity:xxx
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 25000, rate: 4055.12/s (243307/min 243307/5min 243307/15min);
information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
information/ConfigItem: Instantiated 2 ApiUsers.
information/ConfigItem: Instantiated 1 ApiListener.
information/ConfigItem: Instantiated 5 Zones.
information/ConfigItem: Instantiated 1 FileLogger.
information/ConfigItem: Instantiated 8 Endpoints.
information/ConfigItem: Instantiated 43 UserGroups.
information/ConfigItem: Instantiated 36384 Notifications.
information/ConfigItem: Instantiated 12 NotificationCommands.
information/ConfigItem: Instantiated 278 CheckCommands.
information/ConfigItem: Instantiated 586 HostGroups.
information/ConfigItem: Instantiated 1 IcingaApplication.
information/ConfigItem: Instantiated 5248 Hosts.
information/ConfigItem: Instantiated 68523 Dependencies.
information/ConfigItem: Instantiated 66 Users.
information/ConfigItem: Instantiated 8 TimePeriods.
information/ConfigItem: Instantiated 87812 Services.
information/ConfigItem: Instantiated 923 ServiceGroups.
information/ConfigItem: Instantiated 1972 ScheduledDowntimes.
information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
information/cli: Finished validating the configuration file(s).

Regards

The text was updated successfully, but these errors were encountered:

mwaldmueller · 2017-08-16T14:39:03Z

I can reproduce this on another platform:

# icinga2 --version
icinga2 - The Icinga 2 network monitoring daemon (version: r2.7.0-1)

Copyright (c) 2012-2017 Icinga Development Team (https://www.icinga.com/)
License GPLv2+: GNU GPL version 2 or later <http://gnu.org/licenses/gpl2.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Application information:
  Installation root: /usr
  Sysconf directory: /etc
  Run directory: /run
  Local state directory: /var
  Package data directory: /usr/share/icinga2
  State path: /var/lib/icinga2/icinga2.state
  Modified attributes path: /var/lib/icinga2/modified-attributes.conf
  Objects path: /var/cache/icinga2/icinga2.debug
  Vars path: /var/cache/icinga2/icinga2.vars
  PID path: /run/icinga2/icinga2.pid

System information:
  Platform: CentOS Linux
  Platform version: 7 (Core)
  Kernel: Linux
  Kernel version: 3.10.0-514.26.2.el7.x86_64
  Architecture: x86_64

Build information:
  Compiler: GNU 4.8.5
  Build host: unknown

dnsmichi · 2017-08-16T15:12:14Z

Some more numbers please? :)

icinga2 daemon -C

mwaldmueller · 2017-08-17T05:34:16Z

Details

Features on all nodes:

# icinga2 feature list
Disabled features: checker command compatlog gelf graphite ido-mysql influxdb livestatus notification opentsdb perfdata statusdata syslog
Enabled features: api debuglog mainlog

"/etc/icinga2/zones.conf" without satellite endpoints:

object Endpoint "i2-master01.localdomain" {
  host = "10.37.129.100"
}

object Endpoint "i2-master02.localdomain" {
  host = "10.37.129.101"
}

object Zone "master" {
  endpoints = [ "i2-master01.localdomain", "i2-master02.localdomain" ]
}

object Zone "zone1" {
  endpoints = [ ]
  parent = "master"
}

object Zone "zone2" {
  endpoints = [ ]
  parent = "master"
}

object Zone "zone3" {
  endpoints = [ ]
  parent = "master"
}

object Zone "global-templates" {
  global = true
}

"/etc/icinga2/zones.d" on master01:

├── global-templates (6 files)
├── master (8418 files)
├── zone1 (2284 files)
├── zone2 (2514 files)
└── zone3 (430 files)

Configuration validation on master01:

# time icinga2 daemon -C
information/cli: Icinga application loader (version: r2.7.0-1)
information/cli: Loading configuration file(s).
information/ConfigItem: Committing config item(s).
information/ApiListener: My API identity: i2-master01.localdomain
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 24999, rate: 1563.83/s (93830/min 93830/5min 93830/15min);
information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
warning/ClusterEvents: No local endpoint defined. Bailing out.
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 825, rate: 3489.28/s (209357/min 209357/5min 209357/15min);
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 80, rate: 6594.62/s (395677/min 395677/5min 395677/15min);
information/ConfigItem: Instantiated 1 ApiListener.
information/ConfigItem: Instantiated 5 Zones.
information/ConfigItem: Instantiated 3 FileLoggers.
information/ConfigItem: Instantiated 2 Endpoints.
information/ConfigItem: Instantiated 43 UserGroups.
information/ConfigItem: Instantiated 36384 Notifications.
information/ConfigItem: Instantiated 12 NotificationCommands.
information/ConfigItem: Instantiated 278 CheckCommands.
information/ConfigItem: Instantiated 2136 Downtimes.
information/ConfigItem: Instantiated 586 HostGroups.
information/ConfigItem: Instantiated 1 IcingaApplication.
information/ConfigItem: Instantiated 5248 Hosts.
information/ConfigItem: Instantiated 68523 Dependencies.
information/ConfigItem: Instantiated 66 Users.
information/ConfigItem: Instantiated 8 TimePeriods.
information/ConfigItem: Instantiated 87812 Services.
information/ConfigItem: Instantiated 923 ServiceGroups.
information/ConfigItem: Instantiated 1972 ScheduledDowntimes.
information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
information/cli: Finished validating the configuration file(s).

real	0m42.913s
user	0m59.382s
sys	0m8.842s

Configuration validation on master02: ("/var/lib/icinga2/api/zones" is empty)

# time icinga2 daemon -C
information/cli: Icinga application loader (version: r2.7.0-1)
information/cli: Loading configuration file(s).
information/ConfigItem: Committing config item(s).
information/ApiListener: My API identity: i2-master02.localdomain
information/ConfigItem: Instantiated 1 ApiListener.
information/ConfigItem: Instantiated 5 Zones.
information/ConfigItem: Instantiated 2 FileLoggers.
information/ConfigItem: Instantiated 2 Endpoints.
information/ConfigItem: Instantiated 207 CheckCommands.
information/ConfigItem: Instantiated 1 IcingaApplication.
information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
information/cli: Finished validating the configuration file(s).

real	0m0.542s
user	0m0.636s
sys	0m0.118s

Behaviour

master01 establishes a connection with master02 and starts to sync its config: (debug.log on master01)

[2017-08-17 07:10:05 +0200] information/ApiListener: Reconnecting to API endpoint 'i2-master02.localdomain' via host '10.37.129.101' and port '5665'
[2017-08-17 07:10:05 +0200] information/ApiListener: New client connection for identity 'i2-master02.localdomain' to [10.37.129.101]:5665
[2017-08-17 07:10:05 +0200] information/ApiListener: Sending config updates for endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:05 +0200] information/ApiListener: Syncing configuration files for zone 'zone1' to endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:05 +0200] information/ApiListener: Applying config update from endpoint 'i2-master02.localdomain' of zone 'master'.
[2017-08-17 07:10:05 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:05 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:06 +0200] information/ApiListener: Syncing configuration files for zone 'zone3' to endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:06 +0200] information/ApiListener: Syncing configuration files for zone 'zone2' to endpoint 'i2-master02.localdomain'.
[2017-08-17 07:10:07 +0200] information/ApiListener: Syncing runtime objects to endpoint 'i2-master02.localdomain'.

After 60s master02 closes the connection: ("/var/lib/icinga2/api/zones" is still empty, debug.log of master02)

[2017-08-17 07:11:13 +0200] information/JsonRpcConnection: No messages for identity 'i2-master01.localdomain' have been received in the last 60 seconds.
[2017-08-17 07:11:13 +0200] warning/JsonRpcConnection: API client disconnected for identity 'i2-master01.localdomain'
[2017-08-17 07:11:13 +0200] warning/JsonRpcConnection: API client disconnected for identity 'i2-master01.localdomain'
[2017-08-17 07:11:13 +0200] warning/ApiListener: Removing API client for endpoint 'i2-master01.localdomain'. 0 API clients left.
[2017-08-17 07:11:13 +0200] warning/ApiListener: Removing API client for endpoint 'i2-master01.localdomain'. 0 API clients left.

And master01 gets a stacktrace: (debug.log of master01)

[2017-08-17 07:11:12 +0200] warning/JsonRpcConnection: API client disconnected for identity 'i2-master02.localdomain'
[2017-08-17 07:11:12 +0200] warning/ApiListener: Removing API client for endpoint 'i2-master02.localdomain'. 0 API clients left.
[2017-08-17 07:11:12 +0200] critical/ApiListener: Error while syncing endpoint 'i2-master02.localdomain': Error: Tried to read/write from a closed socket.

	(0) libbase.so.2.7.0: <unknown function> (+0xb23ba) [0x7fec2c37c3ba]
	(1) libbase.so.2.7.0: icinga::SocketEventEngineEpoll::ChangeEvents(icinga::SocketEvents*, int) (+0x15c) [0x7fec2c37fb7c]
	(2) libbase.so.2.7.0: icinga::TlsStream::Write(void const*, unsigned long) (+0x60) [0x7fec2c39fe30]
	(3) libbase.so.2.7.0: icinga::NetString::WriteStringToStream(boost::intrusive_ptr<icinga::Stream> const&, icinga::String const&) (+0x88) [0x7fec2c3ca358]
	(4) libremote.so.2.7.0: icinga::JsonRpc::SendMessage(boost::intrusive_ptr<icinga::Stream> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0x57) [0x7fec2badd5a7]
	(5) libremote.so.2.7.0: icinga::ApiListener::UpdateConfigObject(boost::intrusive_ptr<icinga::ConfigObject> const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0xbf4) [0x7fec2bac5ca4]
	(6) libremote.so.2.7.0: icinga::ApiListener::SendRuntimeConfigObjects(boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0x1d7) [0x7fec2bac68b7]
	(7) libremote.so.2.7.0: icinga::ApiListener::SyncClient(boost::intrusive_ptr<icinga::JsonRpcConnection> const&, boost::intrusive_ptr<icinga::Endpoint> const&, bool) (+0x159) [0x7fec2bac6c79]
	(8) libbase.so.2.7.0: icinga::WorkQueue::WorkerThreadProc() (+0x4d4) [0x7fec2c377294]
	(9) libboost_thread-mt.so.1.53.0: <unknown function> (+0xd27a) [0x7fec2cde527a]
	(10) libpthread.so.0: <unknown function> (+0x7dc5) [0x7fec29b15dc5]
	(11) libc.so.6: clone (+0x6d) [0x7fec2984476d]

Test 1

The first test was to reduce the large number of files, so I added all configs to single files for each zone:

# tree -hF
├── [4.0K]  global-templates/
│   └── [227K]  global-templates.conf
├── [4.0K]  master/
│   └── [ 44M]  master.conf
├── [4.0K]  zone1/
│   └── [ 48M]  zone1.conf
├── [4.0K]  zone2/
│   └── [ 27M]  zone2.conf
└── [4.0K]  zone3/
    └── [2.8M]  zone3.conf

Unfortunately it's still the same behaviour than described above and doesn't have a noticeable effect.

Test 2

My second test was to reduce the number of objects. So I removed dependency objects until it worked.

# time icinga2 daemon -C
information/cli: Icinga application loader (version: r2.7.0-1)
information/cli: Loading configuration file(s).
information/ConfigItem: Committing config item(s).
information/ApiListener: My API identity: i2-master01.localdomain
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 24999, rate: 791.1/s (47466/min 47466/5min 47466/15min); empty in 17395 days, 5 hours, 26 minutes and 37 seconds
information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
warning/ClusterEvents: No local endpoint defined. Bailing out.
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 25000, rate: 1844/s (110640/min 110640/5min 110640/15min);
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 20798, rate: 2720.73/s (163244/min 163244/5min 163244/15min);
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 24999, rate: 3307.12/s (198427/min 198427/5min 198427/15min); empty in 59 seconds
information/WorkQueue: #3 (DaemonUtility::LoadConfigFiles) items: 25000, rate: 3867.88/s (232073/min 232073/5min 232073/15min); empty in 2 days, 21 hours, 28 minutes and 34 seconds
information/ConfigItem: Instantiated 1 ApiListener.
information/ConfigItem: Instantiated 5 Zones.
information/ConfigItem: Instantiated 3 FileLoggers.
information/ConfigItem: Instantiated 2 Endpoints.
information/ConfigItem: Instantiated 43 UserGroups.
information/ConfigItem: Instantiated 36384 Notifications.
information/ConfigItem: Instantiated 12 NotificationCommands.
information/ConfigItem: Instantiated 278 CheckCommands.
information/ConfigItem: Instantiated 2406 Downtimes.
information/ConfigItem: Instantiated 586 HostGroups.
information/ConfigItem: Instantiated 1 IcingaApplication.
information/ConfigItem: Instantiated 5248 Hosts.
information/ConfigItem: Instantiated 48297 Dependencies.
information/ConfigItem: Instantiated 66 Users.
information/ConfigItem: Instantiated 8 TimePeriods.
information/ConfigItem: Instantiated 87812 Services.
information/ConfigItem: Instantiated 923 ServiceGroups.
information/ConfigItem: Instantiated 1972 ScheduledDowntimes.
information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
information/cli: Finished validating the configuration file(s).

real	1m15.928s
user	1m19.720s
sys	0m11.544s

The same test on other systems showed that it depends on the systems processing speed how many objects must be removed, either it's more or less. Accordingly it's not a fixed limitation.

mwaldmueller · 2017-08-17T07:11:06Z

Seems like it's related to #2972

dnsmichi · 2017-08-17T13:59:26Z

michi@mbmif ~ $ sudo lldb -p 51373
(lldb) process attach --pid 51373
Process 51373 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
    frame #0: 0x00007fffaf28ef46 libsystem_kernel.dylib`__semwait_signal + 10
libsystem_kernel.dylib`__semwait_signal:
->  0x7fffaf28ef46 <+10>: jae    0x7fffaf28ef50            ; <+20>
    0x7fffaf28ef48 <+12>: movq   %rax, %rdi
    0x7fffaf28ef4b <+15>: jmp    0x7fffaf287cd4            ; cerror
    0x7fffaf28ef50 <+20>: retq

Executable module set to "/usr/local/icinga2/lib/icinga2/sbin/icinga2".
Architecture set to: x86_64h-apple-macosx.
(lldb) bt all
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007fffaf28ef46 libsystem_kernel.dylib`__semwait_signal + 10
    frame #1: 0x00007fffaf215b72 libsystem_c.dylib`nanosleep + 199
    frame #2: 0x00007fffaf2159d3 libsystem_c.dylib`sleep + 42
    frame #3: 0x000000010e82f6ef libbase.2.7.0.dylib`icinga::Application::RunEventLoop() [inlined] icinga::Utility::Sleep(timeout=2.5) at utility.cpp:426 [opt]
    frame #4: 0x000000010e82f6e5 libbase.2.7.0.dylib`icinga::Application::RunEventLoop(this=<unavailable>) at application.cpp:322 [opt]
    frame #5: 0x000000010eec7c12 libicinga.2.7.0.dylib`icinga::IcingaApplication::Main(this=0x00007f9a62061b90) at icingaapplication.cpp:106 [opt]
    frame #6: 0x000000010e837f4f libbase.2.7.0.dylib`icinga::Application::Run(this=<unavailable>) at application.cpp:941 [opt]
    frame #7: 0x000000010e15a7f6 libcli.2.7.0.dylib`icinga::DaemonCommand::Run(this=<unavailable>, vm=<unavailable>, ap=<unavailable>) const at daemoncommand.cpp:314 [opt]
    frame #8: 0x000000010decab40 icinga2`Main() at icinga.cpp:488 [opt]
    frame #9: 0x000000010deccdd0 icinga2`main(argc=7, argv=0x00007fff51d3e5e0) at icinga.cpp:784 [opt]
    frame #10: 0x00007fffaf160235 libdyld.dylib`start + 1

  thread #2
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x000000010e9a57e8, m=0x000070000dccce00) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e88d92f libbase.2.7.0.dylib`icinga::ThreadPool::WorkerThread::ThreadProc(this=<unavailable>, queue=0x000000010e9a57a8) at threadpool.cpp:111 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #3
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x000000010e9a5b50, m=0x000070000dd4fe00) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e88d92f libbase.2.7.0.dylib`icinga::ThreadPool::WorkerThread::ThreadProc(this=<unavailable>, queue=0x000000010e9a5b10) at threadpool.cpp:111 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #4
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x000000010e9a5eb8, m=0x000070000ddd2e00) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e88d92f libbase.2.7.0.dylib`icinga::ThreadPool::WorkerThread::ThreadProc(this=<unavailable>, queue=0x000000010e9a5e78) at threadpool.cpp:111 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #5
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x000000010e9a6220, m=0x000070000de55e00) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e88d92f libbase.2.7.0.dylib`icinga::ThreadPool::WorkerThread::ThreadProc(this=<unavailable>, queue=0x000000010e9a61e0) at threadpool.cpp:111 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #6
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e8dc569 libbase.2.7.0.dylib`boost::condition_variable::do_wait_until(this=0x000000010e9a5730, m=0x000070000ded8e18, timeout=0x000070000ded89f0) at condition_variable.hpp:107 [opt]
    frame #3: 0x000000010e886476 libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(boost::unique_lock<boost::mutex>&, boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> const&) [inlined] boost::condition_variable::timed_wait(this=0x000000010e9a5730, m=0x000070000ded8e18, abs_time=<unavailable>) at condition_variable_fwd.hpp:142 [opt]
    frame #4: 0x000000010e88645a libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(this=0x000000010e9a5730, m=0x000070000ded8e18, wait_duration=<unavailable>) at condition_variable_fwd.hpp:166 [opt]
    frame #5: 0x000000010e88ccda libbase.2.7.0.dylib`icinga::ThreadPool::ManagerThreadProc(this=0x000000010e9a5520) at threadpool.cpp:240 [opt]
    frame #6: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #7: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #8: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #9: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #7
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e8dc569 libbase.2.7.0.dylib`boost::condition_variable::do_wait_until(this=0x000000010e9a69b8, m=0x000070000df5be40, timeout=0x000070000df5bdc0) at condition_variable.hpp:107 [opt]
    frame #3: 0x000000010e886476 libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(boost::unique_lock<boost::mutex>&, boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> const&) [inlined] boost::condition_variable::timed_wait(this=0x000000010e9a69b8, m=0x000070000df5be40, abs_time=<unavailable>) at condition_variable_fwd.hpp:142 [opt]
    frame #4: 0x000000010e88645a libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(this=0x000000010e9a69b8, m=0x000070000df5be40, wait_duration=<unavailable>) at condition_variable_fwd.hpp:166 [opt]
    frame #5: 0x000000010e88f06b libbase.2.7.0.dylib`icinga::Timer::TimerThreadProc() at timer.cpp:269 [opt]
    frame #6: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #7: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #8: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #9: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #8
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a60006ab8, m=0x000070000e1eae20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a60006a50) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #9
    frame #0: 0x00007fffaf28e0c2 libsystem_kernel.dylib`__accept + 10
    frame #1: 0x000000010e883438 libbase.2.7.0.dylib`icinga::Socket::Accept(this=<unavailable>) at socket.cpp:337 [opt]
    frame #2: 0x000000010e4577fc libremote.2.7.0.dylib`icinga::ApiListener::ListenerThreadProc(this=0x00007f9a60006800, server=0x000070000e26de90) at apilistener.cpp:266 [opt]
    frame #3: 0x000000010e4f7fc6 libremote.2.7.0.dylib`boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > > > >::run() [inlined] boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>::operator(a1=<unavailable>)(icinga::ApiListener*, boost::intrusive_ptr<icinga::Socket> const&) const at mem_fn_template.hpp:165 [opt]
    frame #4: 0x000000010e4f7fa5 libremote.2.7.0.dylib`boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > > > >::run() [inlined] void boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > >::operator((null)=0)<boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>&, boost::_bi::list0&, int) at bind.hpp:319 [opt]
    frame #5: 0x000000010e4f7f89 libremote.2.7.0.dylib`boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > > > >::run() [inlined] boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > > >::operator()() at bind.hpp:1294 [opt]
    frame #6: 0x000000010e4f7f89 libremote.2.7.0.dylib`boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::ApiListener, boost::intrusive_ptr<icinga::Socket> const&>, boost::_bi::list2<boost::_bi::value<icinga::ApiListener*>, boost::_bi::value<boost::intrusive_ptr<icinga::TcpSocket> > > > >::run(this=<unavailable>) at thread.hpp:116 [opt]
    frame #7: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #8: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #9: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #10: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #10
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e8dc569 libbase.2.7.0.dylib`boost::condition_variable::do_wait_until(this=0x000000010e9a69b8, m=0x000070000e061e40, timeout=0x000070000e061dc0) at condition_variable.hpp:107 [opt]
    frame #3: 0x000000010e886476 libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(boost::unique_lock<boost::mutex>&, boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> const&) [inlined] boost::condition_variable::timed_wait(this=0x000000010e9a69b8, m=0x000070000e061e40, abs_time=<unavailable>) at condition_variable_fwd.hpp:142 [opt]
    frame #4: 0x000000010e88645a libbase.2.7.0.dylib`bool boost::condition_variable::timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000ll> >(this=0x000000010e9a69b8, m=0x000070000e061e40, wait_duration=<unavailable>) at condition_variable_fwd.hpp:166 [opt]
    frame #5: 0x000000010e88f06b libbase.2.7.0.dylib`icinga::Timer::TimerThreadProc() at timer.cpp:269 [opt]
    frame #6: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #7: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #8: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #9: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #11
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #12
    frame #0: 0x00007fffaf372ec9 libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell + 41
    frame #1: 0x000000010e866759 libbase.2.7.0.dylib`icinga::FIFO::Optimize(this=0x00007f9a5fc66a50) at fifo.cpp:71 [opt]
    frame #2: 0x000000010e86689c libbase.2.7.0.dylib`icinga::FIFO::Read(this=0x00007f9a5fc66a50, buffer=<unavailable>, count=16384, allow_partial=<unavailable>) at fifo.cpp:110 [opt]
    frame #3: 0x000000010e891115 libbase.2.7.0.dylib`icinga::TlsStream::OnEvent(this=0x00007f9a5fc709b0, revents=<unavailable>) at tlsstream.cpp:191 [opt]
    frame #4: 0x000000010e884d00 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=<unavailable>, tid=<unavailable>) at socketevents-poll.cpp:117 [opt]
    frame #5: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #6: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #7: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #8: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #13
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #14
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #15
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #16
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #17
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #18
    frame #0: 0x00007fffaf29019e libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010e8849e6 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=0x00007f9a61009600, tid=<unavailable>) at socketevents-poll.cpp:82 [opt]
    frame #2: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #3: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #19
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a60006f40, m=0x000070000e2f0e20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a60006ed8) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #20
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a60006f40, m=0x000070000e685e20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a60006ed8) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #21
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a60006f40, m=0x000070000e708e20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a60006ed8) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #22
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a60006f40, m=0x000070000e78be20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a60006ed8) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #23
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a6101c870, m=0x000070000dfdee20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a6101c808) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

  thread #24
    frame #0: 0x00007fffaf28ebf2 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fffaf37a7fa libsystem_pthread.dylib`_pthread_cond_wait + 712
    frame #2: 0x000000010e886251 libbase.2.7.0.dylib`boost::condition_variable::wait(this=0x00007f9a6101ccf8, m=0x000070000e891e20) at condition_variable.hpp:76 [opt]
    frame #3: 0x000000010e8ab107 libbase.2.7.0.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x00007f9a6101cc90) at workqueue.cpp:247 [opt]
    frame #4: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #5: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #6: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #7: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13
(lldb) thr sel 12
* thread #12
    frame #0: 0x00007fffaf372ec9 libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell + 41
libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell:
->  0x7fffaf372ec9 <+41>: rep
    0x7fffaf372eca <+42>: movsb  (%rsi), %es:(%rdi)
    0x7fffaf372ecb <+43>: popq   %rbp
    0x7fffaf372ecc <+44>: retq
(lldb) up
libbase.2.7.0.dylib was compiled with optimization - stepping may behave oddly; variables may not be available.
frame #1: 0x000000010e866759 libbase.2.7.0.dylib`icinga::FIFO::Optimize(this=0x00007f9a5fc66a50) at fifo.cpp:71 [opt]
   68  	void FIFO::Optimize(void)
   69  	{
   70  		if (m_Offset - m_DataSize > 1024) {
-> 71  			std::memmove(m_Buffer, m_Buffer + m_Offset, m_DataSize);
   72  			m_Offset = 0;
   73
   74  			if (m_DataSize > 0)
(lldb) p this
(icinga::FIFO *) $0 = 0x00007f9a5fc66a50
(lldb) p *this
(icinga::FIFO) $1 = {
  icinga::Stream = {
    icinga::Object = (m_References = 1, m_Mutex = 0)
    OnDataAvailable = {
      _pimpl = {
        px = 0x00007f9a5fc6cef0
        pn = {
          pi_ = 0x00007f9a5fc6d0e0
        }
      }
    }
    m_Mutex = {
      m = (__sig = 1297437786, __opaque = char [56] @ 0x00007f9744dead58)
    }
    m_CV = {
      internal_mutex = (__sig = 1297437786, __opaque = char [56] @ 0x00007f9744dead98)
      cond = (__sig = 1129270852, __opaque = char [40] @ 0x00007f9744deadd8)
    }
  }
  m_Buffer = 0x0000000147610000 "my\" } \nobject Host \"cluster-332002\" { check_command = \"dummy\" } \nobject Host \"cluster-332003\" { check_command = \"dummy\" } \nobject Host \"cluster-332004\" { check_command = \"dummy\" } \nobject Host \"cluster-332005\" { check_command = \"dummy\" } \nobject Host \"cluster-332006\" { check_command = \"dummy\" } \nobject Host \"cluster-332007\" { check_command = \"dummy\" } \nobject Host \"cluster-332008\" { check_command = \"dummy\" } \nobject Host \"cluster-332009\" { check_command = \"dummy\" } \nobject Host \"cluster-332010\" { check_command = \"dummy\" } \nobject Host \"cluster-332011\" { check_command = \"dummy\" } \nobject Host \"cluster-332012\" { check_command = \"dummy\" } \nobject Host \"cluster-332013\" { check_command = \"dummy\" } \nobject Host \"cluster-332014\" { check_command = \"dummy\" } \nobject Host \"cluster-332015\" { check_command = \"dummy\" } \nobject Host \"cluster-332016\" { check_command = \"dummy\" } \nobject Host \"cluster-332017\" { check_command = \"dummy\" } \nobject"
  m_DataSize = 212651902
  m_AllocSize = 212668416
  m_Offset = 16384
}
(lldb) bt
* thread #12
    frame #0: 0x00007fffaf372ec9 libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell + 41
  * frame #1: 0x000000010e866759 libbase.2.7.0.dylib`icinga::FIFO::Optimize(this=0x00007f9a5fc66a50) at fifo.cpp:71 [opt]
    frame #2: 0x000000010e86689c libbase.2.7.0.dylib`icinga::FIFO::Read(this=0x00007f9a5fc66a50, buffer=<unavailable>, count=16384, allow_partial=<unavailable>) at fifo.cpp:110 [opt]
    frame #3: 0x000000010e891115 libbase.2.7.0.dylib`icinga::TlsStream::OnEvent(this=0x00007f9a5fc709b0, revents=<unavailable>) at tlsstream.cpp:191 [opt]
    frame #4: 0x000000010e884d00 libbase.2.7.0.dylib`icinga::SocketEventEnginePoll::ThreadProc(this=<unavailable>, tid=<unavailable>) at socketevents-poll.cpp:117 [opt]
    frame #5: 0x000000010df01b84 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #6: 0x00007fffaf37993b libsystem_pthread.dylib`_pthread_body + 180
    frame #7: 0x00007fffaf379887 libsystem_pthread.dylib`_pthread_start + 286
    frame #8: 0x00007fffaf37908d libsystem_pthread.dylib`thread_start + 13

dnsmichi · 2017-08-17T14:07:00Z

for i in {1..9999999}; do echo "object Host \"cluster-$i\" { check_command = \"dummy\" } " >> test_hosts.conf; done

cp test_hosts.conf test_hosts2.conf
gsed -i 's/cluster-/cluster-a-/g' test_hosts2.conf

vim test_hosts.conf test_hosts2.conf

/*

*/

-> empty config object blobs, no config parsing involved (just 200MB each)

icinga2a

[2017-08-17 15:02:37 +0200] warning/ApiListener: Error while replaying log for endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b86cc _ZN6icinga11ApiListener9ReplayLogERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 4108
	(5) 7   libremote.2.7.0.dylib               0x00000001018b5139 _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 841
	(6) 8   libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(7) 9   libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(8) 10  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(9) 11  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13


	(0) Replaying log for Endpoint 'icinga2b'

Context:
	(0) Replaying log for Endpoint 'icinga2b'

[2017-08-17 15:02:37 +0200] warning/ApiListener: Error while replaying log for endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b86cc _ZN6icinga11ApiListener9ReplayLogERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 4108
	(5) 7   libremote.2.7.0.dylib               0x00000001018b5139 _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 841
	(6) 8   libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(7) 9   libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(8) 10  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(9) 11  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13


	(0) Replaying log for Endpoint 'icinga2b'

Context:
	(0) Replaying log for Endpoint 'icinga2b'

[2017-08-17 15:02:37 +0200] warning/ApiListener: Error while replaying log for endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b86cc _ZN6icinga11ApiListener9ReplayLogERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 4108
	(5) 7   libremote.2.7.0.dylib               0x00000001018b5139 _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 841
	(6) 8   libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(7) 9   libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(8) 10  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(9) 11  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13


	(0) Replaying log for Endpoint 'icinga2b'

Context:
	(0) Replaying log for Endpoint 'icinga2b'

[2017-08-17 15:02:37 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2b'.
[2017-08-17 15:02:39 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 11683, rate: 8369.75/s (502185/min 1576376/5min 1576377/15min);
[2017-08-17 15:02:46 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 9482.93/s (568977/min 2093183/5min 5279948/15min);
[2017-08-17 15:02:49 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 17636, rate: 9201.08/s (552065/min 1658705/5min 1658706/15min);
[2017-08-17 15:02:56 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24994, rate: 9544.33/s (572661/min 1746240/5min 5378738/15min);
[2017-08-17 15:02:59 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 49516, rate: 8825.97/s (529558/min 1725992/5min 1741980/15min); empty in 15 seconds
[2017-08-17 15:03:02 +0200] information/ApiListener: New client connection for identity 'icinga2b' from [::1]:52202
[2017-08-17 15:03:02 +0200] information/ApiListener: Applying config update from endpoint 'icinga2b' of zone 'master'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2b'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'icinga2b'.
[2017-08-17 15:03:06 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24996, rate: 9986.35/s (599181/min 1827335/5min 5514668/15min);
[2017-08-17 15:03:06 +0200] information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate: 0.0166667/s (1/min 2/5min 2/15min);
[2017-08-17 15:03:08 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:03:08 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:03:08 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:03:09 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 88959, rate: 8385.38/s (503123/min 1753345/5min 1834597/15min); empty in 22 seconds
[2017-08-17 15:03:16 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'icinga2b'.
[2017-08-17 15:03:16 +0200] information/ApiListener: Syncing configuration files for zone 'satellite' to endpoint 'icinga2b'.
[2017-08-17 15:03:16 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24976, rate: 9715.47/s (582929/min 1899190/5min 5618588/15min);
[2017-08-17 15:03:18 +0200] information/WorkQueue: #9 (JsonRpcConnection, #1) items: 0, rate: 0.516667/s (31/min 76/5min 76/15min);
[2017-08-17 15:03:19 +0200] information/WorkQueue: #8 (JsonRpcConnection, #0) items: 0, rate: 0.533333/s (32/min 65/5min 65/15min);
[2017-08-17 15:03:19 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 80139, rate: 8623.53/s (517412/min 1830713/5min 1942461/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:03:23 +0200] information/WorkQueue: #11 (JsonRpcConnection, #3) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 15:03:23 +0200] information/WorkQueue: #10 (JsonRpcConnection, #2) items: 0, rate: 0.433333/s (26/min 26/5min 26/15min);
[2017-08-17 15:03:26 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24982, rate: 10311.6/s (618699/min 1958900/5min 5732387/15min);
[2017-08-17 15:03:29 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 101571, rate: 8733.02/s (523981/min 1869296/5min 2031254/15min); empty in 47 seconds
[2017-08-17 15:03:33 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2b'.
[2017-08-17 15:03:36 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24996, rate: 10909.1/s (654547/min 1985279/5min 5839435/15min);
[2017-08-17 15:03:39 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 108578, rate: 9352.38/s (561143/min 1885552/5min 2142367/15min); empty in 2 minutes and 34 seconds
[2017-08-17 15:03:46 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 23230, rate: 10852.1/s (651125/min 1994633/5min 5937292/15min);
[2017-08-17 15:03:49 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 177386, rate: 9296.42/s (557785/min 1887168/5min 2160231/15min); empty in 25 seconds
[2017-08-17 15:03:56 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 10741.1/s (644467/min 2018843/5min 6031025/15min);
[2017-08-17 15:03:59 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 251248, rate: 7233.53/s (434012/min 1772678/5min 2180145/15min); empty in 34 seconds
[2017-08-17 15:04:06 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24995, rate: 9588.57/s (575315/min 2012703/5min 6097563/15min);
[2017-08-17 15:04:08 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:04:08 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:04:08 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:04:10 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 199152, rate: 7445.93/s (446756/min 1825369/5min 2296693/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:04:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2b'
[2017-08-17 15:04:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2b'. 0 API clients left.
[2017-08-17 15:04:16 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24928, rate: 9010.98/s (540659/min 2067642/5min 6164883/15min);
[2017-08-17 15:04:20 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 188530, rate: 6953.97/s (417238/min 1902547/5min 2373871/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:04:26 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24999, rate: 8219.7/s (493185/min 2133125/5min 6230366/15min);
[2017-08-17 15:04:30 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 206055, rate: 6267.82/s (376069/min 1951726/5min 2423050/15min); empty in 1 minute and 57 seconds
[2017-08-17 15:04:36 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24998, rate: 7641.9/s (458514/min 2207222/5min 6304463/15min);
[2017-08-17 15:04:40 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 236488, rate: 5154.87/s (309292/min 1994088/5min 2465412/15min); empty in 1 minute and 17 seconds
[2017-08-17 15:04:46 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24984, rate: 7175.65/s (430539/min 2273796/5min 6371037/15min);
[2017-08-17 15:04:49 +0200] critical/ApiListener: Error while syncing endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b4653 _ZN6icinga7JsonRpc11SendMessageERKN5boost13intrusive_ptrINS_6StreamEEERKNS2_INS_10DictionaryEEE + 147
	(5) 7   libremote.2.7.0.dylib               0x00000001018c3a96 _ZN6icinga11ApiListener18UpdateConfigObjectERKN5boost13intrusive_ptrINS_12ConfigObjectEEERKNS2_INS_13MessageOriginEEERKNS2_INS_17JsonRpcConnectionEEE + 4886
	(6) 8   libremote.2.7.0.dylib               0x00000001018b7342 _ZN6icinga11ApiListener24SendRuntimeConfigObjectsERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 434
	(7) 9   libremote.2.7.0.dylib               0x00000001018b4fad _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 445
	(8) 10  libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(9) 11  libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(11) 13  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(12) 14  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13


[2017-08-17 15:04:50 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 272008, rate: 5507.92/s (330475/min 2019382/5min 2490706/15min); empty in 1 minute and 16 seconds
[2017-08-17 15:04:56 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 6642.25/s (398535/min 2304280/5min 6433696/15min);
[2017-08-17 15:05:00 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 298431, rate: 5523.67/s (331420/min 2027247/5min 2538109/15min); empty in 1 minute and 52 seconds
[2017-08-17 15:05:02 +0200] information/ApiListener: New client connection for identity 'icinga2b' from [::1]:52212
[2017-08-17 15:05:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2b'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'icinga2b'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Applying config update from endpoint 'icinga2b' of zone 'master'.
[2017-08-17 15:05:06 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 7286.82/s (437209/min 2320196/5min 6538430/15min);
[2017-08-17 15:05:08 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:05:08 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:05:08 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:05:10 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 345343, rate: 4878.07/s (292684/min 1961476/5min 2597572/15min); empty in 1 minute and 13 seconds
[2017-08-17 15:05:16 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'icinga2b'.
[2017-08-17 15:05:16 +0200] information/ApiListener: Syncing configuration files for zone 'satellite' to endpoint 'icinga2b'.
[2017-08-17 15:05:16 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24995, rate: 7485.78/s (449148/min 2288018/5min 6617553/15min);
[2017-08-17 15:05:20 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 358429, rate: 4622.08/s (277325/min 2007724/5min 2656914/15min); empty in 4 minutes and 33 seconds
[2017-08-17 15:05:26 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24990, rate: 7311.85/s (438711/min 2248088/5min 6673075/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:05:30 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 362544, rate: 4742.45/s (284547/min 1975516/5min 2712081/15min); empty in 14 minutes and 41 seconds
[2017-08-17 15:05:36 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24973, rate: 7341.77/s (440506/min 2273733/5min 6748961/15min);
[2017-08-17 15:05:37 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2b'.
[2017-08-17 15:05:40 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 389113, rate: 5089.43/s (305366/min 1960699/5min 2773998/15min); empty in 2 minutes and 26 seconds
[2017-08-17 15:05:46 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 8044.65/s (482679/min 2305215/5min 6856014/15min);
[2017-08-17 15:05:50 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 416237, rate: 5846.52/s (350791/min 1943337/5min 2843274/15min); empty in 2 minutes and 33 seconds
[2017-08-17 15:05:56 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24992, rate: 8215.68/s (492941/min 2286471/5min 6929751/15min);
[2017-08-17 15:06:00 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 415442, rate: 6055.88/s (363353/min 1933948/5min 2907101/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:06:06 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24999, rate: 7522.13/s (451329/min 2295355/5min 6995463/15min);
[2017-08-17 15:06:08 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:06:08 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:06:08 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:06:10 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 431116, rate: 6035.98/s (362159/min 1889441/5min 2963633/15min); empty in 4 minutes and 35 seconds
[2017-08-17 15:06:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2b'
[2017-08-17 15:06:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2b'. 0 API clients left.
[2017-08-17 15:06:16 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24998, rate: 7393.15/s (443589/min 2364581/5min 7064689/15min);
[2017-08-17 15:06:20 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 446402, rate: 5867.37/s (352042/min 1940504/5min 3014696/15min); empty in 4 minutes and 52 seconds
[2017-08-17 15:06:26 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 25000, rate: 7455.97/s (447358/min 2423701/5min 7123809/15min); empty in 1 day, 10 hours, 43 minutes and 26 seconds
[2017-08-17 15:06:30 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 467170, rate: 5631.3/s (337878/min 1981917/5min 3056109/15min); empty in 3 minutes and 44 seconds
[2017-08-17 15:06:36 +0200] information/WorkQueue: #7 (DaemonCommand::Run) items: 24994, rate: 7164.13/s (429849/min 2482346/5min 7182454/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:06:40 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 501406, rate: 5067.68/s (304061/min 2009674/5min 3083866/15min); empty in 2 minutes and 26 seconds
[2017-08-17 15:06:44 +0200] critical/ApiListener: Error while syncing endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b4653 _ZN6icinga7JsonRpc11SendMessageERKN5boost13intrusive_ptrINS_6StreamEEERKNS2_INS_10DictionaryEEE + 147
	(5) 7   libremote.2.7.0.dylib               0x00000001018c3a96 _ZN6icinga11ApiListener18UpdateConfigObjectERKN5boost13intrusive_ptrINS_12ConfigObjectEEERKNS2_INS_13MessageOriginEEERKNS2_INS_17JsonRpcConnectionEEE + 4886
	(6) 8   libremote.2.7.0.dylib               0x00000001018b7342 _ZN6icinga11ApiListener24SendRuntimeConfigObjectsERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 434
	(7) 9   libremote.2.7.0.dylib               0x00000001018b4fad _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 445
	(8) 10  libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(9) 11  libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(11) 13  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(12) 14  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13


[2017-08-17 15:06:45 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 15:06:50 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 440996, rate: 5607.92/s (336475/min 2068602/5min 3184656/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:07:00 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 278444, rate: 7254.27/s (435256/min 2122114/5min 3347209/15min); empty in infinite time, your task handler isn't able to keep up
[2017-08-17 15:07:02 +0200] information/ApiListener: New client connection for identity 'icinga2b' from [::1]:52243
[2017-08-17 15:07:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2b'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'icinga2b'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Applying config update from endpoint 'icinga2b' of zone 'master'.
[2017-08-17 15:07:08 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:07:08 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:07:08 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:07:09 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'icinga2b'.
[2017-08-17 15:07:09 +0200] information/ApiListener: Syncing configuration files for zone 'satellite' to endpoint 'icinga2b'.
[2017-08-17 15:07:10 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 95682, rate: 9375.95/s (562557/min 2183721/5min 3529972/15min); empty in infinite time, your task handler isn't able to keep up
^C[2017-08-17 15:07:25 +0200] information/Application: Received request to shut down.
[2017-08-17 15:07:25 +0200] information/Application: Shutting down...
[2017-08-17 15:07:25 +0200] information/ApiListener: 'api' stopped.
[2017-08-17 15:07:26 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 13400, rate: 10190/s (611399/min 2203255/5min 3612253/15min);
[2017-08-17 15:07:27 +0200] warning/TlsStream: TLS stream was disconnected.
[2017-08-17 15:07:27 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2b'
[2017-08-17 15:07:27 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2b'. 0 API clients left.
[2017-08-17 15:07:27 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2b'.
[2017-08-17 15:07:28 +0200] critical/ApiListener: Error while syncing endpoint 'icinga2b': Error: Tried to read/write from a closed socket.

	(0) 2   libbase.2.7.0.dylib                 0x0000000101c915bd _ZN5boost16exception_detail16throw_exception_ISt13runtime_errorEEvRKT_PKcS7_i + 93
	(1) 3   libbase.2.7.0.dylib                 0x0000000101ce45cd _ZN6icinga21SocketEventEnginePoll12ChangeEventsEPNS_12SocketEventsEi + 413
	(2) 4   libbase.2.7.0.dylib                 0x0000000101cf0b26 _ZN6icinga9TlsStream5WriteEPKvm + 102
	(3) 5   libbase.2.7.0.dylib                 0x0000000101cba882 _ZN6icinga9NetString19WriteStringToStreamERKN5boost13intrusive_ptrINS_6StreamEEERKNS_6StringE + 434
	(4) 6   libremote.2.7.0.dylib               0x00000001018b4653 _ZN6icinga7JsonRpc11SendMessageERKN5boost13intrusive_ptrINS_6StreamEEERKNS2_INS_10DictionaryEEE + 147
	(5) 7   libremote.2.7.0.dylib               0x00000001018c3a96 _ZN6icinga11ApiListener18UpdateConfigObjectERKN5boost13intrusive_ptrINS_12ConfigObjectEEERKNS2_INS_13MessageOriginEEERKNS2_INS_17JsonRpcConnectionEEE + 4886
	(6) 8   libremote.2.7.0.dylib               0x00000001018b7342 _ZN6icinga11ApiListener24SendRuntimeConfigObjectsERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEE + 434
	(7) 9   libremote.2.7.0.dylib               0x00000001018b4fad _ZN6icinga11ApiListener10SyncClientERKN5boost13intrusive_ptrINS_17JsonRpcConnectionEEERKNS2_INS_8EndpointEEEb + 445
	(8) 10  libbase.2.7.0.dylib                 0x0000000101d0a3fb _ZN6icinga9WorkQueue16WorkerThreadProcEv + 1355
	(9) 11  libboost_thread-mt.dylib            0x00000001014dcb84 _ZN5boost12_GLOBAL__N_1L12thread_proxyEPv + 164
	(10) 12  libsystem_pthread.dylib             0x00007fffaf37993b _pthread_body + 180
	(11) 13  libsystem_pthread.dylib             0x00007fffaf379887 _pthread_body + 0
	(12) 14  libsystem_pthread.dylib             0x00007fffaf37908d thread_start + 13

icinga2b

[2017-08-17 14:55:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '7000'
[2017-08-17 14:55:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 14:56:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 14:56:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 14:56:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:56:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:56:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 14:56:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '7000'
[2017-08-17 14:56:13 +0200] information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 14:56:13 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate: 0.0333333/s (2/min 10/5min 30/15min);
[2017-08-17 14:57:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 14:57:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 14:57:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:57:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:57:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '7000'
[2017-08-17 14:57:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 14:57:02 +0200] information/ConfigObject: Dumping program state to file 'icinga2b/lib/icinga2/icinga2.state'
[2017-08-17 14:58:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 14:58:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 14:58:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:58:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:58:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 14:58:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '7000'
[2017-08-17 14:58:08 +0200] information/ApiListener: New client connection for identity 'icinga2a' from [::1]:52131
[2017-08-17 14:58:08 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 14:58:08 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 14:58:08 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 14:58:08 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 14:58:08 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 14:58:18 +0200] information/WorkQueue: #10 (JsonRpcConnection, #2) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 14:58:18 +0200] information/WorkQueue: #8 (JsonRpcConnection, #0) items: 0, rate: 0.05/s (3/min 3/5min 3/15min);
[2017-08-17 14:58:18 +0200] information/WorkQueue: #11 (JsonRpcConnection, #3) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 14:58:18 +0200] information/WorkQueue: #9 (JsonRpcConnection, #1) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 14:59:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 14:59:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 14:59:01 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 14:59:40 +0200] information/ApiListener: Replayed 14 messages.
[2017-08-17 14:59:41 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 14:59:53 +0200] information/JsonRpcConnection: No messages for identity 'icinga2a' have been received in the last 60 seconds.
[2017-08-17 14:59:53 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 14:59:53 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 14:59:53 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 14:59:53 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:00:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 15:00:01 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:00:01 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:00:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:00:02 +0200] information/ApiListener: New client connection for identity 'icinga2a' to [::1]:7000
[2017-08-17 15:00:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:00:02 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:00:02 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:00:02 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:00:02 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:01:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:01:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:01:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:01:13 +0200] information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate: 0.0166667/s (1/min 1/5min 1/15min);
[2017-08-17 15:01:13 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate: 0.0333333/s (2/min 10/5min 30/15min);
[2017-08-17 15:01:44 +0200] information/ApiListener: Replayed 14 messages.
[2017-08-17 15:01:44 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:01:53 +0200] information/JsonRpcConnection: No messages for identity 'icinga2a' have been received in the last 60 seconds.
[2017-08-17 15:01:53 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:02:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:02:02 +0200] information/ConfigObject: Dumping program state to file 'icinga2b/lib/icinga2/icinga2.state'
[2017-08-17 15:02:09 +0200] warning/JsonRpcConnection: Client for endpoint 'icinga2a' has requested heartbeat message but hasn't responded in time. Closing connection.
[2017-08-17 15:02:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:02:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:02:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:02:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:02:15 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:02:15 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:02:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:03:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 15:03:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:03:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:03:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:03:02 +0200] information/ApiListener: New client connection for identity 'icinga2a' to [::1]:7000
[2017-08-17 15:03:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:03:02 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:03:04 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:03:18 +0200] information/WorkQueue: #10 (JsonRpcConnection, #2) items: 0, rate: 0.0833333/s (5/min 5/5min 5/15min);
[2017-08-17 15:03:18 +0200] information/WorkQueue: #9 (JsonRpcConnection, #1) items: 0, rate: 0.05/s (3/min 3/5min 3/15min);
[2017-08-17 15:03:20 +0200] information/WorkQueue: #8 (JsonRpcConnection, #0) items: 0, rate: 0.05/s (3/min 3/5min 3/15min);
[2017-08-17 15:03:25 +0200] information/WorkQueue: #11 (JsonRpcConnection, #3) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 15:04:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:04:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:04:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:04:15 +0200] information/JsonRpcConnection: No messages for identity 'icinga2a' have been received in the last 60 seconds.
[2017-08-17 15:04:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:04:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:04:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:04:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:05:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:05:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 15:05:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:05:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:05:02 +0200] information/ApiListener: New client connection for identity 'icinga2a' to [::1]:7000
[2017-08-17 15:05:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:05:02 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:06:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:06:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:06:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:06:13 +0200] information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate: 0.0166667/s (1/min 3/5min 4/15min);
[2017-08-17 15:06:15 +0200] information/JsonRpcConnection: No messages for identity 'icinga2a' have been received in the last 60 seconds.
[2017-08-17 15:06:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:06:15 +0200] warning/JsonRpcConnection: API client disconnected for identity 'icinga2a'
[2017-08-17 15:06:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:06:15 +0200] warning/ApiListener: Removing API client for endpoint 'icinga2a'. 0 API clients left.
[2017-08-17 15:06:20 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate: 0.0333333/s (2/min 10/5min 30/15min);
[2017-08-17 15:07:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 15:07:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 15:07:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 15:07:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 15:07:02 +0200] information/ApiListener: New client connection for identity 'icinga2a' to [::1]:7000
[2017-08-17 15:07:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:07:02 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 15:07:15 +0200] information/ConfigObject: Dumping program state to file 'icinga2b/lib/icinga2/icinga2.state'
^C[2017-08-17 15:07:26 +0200] information/Application: Received request to shut down.
[2017-08-17 15:07:26 +0200] information/Application: Shutting down...
[2017-08-17 15:07:26 +0200] information/ApiListener: 'api' stopped.
[2017-08-17 15:07:26 +0200] information/ConfigObject: Dumping program state to file 'icinga2b/lib/icinga2/icinga2.state'
[2017-08-17 15:07:26 +0200] information/IcingaApplication: Icinga has shut down.
mbmif /usr/local/tests/icinga2/master-slave (master *+) #

dnsmichi · 2017-08-17T14:10:49Z

Applied a possible fix, tests.

Config:

mbmif /usr/local/tests/icinga2/master-slave/icinga2a/etc/icinga2/zones.d/master (master *+) # ls -lah
total 420560
drwxr-xr-x  9 icinga  staff   306B Aug 17 15:36 .
drwxr-xr-x  5 icinga  staff   170B Oct  2  2015 ..
-rw-r--r--  1 root    staff   102B May  3  2016 abc.conf
-rw-r--r--  1 root    staff   191B Jun 21  2016 hosts.conf
-rw-r--r--  1 root    staff   171B Jan 27  2016 hosts2.conf.dis
-rw-r--r--  1 root    staff   407B Nov 10  2016 many.conf.dis
-rw-r--r--  1 root    staff   1.5K Jun 24  2016 remote.conf
-rw-r--r--  1 root    staff   101M Aug 17 15:36 test_hosts.conf
-rw-r--r--  1 root    staff   104M Aug 17 15:36 test_hosts2.conf

icinga2a

mbmif /usr/local/tests/icinga2/master-slave (master *+) # ./run icinga2a
[2017-08-17 16:05:54 +0200] information/cli: Icinga application loader (version: v2.7.0-58-g52dcce972)
[2017-08-17 16:05:54 +0200] information/cli: Loading configuration file(s).
[2017-08-17 16:05:59 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:05:59 +0200] information/ApiListener: My API identity: icinga2a
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 63 CheckCommands.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 139 Services.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 5 Users.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 19 Downtimes.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 52 Hosts.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 2 NotificationCommands.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 141 Notifications.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 3 Endpoints.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 3 Zones.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 1 ApiListener.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Instantiated 1 ApiUser.
[2017-08-17 16:05:59 +0200] information/ScriptGlobal: Dumping variables to file 'icinga2a/cache/icinga2/icinga2.vars'
[2017-08-17 16:05:59 +0200] information/ConfigObject: Restoring program state from file 'icinga2a/lib/icinga2/icinga2.state'
[2017-08-17 16:05:59 +0200] information/ConfigObject: Restored 430 objects. Loaded 0 new objects without state.
[2017-08-17 16:05:59 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:05:59 +0200] information/ApiListener: 'api' started.
[2017-08-17 16:05:59 +0200] information/ApiListener: Copying 2 zone configuration files for zone 'global-templates' to 'icinga2a/lib/icinga2/api/zones/global-templates'.
[2017-08-17 16:05:59 +0200] information/ApiListener: Applying configuration file update for path 'icinga2a/lib/icinga2/api/zones/global-templates'. Received timestamp '2017-08-17 16:05:59 +0200' (1502978759.287623) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:05:59 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/global-templates//_etc/notifications.conf
[2017-08-17 16:05:59 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/global-templates//_etc/templates.conf.dis
[2017-08-17 16:06:01 +0200] information/ApiListener: Copying 9 zone configuration files for zone 'master' to 'icinga2a/lib/icinga2/api/zones/master'.
[2017-08-17 16:06:01 +0200] information/ApiListener: Applying configuration file update for path 'icinga2a/lib/icinga2/api/zones/master'. Received timestamp '2017-08-17 16:06:01 +0200' (1502978761.577253) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_api/hosts/api-sync-host.conf
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/abc.conf
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/hosts.conf
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/hosts2.conf.dis
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/many.conf.dis
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/remote.conf
[2017-08-17 16:06:01 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/test_hosts.conf
[2017-08-17 16:06:02 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//_etc/test_hosts2.conf
[2017-08-17 16:06:02 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/master//example-cmdb/test.conf
[2017-08-17 16:06:02 +0200] information/ApiListener: Copying 2 zone configuration files for zone 'satellite' to 'icinga2a/lib/icinga2/api/zones/satellite'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Applying configuration file update for path 'icinga2a/lib/icinga2/api/zones/satellite'. Received timestamp '2017-08-17 16:06:02 +0200' (1502978762.328505) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:06:02 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/satellite//_etc/hosts.conf
[2017-08-17 16:06:02 +0200] information/ApiListener: Updating configuration file: icinga2a/lib/icinga2/api/zones/satellite//_etc/many.conf
[2017-08-17 16:06:02 +0200] information/ApiListener: Adding new listener on port '7000'
[2017-08-17 16:06:02 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2b' via host 'localhost' and port '8000'
[2017-08-17 16:06:02 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 16:06:02 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 16:06:02 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 16:06:02 +0200] information/ApiListener: New client connection for identity 'icinga2b' to [::1]:8000
[2017-08-17 16:06:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2b'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'icinga2b'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'icinga2b'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Applying config update from endpoint 'icinga2b' of zone 'master'.
[2017-08-17 16:06:04 +0200] information/ApiListener: Syncing configuration files for zone 'satellite' to endpoint 'icinga2b'.
[2017-08-17 16:06:06 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2b'.
[2017-08-17 16:06:06 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2b'.
[2017-08-17 16:06:06 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2b'.
[2017-08-17 16:06:06 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2b'.
[2017-08-17 16:06:06 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2b'.

icinga2b

mbmif /usr/local/tests/icinga2/master-slave (master *+) # ./run icinga2b
[2017-08-17 16:05:47 +0200] information/cli: Icinga application loader (version: v2.7.0-58-g52dcce972)
[2017-08-17 16:05:47 +0200] information/cli: Loading configuration file(s).
[2017-08-17 16:05:47 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:05:47 +0200] information/ApiListener: My API identity: icinga2b
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 62 CheckCommands.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 1 Service.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 3 Users.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 1 Downtime.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 13 Hosts.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 3 Endpoints.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 3 Zones.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 1 ApiListener.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Instantiated 1 ApiUser.
[2017-08-17 16:05:47 +0200] information/ScriptGlobal: Dumping variables to file 'icinga2b/cache/icinga2/icinga2.vars'
[2017-08-17 16:05:47 +0200] information/ConfigObject: Restoring program state from file 'icinga2b/lib/icinga2/icinga2.state'
[2017-08-17 16:05:47 +0200] information/ConfigObject: Restored 430 objects. Loaded 0 new objects without state.
[2017-08-17 16:05:47 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:05:47 +0200] information/ApiListener: 'api' started.
[2017-08-17 16:05:47 +0200] information/ApiListener: Adding new listener on port '8000'
[2017-08-17 16:05:47 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:05:47 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2a' via host 'localhost' and port '7000'
[2017-08-17 16:05:47 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-08-17 16:05:47 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 16:05:47 +0200] critical/TcpSocket: Invalid socket: Connection refused
[2017-08-17 16:05:47 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '7000'
[2017-08-17 16:05:47 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-08-17 16:05:57 +0200] information/WorkQueue: #4 (ApiListener, RelayQueue) items: 0, rate: 0.533333/s (32/min 32/5min 32/15min);
[2017-08-17 16:05:57 +0200] information/WorkQueue: #5 (ApiListener, SyncQueue) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 16:06:02 +0200] information/ApiListener: New client connection for identity 'icinga2a' from [::1]:52898
[2017-08-17 16:06:02 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2a'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Finished syncing runtime objects to endpoint 'icinga2a'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Finished sending config updates for endpoint 'icinga2a'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Sending replay log for endpoint 'icinga2a'.
[2017-08-17 16:06:02 +0200] information/ApiListener: Finished sending replay log for endpoint 'icinga2a'.
[2017-08-17 16:06:12 +0200] information/WorkQueue: #10 (JsonRpcConnection, #2) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 16:06:12 +0200] information/WorkQueue: #9 (JsonRpcConnection, #1) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 16:06:12 +0200] information/WorkQueue: #11 (JsonRpcConnection, #3) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2017-08-17 16:06:12 +0200] information/WorkQueue: #8 (JsonRpcConnection, #0) items: 0, rate: 0.0166667/s (1/min 1/5min 1/15min);
[2017-08-17 16:06:13 +0200] information/ApiListener: Applying config update from endpoint 'icinga2a' of zone 'master'.
[2017-08-17 16:06:13 +0200] information/ApiListener: Applying configuration file update for path 'icinga2b/lib/icinga2/api/zones/global-templates'. Received timestamp '2017-08-17 16:05:59 +0200' (1502978759.287623) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/global-templates//.timestamp
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/global-templates//_etc/notifications.conf
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/global-templates//_etc/templates.conf.dis
[2017-08-17 16:06:13 +0200] information/ApiListener: Applying configuration file update for path 'icinga2b/lib/icinga2/api/zones/master'. Received timestamp '2017-08-17 16:06:01 +0200' (1502978761.577253) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//.timestamp
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_api/hosts/api-sync-host.conf
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/abc.conf
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/hosts.conf
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/hosts2.conf.dis
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/many.conf.dis
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/remote.conf
[2017-08-17 16:06:13 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/test_hosts.conf
[2017-08-17 16:06:14 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//_etc/test_hosts2.conf
[2017-08-17 16:06:14 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/master//example-cmdb/test.conf
[2017-08-17 16:06:14 +0200] information/ApiListener: Applying configuration file update for path 'icinga2b/lib/icinga2/api/zones/satellite'. Received timestamp '2017-08-17 16:06:02 +0200' (1502978762.328505) is more recent than current timestamp '1970-01-01 01:00:00 +0100' (0.000000).
[2017-08-17 16:06:14 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/satellite//.timestamp
[2017-08-17 16:06:14 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/satellite//_etc/hosts.conf
[2017-08-17 16:06:14 +0200] information/ApiListener: Updating configuration file: icinga2b/lib/icinga2/api/zones/satellite//_etc/many.conf
[2017-08-17 16:06:14 +0200] information/ApiListener: Restarting after configuration change.
[2017-08-17 16:06:14 +0200] information/Application: Got reload command: Starting new instance.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:14 +0200] information/ConfigItem: Committing config item(s).
[2017-08-17 16:06:14 +0200] information/ConfigItem: Triggering Start signal for config items
[2017-08-17 16:06:14 +0200] information/ConfigItem: Activated all objects.
[2017-08-17 16:06:19 +0200] information/Application: Received request to shut down.
[2017-08-17 16:06:19 +0200] information/Application: Shutting down...
[2017-08-17 16:06:19 +0200] information/ApiListener: 'api' stopped.
[2017-08-17 16:06:19 +0200] information/ConfigObject: Dumping program state to file 'icinga2b/lib/icinga2/icinga2.state'
[2017-08-17 16:06:19 +0200] information/IcingaApplication: Icinga has shut down.

dnsmichi · 2017-08-17T16:08:03Z

@mwaldmueller that's how a perfect issue report for reproducing an issue must look like. should be the standard case 👍

dnsmichi · 2017-08-21T08:30:18Z

I'm playing with some more additional logging, i.e. the bytes synced for a specific zone. This does not replace #5509 but only serves as a base though.

[2017-08-21 10:27:42 +0200] information/ApiListener: Applying configuration file update for path 'icinga2a/lib/icinga2/api/zones/master' (215305421 Bytes). Received timestamp '2017-08-21 10:27:41 +0200' (1503304061.896330), Current timestamp '1970-01-01 01:00:00 +0100' (0.000000).

refs #5513

This has been added years ago when we had one thread per client. This changed, but we shouldn't entirely remove this cleanup timer. Instead, move the disconnect timer from 1m to 5m. refs #5513

refs #5513

dnsmichi · 2017-08-21T09:41:03Z

I've split the commits into 3 separate PRs.

Change FIFO::Optimize() frequency for large messages #5524 should fix the issue, merged to master.

Please test that in your master zone using the snapshot packages. icinga2 --version must be greater equal than this: v2.7.0-71

Use the attached files and just let it sync between two master inside their master zone.

master.zip

Successful tests and feedback are mandatory for a backport to 2.7.x.

Enhance client connect/sync logging and include bytes/zone in logs #5523 enhances the logging and adds byte count logging per zone config sync files (log message)

This is independent from the fix, but helps with support. Can be backported to 2.7.x without any special requirements.

Reduce client disconnect frequency #5525 reduces the disconnect frequency.

This PR is to-be-discussed and won't be merged to master now.

This change won't be backported to 2.7.x as this changes the behaviour.

dnsmichi · 2017-08-21T11:46:38Z

@darmagan waiting for your tests.

darmagan · 2017-08-30T12:42:03Z

We have tested this for ubuntu 14.04 and Suse Enterprise. It fixes the closed socket crashes.
There are still entries that say that there are no messages received for 60 secs from satellites, but the timestamps of the Endpoint objects don't show critical delays.

dnsmichi · 2017-08-30T13:19:16Z

Ok, thanks. The referenced PRs #5524 and #5523 will be backported to 2.7.1.

refs #5513 refs #5524

refs #5513 refs #5523

dnsmichi assigned dnsmichi and gunnarbeutner Aug 17, 2017

dnsmichi added bug Something isn't working area/distributed Distributed monitoring (master, satellites, clients) labels Aug 17, 2017

dnsmichi added this to the 2.8.0 milestone Aug 17, 2017

dnsmichi added the blocker Blocks a release or needs immediate attention label Aug 17, 2017

dnsmichi mentioned this issue Aug 17, 2017

[dev.icinga.com #9228] Make disconnecting an api client more graceful #2987

Closed

dnsmichi pushed a commit that referenced this issue Aug 21, 2017

Enhance client connect/sync logging and include bytes/zone in logs

573ec0e

refs #5513

dnsmichi mentioned this issue Aug 21, 2017

Enhance client connect/sync logging and include bytes/zone in logs #5523

Merged

dnsmichi pushed a commit that referenced this issue Aug 21, 2017

Change FIFO::Optimize() frequency for large messages

732a584

refs #5513

dnsmichi mentioned this issue Aug 21, 2017

Change FIFO::Optimize() frequency for large messages #5524

Merged

dnsmichi pushed a commit that referenced this issue Aug 21, 2017

Enhance client connect/sync logging and include bytes/zone in logs

873a553

refs #5513

dnsmichi mentioned this issue Aug 21, 2017

Reduce client disconnect frequency #5525

Closed

dnsmichi assigned darmagan Aug 21, 2017

dnsmichi added the needs feedback We'll only proceed once we hear from you again label Aug 21, 2017

dnsmichi unassigned darmagan Aug 30, 2017

dnsmichi added this to the 2.7.1 milestone Aug 30, 2017

dnsmichi removed this from the 2.8.0 milestone Aug 30, 2017

dnsmichi closed this as completed Aug 30, 2017

dnsmichi removed the needs feedback We'll only proceed once we hear from you again label Aug 30, 2017

dnsmichi pushed a commit that referenced this issue Aug 30, 2017

Change FIFO::Optimize() frequency for large messages

7f787d9

refs #5513 refs #5524

dnsmichi pushed a commit that referenced this issue Aug 30, 2017

Enhance client connect/sync logging and include bytes/zone in logs

c7a5671

refs #5513 refs #5523

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Node in Cluster loses connection #5513

Node in Cluster loses connection #5513

darmagan commented Aug 16, 2017 •

edited by dnsmichi

mwaldmueller commented Aug 16, 2017 •

edited

dnsmichi commented Aug 16, 2017

mwaldmueller commented Aug 17, 2017 •

edited

mwaldmueller commented Aug 17, 2017

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 17, 2017 •

edited

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 21, 2017

dnsmichi commented Aug 21, 2017

dnsmichi commented Aug 21, 2017

darmagan commented Aug 30, 2017 •

edited

dnsmichi commented Aug 30, 2017

Node in Cluster loses connection #5513

Node in Cluster loses connection #5513

Comments

darmagan commented Aug 16, 2017 • edited by dnsmichi

Summary

Infos

Your Environment

mwaldmueller commented Aug 16, 2017 • edited

dnsmichi commented Aug 16, 2017

mwaldmueller commented Aug 17, 2017 • edited

Details

Behaviour

Test 1

Test 2

mwaldmueller commented Aug 17, 2017

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 17, 2017 • edited

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 17, 2017

dnsmichi commented Aug 21, 2017

dnsmichi commented Aug 21, 2017

dnsmichi commented Aug 21, 2017

darmagan commented Aug 30, 2017 • edited

dnsmichi commented Aug 30, 2017

darmagan commented Aug 16, 2017 •

edited by dnsmichi

mwaldmueller commented Aug 16, 2017 •

edited

mwaldmueller commented Aug 17, 2017 •

edited

dnsmichi commented Aug 17, 2017 •

edited

darmagan commented Aug 30, 2017 •

edited