Icinga2: JSON-RPC Crashes with 2.11

Created on 24 Sep 2019  ·  144Comments  ·  Source: Icinga/icinga2

Task List

  • [ ] Reproduce the problem

    • [x] in progress Bisect the commits and deploy each of them into a Terraform/Ansible cloud environment and let them run for 1-3 days until it crashes

    • [ ] Analyse the crashing commit and create possible patches

    • [ ] Test patches

  • [ ] Test mitigations - snapshot packages: https://icinga.com/docs/icinga2/latest/doc/21-development/#snapshot-packages-nightly-builds

Mitigations

https://github.com/Icinga/icinga2/issues/7532#issuecomment-565510038

  • [x] Update nlohmann/json #7712
  • [x] Increase coroutine stack size #7713
  • [x] Revert NotificationResult #7737

Analysis

Related issues

7569

7687

7624

7470

ref/NC/636691
ref/NC/644339
ref/NC/644553
ref/NC/647127
ref/NC/652035
ref/NC/652071
ref/NC/652087

Original Report

The setup is a dual master system which was upgraded to 2.11 around noon yesterday.

In the late evening crashes started to appear and are now consistent. The system ran on 2.11-rc1 before.

The user started upgrading agents to 2.11, this may be related.

ref/NC/636691

Latest crash

  Application version: r2.11.0-1

System information:
  Platform: Ubuntu
  Platform version: 18.04.3 LTS (Bionic Beaver)
  Kernel: Linux
  Kernel version: 4.15.0-1050-aws
  Architecture: x86_64

Build information:
  Compiler: GNU 8.3.0
  Build host: runner-LTrJQZ9N-project-298-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 (+0xc7) [0x7f9a99cb4e97]
        (1) libc.so.6: abort (+0x141) [0x7f9a99cb6801]
        (2) libc.so.6: <unknown function> (+0x3039a) [0x7f9a99ca639a]
        (3) libc.so.6: <unknown function> (+0x30412) [0x7f9a99ca6412]
        (4) icinga2: <unknown function> (+0x3656c3) [0x55c11ec5d6c3]
        (5) icinga2: icinga::NotificationComponent::NotificationTimerHandler() (+0x1116) [0x55c11ec77a06]
        (6) icinga2: <unknown function> (+0x6da759) [0x55c11efd2759]
        (7) icinga2: icinga::Timer::Call() (+0x2d) [0x55c11eff151d]
        (8) icinga2: <unknown function> (+0x6f0acd) [0x55c11efe8acd]
        (9) icinga2: 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) (+0xc5) [0x55c11ef9e5d5]
        (10) icinga2: <unknown function> (+0x75807b) [0x55c11f05007b]
        (11) icinga2: <unknown function> (+0x6a2555) [0x55c11ef9a555]
        (12) icinga2: boost_asio_detail_posix_thread_function (+0xf) [0x55c11f047f3f]
        (13) libpthread.so.0: <unknown function> (+0x76db) [0x7f9a98a756db]
        (14) libc.so.6: clone (+0x3f) [0x7f9a99d9788f]

***
* 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.
***

Could not attach to process.  If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Operation not permitted.
The program is not being run.

Alternative crashes

        (0) libc.so.6: gsignal (+0xc7) [0x7f32355c0e97]
        (1) libc.so.6: abort (+0x141) [0x7f32355c2801]
        (2) libc.so.6: <unknown function> (+0x89897) [0x7f323560b897]
        (3) libc.so.6: <unknown function> (+0x9090a) [0x7f323561290a]
        (4) libc.so.6: cfree (+0x4dc) [0x7f3235619e2c]
        (5) icinga2: <unknown function> (+0x6d90d1) [0x56119dd120d1]
        (6) icinga2: icinga::JsonRpcConnection::SendMessageInternal(boost::intrusive_ptr<icinga::Dictionary> const&) (+0x4f) [0x56119dc4870f]
        (7) icinga2: <unknown function> (+0x5f6eac) [0x56119dc2feac]
        (8) icinga2: boost::asio::detail::strand_service::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long) (+0x75) [0x56119dc8ce85]
        (9) icinga2: <unknown function> (+0x75807b) [0x56119dd9107b]
        (10) icinga2: icinga::IoEngine::RunEventLoop() (+0x5e) [0x56119dd85b1e]
        (11) libstdc++.so.6: <unknown function> (+0xbd66f) [0x7f323349b66f]
        (12) libpthread.so.0: <unknown function> (+0x76db) [0x7f32343816db]
        (13) libc.so.6: clone (+0x3f) [0x7f32356a388f]
aredistributed corcrash queuimportant reNC
Source
picture lazyfrosch

Most helpful comment

87061f4e7 didn't crash for > 3 days. Green light for v2.11.3.

picture Al2Klimov on 24 Feb 2020
👍8 🎉6 😄1

All 144 comments

I was not able to run Icinga 2 on GCC or attach to it:

/build/gdb-JPMZNV/gdb-8.1/gdb/dictionary.c:690: internal-error: void insert_symbol_hashed(dictionary*, symbol*): Assertion `SYMBOL_LANGUAGE (sym) == DICT_LANGUAGE (dict)->la_language' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
lazyfrosch picture lazyfrosch on 24 Sep 2019

After disabling the notification feature and some minutes running:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/lib/x86_64-linux-gnu/icinga2/sbin/icinga2 --no-stack-rlimit daemon --close'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x0000563ab115b5de in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_local_data (
    this=<optimized out>, this=<optimized out>) at /usr/include/c++/8/ext/new_allocator.h:81
81      /usr/include/c++/8/ext/new_allocator.h: No such file or directory.
[Current thread is 1 (Thread 0x7f72580d4700 (LWP 20323))]
(gdb) bt
#0  0x0000563ab115b5de in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_local_data (
    this=<optimized out>, this=<optimized out>) at /usr/include/c++/8/ext/new_allocator.h:81
#1  std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string (__str=...,
    this=<optimized out>, this=<optimized out>, __str=...) at /usr/include/c++/8/bits/basic_string.h:542
#2  icinga::String::String (other=..., this=<optimized out>, this=<optimized out>, other=...) at ./lib/base/string.cpp:37
#3  __gnu_cxx::new_allocator<icinga::String>::construct<icinga::String, icinga::String> (this=0x7f7220590c88,
    __p=0x7473756c43273a27) at /usr/include/c++/8/ext/new_allocator.h:136
#4  std::allocator_traits<std::allocator<icinga::String> >::construct<icinga::String, icinga::String> (__a=...,
    __p=0x7473756c43273a27) at /usr/include/c++/8/bits/alloc_traits.h:475
#5  std::vector<icinga::String, std::allocator<icinga::String> >::emplace_back<icinga::String> (this=<optimized out>)
    at /usr/include/c++/8/bits/vector.tcc:103
#6  0x0000563ab108d70f in icinga::JsonRpcConnection::SendMessageInternal(boost::intrusive_ptr<icinga::Dictionary> const&) ()
    at ./lib/remote/jsonrpcconnection.cpp:186
#7  0x0000563ab1074eac in boost::asio::detail::completion_handler<icinga::JsonRpcConnection::SendMessage(boost::intrusive_ptr<icinga::Dictionary> const&)::{lambda()#1}>::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long) [clone .lto_priv.4649] () at ./lib/remote/jsonrpcconnection.cpp:173
#8  0x0000563ab10d1e85 in boost::asio::detail::strand_service::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long) () at /usr/include/icinga-boost/boost/asio/detail/scheduler_operation.hpp:40
/build/gdb-JPMZNV/gdb-8.1/gdb/dictionary.c:690: internal-error: void insert_symbol_hashed(dictionary*, symbol*): Assertion `SYMBOL_LANGUAGE (sym) == DICT_LANGUAGE (dict)->la_language' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
lazyfrosch picture lazyfrosch on 24 Sep 2019

I have the exactly same issue. Today i've upgraded from 2.10 to 2.11 and the service started to crash. I also noticed that used memory is way higher than before.
I'm thinking to downgrade..

bunghi picture bunghi on 24 Sep 2019

@bunghi please share logs and details, "exactly" the same won't help us...

lazyfrosch picture lazyfrosch on 24 Sep 2019

The Icinga2 environment looks like this:

  • web server running icingaweb2
  • dual node master
  • 13 zones (one endpoint for all but one with 2 endpoints)

This morning we upgraded icinga2 on all 15 servers (masters + zones endpoints). Since then the both endpoints in the zone with 2 crashed (there we have a lot of hosts).

Crash reports:

$ cat report.1569317444.555398
Caught unhandled exception.
Current time: 2019-09-24 11:30:44 +0200

  Application version: r2.11.0-1

System information:
  Platform: Debian GNU/Linux
  Platform version: 9 (stretch)
  Kernel: Linux
  Kernel version: 4.9.0-11-amd64
  Architecture: x86_64

Build information:
  Compiler: GNU 6.3.0
  Build host: runner-LTrJQZ9N-project-298-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

Error: Function call 'opendir' for file '/var/lib/icinga2/api/zones-stage//global' failed with error code 2, 'No such file or directory'

***
* 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.
***
Failed to launch GDB: No such file or directory

$ cat report.1569312889.121968
Caught unhandled exception.
Current time: 2019-09-24 10:14:49 +0200

  Application version: r2.11.0-1

System information:
  Platform: Debian GNU/Linux
  Platform version: 9 (stretch)
  Kernel: Linux
  Kernel version: 4.9.0-11-amd64
  Architecture: x86_64

Build information:
  Compiler: GNU 6.3.0
  Build host: runner-LTrJQZ9N-project-298-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

Error: [json.exception.parse_error.101] parse error at line 1, column 28: syntax error while parsing value - unexpected '{'; expected end of input


        (0) icinga2: icinga::JsonDecode(icinga::String const&) (+0x779) [0x55e373ddfac9]
        (1) icinga2: icinga::Process::DoEvents() (+0x295) [0x55e373e33bf5]
        (2) icinga2: icinga::Process::IOThreadProc(int) (+0x3cd) [0x55e373e3529d]
        (3) libstdc++.so.6: <unknown function> (+0xb9e6f) [0x7fa157ae2e6f]
        (4) libpthread.so.0: <unknown function> (+0x74a4) [0x7fa1589194a4]
        (5) libc.so.6: clone (+0x3f) [0x7fa157257d0f]



***
* 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.
***
Failed to launch GDB: No such file or directory

Since upgraded this morning it crashed 5 times with Out of Memory kernel error.
kern_node1.log
kern_node2.log

Memory usage after upgrade:

image

bunghi picture bunghi on 24 Sep 2019

I don't know if I should open a different issue for performance degradation after upgrade. Both RAM and CPU usage increased:

image

image

bunghi picture bunghi on 25 Sep 2019

Memory and CPU usage are expected to raise with the introduction of user land threads with Boost Coroutines. This is different to this issue.

Also, the Json error between main and spawn helper process is a new issue, please move this into a dedicated issue, as requested in https://github.com/Icinga/icinga2/issues/7531#issuecomment-534547311
The error with opendir also is different, new issue please.

dnsmichi picture dnsmichi on 25 Sep 2019

@dnsmichi It's not because of the dependencies, otherwise this config would crash:

for (i in range(259)) {
    object Host i {
        check_command = "dummy"
        check_interval = 5s
    }

    object Dependency i use (i) {
        parent_host_name = i
        child_host_name = (i + 1) % 259
        disable_checks = true
    }
}
Al2Klimov picture Al2Klimov on 26 Sep 2019
👍1

It could be related to JsonEncode seen in various other places as well, maybe related to how memory is allocated and later free'd for encoding dictionaries.

dnsmichi picture dnsmichi on 8 Oct 2019

Hi,

Today it crashed again, after a while.. maybe output helps:

$ cat report.1571908186.877839
  Application version: r2.11.1-1

System information:
  Platform: Debian GNU/Linux
  Platform version: 9 (stretch)
  Kernel: Linux
  Kernel version: 4.9.0-11-amd64
  Architecture: x86_64

Build information:
  Compiler: GNU 6.3.0
  Build host: runner-LTrJQZ9N-project-298-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 (+0xcf) [0x7f1a2f41dfff]
        (1) libc.so.6: abort (+0x16a) [0x7f1a2f41f42a]
        (2) libc.so.6: <unknown function> (+0x70c00) [0x7f1a2f45bc00]
        (3) libc.so.6: <unknown function> (+0x76fc6) [0x7f1a2f461fc6]
        (4) libc.so.6: <unknown function> (+0x7780e) [0x7f1a2f46280e]
        (5) icinga2: icinga::ObjectImpl<icinga::CheckResult>::~ObjectImpl() (+0x7f) [0x558be62d3e1f]
        (6) icinga2: <unknown function> (+0x55b123) [0x558be6363123]
        (7) icinga2: icinga::Checkable::ProcessCheckResult(boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::MessageOrigin> const&) (+0x17a2) [0x558be62f9502]
        (8) icinga2: icinga::ClusterEvents::CheckResultAPIHandler(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0xa6c) [0x558be62fbb7c]
        (9) icinga2: std::_Function_handler<icinga::Value (boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&), icinga::Value (*)(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&)>::_M_invoke(std::_Any_data const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0x23) [0x558be6205713]
        (10) icinga2: icinga::JsonRpcConnection::MessageHandler(icinga::String const&) (+0x531) [0x558be6151451]
        (11) icinga2: icinga::JsonRpcConnection::HandleIncomingMessages(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x283) [0x558be615ad03]
        (12) icinga2: <unknown function> (+0x43a18d) [0x558be624218d]
        (13) libboost_context.so.1.67.0: make_fcontext (+0x2f) [0x7f1a31dad72f]

***
* 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.
***

Failed to launch GDB: No such file or directory
bunghi picture bunghi on 24 Oct 2019

@lippserd @Al2Klimov my suspicion is that this is related to the JSON library with encode/decode, likewise object serialization and a possible leak in there. I haven't run Valgrind yet, but this would be the next thing to try.

dnsmichi picture dnsmichi on 25 Oct 2019

ref/NC/644339

Baboon92 picture Baboon92 on 25 Oct 2019

ref/NC/644553

mwaldmueller picture mwaldmueller on 29 Oct 2019

I am experiencing exactly the same crash output as @bunghi posted above. I have a 2 node master cluster and around 200 agent instances. Prior to the upgrade to 2.11 the masters were stable, now both nodes crash several times a day. 

Build information:
  Compiler: GNU 4.8.5
  Build host: runner-LTrJQZ9N-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) [0x7f3a87108337]
        (1) libc.so.6: abort (+0x148) [0x7f3a87109a28]
        (2) libc.so.6: <unknown function> (+0x78e87) [0x7f3a8714ae87]
        (3) libc.so.6: <unknown function> (+0x7f7c4) [0x7f3a871517c4]
        (4) libc.so.6: <unknown function> (+0x82f00) [0x7f3a87154f00]
        (5) libc.so.6: __libc_malloc (+0x4c) [0x7f3a87157adc]
        (6) libstdc++.so.6: operator new(unsigned long) (+0x1d) [0x7f3a87c32ecd]
        (7) /usr/lib64/icinga2/sbin/icinga2() [0x66093f]
        (8) /usr/lib64/icinga2/sbin/icinga2() [0x6b9c12]
        (9) icinga2: icinga::JsonDecode(icinga::String const&) (+0x4ad) [0x917b2d]
        (10) icinga2: icinga::ApiListener::ReplayLog(boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0xa4d) [0xb4497d]
        (11) icinga2: icinga::ApiListener::SyncClient(boost::intrusive_ptr<icinga::JsonRpcConnection> const&, boost::intrusive_ptr<icinga::Endpoint> const&, bool) (+0x61f) [0xb4699f]
        (12) /usr/lib64/icinga2/sbin/icinga2() [0xb47a7a]
        (13) libboost_context.so.1.69.0: make_fcontext (+0x2f) [0x7f3a89bf718f]

