Icinga has terminated unexpectatedly after API interaction

[K0nne]

Describe the bug

Hi!

Today I was wondering about a strange "backend unavailable" flapping in icingaweb2 in our qs stage.
Upon investigating I found out, that our secondary master had died:

/var/log/icinga2.log

[2021-01-05 10:53:12 +0100] information/ConfigObjectUtility: Created and activated object 'HOSTNAME!ab06acac-fad3-48d7-bd9c-8fd1991bd53c' of type 'Downtime'.
[2021-01-05 10:53:12 +0100] information/Downtime: Triggering downtime 'HOSTNAME!CPU!06c488b0-2b95-40cf-96c5-3925a01cfd7b' for checkable 'HOSTNAME!CPU'.
[2021-01-05 10:53:12 +0100] information/ConfigObjectUtility: Created and activated object 'HOSTNAME!CPU!06c488b0-2b95-40cf-96c5-3925a01cfd7b' of type 'Downtime'.
[2021-01-05 10:53:12 +0100] information/Downtime: Triggering downtime 'HOSTNAME!Interface Usage!2cb19350-92b5-4fec-9f15-019bb8b228cd' for checkable 'HOSTNAME!Interface Usage'.
[2021-01-05 10:53:12 +0100] information/ConfigObjectUtility: Created and activated object 'HOSTNAME!Interface Usage!2cb19350-92b5-4fec-9f15-019bb8b228cd' of type 'Downtime'.
[2021-01-05 10:53:12 +0100] information/ConfigObjectUtility: Created and activated object 'HOSTNAME!ping4!3eded8b1-a01c-46ef-a3d2-3783b862e8aa' of type 'Downtime'.
[2021-01-05 10:53:13 +0100] information/Checkable: Checkable 'HOSTNAME' has 2 notification(s). Checking filters for type 'DowntimeStart', sends will be logged.
[2021-01-05 10:53:13 +0100] information/Notification: Sending 'DowntimeStart' notification 'HOSTNAME!DOWNTIMENAME' for user 'ICINGAUSER'
[2021-01-05 10:53:13 +0100] information/Notification: Completed sending 'DowntimeStart' notification 'HOSTNAME!DOWNTIMENAME' for checkable 'HOSTNAME' and user 'ICINGAUSER' using command 'DATEVitm-notification'.
[2021-01-05 10:53:17 +0100] information/Downtime: Triggering downtime 'HOSTNAME!ab06acac-fad3-48d7-bd9c-8fd1991bd53c' for checkable 'HOSTNAME'.
[2021-01-05 10:53:17 +0100] information/Checkable: Checkable 'HOSTNAME!ping4' has 1 notification(s). Checking filters for type 'DowntimeStart', sends will be logged.
[2021-01-05 10:53:17 +0100] information/Downtime: Triggering downtime 'HOSTNAME!ping4!3eded8b1-a01c-46ef-a3d2-3783b862e8aa' for checkable 'HOSTNAME!ping4'.
[2021-01-05 10:53:38 +0100] information/ConfigObject: Dumping program state to file '/var/lib/icinga2/icinga2.state'