***
* 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.
***

Failed to launch GDB: No such file or directory

I've installed gdb on the masters to see if it provides any useful details.

Mark

MarkNReynolds picture MarkNReynolds on 4 Nov 2019

ref/NC/647127

carraroj picture carraroj on 11 Nov 2019

Yesterday (Nov 14th 2019) we experienced the same crash as @bunghi mentioned.
Dual master setup here, 4 zones.

Both masters run 2.11.2-1.xenial.

Caught unhandled exception.
Current time: 2019-11-14 15:30:05 +0100

  Application version: r2.11.2-1

System information:
  Platform: Ubuntu
  Platform version: 16.04.6 LTS (Xenial Xerus)
  Kernel: Linux
  Kernel version: 4.4.0-101-generic
  Architecture: x86_64

Build information:
  Compiler: GNU 5.4.0
  Build host: runner-LTrJQZ9N-project-298-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

Error: [json.exception.parse_error.101] parse error at line 1, column 27: syntax error while parsing value - unexpected '{'; expected end of input


        (0) icinga2: icinga::JsonDecode(icinga::String const&) (+0xcb2) [0x5fca02]
        (1) icinga2: icinga::Process::DoEvents() (+0x27c) [0x63b85c]
        (2) icinga2: icinga::Process::IOThreadProc(int) (+0x3b7) [0x6400a7]
        (3) libstdc++.so.6: <unknown function> (+0xb8c80) [0x7fb42e48ec80]
        (4) libpthread.so.0: <unknown function> (+0x76ba) [0x7fb42f0456ba]
        (5) libc.so.6: clone (+0x6d) [0x7fb43035041d]



***
* 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.
***
Failed to launch GDB: No such file or directory
Napsty picture Napsty on 15 Nov 2019

Hi all,

We are able to reproduce the crash and are working on a fix since quite some time.
Most of the time was/is used on gathering insights why this is happening.
There is no estimate for a fix unfortunately. Though we are working hard on resolving this as soon as possible. Thanks to @dnsmichi for the following summary. Please read on:

Json-RPC Crash Analysis

Author: @dnsmichi
Started: 2019-09-25
Last Updated: 2019-12-06

All GitHub issue and customer ticket stack traces and insights.
First seen within a HA cluster with notifications and pki requests.

Observation: Increased memory usage with 2.11.
Observation: Boost ASIO and JSON related.

Origins

JsonRPC Messages

IoEngine

RunEventLoop switches between coroutines, JsonRpcConnection::SendMessageInternal is called and a cfree() crashes. Leads to memory corruption.

(0) libc.so.6: gsignal (+0xc7) [0x7f32355c0e97]
       (1) libc.so.6: abort (+0x141) [0x7f32355c2801]
       (2) libc.so.6: <unknown function> (+0x89897) [0x7f323560b897]
       (3) libc.so.6: <unknown function> (+0x9090a) [0x7f323561290a]
       (4) libc.so.6: cfree (+0x4dc) [0x7f3235619e2c]
       (5) icinga2: <unknown function> (+0x6d90d1) [0x56119dd120d1]
       (6) icinga2: icinga::JsonRpcConnection::SendMessageInternal(boost::intrusive_ptr<icinga::Dictionary> const&) (+0x4f) [0x56119dc4870f]
       (7) icinga2: <unknown function> (+0x5f6eac) [0x56119dc2feac]
       (8) icinga2: boost::asio::detail::strand_service::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long) (+0x75) [0x56119dc8ce85]
       (9) icinga2: <unknown function> (+0x75807b) [0x56119dd9107b]
       (10) icinga2: icinga::IoEngine::RunEventLoop() (+0x5e) [0x56119dd85b1e]
       (11) libstdc++.so.6: <unknown function> (+0xbd66f) [0x7f323349b66f]
       (12) libpthread.so.0: <unknown function> (+0x76db) [0x7f32343816db]
       (13) libc.so.6: clone (+0x3f) [0x7f32356a388f]

Heartbeats

JsonRpcConnection::HandleAndWriteHeartbeats

calls JsonRpcConnection::SendMessageInternal.

(0) libc.so.6: gsignal (+0xc7) [0x7f1c47a35e97]
(1) libc.so.6: abort (+0x141) [0x7f1c47a37801]
(2) libc.so.6: <unknown function> (+0x3039a) [0x7f1c47a2739a]
(3) libc.so.6: <unknown function> (+0x30412) [0x7f1c47a27412]
(4) icinga2: <unknown function> (+0x578603) [0x55aadd980603]
(5) icinga2: icinga::JsonRpcConnection::HandleAndWriteHeartbeats(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x960) [0x55aadda20270]
(6) icinga2: <unknown function> (+0x5e277d) [0x55aadd9ea77d]
(7) libboost_context.so.1.67.0: make_fcontext (+0x2f) [0x7f1c4509a65f]

Thread Pool

ASIO based implementation.

Calls Timer which crashes inside the NotificationTimerHandler (this invokes the reminder notifications).

(0) libc.so.6: gsignal (+0xc7) [0x7f9a99cb4e97]
(1) libc.so.6: abort (+0x141) [0x7f9a99cb6801]
(2) libc.so.6: <unknown function> (+0x3039a) [0x7f9a99ca639a]
(3) libc.so.6: <unknown function> (+0x30412) [0x7f9a99ca6412]
(4) icinga2: <unknown function> (+0x3656c3) [0x55c11ec5d6c3]
(5) icinga2: icinga::NotificationComponent::NotificationTimerHandler() (+0x1116) [0x55c11ec77a06]
(6) icinga2: <unknown function> (+0x6da759) [0x55c11efd2759]
(7) icinga2: icinga::Timer::Call() (+0x2d) [0x55c11eff151d]
(8) icinga2: <unknown function> (+0x6f0acd) [0x55c11efe8acd]
(9) icinga2: 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) (+0xc5) [0x55c11ef9e5d5]
(10) icinga2: <unknown function> (+0x75807b) [0x55c11f05007b]
(11) icinga2: <unknown function> (+0x6a2555) [0x55c11ef9a555]
(12) icinga2: boost_asio_detail_posix_thread_function (+0xf) [0x55c11f047f3f]
(13) libpthread.so.0: <unknown function> (+0x76db) [0x7f9a98a756db]
(14) libc.so.6: clone (+0x3f) [0x7f9a99d9788f]

JsonDecode

Points to char buffer corruption.

Error: [json.exception.parse_error.101] parse error at line 1, column 28: syntax error while parsing value - unexpected '{'; expected end of input


        (0) icinga2: icinga::JsonDecode(icinga::String const&) (+0x779) [0x55e373ddfac9]

https://github.com/Icinga/icinga2/issues/7532#issuecomment-534542773

Points to corruption with large file chunks read from JSON.

(0) libc.so.6: gsignal (+0x37) [0x7f3a87108337]
(1) libc.so.6: abort (+0x148) [0x7f3a87109a28]
(2) libc.so.6: <unknown function> (+0x78e87) [0x7f3a8714ae87]
(3) libc.so.6: <unknown function> (+0x7f7c4) [0x7f3a871517c4]
(4) libc.so.6: <unknown function> (+0x82f00) [0x7f3a87154f00]
(5) libc.so.6: __libc_malloc (+0x4c) [0x7f3a87157adc]
(6) libstdc++.so.6: operator new(unsigned long) (+0x1d) [0x7f3a87c32ecd]
(7) /usr/lib64/icinga2/sbin/icinga2() [0x66093f]
(8) /usr/lib64/icinga2/sbin/icinga2() [0x6b9c12]
(9) icinga2: icinga::JsonDecode(icinga::String const&) (+0x4ad) [0x917b2d]
(10) icinga2: icinga::ApiListener::ReplayLog(boost::intrusive_ptr<icinga::JsonRpcConnection> const&) (+0xa4d) [0xb4497d]
(11) icinga2: icinga::ApiListener::SyncClient(boost::intrusive_ptr<icinga::JsonRpcConnection> const&, boost::intrusive_ptr<icinga::Endpoint> const&, bool) (+0x61f) [0xb4699f]

https://github.com/Icinga/icinga2/issues/7532#issuecomment-549272700

PKI Requests which save a JSON file

Involves JsonEncode().

[2019-10-25 08:06:25 +0200] warning/JsonRpcConnection: Error while processing message for identity 'agent42.keksi.com'
Error: basic_ios::clear: iostream error


        (0) libstdc++.so.6: <unknown function> (+0xfbfca) [0x7ff5fd73ffca]
        (1) icinga2: icinga::Utility::SaveJsonFile(icinga::String const&, int, icinga::Value const&) (+0x198) [0x96d3f8]
        (2) /usr/lib64/icinga2/sbin/icinga2() [0xa87347]
        (3) icinga2: std::_Function_handler<icinga::Value (boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&), icinga::Value (*)(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&)>::_M_invoke(std::_Any_data const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0xf) [0xabe06f]
        (4) icinga2: icinga::JsonRpcConnection::MessageHandler(icinga::String const&) (+0x490) [0xa8da00]
        (5) icinga2: icinga::JsonRpcConnection::HandleIncomingMessages(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x10c) [0xab2b6c]
        (6) /usr/lib64/icinga2/sbin/icinga2() [0xab48b1]
        (7) libboost_context.so.1.69.0: make_fcontext (+0x2f) [0x7ff5ff7343af]

ref/NC/644339

CheckResult handling in the Cluster

(0) libc.so.6: gsignal (+0xcf) [0x7f1a2f41dfff]
(1) libc.so.6: abort (+0x16a) [0x7f1a2f41f42a]
(2) libc.so.6: <unknown function> (+0x70c00) [0x7f1a2f45bc00]
(3) libc.so.6: <unknown function> (+0x76fc6) [0x7f1a2f461fc6]
(4) libc.so.6: <unknown function> (+0x7780e) [0x7f1a2f46280e]
(5) icinga2: icinga::ObjectImpl<icinga::CheckResult>::~ObjectImpl() (+0x7f) [0x558be62d3e1f]
(6) icinga2: <unknown function> (+0x55b123) [0x558be6363123]
(7) icinga2: icinga::Checkable::ProcessCheckResult(boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::MessageOrigin> const&) (+0x17a2) [0x558be62f9502]
(8) icinga2: icinga::ClusterEvents::CheckResultAPIHandler(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0xa6c) [0x558be62fbb7c]
(9) icinga2: std::_Function_handler<icinga::Value (boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&), icinga::Value (*)(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&)>::_M_invoke(std::_Any_data const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0x23) [0x558be6205713]
(10) icinga2: icinga::JsonRpcConnection::MessageHandler(icinga::String const&) (+0x531) [0x558be6151451]
(11) icinga2: icinga::JsonRpcConnection::HandleIncomingMessages(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x283) [0x558be615ad03]
(12) icinga2: <unknown function> (+0x43a18d) [0x558be624218d]

This involves Deserialize() calls which invoke JsonDecode().

Changes with possible influence

Replaced JSON library which may corrupt the stack from serialize/deserialize

https://github.com/Icinga/icinga2/pull/7019

Json is involved in any crash above, this is priority number one.

Scenario Tasks:

  • Fire many node setup pki requests against an HA cluster and/or single instance. WIP, being analysed by @dnsmichi
  • Or have many (docker) clients which try to sign a certificate WIP, being analysed by @al2klimov
  • Or fire large nested check results into the cluster
  • Or have a lot of replay log (maybe hard to trigger)

Maybe also create a standalone PoC which uses Icinga code and just stresses the JsonEncode/JsonDecode in a multi-threaded and asio-coroutine involved scenario.

Replaced UTF8 Library

May have an influence, comes in combination with the JSON library updates.

Task: Take this into account while debugging.

https://github.com/Icinga/icinga2/pull/7014

NotificationResult being passed inside the cluster

Crashes happen even when notifications are disabled. OnNotificationRequested() is relayed throughout the cluster, low possible influence here.

Network stack in general, specifically the latest changes for Coroutine Spawn for Nessus Scan Crashes - Disconnects, etc.

Maybe, but the error pattern does not match in this regard. Then we would see direct connection crashes on every connect.

Fixes which may have an influence

Things to proof: Many open sockets cause JsonRPC to crash from within Boost Asio/Context?

Things to proof: None. The PR needs to be tested and merged, in combination with the other crashes.

lippserd picture lippserd on 6 Dec 2019
👍1

As an idea to reproduce a huge replay log: Configure a zone with 2 nodes in a HA-setup and shut one node down for quite a while. When you restart it, there should be a significant size of replay log, especially if you send a lot of data to the remaining node.

widhalmt picture widhalmt on 6 Dec 2019

Update

At the moment I'm bisecting 2.10..2.11 in the setup I've already described. This will take some time as one bisect step takes the following times:

  • Terraform destroy/apply
  • Ansible playbook
  • Crash interval

But this bisect step time can be halved by doubling the amount of setups (we're working on this together with @mxhash). Yes, two times a whole Icinga env with 2 masters and 300 agents.

So far I've figured out that the RC1 was already affected.

Al2Klimov picture Al2Klimov on 10 Dec 2019

Memory Analysis Test Setup

cd centos7-dev
vagrant up
vagrant ssh

i2_debug 

chown -R icinga:icinga /usr/local/icinga2/

icinga2 api setup

cp /usr/local/icinga2/var/lib/icinga2/certs//icinga2-centos7-dev.vagrant.demo.icinga.com.crt /vagrant/

/usr/local/icinga2/lib/icinga2/prepare-dirs /usr/local/icinga2/etc/sysconfig/icinga2

yum -y install valgrind 


valgrind --trace-children=yes --leak-check=full --show-leak-kinds=all --log-file=valgrind-`date +%s`.log /usr/local/icinga2/lib64/icinga2/sbin/icinga2 daemon

Second terminal.

cd centos7-dev 
mkdir -p etc/icinga2/features-enabled
mkdir -p etc/icinga2/features-available 

while true; do icinga2 node setup -DSysconfDir=`pwd`/etc -DLocalStateDir=`pwd`/var --cn a1 --zone a1 --endpoint p1 --parent_zone master --parent_host 192.168.33.21 --trustedcert icinga2-centos7-dev.vagrant.demo.icinga.com.crt; done

Results

  • ConfigCompiler leaks are expected, that's a one shot not freeing the sandbox afterwards (memory fragmentation), with the config objects holding references to debug info
  • RingBuffers store stats, one time allocation
  • Boost via OpenSSL Initialize - runtime malloc
  • Boost Asio Coroutines use a default stack size of 64KB, this is treated as false positive
  • Thread init loses some bytes (Timer thread, Threadpool, etc.)
  • LazyInit'ing the IoEngine instance is also expected
==22248== Memcheck, a memory error detector
==22248== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==22248== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info
==22248== Command: /usr/local/icinga2/lib64/icinga2/sbin/icinga2 --no-stack-rlimit daemon
==22248== Parent PID: 16971
==22248==
==22280== Warning: client switching stacks?  SP change: 0x154ea2e0 --> 0x14cd13b0
==22280==          to suppress, use: --max-stackframe=8490800 or greater
==22280== Warning: client switching stacks?  SP change: 0x14cd0de0 --> 0x154ea2e0
==22280==          to suppress, use: --max-stackframe=8492288 or greater
==22321==
==22321== HEAP SUMMARY:
==22321==     in use at exit: 6,613,370 bytes in 119,590 blocks
==22321==   total heap usage: 739,271 allocs, 619,681 frees, 105,255,095 bytes allocated

==22316== LEAK SUMMARY:
==22316==    definitely lost: 2,480 bytes in 28 blocks
==22316==    indirectly lost: 517 bytes in 8 blocks
==22316==      possibly lost: 143,232 bytes in 50 blocks
==22316==    still reachable: 6,461,871 bytes in 119,441 blocks
==22316==                       of which reachable via heuristic:
==22316==                         stdstring          : 2,114,986 bytes in 34,598 blocks
==22316==                         newarray           : 1,648 bytes in 1 blocks
==22316==         suppressed: 0 bytes in 0 blocks
==22316==
==22316== For counts of detected and suppressed errors, rerun with: -v
==22316== ERROR SUMMARY: 34 errors from 34 contexts (suppressed: 0 from 0)

Ideas

One thing which comes to mind with large buffers, while looking into valgrind logs:

  • The current coroutine stack size uses the default of 64KB on Linux/Unix, this was only raised for Windows agents after the debug session after RC1. The Linux parts never changed from the original implementation.
  • On the Windows side, specific stack guards and page protection was in place, with raising the stack size this had an influence.
  • For testing purposes, I'd suggest raising the stack size limit @Al2Klimov @lippserd

https://github.com/Icinga/icinga2/blob/master/lib/base/io-engine.hpp#L104

I'll continue with memory analysis with massif/heaptrack.

dnsmichi picture dnsmichi on 10 Dec 2019

@dnsmichi I've added this to my to do list.

TODO

  • [x] bisect
  • [x] turn off 200/300 agents
  • [x] newer JSON lib
  • [ ] old JSON lib
  • [ ] bad ticket
  • [ ] wrong ticket
  • [x] stack size
Al2Klimov picture Al2Klimov on 10 Dec 2019

Memory Analysis with Heaptrack

https://milianw.de/blog/heaptrack-a-heap-memory-profiler-for-linux.html

Actually a small CMake patch is needed, https://github.com/KDE/heaptrack/pull/23

yum -y install libdwarf-devel elfutils libunwind-devel libzstd-devel

cd
# git clone https://github.com/KDE/heaptrack
git clone https://github.com/dnsmichi/heaptrack 
cd heaptrack

git checkout bugfix/cmake-boost-zstd 

mkdir build
cd build

cmake -DCMAKE_BUILD_TYPE=Release -DBoost_NO_BOOST_CMAKE=TRUE -DBoost_NO_SYSTEM_PATHS=TRUE -DBOOST_LIBRARYDIR=/usr/lib64/boost169 -DBOOST_INCLUDEDIR=/usr/include/boost169 -DBoost_ADDITIONAL_VERSIONS='1.69;1.69.0' ..

make 

cd ..

./build/bin/heaptrack /usr/local/icinga2/lib64/icinga2/sbin/icinga2 daemon

Stress Test

while true; do sleep 0.1 && icinga2 node setup -DSysconfDir=`pwd`/etc -DLocalStateDir=`pwd`/var --cn a1 --zone a1 --endpoint p1 --parent_zone master --parent_host 192.168.33.21 --trustedcert icinga2-centos7-dev.vagrant.demo.icinga.com.crt &>/dev/null &  done

Results

./build/bin/heaptrack --analyze "/root/heaptrack/heaptrack.icinga2.26504.gz"

Nothing new thus far. I'll continue on Friday.

dnsmichi picture dnsmichi on 10 Dec 2019

Since I cannot reproduce the crash here, I'm going a different route with things we can try together to help mitigate the issue.

Stack Rlimit

Anyone affected by the problem, please try this first!

By default, Icinga tries to lower the stack limit. This can be superseded by adding the following parameter to the systemd service file or init script:

In case of Systemd, copy the existing service file and then modify it accordingly.

cp /usr/lib/systemd/system/icinga2.service /etc/systemd/system/icinga2.service
vim /etc/systemd/system/icinga2.service

ExecStart=/usr/sbin/icinga2 daemon --no-stack-rlimit --close-stdio -e ${ICINGA2_ERROR_LOG}

systemctl daemon-reload

systemctl restart icinga2

ps aux | grep icinga2
icinga   25282  0.0  0.4 368984  8692 ?        Ssl  17:18   0:00 /usr/lib64/icinga2/sbin/icinga2 daemon --no-stack-rlimit --close-stdio -e /var/log/icinga2/error.log
icinga   25294 25.5  1.2 1136692 23636 ?       Sl   17:18   0:31 /usr/lib64/icinga2/sbin/icinga2 daemon --no-stack-rlimit --close-stdio -e /var/log/icinga2/error.log
icinga   25316  0.3  0.8 718888 15560 ?        S    17:18   0:00 /usr/lib64/icinga2/sbin/icinga2 daemon --no-stack-rlimit --close-stdio -e /var/log/icinga2/error.log

You don't need any package update for this, just try that from within Systemd.

JSON Library Update

Next idea, merged with #7712

We use nlohmann/json 3.5.0, current is 3.7.3. The diff points to the following possibilities:

https://github.com/nlohmann/json/pull/1436

For a deeply-nested JSON object, the recursive implementation of json_value::destroy function causes stack overflow.

https://github.com/nlohmann/json/issues/1708
https://github.com/nlohmann/json/pull/1722

Stack size

https://github.com/nlohmann/json/issues/1693#issuecomment-516980690

Integer Overflow

https://github.com/nlohmann/json/issues/1447

UTF8, json dump out of bounds

https://github.com/nlohmann/json/issues/1445

Coroutine stack size

PR: #7713

With #6559 I have learned that the default stack size for coroutines may to low causing crashes on Windows in this regard. The default of 64KB may be too low, especially keeping in mind that for example nlohmann/json puts an overhead of 1 pointer for each JSON object. If many of them are used within a coroutine, e.g. an agent/satellite replaying the log, the theory says that 64KB may be too low.

Our application default would be 256KB the lowest, if the application is not started with --no-stack-rlimit (which is the default param used on Debian and RHEL). 

int Application::GetDefaultRLimitStack()
{
        return 256 * 1024;
}

Therefore I consider setting a Coroutine stack size of 256KB (maybe 512KB) a better default than the Boost ASIO default. This may increase the memory foot print of course, but prevent any stack corruption which likely happens here.

References I had in my pocket:

Test Cases

Instructions for testing the snapshot packages are here: https://icinga.com/docs/icinga2/latest/doc/21-development/#snapshot-packages-nightly-builds

dnsmichi picture dnsmichi on 13 Dec 2019

For a deeply-nested JSON object, the recursive implementation of json_value::destroy function causes stack overflow.

Good catch, this fits the symptoms. I'll add this to my TODO list.

Al2Klimov picture Al2Klimov on 16 Dec 2019

I've updated the original report with the latest findings.

dnsmichi picture dnsmichi on 16 Dec 2019

@dnsmichi We had the same issue since this morning, after a reboot Icinga can't start anymore running via systemctl. It crashes after approx. 8/9 minutes with a lot of pidkills.

What is advised to do here? We are running version: r2.11.2-1 and are having issues with 1 of our master services now.

remys89 picture remys89 on 16 Dec 2019

@remys89 It would be great if you could test our snapshot packages.

lippserd picture lippserd on 16 Dec 2019

@lippserd That would be great if you could assist in what to-do when stuff breaks even more on that server. I will discuss in the meanwhile with my team what we want to do, since it is production.

remys89 picture remys89 on 16 Dec 2019

I've deployed a setup with not 302, but 246 machines with v2.11 + @dnsmichi's update of our JSON lib. I'll give you an update tomorrow.

Al2Klimov picture Al2Klimov on 16 Dec 2019

@lippserd That would be great if you could assist in what to-do when stuff breaks even more on that server.

I'm not sure if that's related to this issue, therefore I'd suggest to create a new issue including more details guided with the issue template.

Also, please enable core dumps and add the crash reports and logs to the issue.

dnsmichi picture dnsmichi on 16 Dec 2019

@lippserd That would be great if you could assist in what to-do when stuff breaks even more on that server.

I'm not sure if that's related to this issue, therefore I'd suggest to create a new issue including more details guided with the issue template.

Also, please enable core dumps and add the crash reports and logs to the issue.

We are first restoring the server to the last working version from last friday. We configure it completely with Ansible so it should be ok. When it is up, we will configure it with ansible again and see if the effect remains.

remys89 picture remys89 on 16 Dec 2019

The environment I've deployed yesterday has been up and running for 19h. This may or may not be enough for you as a proof that #7712 fixes #7532 and you may or may not release the RC1.

For me it's not enough as the environment significantly differs form my original one (long story). I'll deploy a definitively affected version on the same machines and give you an update tomorrow.

CC @dnsmichi @lippserd @gethash

Al2Klimov picture Al2Klimov on 17 Dec 2019

Unfortunately the expected crash didn't happen tonight, so I actually didn't successfully verify #7712. I'll extend the env to the original size and give you an update tomorrow.

Al2Klimov picture Al2Klimov on 18 Dec 2019

Meanwhile everyone subscribed to this issue, or having the issue, please deploy the snapshot packages and verify they are working. The changeset between 2.12 and 2.11.2 is small, it only contains the IcingaDB and smaller DSL enhancements, no breaking changes at all.

dnsmichi picture dnsmichi on 18 Dec 2019

Meanwhile everyone subscribed to this issue, or having the issue, please deploy the snapshot packages and verify they are working. The changeset between 2.12 and 2.11.2 is small, it only contains the IcingaDB and smaller DSL enhancements, no breaking changes at all.

To give you some feedback:

We noticed a lot of checks running every 5 minutes. Everytime the checks started, the CPU usage spiked hugely, crashed the Icinga2 process.
We changed some intervals and went from 4 vCPU to 8 vCPU (F size in Azure).

For now, the service hasn't crashed anymore and is around 20% CPU usage. After christmas i will try this snapshot to verify if it solves the issues with a lower resourced VM.

remys89 picture remys89 on 18 Dec 2019

In one of my two environments the master crashed as expected. This proved the environment. From now both envs will prove #7712. I'll give you an update tomorrow.

Al2Klimov picture Al2Klimov on 19 Dec 2019

v2.11 + #7712 crashed. Red light for both v2.11.x and v2.12-rc1. I'll continue bisecting on the proved envs next year and give you and update ASAP.

Merry Xmas and a happy NY,
AK

@gethash @lippserd @dnsmichi

Al2Klimov picture Al2Klimov on 20 Dec 2019
👍1

https://github.com/Al2Klimov/icinga-iliketrains

Al2Klimov picture Al2Klimov on 20 Dec 2019

@Al2Klimov @lippserd #7713 with the increased coroutine stack size was not included in the tests, right?

Especially the mention of nested XML tree structures in combination with Boost ASIO sound familiar with our problem and JSON structures.

https://stackoverflow.com/questions/41030285/boostproperty-treeread-xml-segfaults-in-an-asio-handler-spawned-using-boost

If 256KB are not enough, please continue with your immediate tests and raise this limit to

  • 512 KB
  • 1024KB
  • 2048KB
  • 4096KB
  • 8192KB

to mitigate whether this has an impact. On Windows, it definitely had.

https://github.com/Icinga/icinga2/pull/7713/files#diff-79f8d5c1848645a80a0fd35e6cd24c0c

dnsmichi picture dnsmichi on 6 Jan 2020

I tested the last current snapshots which included the PR in question. --no-stack-rlimit was active. My test setup included two masters and two satellites having the api, check, log and notification features enabled. I noticed that the config master produced a massive amount of state files. The crashes are reproducible and look like the following:

GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/lib/x86_64-linux-gnu/icinga2/sbin/icinga2...Reading symbols from /usr/lib/debug/.build-id/01/267f040293ca31203a53bba04029d07430e3c0.debug...done.
done.
[New LWP 3269]
[New LWP 3271]
[New LWP 3277]
[New LWP 3273]
[New LWP 3270]
[New LWP 3266]
[New LWP 3315]
[New LWP 3318]
[New LWP 3278]
[New LWP 3268]
[New LWP 3330]
[New LWP 3332]
[New LWP 3328]
[New LWP 3326]
[New LWP 3319]
[New LWP 3325]
[New LWP 3265]
[New LWP 3316]
[New LWP 3331]
[New LWP 3321]
[New LWP 3317]
[New LWP 3322]
[New LWP 3324]
[New LWP 3272]
[New LWP 3267]
[New LWP 3323]
[New LWP 3275]
[New LWP 3276]
[New LWP 3333]
[New LWP 3327]
[New LWP 3314]
[New LWP 3320]
[New LWP 3274]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/lib/x86_64-linux-gnu/icinga2/sbin/icinga2 --no-stack-rlimit daemon --close'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  std::__atomic_base<unsigned long>::fetch_add (__m=std::memory_order_seq_cst, __i=1, this=0x41d77ec376281a09) at /usr/include/c++/8/bits/atomic_base.h:512
512     /usr/include/c++/8/bits/atomic_base.h: No such file or directory.
[Current thread is 1 (Thread 0x7f1a81784700 (LWP 3269))]
(gdb) bt full
#0  std::__atomic_base<unsigned long>::fetch_add (__m=std::memory_order_seq_cst, __i=1, this=0x41d77ec376281a09) at /usr/include/c++/8/bits/atomic_base.h:512
No locals.
#1  icinga::intrusive_ptr_add_ref (object=0x41d77ec376281a01) at ./lib/base/object.cpp:248
No locals.
#2  boost::intrusive_ptr<icinga::Object>::intrusive_ptr (add_ref=<optimized out>, p=<optimized out>, this=<optimized out>, this=<optimized out>, p=<optimized out>, add_ref=<optimized out>) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:69
No locals.
#3  boost::dynamic_pointer_cast<icinga::Object, icinga::Object> (p=...) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:312
No locals.
#4  _ZNK6icinga5ValuecvN5boost13intrusive_ptrIT_EEINS_6ObjectEEEv (this=<optimized out>) at ./lib/base/value.hpp:103
        __PRETTY_FUNCTION__ = <optimized out>
        object = <optimized out>
        tobject = {px = 0x41d77ec376281a01}
#5  0x0000563bd299bb2d in SerializeStack::Push (this=0x7f1a81783160, name=..., val=...) at ./lib/base/serializer.cpp:44
        obj = {px = 0x0}
        __PRETTY_FUNCTION__ = "void SerializeStack::Push(const icinga::String&, const icinga::Value&)"
#6  0x0000563bd29ac0dd in SerializeObject (stack=..., attributeTypes=4, input=...) at /usr/include/c++/8/bits/allocator.h:139
        field = {ID = 0, TypeName = 0x563bd2bb8af9 "Value", Name = 0x563bd2ac065d "command", NavigationName = 0x563bd2ac065d "command", RefTypeName = 0x0, Attributes = 4, ArrayRank = 0}
        value = {m_Value = {which_ = 4, storage_ = {<boost::detail::aligned_storage::aligned_storage_imp<32, 8>> = {data_ = {buf = "\001\032(v\303~\327A\027\000\000\000\000\000\000\000\027\000\000\000\000\000\000\000\002\000\000\000\000\000\000", align_ = {<No data fields>}}}, static size = <optimized out>, 
              static alignment = <optimized out>}}}
        i = 0
        type = {px = 0x563bd4302eb0}
        fields = std::vector of length 0, capacity 8
        olock = {m_Object = 0x7f1a280deb10, m_Locked = true}
        type = <optimized out>
        fields = <optimized out>
        olock = <optimized out>
        i = <optimized out>
        field = <optimized out>
        value = <optimized out>
#7  SerializeInternal (value=..., attributeTypes=4, stack=...) at ./lib/base/serializer.cpp:253
        input = {px = 0x7f1a280deb10}
        array = {px = 0x0}
        dict = {px = 0x0}
        ns = {px = 0x0}
#8  0x0000563bd29ac719 in icinga::Serialize (value=..., attributeTypes=<optimized out>) at ./lib/base/serializer.cpp:259

        stack = {Entries = std::deque with 0 elements}
#9  0x0000563bd279b51e in icinga::ClusterEvents::NotificationSentUserHandler (notification=..., checkable=..., user=..., notificationType=<optimized out>, cr=..., nr=..., author=..., commentText=..., command=..., origin=...) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:96
        listener = {px = 0x7f1a74004bc0}
        host = {px = 0x7f1a74363570}
        service = {px = 0x0}
        params = {px = 0x7f19fc104ba0}
        message = {px = 0x7f1a6d37b2c0}
#10 0x0000563bd2701bef in boost::function10<void, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>::operator() (a9=..., a8=..., a7=..., a6=..., a5=..., a4=..., a3=<optimized out>, a2=..., a1=..., a0=..., this=<optimized out>)
    at /usr/include/boost/function/function_template.hpp:682
No locals.
#11 boost::signals2::detail::call_with_tuple_args<boost::signals2::detail::void_type>::m_invoke<boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>, 0u, 1u, 2u, 3u, 4u, 5u, 6u, 7u, 8u, 9u, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>(boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>&, boost::signals2::detail::unsigned_meta_array<0u, 1u, 2u, 3u, 4u, 5u, 6u, 7u, 8u, 9u>, std::tuple<boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&> const&, boost::enable_if<boost::is_void<boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>::result_type>, void>::type*) const (this=<optimized out>, args=std::tuple containing = {...}, func=...)
    at /usr/include/boost/signals2/detail/variadic_slot_invoker.hpp:105
No locals.
#12 boost::signals2::detail::call_with_tuple_args<boost::signals2::detail::void_type>::operator()<boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, 10ul>(boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>&, std::tuple<boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&> const&, mpl_::size_t<10ul>) const (this=<optimized out>, args=std::tuple containing = {...}, func=...)
    at /usr/include/boost/signals2/detail/variadic_slot_invoker.hpp:90
No locals.
#13 boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>::operator()<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<i--Type <RET> for more, q to quit, c to continue without paging--
nt> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >(boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > const&) const (connectionBody=..., this=0x7f1a81783620) at /usr/include/boost/signals2/detail/variadic_slot_invoker.hpp:133
No locals.
#14 boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >::dereference() const (this=0x7f1a81783420) at /usr/include/boost/signals2/detail/slot_call_iterator.hpp:110
No locals.
#15 boost::iterators::iterator_core_access::dereference<boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >(boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > const&) (f=...) at /usr/include/boost/iterator/iterator_facade.hpp:550
No locals.
#16 boost::iterators::detail::iterator_facade_base<boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >, boost::signals2::detail::void_type, boost::iterators::single_pass_traversal_tag, boost::signals2::detail::void_type const&, long, false, false>::operator*() const (this=0x7f1a81783420)
    at /usr/include/boost/iterator/iterator_facade.hpp:656
No locals.
#17 boost::signals2::optional_last_value<void>::operator()<boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >(boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >, boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> --Type <RET> for more, q to quit, c to continue without paging--
const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >) const (this=<optimized out>, last=..., first=...)
    at /usr/include/boost/signals2/optional_last_value.hpp:57