[2021-01-05 10:57:22 +0100] information/Checkable: Checkable 'HOSTNAME!CPU' has 1 notification(s). Checking filters for type 'DowntimeEnd', sends will be logged.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!CPU!06c488b0-2b95-40cf-96c5-3925a01cfd7b' of type 'Downtime'.
[2021-01-05 10:57:22 +0100] information/Checkable: Checkable 'HOSTNAME!Interface Usage' has 1 notification(s). Checking filters for type 'DowntimeEnd', sends will be logged.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!Interface Usage!2cb19350-92b5-4fec-9f15-019bb8b228cd' of type 'Downtime'.
[2021-01-05 10:57:22 +0100] information/Checkable: Checkable 'HOSTNAME!ping4' has 1 notification(s). Checking filters for type 'DowntimeEnd', sends will be logged.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!ping4!3eded8b1-a01c-46ef-a3d2-3783b862e8aa' of type 'Downtime'.
[2021-01-05 10:57:22 +0100] information/Checkable: Checkable 'HOSTNAME' has 2 notification(s). Checking filters for type 'DowntimeEnd', sends will be logged.
[2021-01-05 10:57:22 +0100] information/Notification: Sending 'DowntimeEnd' notification 'HOSTNAME!DOWNTIMENAME' for user 'ICINGAUSER'
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!ab06acac-fad3-48d7-bd9c-8fd1991bd53c' of type 'Downtime'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!Interface Usage!DATEVitm-netzwerkservice' of type 'Notification'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!CPU!DATEVitm-netzwerkservice' of type 'Notification'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!DOWNTIMENAME' of type 'Notification'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!NOTIFICATIONNAME-HOST' of type 'Notification'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!CPU' of type 'Service'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!Interface Usage' of type 'Service'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!ping4!NOTIFICATIONNAME-SERVICE' of type 'Notification'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME!ping4' of type 'Service'.
[2021-01-05 10:57:22 +0100] information/ConfigObjectUtility: Deleted object 'HOSTNAME' of type 'Host'.
[2021-01-05 10:57:22 +0100] critical/Application: Icinga 2 has terminated unexpectedly. Additional information can be found in '/var/log/icinga2/crash/report.1609840642.827869'

[2021-01-05 10:59:17 +0100] information/ApiListener: New client connection for identity 'MASTER01' from [x.x.x.x]:44222
[2021-01-05 10:59:27 +0100] information/ApiListener: New client connection for identity 'MASTER01' from [x.x.x.x]:44266
[2021-01-05 10:59:37 +0100] information/ApiListener: New client connection for identity 'MASTER01' from [x.x.x.x]:44294
[2021-01-05 10:59:47 +0100] information/ApiListener: New client connection for identity 'MASTER01' from [x.x.x.x]:44306

<...>
The same logfiles repeat every 10 seconds until manual icinga2 restart this morning. It seems like the 2nd master was not able to receive any data after this.

/var/log/icinga2/crash/report.1609840642.827869

  Application version: 2.11.7-1

System information:
  Platform: Red Hat Enterprise Linux Server
  Platform version: 7.9 (Maipo)
  Kernel: Linux
  Kernel version: 3.10.0-1160.6.1.el7.x86_64
  Architecture: x86_64

Build information:
  Compiler: GNU 4.8.5
  Build host: runner-hh8q3bz2-project-322-concurrent-0

Application information:

General paths:
  Config directory: /etc/icinga2
  Data directory: /var/lib/icinga2
  Log directory: /var/log/icinga2
  Cache directory: /var/cache/icinga2
  Spool directory: /var/spool/icinga2
  Run directory: /run/icinga2

Old paths (deprecated):
  Installation root: /usr
  Sysconf directory: /etc
  Run directory (base): /run
  Local state directory: /var

Internal paths:
  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
Stacktrace:

        (0) libc.so.6: gsignal (+0x37) [0x7ff5bdfaa387]
        (1) libc.so.6: abort (+0x148) [0x7ff5bdfaba78]
        (2) libc.so.6: <unknown function> (+0x78ed7) [0x7ff5bdfeced7]
        (3) libc.so.6: <unknown function> (+0x7f3e4) [0x7ff5bdff33e4]
        (4) libc.so.6: <unknown function> (+0x814db) [0x7ff5bdff54db]
        (5) icinga2: icinga::Notification::ExecuteNotificationHelper(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&) (+0x1df) [0xa31e7f]
        (6) icinga2: std::_Function_handler<void (), std::_Bind<std::_Mem_fn<void (icinga::Notification::*)(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)> (icinga::Notification*, icinga::NotificationType, boost::intrusive_ptr<icinga::User>, boost::intrusive_ptr<icinga::CheckResult>, bool, icinga::String, icinga::String)> >::_M_invoke(std::_Any_data const&) (+0x42) [0xa2bf22]
        (7) /usr/lib64/icinga2/sbin/icinga2() [0x907b33]
        (8) icinga2: boost::asio::detail::executor_op<boost::asio::detail::work_dispatcher<bool icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>, std::allocator<void>, boost::asio::detail::scheduler_operation>::do_complete(void*, std::allocator<void>*, boost::system::error_code const&, unsigned long) (+0x106) [0xbfed66]
        (9) /usr/lib64/icinga2/sbin/icinga2() [0x6313e1]
        (10) /usr/lib64/icinga2/sbin/icinga2() [0x631732]
        (11) icinga2: boost_asio_detail_posix_thread_function (+0xf) [0x823d5f]
        (12) libpthread.so.0: <unknown function> (+0x7ea5) [0x7ff5be349ea5]
        (13) libc.so.6: clone (+0x6d) [0x7ff5be07296d]