No locals.
#18 boost::signals2::detail::combiner_invoker<void>::operator()<boost::signals2::optional_last_value<void>, boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >(boost::signals2::optional_last_value<void>&, boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >, boost::signals2::detail::slot_call_iterator_t<boost::signals2::detail::variadic_slot_invoker<boost::signals2::detail::void_type, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&>, std::_List_iterator<boost::shared_ptr<boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> > >, boost::signals2::detail::connection_body<std::pair<boost::signals2::detail::slot_meta_group, boost::optional<int> >, boost::signals2::slot<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)> >, boost::signals2::mutex> >) const (this=<optimized out>, last=..., first=..., combiner=...) at /usr/include/boost/signals2/detail/result_type_wrapper.hpp:64
No locals.
#19 boost::signals2::detail::signal_impl<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&), boost::signals2::optional_last_value<void>, int, std::less<int>, boost::function<void (boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>, boost::function<void (boost::signals2::connection const&, boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&)>, boost::signals2::mutex>::operator()(boost::intrusive_ptr<icinga::Notification> const&, boost::intrusive_ptr<icinga::Checkable> const&, boost::intrusive_ptr<icinga::User> const&, icinga::NotificationType const&, boost::intrusive_ptr<icinga::CheckResult> const&, boost::intrusive_ptr<icinga::NotificationResult> const&, icinga::String const&, icinga::String const&, icinga::String const&, boost::intrusive_ptr<icinga::MessageOrigin> const&) (this=<optimized out>, args#0=..., 
    args#1=..., args#2=..., args#3=<optimized out>, args#4=..., args#5=..., args#6=..., args#7=..., args#8=..., args#9=...) at /usr/include/boost/signals2/detail/signal_template.hpp:243
        local_state = {px = 0x563bd42ce700, pn = {pi_ = 0x563bd42ce7f0}}
        it = non-dereferenceable iterator for std::list
        invoker = {_args = std::tuple containing = {[1] = <optimized out>, [2] = <optimized out>, [3] = <optimized out>, [4] = <optimized out>, [5] = <optimized out>, [6] = <optimized out>, [7] = <optimized out>, [8] = <optimized out>, [9] = @0x7f1a81783850, [10] = @0x7f1a81783778}}
        cache = {result = {<boost::optional_detail::optional_base<boost::signals2::detail::void_type>> = {<boost::optional_detail::optional_tag> = {<No data fields>}, m_initialized = false, m_storage = {dummy_ = {data = "\035", aligner_ = 29 '\035'}}}, <No data fields>}, 
          tracked_ptrs = {<std::allocator<boost::variant<boost::shared_ptr<void>, boost::signals2::detail::foreign_void_shared_ptr> >> = {<__gnu_cxx::new_allocator<boost::variant<boost::shared_ptr<void>, boost::signals2::detail::foreign_void_shared_ptr> >> = {<No data fields>}, <No data fields>}, 
            static is_stack_buffer_empty = <optimized out>, members_ = {<boost::aligned_storage<240, 8>> = {<boost::detail::aligned_storage::aligned_storage_imp<240, 8>> = {data_ = {
                    buf = "\000NӃ\032\177\000\000\004\000\000\000\032\177\000\000\300\262\067m\032\177\000\000\n\000\000\000\000\000\000\000\220\064x\201\032\177\000\000\000\000\000\000\000\000\000\000\004\000\000\000;V\000\000\000\071\000l\032\177\000\000\350\260\060\324;V\000\000\330\065x\201\032\177\000\000\340\065x\201\032\177\000\000\004\000\000\000\032\177\000\000\220I\357\064\032\177\000\000\350\260\060\324;V\000\000)E\231\322;V\000\000\270\260\060\324;V\000\000\004\000\000\000\032\177\000\000\020\353\r(\032\177\000\000\360\204\321\322;V\000\000\204\203%v\303~\327A\000\000\000\000\032\177\000\000\001\000\000\000\031\177\000\000\000\000\000\000\000\000@@\036\000\000\000\000\000\000\000p^\324\322;V\000\000\200"..., align_ = {<No data fields>}}}, static size = <optimized out>, static alignment = <optimized out>}, capacity_ = 10}, buffer_ = 0x7f1a81783518, size_ = 0}, f = {_args = std::tuple containing = {
              [1] = @0x7f1a81783788, [2] = @0x7f1a81783780, [3] = @0x7f1a3ca91da0, [4] = @0x7f1a8178375c, [5] = @0x7f1a3ca91d98, [6] = @0x7f1a81783770, [7] = @0x7f1a3ca91d70, [8] = @0x7f1a3ca91d50, [9] = @0x7f1a81783850, [10] = @0x7f1a81783778}}, connected_slot_count = 1, disconnected_slot_count = 0, 
          m_active_slot = 0x563bd43ba640}
        janitor = {<boost::noncopyable_::noncopyable> = {<No data fields>}, _cache = @0x7f1a81783510, _sig = @0x563bd42ce6d0, _connection_bodies = 0x563bd42ce730}
        list_lock = <optimized out>
#20 0x0000563bd273fa2a in icinga::Notification::ExecuteNotificationHelper (this=<optimized out>, type=<optimized out>, user=..., cr=..., force=<optimized out>, author=..., text=...) at /usr/include/boost/smart_ptr/shared_ptr.hpp:726
        notificationName = {static NPos = 18446744073709551615, m_Data = "dummy-5508!dummy"}
        userName = {static NPos = 18446744073709551615, m_Data = "user5"}
        checkableName = {static NPos = 18446744073709551615, m_Data = "dummy-5508"}
        command = {px = 0x7f1a70000cd0}
        commandName = {static NPos = 18446744073709551615, m_Data = "dummy-notification"}
        nr = <optimized out>
        ex = <optimized out>
#21 0x0000563bd26de231 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&> (__t=<optimized out>, __f=<optimized out>) at /usr/include/c++/8/bits/invoke.h:89
No locals.
--Type <RET> for more, q to quit, c to continue without paging--
#22 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=<optimized out>, __fn=<optimized out>) at /usr/include/c++/8/bits/invoke.h:95
No locals.
#23 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>) (__args=..., this=<optimized out>) at /usr/include/c++/8/functional:400
No locals.
#24 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=<optimized out>) at /usr/include/c++/8/functional:484
No locals.
#25 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
No locals.
#26 0x0000563bd296aedd in icinga::ThreadPool::Post<std::function<void ()> >(std::function<void ()>, icinga::SchedulerPolicy)::{lambda()#1}::operator()() const () at /usr/include/c++/8/bits/std_function.h:682
        l_TimerMutex = <optimized out>
        l_StopTimerThread = false
        l_False = "false"
        l_True = "true"
        icinga::l_RandomMutex = <optimized out>
        l_Utf8Replacement = "�"
        icinga::l_Mutexes = <optimized out>
        l_Null = "null"
        l_TimerCV = <optimized out>
        l_TimerThread = <optimized out>
        icinga::l_SSLInitialized = true
        l_Timers = <optimized out>
        l_AliveTimers = 13
        boost::optional_ns::in_place_init_if = <optimized out>
        std::__ioinit = <optimized out>
        boost::asio::error::misc_category = <optimized out>
        boost::optional_ns::in_place_init = <optimized out>
        boost::none = <optimized out>
        boost::asio::error::addrinfo_category = <optimized out>
        boost::asio::error::netdb_category = <optimized out>
        boost::asio::error::system_category = <optimized out>
        l_StopTimerThread = <optimized out>
        l_AliveTimers = <optimized out>
        nlohmann::(anonymous namespace)::from_json = <optimized out>
        l_LastExceptionContext = <optimized out>
        l_ProcessOnceFlag = <optimized out>
        l_FDs = <optimized out>
        l_EventFDs = <optimized out>
        icinga::l_RandomMutex = <optimized out>
        icinga::l_SSLInitialized = <optimized out>
        l_LastExceptionStack = <optimized out>
        l_ProcessControlPID = <optimized out>
        l_SpawnHelperOnceFlag = <optimized out>
        l_TimerThread = <optimized out>
        (anonymous namespace)::io0::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io1::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io2::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io3::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io4::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io5::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io6::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io7::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io8::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io9::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io10::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io11::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io12::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io13::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io14::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io15::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io16::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io17::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io18::l_InitializeOnce = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        (anonymous namespace)::io19::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io20::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io21::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io22::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io23::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io24::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io25::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io26::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io27::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io28::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io29::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io30::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io31::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io32::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io33::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io34::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io35::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io36::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io37::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io38::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io39::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io40::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io41::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io42::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io43::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io44::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io45::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io46::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io47::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io48::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io49::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io50::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io51::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io52::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io53::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io54::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io55::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io56::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io57::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io58::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io59::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io60::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io61::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io62::l_InitializeOnce = <optimized out>
        (anonymous namespace)::io63::l_InitializeOnce = <optimized out>
        l_InternalNSBehavior = <optimized out>
        boost::optional_ns::in_place_init_if = <optimized out>
        boost::optional_ns::in_place_init = <optimized out>
        boost::asio::error::misc_category = <optimized out>
        boost::asio::error::system_category = <optimized out>
        std::__ioinit = <optimized out>
        boost::asio::ssl::error::stream_category = <optimized out>
        l_Restarting = <optimized out>
        l_ProcessMutex = <optimized out>
        boost::none = <optimized out>
        l_ProcessControlMutex = <optimized out>
        nlohmann::(anonymous namespace)::to_json = <optimized out>
        l_Indent = <optimized out>
        l_Timers = <optimized out>
        l_TimerMutex = <optimized out>
        l_Null = <optimized out>
        l_InExceptionHandler = <optimized out>
        boost::asio::error::ssl_category = <optimized out>
        l_TimerCV = <optimized out>
        l_EndiannessDetector = <optimized out>
        l_True = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        boost::asio::error::addrinfo_category = <optimized out>
        l_Processes = <optimized out>
        l_ConsoleType = <optimized out>
        l_Utf8Replacement = <optimized out>
        l_ProcessControlFD = <optimized out>
        l_Frames = <optimized out>
        l_False = <optimized out>
        boost::asio::error::netdb_category = <optimized out>
        l_ShutdownTimersCleanlyOnExit = <optimized out>
        icinga::l_Mutexes = <optimized out>
        icinga::WorkQueue::m_NextID = {<std::__atomic_base<int>> = {static _S_alignment = 4, _M_i = 9}, <No data fields>}
        icinga::Configuration::RLimitFiles = 16384
        icinga::Configuration::AttachDebugger = false
        icinga::Configuration::RLimitStack = 262144
        icinga::Configuration::RLimitProcesses = 16384
#27 0x0000563bd292a065 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=<optimized out>, base=<optimized out>) at /usr/include/boost/asio/impl/system_executor.hpp:35
        o = <optimized out>
        allocator = <optimized out>
        p = {a = <optimized out>, v = 0x0, p = 0x0}
        handler = {work_ = {executor_ = {<No data fields>}, owns_ = true}, handler_ = {__this = 0x563bd2d48740 <icinga::Application::GetTP()::tp>, __callback = {<std::_Maybe_unary_or_binary_function<void>> = {<No data fields>}, <std::_Function_base> = {static _M_max_size = 16, static _M_max_align = 8, 
                _M_functor = {_M_unused = {_M_object = 0x7f1a81783ca0, _M_const_object = 0x7f1a81783ca0, _M_function_pointer = 0x7f1a81783ca0, _M_member_pointer = (void (std::_Undefined_class::*)(std::_Undefined_class * const)) 0x7f1a81783ca0, this adjustment 1}, 
                  _M_pod_data = "\240<x\201\032\177\000\000\001\000\000\000\000\000\000"}, _M_manager = 0x0}, _M_invoker = 0x563bd4325f80}}}
        b = <optimized out>
#28 0x0000563bd29c4f1b in boost::asio::detail::scheduler_operation::complete (bytes_transferred=<optimized out>, ec=..., owner=0x563bd4325f80, this=<optimized out>) at /usr/include/boost/asio/detail/scheduler_operation.hpp:40
No locals.
#29 boost::asio::detail::scheduler::do_run_one (ec=..., this_thread=..., lock=..., this=<optimized out>) at /usr/include/boost/asio/detail/impl/scheduler.ipp:401
        task_result = <optimized out>
        on_exit = <optimized out>
        o = <optimized out>
        more_handlers = true
#30 boost::asio::detail::scheduler::run (this=<optimized out>, ec=...) at /usr/include/boost/asio/detail/impl/scheduler.ipp:154
        this_thread = {<boost::asio::detail::thread_info_base> = {<boost::asio::detail::noncopyable> = {<No data fields>}, reusable_memory_ = {0x7f1a240cc830, 0x0}}, private_op_queue = {<boost::asio::detail::noncopyable> = {<No data fields>}, front_ = 0x0, back_ = 0x0}, private_outstanding_work = 0}
        ctx = {<boost::asio::detail::noncopyable> = {<No data fields>}, key_ = 0x563bd4325f80, value_ = 0x7f1a81783d80, next_ = 0x0}
        lock = {<boost::asio::detail::noncopyable> = {<No data fields>}, mutex_ = @0x563bd4325fb0, locked_ = false}
        n = 1451553
#31 0x0000563bd28fb765 in boost::asio::thread_pool::thread_function::operator() (this=<optimized out>) at /usr/include/boost/asio/impl/thread_pool.ipp:33
        ec = {m_val = 0, m_cat = 0x7f1a843ce070}
        ec = <optimized out>
#32 boost::asio::detail::posix_thread::func<boost::asio::thread_pool::thread_function>::run (this=<optimized out>) at /usr/include/boost/asio/detail/posix_thread.hpp:86
No locals.
#33 0x0000563bd29bccff in boost::asio::detail::boost_asio_detail_posix_thread_function (arg=<optimized out>) at /usr/include/boost/asio/detail/impl/posix_thread.ipp:74
        func = {ptr = 0x563bd4326200}
#34 0x00007f1a843d6fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
        ret = <optimized out>
        pd = <optimized out>
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139751818020608, -2113946693049274543, 140734008723230, 140734008723231, 139751818020608, 94814963045552, 2061736441401028433, 2061743542559944529}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
#35 0x00007f1a839ae4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.
lippserd picture lippserd on 7 Jan 2020 
#9  0x0000563bd279b51e in icinga::ClusterEvents::NotificationSentUserHandler (notification=..., checkable=..., user=..., notificationType=<optimized out>, cr=..., nr=..., author=..., commentText=..., command=..., origin=...) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:96
        listener = {px = 0x7f1a74004bc0}
        host = {px = 0x7f1a74363570}
        service = {px = 0x0}
        params = {px = 0x7f19fc104ba0}
        message = {px = 0x7f1a6d37b2c0}

Since service is a nullptr, this is a host notification sync. 

        notificationName = {static NPos = 18446744073709551615, m_Data = "dummy-5508!dummy"}
        userName = {static NPos = 18446744073709551615, m_Data = "user5"}
        checkableName = {static NPos = 18446744073709551615, m_Data = "dummy-5508"}
        command = {px = 0x7f1a70000cd0}
        commandName = {static NPos = 18446744073709551615, m_Data = "dummy-notification"}

@lippserd I suspect a problem with #6722 here. Since this already was part of 2.11, the analysis matches this partially. We could try reverting it and see whether this has any effect.

Keep in mind though that the original crash was not related to notifications, so my merged PRs with #7712 and #7713 may have an impact on the crash itself.

dnsmichi picture dnsmichi on 7 Jan 2020

I've reproduced @lippserd's bug ("Notification-Result-Bug") with cd44c5371 and will bisect it independently of the JSON-RPC-Bug.

Al2Klimov picture Al2Klimov on 8 Jan 2020

@lippserd I've updated https://github.com/Al2Klimov/icinga-iliketrains and my instance of it:

  • node setup signs lazily to work around a problem which prevented the next bisect step up to and including today
  • the nodes can open 1000000 files, just to be sure
  • core dumps are enabled o/
  • packages are being cached

Now as the setup has changed I'll wait until today evening to prove it.

Al2Klimov picture Al2Klimov on 10 Jan 2020

@lippserd ... and I've documented your bug:

https://github.com/Al2Klimov/icinga-ilikenotificationresults

Al2Klimov picture Al2Klimov on 10 Jan 2020

Does the crash still happen with git master?

dnsmichi picture dnsmichi on 10 Jan 2020

Which crash? Mine or @lippserd's? Neither I can test mine as the only env for it is busy (for the next one or two weeks), nor the other one as the next 24 hours would cross the weekend. Shall I test @lippserd's crash monday-tuesday?

Al2Klimov picture Al2Klimov on 10 Jan 2020

The JSON-RPC crash from this issue. The NotificationResult crash happened during testing and was resolved with reverting the patch introduced in 2.11 (see #7737 being now merged to master).

dnsmichi picture dnsmichi on 10 Jan 2020

Once we've done 2.11.x, we should have a look at what's wrong with that now reverted patch.

Al2Klimov picture Al2Klimov on 10 Jan 2020

Once we've done 2.11.x, we should have a look at what's wrong with that now reverted patch.

Since it wasn't tested in-depth nor incorporated for IcingaDB, there's no extra value or loosing value here with just leaving that as is, reverted. If IcingaDB ever needs the executed notification command line, we may re-iterate on a new design.

This doesn't answer my question though.

only env for it is busy (for the next one or two weeks)

I'd suggest to shift priorities with testing the git master then. I've discussed that possibility with @lippserd yesterday.

dnsmichi picture dnsmichi on 10 Jan 2020

I've not even looked into the Git master due to the experience with #7712. We have < 10 bisect steps and a lot of possible shots-in-the-dark. I'm honestly working on another parallel env for the shots (which may or may not solve the problem), but I'll keep one env for bisecting (which will find the problem very likely).

Al2Klimov picture Al2Klimov on 10 Jan 2020

Maybe someone of the externals thinks that we haven't any progress there, but that's not true. My reproduction strategy is getting better and better (slowly, but surely) and my cause search strategy – Git bisect – will definitively find the problem's cause.

Al2Klimov picture Al2Klimov on 10 Jan 2020

Hi
@bunghi @MarkNReynolds @Napsty @mattrose @jivuvtramvae @verboEse @BastiBr @Sec42
and all others facing this bug,

We pushed several changes to our snapshot packages which affect and may mitigate the JSON-RPC crash (and another segfault related to notification result syncing). It would be of great help to us if you could test those packages in your environments and provide feedback. Please enable core dumps beforehand so that we get as many information as possible if the crash still occurs. If the crash happens "reliably" in your setup, please share as much details as possible about your setup.

Thanks and cheers,
Eric

lippserd picture lippserd on 10 Jan 2020
👍1

... and here's how you enable core dumps: https://github.com/Al2Klimov/icinga-iliketrains/blob/001c57022b825bf8f5e4cf6845d191dca7d3a847/ansible-playbook.yml#L152

Al2Klimov picture Al2Klimov on 10 Jan 2020

Good news: The updated env crashed as expected.

Bad news: That took about 2.5 days. Better late than never.

Al2Klimov picture Al2Klimov on 13 Jan 2020

Core dump & co.: https://nextcloud.icinga.com/index.php/s/nJ6yeAY2cFeQYyL

Al2Klimov picture Al2Klimov on 13 Jan 2020

The crashed env was 1c79c2b34. Now I deployed e909302fd. I'll give you an update during the next 1-2.5 days.

Al2Klimov picture Al2Klimov on 13 Jan 2020

Some notes.

Might have an influence if both endpoint direction attempt to connect to each other with clearing one side right after. Or many broken pipes, e.g. the other side closes the socket not so clean.

Other research things, not sure if they match.

https://github.com/ceph/spawn/commits/master is a header only fork by a RedHat developer of asio::spawn making use of callcc instead of fcontext from the coroutine library. It removes the coroutine layer entirely.

Might again have to do something with stack unwinding and exceptions. Worth collecting the Boost versions and OS'es into a table for variety patterns?

dnsmichi picture dnsmichi on 15 Jan 2020

e909302fd didn't crash, so we have a commit range: (e909302fd.. 1c79c2b34]

I'll continue with 794374a32 and give you an update on monday.

Al2Klimov picture Al2Klimov on 16 Jan 2020

Thanks 👍

I have another theory: A combination of stack sizes, recursion and large JSON blobs processed inside the coroutines. If the connection between agent/master is dropped uncleanly, say broken pipe or connection reset, there may be a leak with a running coroutine which never terminates. Or something else corrupts the stack then, or we hit the number of opened files.

This may be influenced with setups where the connection direction is in both ends, contradicting to what's written in the docs. This is where a timer kills off the secondary connection for the endpoint, on both sides (race condition time).

Similar to number of spawned threads, we likely should measure how many coroutines we have spawned and log that somewhere with a timer, similar to the Workqueues, plus an API stats metric.

dnsmichi picture dnsmichi on 16 Jan 2020

794374a32 crashed. New commit range: (e909302fd.. 794374a32] - https://github.com/icinga/icinga2/compare/e909302..794374a

I'll continue with 37de1a919 and give you an update on monday.

Al2Klimov picture Al2Klimov on 16 Jan 2020

Follow-up read on the Ceph discussion: https://lists.ceph.io/hyperkitty/list/[email protected]/thread/6LBFZIFUPTJQ3SNTLVKSQMVITJWVWTZ6/?sort=date

The pooled_fixedsize_stack appears to have the same 2 limitations as the
current fixedsize_stack: each stack has a fixed size of 128K by default,
and there's no memory protection to detect stack overflows. The only
difference seems to be that freed stacks are kept in a boost::pool to be
reused for later stack allocations.

The motivation for enforcing a limit on the per-connection stack size is
to help scale to lots of concurrent connections. However, if the
requests are mostly object gets/puts, we'll be buffering up to 16M of
object data per request and that's going to dwarf these stacks.

I think the protected_fixedsize_stack gives us the most flexibility
here. In addition to the overflow detection from mmap+mprotect, it lets
us map a comfortable amount of memory without having to allocate pages
for them up front, and essentially behaving like the pthread stacks
we're used to.

I've tried implementing their fork, but it uses several C++14/17 features. Let's if we can just boil it down to whatever is needed. https://github.com/Icinga/icinga2/pull/7762 - https://github.com/boostorg/asio/pull/55/files

Other collected thoughts.

https://github.com/boostorg/beast/issues/1055

I built a REST based server built upon the http_client_coro.cpp example which uses stackful coroutines. During one of our request handlers the app needs to reread an xml config file using boost::property_tree. In the read_xml_internal method we get a Access Violation exception. The top of the stack shows the function _chkstk() being called. Using VS2017 core guideline checker we get C6262 warning in the boost property tree that too much stack space is being used. We set the Linker->System->Stack Reserve Size to 4194304 but the crash still happens.

https://groups.google.com/forum/#!topic/boost-list/Lgo931jYc0E

In C and C++, each coroutine (and thread for that matter) must have a single,
contiguous stack which, in addition, cannot grow. Because of this, you should 1) avoid large local variables (e.g., arrays), 2) avoid recursion of any kind, 3) avoid calling any other functions that use a lot of stack (see 1) and 2)), 4) have enough stack space for signal handling [actually, the best thing to do is to install an alternate signal stack by using sigaltstack()].

If you're running in 64-bit mode, try setting the stack size of each coroutine
to something like 1MB; the system's demand-paging logic will actually allocate
as much physical memory as the program needs. But the fundamental limitations
listed above remain.

My last guess for now is that with the stack protection changes implemented in the Kernel because of the Intel microcode fuckup, the behaviour of these stackful coroutines is different to what it used to be before. On Windows, there was definitely some stack protection going on, corrupting the stack with guard pages.

I'd say this wouldn't crash if being run on a Kernel without these stack protection patches.

dnsmichi picture dnsmichi on 17 Jan 2020

37de1a919 crashed. New commit range: (e909302..37de1a919]

I'll continue with 64568f596 and give you an update on monday.

Al2Klimov picture Al2Klimov on 17 Jan 2020
👍1

@lippserd Congrats, 1c79c2b34 crashes w/ (1) in about 3h. I'll re-test it and give you an update ASAP.

1

- hosts: 'icingas:!aklimov-iliketrains2-master1:!aklimov-iliketrains2-master2'
  become: yes
  become_method: sudo
  tasks:
  - copy:
      dest: /vola.pl
      owner: root
      group: root
      mode: '0755'
      content: |
        #!/usr/bin/perl
        while (1) {
          sleep((rand() * 9 + 1) * 60);
          print "OFF\n";
          `iptables -I INPUT -p tcp -m tcp --dport 5665 -j DROP`;
          `iptables -I OUTPUT -p tcp -m tcp --dport 5665 -j DROP`;
          sleep((rand() * 4 + 1) * 60);
          print "ON\n";
          `iptables -D INPUT -p tcp -m tcp --dport 5665 -j DROP`;
          `iptables -D OUTPUT -p tcp -m tcp --dport 5665 -j DROP`
        }
  - copy:
      dest: /etc/systemd/system/vola.service
      owner: root
      group: root
      mode: '0644'
      content: |
        [Unit]
        [Service]
        ExecStart=/vola.pl
        [Install]
        WantedBy=multi-user.target
  - systemd:
      daemon_reload: yes
  - service:
      name: vola
      state: started
      enabled: yes
Al2Klimov picture Al2Klimov on 17 Jan 2020
🚀1

The 2nd time it needed 24h. I'll re-test it again and give you an update ASAP.

Al2Klimov picture Al2Klimov on 20 Jan 2020

Meanwhile, following the diff leads to the following assumptions:

  • NetStream implementation for ASIO streams
  • Object locking refactoring based on atomic, avoiding spin locks
  • Threadpool replacement from our own to Boost.ASIO
  • Timer pointer fixes, but this would affect 2.10.5 as well
  • boost::filesystem exceptions
  • Log replay fixes
dnsmichi picture dnsmichi on 20 Jan 2020