***
* This would indicate a runtime problem or configuration error. If you believe this is a bug in Icinga 2
* please submit a bug report at https://github.com/Icinga/icinga2 and include this stack trace as well as any other
* information that might be useful in order to reproduce this problem.
***

/var/log/icinga2/error.log

*** Error in `/usr/lib64/icinga2/sbin/icinga2': corrupted size vs. prev_size: 0x00007ff4f404e630 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7f3e4)[0x7ff5bdff33e4]
/lib64/libc.so.6(+0x814db)[0x7ff5bdff54db]
/usr/lib64/icinga2/sbin/icinga2(_ZN6icinga12Notification25ExecuteNotificationHelperENS_16NotificationTypeERKN5boost13intrusive_ptrINS_4UserEEERKNS3_INS_11CheckResultEEEbRKNS_6StringESE_+0x1df)[0xa31e7f]
/usr/lib64/icinga2/sbin/icinga2(_ZNSt17_Function_handlerIFvvESt5_BindIFSt7_Mem_fnIMN6icinga12NotificationEFvNS3_16NotificationTypeERKN5boost13intrusive_ptrINS3_4UserEEERKNS7_INS3_11CheckResultEEEbRKNS3_6StringESI_EEPS4_S5_S9_SD_bSG_SG_EE
E9_M_invokeERKSt9_Any_data+0x42)[0xa2bf22]
/usr/lib64/icinga2/sbin/icinga2[0x907b33]
/usr/lib64/icinga2/sbin/icinga2(_ZN5boost4asio6detail11executor_opINS1_15work_dispatcherIZN6icinga10ThreadPool4PostISt8functionIFvvEEEEbT_NS4_15SchedulerPolicyEEUlvE_EESaIvENS1_19scheduler_operationEE11do_completeEPvPSF_RKNS_6system10err
or_codeEm+0x106)[0xbfed66]
/usr/lib64/icinga2/sbin/icinga2[0x6313e1]
/usr/lib64/icinga2/sbin/icinga2[0x631732]
/usr/lib64/icinga2/sbin/icinga2(boost_asio_detail_posix_thread_function+0xf)[0x823d5f]
/lib64/libpthread.so.0(+0x7ea5)[0x7ff5be349ea5]
/lib64/libc.so.6(clone+0x6d)[0x7ff5be07296d]
======= Memory map: ========
<...>
Caught SIGABRT.
Current time: 2021-01-05 10:57:22 +0100

To Reproduce

A coleague of mine created and deleted hosts (config objects) via API.

Expected behavior

Icinga should survive this.

Your Environment

Include as many relevant details about the environment you experienced the problem in

• Version used (icinga2 --version):
  2.11.7
• Operating System and version:
  RHEL 7.9
• Enabled features (icinga2 feature list):

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

• Icinga Web 2 version and modules (System - About):

Icinga Web 2 Version
    2.7.4
Git Commit
    3ebfb5c38330d22966d24d2ace57d7eb3fb2a6db
PHP Version
    7.1.8
Git Commit Datum
    2020-08-17
Copyright
    © 2013-2021 Das Icinga Projekt 

• Config validation (icinga2 daemon -C):

[2021-01-07 08:31:46 +0100] information/cli: Icinga application loader (version: 2.11.7-1)
[2021-01-07 08:31:46 +0100] information/cli: Loading configuration file(s).
[2021-01-07 08:31:46 +0100] information/ConfigItem: Committing config item(s).
[2021-01-07 08:31:46 +0100] information/ApiListener: My API identity: MASTER02
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 2 ScheduledDowntimes.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 37 HostGroups.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 FileLogger.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 NotificationCommand.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 NotificationComponent.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 292 Notifications.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 IcingaApplication.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 32 Hosts.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 13 Downtimes.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 ApiListener.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 GraphiteWriter.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 PerfdataWriter.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 CheckerComponent.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 9 Zones.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 9 Endpoints.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 5 ApiUsers.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 242 CheckCommands.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 3 TimePeriods.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 1 User.
[2021-01-07 08:31:46 +0100] information/ConfigItem: Instantiated 248 Services.
[2021-01-07 08:31:46 +0100] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
[2021-01-07 08:31:46 +0100] information/cli: Finished validating the configuration file(s).

Additional context

I think this is related: the same coleague, the same tests :) #8583
This one here had a different behaviour, so I made a seperate issue.

[K0nne]

After the crash of the secondary master the icinga2.log of the primary master was filled every ~30 seconds with these messages:

/var/log/icinga2/icinga2.log

[2021-01-07 00:08:01 +0100] information/ApiListener: Replayed 1 messages.
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished sending replay log for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished syncing endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:01 +0100] information/WorkQueue: #5 (ApiListener, RelayQueue) items: 1104, rate:  0/s (0/min 3363/5min 8135/15min); empty in 1 minute and 49 seconds
[2021-01-07 00:08:01 +0100] information/IdoMysqlConnection: Pending queries: 104 (Input: 5/s; Output: 2/s)
[2021-01-07 00:08:01 +0100] information/ApiListener: Reconnecting to endpoint 'MASTER02' via host 'x.x.x.x' and port '5665'
[2021-01-07 00:08:01 +0100] information/ApiListener: New client connection for identity 'MASTER02' to [x.x.x.x]:5665
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished reconnecting to endpoint 'MASTER02' via host 'x.x.x.x' and port '5665'
[2021-01-07 00:08:01 +0100] information/ApiListener: Sending config updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] warning/JsonRpcConnection: API client disconnected for identity 'MASTER02'
[2021-01-07 00:08:01 +0100] warning/ApiListener: Removing API client for endpoint 'MASTER02'. 0 API clients left.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for zone 'hv' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for global zone 'linux-commands' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for global zone 'windows-commands' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for zone 'ZONE01' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing configuration files for zone 'ZONE02' to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished sending config file updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Syncing runtime objects to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished syncing runtime objects to endpoint 'MASTER02'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Finished sending runtime config updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:01 +0100] information/ApiListener: Sending replay log for endpoint 'MASTER02' in zone 'master'.

[2021-01-07 00:08:36 +0100] information/ApiListener: Replayed 1 messages.
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished sending replay log for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished syncing endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:36 +0100] information/WorkQueue: #5 (ApiListener, RelayQueue) items: 1471, rate:  0/s (0/min 3363/5min 8134/15min); empty in 2 minutes and 19 seconds
[2021-01-07 00:08:36 +0100] information/IdoMysqlConnection: Pending queries: 112 (Input: 8/s; Output: 3/s)
[2021-01-07 00:08:36 +0100] information/ApiListener: Reconnecting to endpoint 'MASTER02' via host 'x.x.x.x' and port '5665'
[2021-01-07 00:08:36 +0100] information/ApiListener: New client connection for identity 'MASTER02' to [x.x.x.x]:5665
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished reconnecting to endpoint 'MASTER02' via host 'x.x.x.x' and port '5665'
[2021-01-07 00:08:36 +0100] warning/JsonRpcConnection: API client disconnected for identity 'MASTER02'
[2021-01-07 00:08:36 +0100] warning/ApiListener: Removing API client for endpoint 'MASTER02'. 0 API clients left.
[2021-01-07 00:08:36 +0100] information/ApiListener: Sending config updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for zone 'hv' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for global zone 'linux-commands' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for global zone 'windows-commands' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for zone 'ZONE01' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing configuration files for zone 'ZONE02' to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished sending config file updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Syncing runtime objects to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished syncing runtime objects to endpoint 'MASTER02'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Finished sending runtime config updates for endpoint 'MASTER02' in zone 'master'.
[2021-01-07 00:08:36 +0100] information/ApiListener: Sending replay log for endpoint 'MASTER02' in zone 'master'.

[widhalmt]

ref/NC/699401

[julianbrost]

This sounds like it might be a similar problem as #8583 but with different components involved: handling incoming object deletions and sending notifications.

After the crash of the secondary master the icinga2.log of the primary master was filled every ~30 seconds with these messages:

@K0nne Are there any corresponding log messages on the second master? Looks like it is reconnecting in regular intervals, possibly stuck in some reload or crash loop.

[K0nne]

@julianbrost No, after the crash the log of the second master is just filled with new client connection messages every 30 seconds for days. There are no messages about receiving anything. Also its "zones-stage" directory wasn't updated anymore until the process was reloaded.

[julianbrost]

Logs from #8583 (comment) are probably also relevant here (especially QS_MASTER_2)

[julianbrost]

Given the logs, I was able to reproduce a crash within icinga::Notification::ExecuteNotificationHelper. The crash looks a bit different (segfault instead of abort libc), but this could as well be due to testing on a different system, it's undefined behavior after all:

#0  0x00007f52e967c2fb in __dynamic_cast () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#1  0x00005626528e82e3 in boost::dynamic_pointer_cast<icinga::Notification, icinga::Object> (p=...) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:312
#2  0x00005626528de088 in _ZNK6icinga5ValuecvN5boost13intrusive_ptrIT_EEINS_12NotificationEEEv (this=0x7f5270002300) at /i2cp/lib/base/value.hpp:103
#3  0x0000562652a0bbdc in icinga::UnpackCaller::Invoke<void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool), 0ul, 1ul, 2ul, 3ul, 4ul, 5ul, 6ul, 7ul> (this=0x7f52e736487f, f=0x562652a039f0 <icinga::PluginNotificationTask::ScriptFunc(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool)>, args=std::vector of length 8, capacity 8 = {...}) at /i2cp/lib/base/functionwrapper.hpp:69
#4  0x0000562652a0afd1 in icinga::UnpackCaller::operator()<void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool), 8> (this=0x7f52e736487f, f=0x562652a039f0 <icinga::PluginNotificationTask::ScriptFunc(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool)>, args=std::vector of length 8, capacity 8 = {...}) at /i2cp/lib/base/functionwrapper.hpp:76
#5  0x0000562652a0a1e0 in icinga::FunctionWrapper<void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool), 8, void>::Invoke (function=0x562652a039f0 <icinga::PluginNotificationTask::ScriptFunc(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool)>, arguments=std::vector of length 8, capacity 8 = {...}) at /i2cp/lib/base/functionwrapper.hpp:94
#6  0x0000562652a08baf in icinga::WrapFunction<void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool)>(void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool))::{lambda(std::vector<icinga::Value, std::allocator<icinga::Value> > const&)#1}::operator()(std::vector<icinga::Value, std::allocator<icinga::Value> > const&) const (this=0x56265416f078, arguments=std::vector of length 8, capacity 8 = {...}) at /i2cp/lib/base/functionwrapper.hpp:117
#7  0x0000562652a0b063 in std::_Function_handler<icinga::Value (std::vector<icinga::Value, std::allocator<icinga::Value> > const&), icinga::WrapFunction<void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool)>(void (*)(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, int, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::Dictionary> const&, bool))::{lambda(std::vector<icinga::Value, std::allocator<icinga::Value> > const&)#1}>::_M_invoke(std::_Any_data const&, std::vector<icinga::Value, std::allocator<icinga::Value> > const&) (__functor=..., __args#0=std::vector of length 8, capacity 8 = {...}) at /usr/include/c++/8/bits/std_function.h:283
#8  0x00005626523f55e7 in std::function<icinga::Value (std::vector<icinga::Value, std::allocator<icinga::Value> > const&)>::operator()(std::vector<icinga::Value, std::allocator<icinga::Value> > const&) const (this=0x56265416f078, __args#0=std::vector of length 8, capacity 8 = {...}) at /usr/include/c++/8/bits/std_function.h:687
#9  0x000056265236edc5 in icinga::Function::Invoke (this=0x56265416f000, arguments=std::vector of length 8, capacity 8 = {...}) at /i2cp/lib/base/function.cpp:25
#10 0x000056265287a748 in icinga::NotificationCommand::Execute (this=0x7f52c0005e90, notification=..., user=..., cr=..., type=@0x7f52e7364c54: icinga::NotificationDowntimeEnd, author=..., comment=..., resolvedMacros=..., useResolvedMacros=false) at /i2cp/lib/icinga/notificationcommand.cpp:17
#11 0x0000562652876567 in icinga::Notification::ExecuteNotificationHelper (this=0x7f522407cc50, type=icinga::NotificationDowntimeEnd, user=..., cr=..., force=false, author=..., text=...) at /i2cp/lib/icinga/notification.cpp:544
#12 0x000056265298cbbb in std::__invoke_impl<void, void (icinga::Notification::*&)(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&), icinga::Notification*&, icinga::NotificationType&, boost::intrusive_ptr<icinga::User>&, boost::intrusive_ptr<icinga::CheckResult>&, bool&, icinga::String&, icinga::String&> (__f=@0x7f52ac0011d0: (void (icinga::Notification::*)(class icinga::Notification * const, enum icinga::NotificationType, const class boost::intrusive_ptr<icinga::User> &, const class boost::intrusive_ptr<icinga::CheckResult> &, bool, const class icinga::String &, const class icinga::String &)) 0x56265287632e <icinga::Notification::ExecuteNotificationHelper(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)>, __t=@0x7f52ac001240: 0x7f522407cc50, __args#0=@0x7f52ac001238: icinga::NotificationDowntimeEnd, __args#1=..., __args#2=..., __args#3=@0x7f52ac001220: false, __args#4=..., __args#5=...) at /usr/include/c++/8/bits/invoke.h:73
#13 0x000056265296dab1 in std::__invoke<void (icinga::Notification::*&)(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&), icinga::Notification*&, icinga::NotificationType&, boost::intrusive_ptr<icinga::User>&, boost::intrusive_ptr<icinga::CheckResult>&, bool&, icinga::String&, icinga::String&> (__fn=@0x7f52ac0011d0: (void (icinga::Notification::*)(class icinga::Notification * const, enum icinga::NotificationType, const class boost::intrusive_ptr<icinga::User> &, const class boost::intrusive_ptr<icinga::CheckResult> &, bool, const class icinga::String &, const class icinga::String &)) 0x56265287632e <icinga::Notification::ExecuteNotificationHelper(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)>, __args#0=@0x7f52ac001240: 0x7f522407cc50, __args#1=@0x7f52ac001238: icinga::NotificationDowntimeEnd, __args#2=..., __args#3=..., __args#4=@0x7f52ac001220: false, __args#5=..., __args#6=...) at /usr/include/c++/8/bits/invoke.h:95
#14 0x0000562652943e3f in std::_Bind<void (icinga::Notification::*(icinga::Notification*, icinga::NotificationType, boost::intrusive_ptr<icinga::User>, boost::intrusive_ptr<icinga::CheckResult>, bool, icinga::String, icinga::String))(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)>::__call<void, , 0ul, 1ul, 2ul, 3ul, 4ul, 5ul, 6ul>(std::tuple<>&&, std::_Index_tuple<0ul, 1ul, 2ul, 3ul, 4ul, 5ul, 6ul>) (this=0x7f52ac0011d0, __args=...) at /usr/include/c++/8/functional:400
#15 0x000056265291e04e in std::_Bind<void (icinga::Notification::*(icinga::Notification*, icinga::NotificationType, boost::intrusive_ptr<icinga::User>, boost::intrusive_ptr<icinga::CheckResult>, bool, icinga::String, icinga::String))(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)>::operator()<, void>() (this=0x7f52ac0011d0) at /usr/include/c++/8/functional:484
#16 0x000056265290058b in std::_Function_handler<void (), std::_Bind<void (icinga::Notification::*(icinga::Notification*, icinga::NotificationType, boost::intrusive_ptr<icinga::User>, boost::intrusive_ptr<icinga::CheckResult>, bool, icinga::String, icinga::String))(icinga::NotificationType, boost::intrusive_ptr<icinga::User> const&, boost::intrusive_ptr<icinga::CheckResult> const&, bool, icinga::String const&, icinga::String const&)> >::_M_invoke(std::_Any_data const&) (__functor=...) at /usr/include/c++/8/bits/std_function.h:297
#17 0x00005626523ea5c4 in std::function<void ()>::operator()() const (this=0x7f52e7365a28) at /usr/include/c++/8/bits/std_function.h:687
#18 0x00005626523ff45b in icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}::operator()() const (this=0x56265332dd00 <icinga::Application::GetTP()::tp>) at /i2cp/lib/base/threadpool.hpp:63
#19 0x00005626524ef6ec in boost::asio::asio_handler_invoke<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>(icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}&, ...) (function=...) at /usr/include/boost/asio/handler_invoke_hook.hpp:69
#20 0x00005626524ec123 in boost_asio_handler_invoke_helpers::invoke<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}, {lambda()#1}>(icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}&, {lambda()#1}&) (function=..., context=...) at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#21 0x00005626524e717f in boost::asio::system_executor::dispatch<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}, std::allocator<void> >(icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}&&, std::allocator<void> const&) const (this=0x7f52e7365a8f, f=...) at /usr/include/boost/asio/impl/system_executor.hpp:39
#22 0x00005626524e174d in boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>::operator()() (this=0x7f52e7365bc0) at /usr/include/boost/asio/detail/work_dispatcher.hpp:58
#23 0x00005626524d7aa1 in boost::asio::asio_handler_invoke<boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}> >(boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>&, ...) (function=...) at /usr/include/boost/asio/handler_invoke_hook.hpp:69
#24 0x00005626524c5e9b in boost_asio_handler_invoke_helpers::invoke<boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>, icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>(boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>&, icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}&) (function=..., context=...) at /usr/include/boost/asio/detail/handler_invoke_helpers.hpp:37
#25 0x00005626524b36e5 in boost::asio::detail::executor_op<boost::asio::detail::work_dispatcher<icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}>, std::allocator<void>, boost::asio::detail::scheduler_operation>::do_complete(void*, std::allocator<void>*, boost::system::error_code const&, unsigned long) (owner=0x5626541969c0, base=0x7f52ac037c90) at /usr/include/boost/asio/detail/executor_op.hpp:70
#26 0x00005626523d04f4 in boost::asio::detail::scheduler_operation::complete (this=0x7f52ac037c90, owner=0x5626541969c0, ec=..., bytes_transferred=0) at /usr/include/boost/asio/detail/scheduler_operation.hpp:40
#27 0x00005626523d2be3 in boost::asio::detail::scheduler::do_run_one (this=0x5626541969c0, lock=..., this_thread=..., ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:401
#28 0x00005626523d2768 in boost::asio::detail::scheduler::run (this=0x5626541969c0, ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:154
#29 0x00005626523d2ed0 in boost::asio::thread_pool::thread_function::operator() (this=0x562654197458) at /usr/include/boost/asio/impl/thread_pool.ipp:33
#30 0x000056265250a106 in boost::asio::detail::posix_thread::func<boost::asio::thread_pool::thread_function>::run (this=0x562654197450) at /usr/include/boost/asio/detail/posix_thread.hpp:86
#31 0x00005626523d2e15 in boost::asio::detail::boost_asio_detail_posix_thread_function (arg=0x562654197450) at /usr/include/boost/asio/detail/impl/posix_thread.ipp:74
#32 0x00007f52e9d0bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#33 0x00007f52e93844cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

This looks like a problem with DowntimeEnd notifications being sent while the corresponding config objects are deleted. I'll investigate this further. So far, I only observed the crash on the secondary master.

[julianbrost]

I've just created a pull-request #8591 with what I believe might be the cause of this crash: when notifications are sent while the corresponding notification object is deleted, Icinga may operate on memory after it has been freed. The logs show that there was an attempt to send a notification right before the crash.

@K0nne Would you be willing to test a snapshot build with this PR and #8588 included? I believe these should fix the crashes you have reported.

[K0nne]

@julianbrost I'm willing to help. Can you please provide rhel packages for the 2.11 branch?