64568f596 didn't crash. New commit range: (64568f596..37de1a919]

I'll continue with 56894bea1 and give you an update on thursday.

Al2Klimov picture Al2Klimov on 20 Jan 2020
👍1

56894bea1 was killed – not what I expected.

I'll continue with 02db12ae0 and give you an update on friday.

Al2Klimov picture Al2Klimov on 21 Jan 2020

The remaining commit range and the changes are a bit long, but some commits seem not to build. I've patched them:

for c in $(git log --format=%h --first-parent 64568f5..37de1a9); do git checkout $c; git cherry-pick 56894bea17df0f7ede19dd1df2b093033ea4190c; git push origin HEAD:refs/heads/aklimov/iliketrains4/$c; done

... and will hopefully continue with 43e9ae5f8.

Al2Klimov picture Al2Klimov on 21 Jan 2020

I've added the network volatility to the test env spec as it crashed again in less than two days.

Al2Klimov picture Al2Klimov on 22 Jan 2020

The master (18eb06e33) crashed – on both master nodes this time.

Al2Klimov picture Al2Klimov on 23 Jan 2020

Just a comment from my side here, since questions are around - I now see the bisect strategy from @Al2Klimov as the only valid strategy to find out about the error.

Currently, I don't have further ideas for mitigating the error, except for raising the stack limit for coroutines. Which would highlight a stack overflow, but that's still a problem not necessarily solved with additional memory.

This involves waiting and no immediate feedback, and is totally different to a scenario where you debug something and it crashes after 1 hour in your dev environment.

After finding the commit which creates the problem, we sure need to invest development time to actually create a patch. And this patch again requires tests, and then we'll consider releasing 2.12 RC.

Currently this problem solely blocks the entire release chain for the IcingaDB release, including Web 2.8, the icingadb module, IcingaDB itself and Icinga 2.12.

After that's done, backporting the fix to 2.11, testing it again and then releasing a bugfix release is on the TODO list.

Cheers,
Michael

dnsmichi picture dnsmichi on 23 Jan 2020
👍3 🚀1

I now see the bisect strategy from @Al2Klimov as the only valid strategy to find out about the error.

Finally somebody says it! 😎

Al2Klimov picture Al2Klimov on 23 Jan 2020

43e9ae5 didn't crash. New commit range: (43e9ae5..37de1a9]

I'll continue with 268c8b395 and give you an update on monday.

Al2Klimov picture Al2Klimov on 24 Jan 2020

Thanks. Boils down to https://github.com/icinga/icinga2/compare/43e9ae5..37de1a9

  • Threadpool replacement from our own to Boost.ASIO
  • Timer pointer fixes and the flush log timer fixes
  • boost::filesystem exceptions
  • API EventQueue changes
  • NotificationResult (removed in master, crashes, no impact)

Since the Timer is something we implement ourselves, I'll investigate here for a possible mitigation/change.

dnsmichi picture dnsmichi on 24 Jan 2020

268c8b395 got killed, but not segv-ed. Assuming that it's not affected. New commit range: (268c8b395..37de1a919]

I'll continue with 0438c866f and give you an update on wednesday.

Al2Klimov picture Al2Klimov on 27 Jan 2020

Thanks a lot for the update. This removes the Timer fixes.
https://github.com/icinga/icinga2/compare/268c8b3..37de1a9

  • Threadpool replacement from our own to Boost.ASIO
  • boost::filesystem exceptions
  • API EventQueue changes
  • NotificationResult (removed in master, crashes, no impact)

Now I need to wait for future updates, I currently don't know what would cause the crash from the diff.

dnsmichi picture dnsmichi on 27 Jan 2020

... and I don't know whether 268c8b3 actually isn't affected, yet.

Al2Klimov picture Al2Klimov on 27 Jan 2020

I've been analyzing #7771 with the boost::filesystem::remove_all call. There's a certain chance that these recursive attempts (and failure when a file cannot be deleted) cause a stack overflow, like mentioned here: http://boost.2283326.n4.nabble.com/filesystem-remove-all-error-handling-td2603383.html

Specifically, ApiListener::ConfigUpdateHandler() is called every time we receive a cluster config sync update. I've seen this exception on both Windows in #7761 (1.69.0) and Debian 10 in #7771 (1.67.0.1) now. 

[2020-01-20 15:18:38 +0100] warning/JsonRpcConnection: Error while processing message for identity 'broker01.example.com'
Error: boost::filesystem::remove: Directory not empty: "/var/lib/icinga2/api/zones-stage/"


        (0) libboost_filesystem.so.1.67.0: <unknown function> (+0xe2ef) [0x7fc4bd0062ef]
        (1) libboost_filesystem.so.1.67.0: boost::filesystem::detail::remove_all(boost::filesystem::path const&, boost::system::error_code*) (+0xb6) [0x7fc4bd006946]
        (2) icinga2: icinga::Utility::RemoveDirRecursive(icinga::String const&) (+0x8f) [0x63967f]
        (3) icinga2: icinga::ApiListener::ConfigUpdateHandler(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0x55b) [0x753aab]
        (4) icinga2: std::_Function_handler<icinga::Value (boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&), icinga::Value (*)(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&)>::_M_invoke(std::_Any_data const&, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) (+0xf) [0x7a828f]
        (5) icinga2: icinga::JsonRpcConnection::MessageHandler(icinga::String const&) (+0x5b6) [0x7d8d66]
        (6) icinga2: icinga::JsonRpcConnection::HandleIncomingMessages(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x1b6) [0x7da926]
        (7) /usr/lib/x86_64-linux-gnu/icinga2/sbin/icinga2() [0x858f17]
        (8) libboost_context.so.1.67.0: make_fcontext (+0x2f) [0x7fc4bd63673f]

I'll continue with reading and testing tomorrow.

dnsmichi picture dnsmichi on 27 Jan 2020
👍2

@lippserd @gethash @Al2Klimov I had another idea while having a shower in the morning - what if the 64KB stack size for coroutines influences this behavior when boost::filesystem::remove_all is run with a huge set of directories and files, coming from zones.d? The recursion may have an influence and cause a stack overflow.

RenameFile might also be involved, since this also is used with SaveJsonFile in PKI requests. So a more generic problem with boost::filesystem over time.

Similar pattern what I had analyzed with the JSON decoding already.

dnsmichi picture dnsmichi on 28 Jan 2020

Also interesting to read with recursion and stackful operations in mind:

dnsmichi picture dnsmichi on 28 Jan 2020

0438c86 didn't crash. New commit range: (0438c86..37de1a9]

I'll continue with a630d0185 and give you an update on friday.

Al2Klimov picture Al2Klimov on 29 Jan 2020

Ok, thanks, then the boost::filesystem::remove_all thingy is a different one, likely sourced from user cleanup scripts or corrupt filesystems.

https://github.com/icinga/icinga2/compare/0438c86..37de1a9

  • API EventQueue changes
  • NotificationResult

For the API Event Queue, we're registering signal handlers in lib/icinga/apievents.cpp. Maybe the condition change in 

        if (queues.empty() && !inboxes)
                return;

now continues and fills the inboxes for some reason. I need to test-drive this locally just to be sure about it.

dnsmichi picture dnsmichi on 29 Jan 2020

a630d01 crashed. First bad commit: a630d01

Not really helpful as we've already reverted it and that revert still crashed. 😞

@dnsmichi Please list the (merge) commits I shall apply to each first-parent commit of v2.10.0..v2.11.0 for a new bisect in addition to cb21086d6.

Al2Klimov picture Al2Klimov on 30 Jan 2020
😕1

We had a longer offline meeting, so here's another approach:

First bad

a630d01 - Merge pull request #6722 from Icinga/feature/notification-result Add notification result store/sync

Last good

0438c86 - Merge pull request #7102 from Icinga/feature/boost-fs-7101 Replace self-written filesystem ops with boost.filesystem

Tasks:

Base commit a630d01

git checkout -b bugfix/json-rpc-nr a630d01

  • Revert NR PR immediately as full. To rule out that the revert in git master is broken, or anything else. do this on the first run

git revert -m 1 a630d0185fb5e6270c0238002c03c91ac02b21fe

  • Add mitigation patch: JSON-Library update #7712 second
git cherry-pick -x 5725ba4bf37ef5e3eab718f0cab4b4f673d8d602
  • Add mitigation patch: Boost Coroutines: Increase the default stack size from 64 to 256KB #7713 third

This requires the changes/fixes from

  • Nessus Scan Crash: Introduce IoEngine::SpawnCoroutine wrapping asio::spawn and Boost exceptions #7491

This is a pain to backport with the get_io_service() and GetContext() differences. We still need the exception swallowing fixes to be sure.

dnsmichi picture dnsmichi on 30 Jan 2020

Damn. It seems the one patch doesn't apply to the one end of the bisect range and the other patch doesn't apply to the other one.

@lippserd @bobapple @gethash We need ASAP a customer where we can easily reproduce the crash (the right crash!) and where our PS colleagues can install my custom packages for (let's say) one or two days (total, not per bisect step).

Al2Klimov picture Al2Klimov on 30 Jan 2020

I'll run the setup over the weekend with the current Git master (as of right now) and GDB attached to the main process.

@dnsmichi Any tips e.g. additional packages to install?

@dnsmichi @htriem @N-o-X @lippserd Please paste your public SSH keys here.

Al2Klimov picture Al2Klimov on 31 Jan 2020

Forget it, I've got this one:

for u in dnsmichi htriem N-o-X lippserd; do curl -sSL https://github.com/$u.keys; done
Al2Klimov picture Al2Klimov on 31 Jan 2020

@Al2Klimov I would prefer if you'd run the following which we agreed on yesterday. 

git checkout -b bugfix/json-rpc-nr a630d01

Revert NR PR immediately as full. To rule out that the revert in git master is broken, or anything else. do this on the first run

git revert -m 1 a630d0185fb5e6270c0238002c03c91ac02b21fe

If that fails, please coordinate with @lippserd on the next steps to take.

In terms of SSH keys, please get in touch with @bobapple. People may use different keys for GH and servers btw.

dnsmichi picture dnsmichi on 31 Jan 2020

Bisect summary

Icinga 2 commit | crashed? | Env. spec.
--|--|--
c37c40d8c (master) | yes | all w/ GDB
1c79c2b (~ v2.11rc1) | yes | all ex. network volatility
794374a | yes | a.e.n.v.
37de1a9 | yes | a.e.n.v.
a630d01 (1st bad) | yes | all
0438c86 | no | all
43e9ae5 | no | all
64568f5 | no | a.e.n.v.
e909302 | no | a.e.n.v.

Al2Klimov picture Al2Klimov on 3 Feb 2020
👍2

Notes:

master with gdb: WorkQueue -> Bind -> Function -> MessageOrigin destructor -> JsonRpcConnection destruktur -> _free -> Bumm

Parallel task: thread sanitizer analysis down the rabbit hole.
https://lemire.me/blog/2016/04/20/no-more-leaks-with-sanitize-flags-in-gcc-and-clang/
https://github.com/google/sanitizers/wiki/ThreadSanitizerCppManual

stack-use-after-scope wrap_memmove
dnsmichi picture dnsmichi on 3 Feb 2020

Damn. It seems the one patch doesn't apply to the one end of the bisect range and the other patch doesn't apply to the other one.

@lippserd @bobapple @gethash We need ASAP a customer where we can easily reproduce the crash (the right crash!) and where our PS colleagues can install my custom packages for (let's say) one or two days (total, not per bisect step).

Hi
if you need a system where testing these patch we are available.. please send an email to Kiratech.
Thanks

Matteo

mbaruchello77 picture mbaruchello77 on 3 Feb 2020

How fast does your system crash?

Al2Klimov picture Al2Klimov on 3 Feb 2020

1 min or less

mbaruchello77 picture mbaruchello77 on 3 Feb 2020

Also w/ the latest snapshot packages (as of right now)?

Al2Klimov picture Al2Klimov on 3 Feb 2020

no snapshot package

mbaruchello77 picture mbaruchello77 on 3 Feb 2020

Then please test them.

Al2Klimov picture Al2Klimov on 3 Feb 2020

can you contact me in private? matteo.[email protected]

mbaruchello77 picture mbaruchello77 on 4 Feb 2020

@mbaruchello77 Thanks for the offer, we'll do that!

lippserd picture lippserd on 4 Feb 2020
👍1

Stacktrace generated with -fsanitize=address Clang flag after killing 10 JSON-RPC connections with valid endpoints:

[2020-02-03 15:38:31 +0100] information/ApiListener: Finished syncing runtime objects to endpoint 'localhost'.
[2020-02-03 15:38:31 +0100] information/ApiListener: Finished sending runtime config updates for endpoint 'localhost' in zone 'localhost'.
==54100==WARNING: ASan is ignoring requested __asan_handle_no_return: stack top: 0x700002ef9000; bottom 0x000113e8e000; size: 0x6ffeef06b000 (123140722569216)
False positive error reports may follow
For details see https://github.com/google/sanitizers/issues/189
=================================================================
==54100==ERROR: AddressSanitizer: stack-buffer-underflow on address 0x000113e8fc08 at pc 0x00010c2d4fc9 bp 0x000113e8f6e0 sp 0x000113e8ee78
READ of size 168 at 0x000113e8fc08 thread T62
[2020-02-03 15:41:07 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:07 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 9 API clients left.
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 8 API clients left.
    #0 0x10c2d4fc8 in wrap_memmove (libclang_rt.asan_osx_dynamic.dylib:x86_64h+0x1cfc8)

0x000113e8fc08 is located 254984 bytes inside of 262144-byte region [0x000113e51800,0x000113e91800)
allocated by thread T77 here:
    #0 0x10c3187d3 in wrap_malloc (libclang_rt.asan_osx_dynamic.dylib:x86_64h+0x607d3)

Thread T62 created by T0 here:
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
    #0 0x10c3107cd in wrap_pthread_create (libclang_rt.asan_osx_dynamic.dylib:x86_64h+0x587cd)
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 7 API clients left.
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 6 API clients left.
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 5 API clients left.
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 4 API clients left.
[2020-02-03 15:41:08 +0100] warning/JsonRpcConnection: API client disconnected for identity 'localhost'
[2020-02-03 15:41:08 +0100] warning/ApiListener: Removing API client for endpoint 'localhost'. 3 API clients left.
    #1 0x10095e783 in std::__1::__libcpp_thread_create(_opaque_pthread_t**, void* (*)(void*), void*) __threading_support:328
    #2 0x100e98d5e in std::__1::thread::thread<void (icinga::IoEngine::*)(), icinga::IoEngine*, void>(void (icinga::IoEngine::*&&)(), icinga::IoEngine*&&) thread:368
    #3 0x100876434 in std::__1::thread::thread<void (icinga::IoEngine::*)(), icinga::IoEngine*, void>(void (icinga::IoEngine::*&&)(), icinga::IoEngine*&&) thread:360
    #4 0x10087514c in icinga::IoEngine::IoEngine() io-engine.cpp:93
    #5 0x100876634 in icinga::IoEngine::IoEngine() io-engine.cpp:88
    #6 0x100e88f89 in icinga::IoEngine::$_64::operator()() const io-engine.cpp:75
    #7 0x100e88f2e in decltype(std::__1::forward<icinga::IoEngine::$_64&>(fp)()) std::__1::__invoke<icinga::IoEngine::$_64&>(icinga::IoEngine::$_64&) type_traits:4361
    #8 0x100e88ece in std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > std::__1::__invoke_void_return_wrapper<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > >::__call<icinga::IoEngine::$_64&>(icinga::IoEngine::$_64&) __functional_base:318
    #9 0x100e88e8e in std::__1::__function::__alloc_func<icinga::IoEngine::$_64, std::__1::allocator<icinga::IoEngine::$_64>, std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() functional:1527
    #10 0x100e8561f in std::__1::__function::__func<icinga::IoEngine::$_64, std::__1::allocator<icinga::IoEngine::$_64>, std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() functional:1651
    #11 0x100e8a5fc in std::__1::__function::__value_func<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() const functional:1799
    #12 0x100e8a3ab in std::__1::function<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() const functional:2347
    #13 0x100874b14 in icinga::LazyInit<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > >::Get() lazy-init.hpp:56
    #14 0x100873ecf in icinga::IoEngine::Get() io-engine.cpp:79
    #15 0x101325e81 in icinga::ApiListener::AddListener(icinga::String const&, icinga::String const&) apilistener.cpp:364
    #16 0x101323609 in icinga::ApiListener::Start(bool) apilistener.cpp:255
    #17 0x1008066e3 in icinga::ConfigObject::Activate(bool, icinga::Value const&) configobject.cpp:367
    #18 0x101201330 in icinga::ConfigItem::ActivateItems(icinga::WorkQueue&, std::__1::vector<boost::intrusive_ptr<icinga::ConfigItem>, std::__1::allocator<boost::intrusive_ptr<icinga::ConfigItem> > > const&, bool, bool, bool, icinga::Value const&) configitem.cpp:696
    #19 0x101bbee83 in RunWorker(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, bool, icinga::String const&) daemoncommand.cpp:281
    #20 0x101b5c30d in StartUnixWorker(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, bool, icinga::String const&) daemoncommand.cpp:507
    #21 0x101b559fb in icinga::DaemonCommand::Run(boost::program_options::variables_map const&, std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&) const daemoncommand.cpp:697
    #22 0x10074b1eb in Main() icinga.cpp:662
    #23 0x10073fea0 in main icinga.cpp:959
    #24 0x7fff7142b404 in start (libdyld.dylib:x86_64+0x11404)

Thread T77 created by T0 here:
    #0 0x10c3107cd in wrap_pthread_create (libclang_rt.asan_osx_dynamic.dylib:x86_64h+0x587cd)
    #1 0x10095e783 in std::__1::__libcpp_thread_create(_opaque_pthread_t**, void* (*)(void*), void*) __threading_support:328
    #2 0x100e98d5e in std::__1::thread::thread<void (icinga::IoEngine::*)(), icinga::IoEngine*, void>(void (icinga::IoEngine::*&&)(), icinga::IoEngine*&&) thread:368
    #3 0x100876434 in std::__1::thread::thread<void (icinga::IoEngine::*)(), icinga::IoEngine*, void>(void (icinga::IoEngine::*&&)(), icinga::IoEngine*&&) thread:360
    #4 0x10087514c in icinga::IoEngine::IoEngine() io-engine.cpp:93
    #5 0x100876634 in icinga::IoEngine::IoEngine() io-engine.cpp:88
    #6 0x100e88f89 in icinga::IoEngine::$_64::operator()() const io-engine.cpp:75
    #7 0x100e88f2e in decltype(std::__1::forward<icinga::IoEngine::$_64&>(fp)()) std::__1::__invoke<icinga::IoEngine::$_64&>(icinga::IoEngine::$_64&) type_traits:4361
    #8 0x100e88ece in std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > std::__1::__invoke_void_return_wrapper<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > >::__call<icinga::IoEngine::$_64&>(icinga::IoEngine::$_64&) __functional_base:318
    #9 0x100e88e8e in std::__1::__function::__alloc_func<icinga::IoEngine::$_64, std::__1::allocator<icinga::IoEngine::$_64>, std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() functional:1527
    #10 0x100e8561f in std::__1::__function::__func<icinga::IoEngine::$_64, std::__1::allocator<icinga::IoEngine::$_64>, std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() functional:1651
    #11 0x100e8a5fc in std::__1::__function::__value_func<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() const functional:1799
    #12 0x100e8a3ab in std::__1::function<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > ()>::operator()() const functional:2347
    #13 0x100874b14 in icinga::LazyInit<std::__1::unique_ptr<icinga::IoEngine, std::__1::default_delete<icinga::IoEngine> > >::Get() lazy-init.hpp:56
    #14 0x100873ecf in icinga::IoEngine::Get() io-engine.cpp:79
    #15 0x101325e81 in icinga::ApiListener::AddListener(icinga::String const&, icinga::String const&) apilistener.cpp:364
    #16 0x101323609 in icinga::ApiListener::Start(bool) apilistener.cpp:255
    #17 0x1008066e3 in icinga::ConfigObject::Activate(bool, icinga::Value const&) configobject.cpp:367
    #18 0x101201330 in icinga::ConfigItem::ActivateItems(icinga::WorkQueue&, std::__1::vector<boost::intrusive_ptr<icinga::ConfigItem>, std::__1::allocator<boost::intrusive_ptr<icinga::ConfigItem> > > const&, bool, bool, bool, icinga::Value const&) configitem.cpp:696
    #19 0x101bbee83 in RunWorker(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, bool, icinga::String const&) daemoncommand.cpp:281
    #20 0x101b5c30d in StartUnixWorker(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, bool, icinga::String const&) daemoncommand.cpp:507
    #21 0x101b559fb in icinga::DaemonCommand::Run(boost::program_options::variables_map const&, std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&) const daemoncommand.cpp:697
    #22 0x10074b1eb in Main() icinga.cpp:662
    #23 0x10073fea0 in main icinga.cpp:959
    #24 0x7fff7142b404 in start (libdyld.dylib:x86_64+0x11404)

SUMMARY: AddressSanitizer: stack-buffer-underflow (libclang_rt.asan_osx_dynamic.dylib:x86_64h+0x1cfc8) in wrap_memmove
Shadow bytes around the buggy address:
  0x1000227d1f30: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1f40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1f50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1f60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1f70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x1000227d1f80: f1[f1]f1 f1 00 00 f3 f3 00 00 00 00 00 00 00 00
  0x1000227d1f90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1fa0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1fb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1fc0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000227d1fd0: 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1 f1
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==54100==ABORTING
Caught SIGABRT.
Current time: 2020-02-03 15:41:10 +0100

[2020-02-03 15:41:10 +0100] critical/Application: Icinga 2 has terminated unexpectedly. Additional information can be found in '/Users/noah/i2/var/log/icinga2/crash/report.1580740870.629094'

Same case, but debugged with LLDB:

(lldb) bt
* thread #24, stop reason = Use of out-of-scope stack memory
  * frame #0: 0x000000010e148880 libclang_rt.asan_osx_dynamic.dylib`__asan::AsanDie()
    frame #1: 0x000000010e15f81f libclang_rt.asan_osx_dynamic.dylib`__sanitizer::Die() + 175
    frame #2: 0x000000010e14676b libclang_rt.asan_osx_dynamic.dylib`__asan::ScopedInErrorReport::~ScopedInErrorReport() + 411
    frame #3: 0x000000010e145f9f libclang_rt.asan_osx_dynamic.dylib`__asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool) + 447
    frame #4: 0x000000010e0fbfe9 libclang_rt.asan_osx_dynamic.dylib`wrap_memmove + 713
    frame #5: 0x00007fff71665bf8 libunwind.dylib`unw_init_local + 33
    frame #6: 0x00007fff716665cb libunwind.dylib`unwind_phase2 + 41
    frame #7: 0x00007fff71669ed1 libunwind.dylib`_Unwind_Resume + 51
    frame #8: 0x000000010322886c icinga2`icinga::JsonRpc::ReadMessage(stream=0x0000616004162008, yc=boost::asio::yield_context @ 0x0000000115bb1840, maxMessageLength=-1)(), boost::asio::executor> >, long) at jsonrpc.cpp:0:1
    frame #9: 0x000000010322a252 icinga2`icinga::JsonRpcConnection::HandleIncomingMessages(this=0x0000616004161f80, yc=boost::asio::yield_context @ 0x0000000115bb1fa0)(), boost::asio::executor> >) at jsonrpcconnection.cpp:67:14
    frame #10: 0x00000001038c22b3 icinga2`icinga::JsonRpcConnection::Start(this=0x00006060003e8e50, yc=boost::asio::yield_context @ 0x0000000115bb20e0)::$_67::operator()(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) const at jsonrpcconnection.cpp:55:83
    frame #11: 0x00000001038c1fa0 icinga2`void icinga::IoEngine::SpawnCoroutine<boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67>(this=0x00006060003e8e50, yc=boost::asio::yield_context @ 0x0000000115bb22c0)::$_67)::'lambda'(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >)::operator()(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) const at io-engine.hpp:125:6
    frame #12: 0x00000001038c1c3c icinga2`boost::asio::detail::coro_entry_point<boost::asio::executor_binder<void (*)(), boost::asio::io_context::strand>, void icinga::IoEngine::SpawnCoroutine<boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67>(boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67)::'lambda'(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >)>::operator(this=0x00000001152485e0, ca=0x0000000115bb2490)(boost::coroutines::pull_coroutine<void>&) at spawn.hpp:337:7
    frame #13: 0x00000001038c1700 icinga2`boost::coroutines::detail::push_coroutine_object<boost::coroutines::pull_coroutine<void>, void, boost::asio::detail::coro_entry_point<boost::asio::executor_binder<void (*)(), boost::asio::io_context::strand>, void icinga::IoEngine::SpawnCoroutine<boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67>(boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67)::'lambda'(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >)>&, boost::coroutines::basic_standard_stack_allocator<boost::coroutines::stack_traits> >::run(this=0x0000000115bb2760) at push_coroutine_object.hpp:302:11
    frame #14: 0x00000001038c1359 icinga2`void boost::coroutines::detail::trampoline_push_void<boost::coroutines::detail::push_coroutine_object<boost::coroutines::pull_coroutine<void>, void, boost::asio::detail::coro_entry_point<boost::asio::executor_binder<void (*)(), boost::asio::io_context::strand>, void icinga::IoEngine::SpawnCoroutine<boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67>(boost::asio::io_context::strand, icinga::JsonRpcConnection::Start()::$_67)::'lambda'(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >)>&, boost::coroutines::basic_standard_stack_allocator<boost::coroutines::stack_traits> > >(t=(fctx = 0x0000000115248400, data = 0x0000000115248440)) at trampoline_push.hpp:70:11
    frame #15: 0x000000010dc5fa2f libboost_context-mt.dylib`trampoline + 3
(lldb)
N-o-X picture N-o-X on 4 Feb 2020
👍2

Next rounds:

  • Master + API-Event-Streams Static-Initialize disable + Debug build active
  • Master + keepAlive ptr int JsonRpcConnection::Start()
  • Master + Timer/Log/Flush reverts

In additional to that, going further with the ASAN analysis. Yesterday we stopped at JsonDecode where the MessageHandler() from the JSON-RPC connection read sometimes crashed when sending back the response.

dnsmichi picture dnsmichi on 4 Feb 2020
👍4

04df04eea didn't crash for 2.5 days. Jackpot, @dnsmichi!

Al2Klimov picture Al2Klimov on 6 Feb 2020
👍2 🚀1 🎉1

Been following this issue since my comment in November and I just wanted to say thanks Alexander and Michi and everyone else doing this cherry-pick debugging to find the source of the problem. I hope that you've found it now, your last comment sounds positive! Again big thanks to everyone involved!

Napsty picture Napsty on 6 Feb 2020
❤3 🚀1 🎉1

04df04e didn't crash for 2.5 days. Jackpot, @dnsmichi!

Oh, f*ck. Thanks for the update. Will join you soon for more investigations.

dnsmichi picture dnsmichi on 6 Feb 2020

Just to be sure I'll run both 1a7d52526 and d0822ef23 over the weekend w/o network volatility. I'll give you an update on monday.

Al2Klimov picture Al2Klimov on 6 Feb 2020
👍3

Perfect, thanks. A note to @N-o-X investigations - we cannot be sure whether we hit some false positives here with the address sanitizer checks. We'll investigate here in the future, and add the things learned thus far for coming debug iterations.

dnsmichi picture dnsmichi on 6 Feb 2020
👍1

I'm back with guessing (unfortunately). First, let's summarize the findings a bit more.

Analysis

We now have learned that disabling the event listeners for the API streams does not crash. Which in term means, that we have essentially disabled the API Event Stream feature inside the code. This is something we _cannot release_.

Our analysis table shows that 37de1a919bc2ee91ad4d8edce2b86339130e6e51 is the commit after the first bad, with the NotificationResult revert having no immediate effect. This revert solves another issue @lippserd had encountered, and must stay on the list for reverts for 2.11.x backports.

boost::signals2 Event handling

Yesterday (and this morning while having a shower), I thought about the impact of the underlaying "observer pattern" with boost::signals2 being used for the event handling.

In short, e.g. OnNotificationSentToAllUsers is a signal object, where function callback handlers can be registered onto.

Each time the signal is invoked, e.g. when a new notification has been sent, all the registered slots are being fired one after the other.

boost::signals2 has its very own way for thread-safety and guards the operations with a local mutex.
This is described here: https://www.boost.org/doc/libs/1_43_0/doc/html/signals2/thread-safety.html

Theory

From the analysis now the following theory arises:

We have the following event consumers:

  • Cluster Events
  • API Event Streams
$ grep -r 'OnNotificationSentToAllUsers\.connect' lib/
lib//perfdata/elasticsearchwriter.cpp:  Checkable::OnNotificationSentToAllUsers.connect(std::bind(&ElasticsearchWriter::NotificationSentToAllUsersHandler, this, _1, _2, _3, _4, _5, _6, _7));
lib//icingadb/icingadb-objects.cpp: Checkable::OnNotificationSentToAllUsers.connect([](
lib//db_ido/dbevents.cpp:   Checkable::OnNotificationSentToAllUsers.connect(std::bind(&DbEvents::LastNotificationChangedHandler, _1, _2));
lib//db_ido/dbevents.cpp:   Checkable::OnNotificationSentToAllUsers.connect(std::bind(&DbEvents::AddNotificationHistory, _1, _2, _3, _4, _5, _6, _7));
lib//icinga/clusterevents.cpp:  Checkable::OnNotificationSentToAllUsers.connect(&ClusterEvents::NotificationSentToAllUsersHandler);
lib//icinga/apievents.cpp:  Checkable::OnNotificationSentToAllUsers.connect(&ApiEvents::NotificationSentToAllUsersHandler);

All other features are turned off.

root@ip-172-31-37-212:/var/log/icinga2# icinga2 feature list
Disabled features: command compatlog debuglog elasticsearch gelf graphite influxdb livestatus opentsdb perfdata statusdata syslog
Enabled features: api checker mainlog notification

I don't think that boost::signals2 and its slots have a direct impact here, this library is bullet-proof since more than 5 years.

Whenever slots are completed, boost::signals2 does a cleanup on its own (lazy).

I do think that the changes with 37de1a919bc2ee91ad4d8edce2b86339130e6e51 could introduce an incompatible design pattern where "maybe" things are getting weird.

Probably this even starts before the if-condition mentioned in https://github.com/Icinga/icinga2/issues/7532#issuecomment-579701909 takes place.

Specifically, the code parts above should be analyzed and compared.

        std::vector<EventQueue::Ptr> queues = EventQueue::GetQueuesForType("Notification");
        auto inboxes (EventsRouter::GetInstance().GetInboxes(EventType::Notification));

        if (queues.empty() && !inboxes)
                return;

Last but not least, check the compilers involved here. gcc versions are known to sometimes generate assembler code and code optimizations we do not expect.

Cluster Events vs API Stream

Vice versa, take the cluster events into account. With disabling one side (API streams), the pattern of 2 consumers is gone. Maybe the changes within sending JSON-RPC messages from such cluster events have an influence here too. @lippserd

Tests

  • Revert 37de1a919bc2ee91ad4d8edce2b86339130e6e51 with the NR revert based on 2.11.2 tag and see if it still crashes @Al2Klimov
  • Analyse the code changes with 37de1a919bc2ee91ad4d8edce2b86339130e6e51 @N-o-X
  • Analyse involved compiler versions @dnsmichi

Possible Reverts

  • NotificationResult
  • API Event Streams
dnsmichi picture dnsmichi on 7 Feb 2020
👀1

Here's some flow analysis.

Notification to Signals & ClusterEvent to Signal

IMG_5395

ClusterEvent in Coroutine Scope triggering ApiEvents

IMG_5396

dnsmichi picture dnsmichi on 7 Feb 2020

Neither 1a7d525 nor d0822ef crashed which is strange. I'll re-test both w/ network volatility and give you an update on thursday.

Al2Klimov picture Al2Klimov on 11 Feb 2020

Neither 1a7d525 nor d0822ef crashed which is strange. I'll re-test both w/ network volatility and give you an update on thursday.

@Al2Klimov Can you please explain the test strategy for these commits above? I thought we already had tested them.

dnsmichi picture dnsmichi on 11 Feb 2020

No, unfortunately the test failed and I just added network volatility to the strategy.

Al2Klimov picture Al2Klimov on 12 Feb 2020

v2.11.2 w/o NotificationResult crashed while the additional comment-out didn't – as expected. Lessons learned:

  1. That additional comment-out also applies to v2.11.2, not just to master – i.e. we can make a v2.11.3 as promised w/o much more work
  2. The network volatility is not just a accelerator, but a key factor

I'm still testing v2.11.2 w/o NotificationResult and ASIO EventQueue reverted and will give you an update tomorrow in the evening.

Al2Klimov picture Al2Klimov on 13 Feb 2020
  • 97afae3a5 crashed, but w/ ABRT, not SEGV and no core dump
  • v2.11.2 w/o NotificationResult seems to crash faster w/ libfaketime – again w/ ABRT (stack trace below) – I'll re-test it just to be sure
  • I'm still testing 87061f4e7 and will give you an update on monday
    (0) libc.so.6: gsignal (+0x10b) [0x7f2a773e57bb]
    (1) libc.so.6: abort (+0x121) [0x7f2a773d0535]
    (2) libc.so.6: <unknown function> (+0x79508) [0x7f2a77427508]
    (3) libc.so.6: <unknown function> (+0x7fc1a) [0x7f2a7742dc1a]
    (4) libc.so.6: <unknown function> (+0x80184) [0x7f2a7742e184]
    (5) icinga2: <unknown function> (+0x781441) [0x557a481c6441]
    (6) icinga2: <unknown function> (+0x5fb582) [0x557a48040582]
    (7) icinga2: boost::asio::detail::strand_service::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long) (+0x75) [0x557a48094105]
    (8) icinga2: <unknown function> (+0x7531eb) [0x557a481981eb]
    (9) icinga2: icinga::IoEngine::RunEventLoop() (+0x5e) [0x557a4818cc8e]
    (10) libstdc++.so.6: <unknown function> (+0xbbb2f) [0x7f2a777c9b2f]
    (11) libpthread.so.0: <unknown function> (+0x7fa3) [0x7f2a77ecffa3]
    (12) libc.so.6: clone (+0x3f) [0x7f2a774a74cf]
Al2Klimov picture Al2Klimov on 14 Feb 2020

Just got an idea: At the moment a JSON-RPC connection has a strand. The four coroutines are being spawned there, each with the function to run which carries a keep-alive pointer to the connection incl. the strand. Once all of the functions are done, they get destroyed with the keep-alive pointers, the connection and the strand... before or after the coroutines running inside the strand actually terminate? If before: Does the strand unwind the coroutines? If yes: Is the unwinder effectively being thrown inside a destructor? If yes: What are the consequences?

Al2Klimov picture Al2Klimov on 14 Feb 2020
👍1

"Unfortunately" the coroutine-strand destructor cycle purrs like a cat.

PoC

// ...

class MyLog
{
public:
    ~MyLog()
    {
        std::cerr << "MyLog!" << std::endl;
    }
};

class Lolcat
{
public:
    Lolcat(boost::asio::io_context& io) : m_Strand(io)
    {
        boost::asio::spawn(m_Strand, [this](boost::asio::yield_context yc) {
            delete this;
        });
    }

    ~Lolcat()
    {
        std::cerr << "LOLCAT!" << std::endl;
    }

private:
    MyLog ml1;
    boost::asio::io_context::strand m_Strand;
    MyLog ml2;
};

// ...

int DaemonCommand::Run(const po::variables_map& vm, const std::vector<std::string>& ap) const
{
    {
        boost::asio::io_context io;
        new Lolcat(io);
        io.run();
    }

// ...
}

Output

LOLCAT!
MyLog!
MyLog!
Al2Klimov picture Al2Klimov on 17 Feb 2020

Another thought on this: Is it safe to spawn a coroutine in another coroutine? We do that e.g. for Disconnect() which cleans up everything - and may break specific things in there.

dnsmichi picture dnsmichi on 17 Feb 2020

See #7837. I'll test v2.11.2 + #7837 w/o #7846 and give you an update on friday.

Al2Klimov picture Al2Klimov on 19 Feb 2020

v2.11.2 + #7837 w/o #7846 crashes, so we should include #7846 in v2.11.3.

I'll re-test v2.11.2 + #7846 + #7837 for 2.5 days and give you an update on monday.

Al2Klimov picture Al2Klimov on 20 Feb 2020

s/2.5 days/3.5 days/

Al2Klimov picture Al2Klimov on 20 Feb 2020

Just to be sure I'll also test v2.11.2 + #7837 + #7849 w/o #7846.

Al2Klimov picture Al2Klimov on 20 Feb 2020

Apropos testing: Thanks a lot to:

  • @hetznercloud for a Quota of currently up to 909 (!) VMs
  • @hashicorp for Terraform
  • @ansible for Ansible
  • @lazyfrosch for our packaging CI/CD (which allows easy misusing for custom packages)

W/o all of you... I don't know.

Al2Klimov picture Al2Klimov on 20 Feb 2020

Unfortunately v2.11.2 + #7837 + #7849 w/o #7846 crashes, so we definitively need #7846.

Al2Klimov picture Al2Klimov on 21 Feb 2020

87061f4e7 didn't crash for > 3 days. Green light for v2.11.3.

Al2Klimov picture Al2Klimov on 24 Feb 2020
👍8 🎉6 😄1

CC @gethash

Al2Klimov picture Al2Klimov on 24 Feb 2020

No crashes in my test setups as well 👍

lippserd picture lippserd on 24 Feb 2020
👍6 😄1

Thanks for the heads-up. All these patches (#7837 + #7849 + #7846) applied to master have been tested as well?

dnsmichi picture dnsmichi on 25 Feb 2020

I'll take care of that.

Al2Klimov picture Al2Klimov on 25 Feb 2020
❤1

Testing e930efd1a and 699047e34 – just to be sure. I'll give you an update on thursday.

Al2Klimov picture Al2Klimov on 25 Feb 2020

e930efd1a has purred like a cat for two days. Green light for v2.12rc1.

Al2Klimov picture Al2Klimov on 27 Feb 2020
🎉4 👍3 ❤1

I have a similar crash with a large number of endpoints that have been removed from the config but are still attempting to connect. There is about 400 endpoints hammering away and icinga2 can only stay up for around 20hours until I get this error:

icinga2: /usr/include/icinga-boost/boost/smart_ptr/intrusive_ptr.hpp:199: T* boost::intrusive_ptr<T>::operator->() const [with T = icinga::Endpoint]: Assertion `px != 0' failed.
Caught SIGABRT.
Current time: 2020-03-02 10:15:08 +0000

Will the latest snapshot discussed here fix this? Or should I lodge a separate bug report.
The de-configured endpoints will be re-enabled shortly, so I expect the problem to go away, but its clear that many endpoints being rejected shouldn't be grounds for a crash.

This is a sample of the debuglog:

[2020-03-01 22:28:48 +0000] notice/JsonRpcConnection: Received 'event::SetNextCheck' message from identity 'fp-mlb-au.example.com'.
[2020-03-01 22:28:48 +0000] notice/ClusterEvents: Discarding 'next check changed' message from 'fp-mlb-au.example.com': Invalid endpoint origin (client not allowed)

These messages happen over and over - the debug log gets very large quickly. There are about 10000 hosts behind the collective endpoints by the way, not sure that makes a difference, but some of those endpoints would have a ton of updates not sent.

davekempe picture davekempe on 2 Mar 2020

@davekempe Please try v2.11.3 once it has been released (later today).

Al2Klimov picture Al2Klimov on 3 Mar 2020

Please could all of you test v2.11.3 and tell whether it has fixed your particular problem?

Al2Klimov picture Al2Klimov on 6 Mar 2020

Hey sorry I was going to get back bug the big was closed. Happy to report the issue is fixed. I was able to simulate the problem reliably as it happened every 24 hours in our environment if we removed the endpoints via automation. After the update it has been fine with no crashes.

davekempe picture davekempe on 6 Mar 2020
🚀2 🎉1

Unfortunately, we still have the problem.

[2020-03-04 09:43:14 +0100] warning/JsonRpcConnection: Error while sending JSON-RPC message for identity 'host.abc.com'
Error: Connection reset by peer


        (0) icinga2: icinga::JsonRpc::SendRawMessage(std::shared_ptr<icinga::AsioTlsStream> const&, icinga::String const&, boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::exe
        (1) icinga2: icinga::JsonRpcConnection::WriteOutgoingMessages(boost::asio::basic_yield_context<boost::asio::executor_binder<void (*)(), boost::asio::executor> >) (+0x231) [0xb64351]
        (2) /usr/lib64/icinga2/sbin/icinga2() [0xb6477a]
        (3) /usr/lib64/icinga2/sbin/icinga2() [0xb64c58]
        (4) libboost_context.so.1.69.0: make_fcontext (+0x2f) [0x7f81b595b18f]



[2020-03-04 09:43:14 +0100] warning/JsonRpcConnection: API client disconnected for identity 'host.abc.com'
hardoverflow picture hardoverflow on 6 Mar 2020

@hardoverflow ... and it still crashes?

Al2Klimov picture Al2Klimov on 6 Mar 2020

@Al2Klimov @N-o-X Was the master branch (snapshot packages) affected of this bug? If so the master branch is currently not fixed, since the fixing changes are directly merged into the support/2.11 branch.

The master branch should be tested prior a 2.12 release to ensure the bug is fixed there too.

mcktr picture mcktr on 6 Mar 2020

@mcktr every change has also been merged into the master branch: https://github.com/Icinga/icinga2/pull/7841 https://github.com/Icinga/icinga2/pull/7837 https://github.com/Icinga/icinga2/pull/7737

N-o-X picture N-o-X on 9 Mar 2020

... and tested successfully.

Al2Klimov picture Al2Klimov on 9 Mar 2020

@Al2Klimov Once the cluster is running, it is also running. The error occurs sporadically when deploying. After a while, the ConfigMaster crashed. The second master is still running.

● icinga2.service - Icinga host/service/network monitoring system
   Loaded: loaded (/usr/lib/systemd/system/icinga2.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2020-03-17 10:14:15 CET; 3min 29s ago
  Process: 34392 ExecReload=/usr/lib/icinga2/safe-reload /etc/sysconfig/icinga2 (code=exited, status=0/SUCCESS)
  Process: 30207 ExecStart=/usr/sbin/icinga2 daemon --close-stdio -e ${ICINGA2_ERROR_LOG} (code=exited, status=139)
 Main PID: 30207 (code=exited, status=139)

Mar 17 07:11:03 master-a.fqdn.de safe-reload[18089]: Validating config files: Done
Mar 17 07:11:03 master-a.fqdn.de safe-reload[18089]: Reloading Icinga 2: Done
Mar 17 07:12:00 master-a.fqdn.de systemd[1]: Reloaded Icinga host/service/network monitoring system.
Mar 17 10:06:47 master-a.fqdn.de systemd[1]: Reloading Icinga host/service/network monitoring system.
Mar 17 10:07:12 master-a.fqdn.de safe-reload[34392]: Validating config files: Done
Mar 17 10:07:12 master-a.fqdn.de safe-reload[34392]: Reloading Icinga 2: Done
Mar 17 10:08:16 master-a.fqdn.de systemd[1]: Reloaded Icinga host/service/network monitoring system.
Mar 17 10:14:15 master-a.fqdn.de systemd[1]: icinga2.service: main process exited, code=exited, status=139/n/a
Mar 17 10:14:15 master-a.fqdn.de systemd[1]: Unit icinga2.service entered failed state.
Mar 17 10:14:15 master-a.fqdn.de systemd[1]: icinga2.service failed.

We also observe the following network bandwidth for masters and satellites.
grafik

hardoverflow picture hardoverflow on 17 Mar 2020

Please share the output of icinga2 --version ran on the crashed node.

Al2Klimov picture Al2Klimov on 17 Mar 2020 
icinga2 - The Icinga 2 network monitoring daemon (version: 2.11.3-1)

Copyright (c) 2012-2020 Icinga GmbH (https://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.

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

Build information:
  Compiler: GNU 4.8.5
  Build host: runner-LTrJQZ9N-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
[[email protected]]#
hardoverflow picture hardoverflow on 17 Mar 2020

Damn. It's actually v2.11.3.

@lippserd @N-o-X @htriem We've got a (hopefully not so) big problem.

Al2Klimov picture Al2Klimov on 17 Mar 2020

@hardoverflow Could you please upload core dumps here

lippserd picture lippserd on 17 Mar 2020

@lippserd Done. Can u confirm?

hardoverflow picture hardoverflow on 18 Mar 2020

Confirmed.

All of you: If you give us core dumps, please gzip them – and if you request them, request to gzip them. Not neccessarily all of us have enterprise downlinks due to COVID19.

Al2Klimov picture Al2Klimov on 18 Mar 2020
👍1
Was this page helpful?
0 / 5 - 0 ratings

Related issues

peteeckel picture peteeckel  ·  4Comments
xeiss picture xeiss  ·  6Comments
icinga-migration picture icinga-migration  ·  6Comments
Thomas-Gelf picture Thomas-Gelf  ·  5Comments
mickenordin picture mickenordin  ·  5Comments