Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add additional logging for config sync #5212

Closed
3 tasks done
Crunsher opened this issue May 2, 2017 · 1 comment
Closed
3 tasks done

Add additional logging for config sync #5212

Crunsher opened this issue May 2, 2017 · 1 comment
Labels
area/distributed Distributed monitoring (master, satellites, clients) area/log Logging related enhancement New feature or request
Milestone

Comments

@Crunsher
Copy link
Contributor

Crunsher commented May 2, 2017

  • Write logs with the PID (to know what daemon logged it)
  • Log who sent a config update
  • Log the timestamp version of a zone config received
@Crunsher Crunsher added area/distributed Distributed monitoring (master, satellites, clients) enhancement New feature or request area/log Logging related labels May 2, 2017
@Crunsher Crunsher self-assigned this May 2, 2017
Crunsher added a commit that referenced this issue May 2, 2017
Crunsher added a commit that referenced this issue May 2, 2017
Crunsher added a commit that referenced this issue May 2, 2017
Crunsher added a commit that referenced this issue May 2, 2017
@Crunsher Crunsher added this to the 2.6.4 milestone May 3, 2017
dnsmichi pushed a commit that referenced this issue May 4, 2017
dnsmichi pushed a commit that referenced this issue May 4, 2017
@dnsmichi
Copy link
Contributor

As discussed, the log addition breaks an HA cluster. I need to work on #5133 and therefore will provide a fix by myself.

[2017-05-12 10:11:50 +0200] information/ApiListener: Applying configuration file update for path './icinga2a/lib/icinga2/api/zones/master'. Received timestamp '2017-05-12 10:11:50 +0200' (1494576710.718512) is more recent than current timestamp '2017-05-12 10:10:53 +0200' (1494576653.584635).
[2017-05-12 10:11:50 +0200] information/ApiListener: Copying 1 zone configuration files for zone 'satellite' to './icinga2a/lib/icinga2/api/zones/satellite'.
[2017-05-12 10:11:50 +0200] information/ApiListener: Applying configuration file update for path './icinga2a/lib/icinga2/api/zones/satellite'. Received timestamp '2017-05-12 10:11:50 +0200' (1494576710.720124) is more recent than current timestamp '2017-05-12 10:10:53 +0200' (1494576653.588971).
[2017-05-12 10:11:50 +0200] information/ApiListener: Adding new listener on port '7000'
[2017-05-12 10:11:50 +0200] information/ConfigItem: Activated all objects.
[2017-05-12 10:11:50 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2b' via host 'localhost' and port '8000'
[2017-05-12 10:11:50 +0200] information/ApiListener: Reconnecting to API endpoint 'icinga2c' via host 'localhost' and port '9000'
[2017-05-12 10:11:50 +0200] critical/Socket: Invalid socket: Connection refused
[2017-05-12 10:11:50 +0200] critical/Socket: Invalid socket: Connection refused
[2017-05-12 10:11:50 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '8000'
[2017-05-12 10:11:50 +0200] critical/ApiListener: Cannot connect to host 'localhost' on port '9000'
[2017-05-12 10:11:55 +0200] warning/TlsStream: TLS stream was disconnected.
[2017-05-12 10:11:55 +0200] critical/ApiListener: Client TLS handshake failed (from [::1]:59420)
Context:
	(0) Handling new API client connection

[2017-05-12 10:11:55 +0200] information/ApiListener: New client connection from [::1]:59421 (no client certificate)
[2017-05-12 10:11:55 +0200] warning/TlsStream: TLS stream was disconnected.
[2017-05-12 10:11:56 +0200] warning/ApiListener: No data received on new API connection for identity ''. Ensure that the remote endpoints are properly configured in a cluster setup.
Context:
	(0) Handling new API client connection

[2017-05-12 10:12:05 +0200] information/ApiListener: New client connection for identity 'icinga2b' from [::1]:59438
[2017-05-12 10:12:05 +0200] information/ApiListener: Sending config updates for endpoint 'icinga2b'.
[2017-05-12 10:12:05 +0200] information/ApiListener: Syncing configuration files for global zone 'global-templates' to endpoint 'icinga2b'.
[2017-05-12 10:12:05 +0200] information/ApiListener: Syncing configuration files for zone 'master' to endpoint 'icinga2b'.
[2017-05-12 10:12:05 +0200] information/ApiListener: Syncing configuration files for zone 'satellite' to endpoint 'icinga2b'.
[2017-05-12 10:12:05 +0200] information/ApiListener: Syncing runtime objects to endpoint 'icinga2b'.
Assertion failed: (px != 0), function operator->, file /usr/local/include/boost/smart_ptr/intrusive_ptr.hpp, line 198.
Process 95631 stopped
* thread #8: tid = 0x126028a, 0x00007fff99a9ddd6 libsystem_kernel.dylib`__pthread_kill + 10, stop reason = signal SIGABRT
    frame #0: 0x00007fff99a9ddd6 libsystem_kernel.dylib`__pthread_kill + 10
libsystem_kernel.dylib`__pthread_kill:
->  0x7fff99a9ddd6 <+10>: jae    0x7fff99a9dde0            ; <+20>
    0x7fff99a9ddd8 <+12>: movq   %rax, %rdi
    0x7fff99a9dddb <+15>: jmp    0x7fff99a96cdf            ; cerror_nocancel
    0x7fff99a9dde0 <+20>: retq
(lldb) bt
* thread #8: tid = 0x126028a, 0x00007fff99a9ddd6 libsystem_kernel.dylib`__pthread_kill + 10, stop reason = signal SIGABRT
  * frame #0: 0x00007fff99a9ddd6 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff99b89787 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fff99a03420 libsystem_c.dylib`abort + 129
    frame #3: 0x00007fff999ca893 libsystem_c.dylib`__assert_rtn + 320
    frame #4: 0x00000001006e89a9 libremote.2.6.3.dylib`boost::intrusive_ptr<icinga::Zone>::operator->(this=0x0000000101e3e0f0) const + 73 at intrusive_ptr.hpp:198
    frame #5: 0x000000010077c3b9 libremote.2.6.3.dylib`icinga::ApiListener::ConfigUpdateHandler(origin=0x0000700009016008, params=0x0000700009015dd8) + 1577 at apilistener-filesync.cpp:287
    frame #6: 0x00000001007095ec libremote.2.6.3.dylib`boost::detail::function::function_invoker2<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&>::invoke(function_ptr=0x0000000101b08b28, a0=0x0000700009016008, a1=0x0000700009015dd8) + 92 at function_template.hpp:101
    frame #7: 0x00000001006cc26f libremote.2.6.3.dylib`boost::function2<icinga::Value, boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&>::operator(this=0x0000000101b08b20, a0=0x0000700009016008, a1=0x0000700009015dd8)(boost::intrusive_ptr<icinga::MessageOrigin> const&, boost::intrusive_ptr<icinga::Dictionary> const&) const + 191 at function_template.hpp:770
    frame #8: 0x00000001006cc19b libremote.2.6.3.dylib`icinga::ApiFunction::Invoke(this=0x0000000101b08b00, origin=0x0000700009016008, arguments=0x0000700009015dd8) + 59 at apifunction.cpp:31
    frame #9: 0x0000000100868df8 libremote.2.6.3.dylib`icinga::JsonRpcConnection::MessageHandler(this=0x0000000101d6e800, jsonString=0x0000000101e08c78) + 3096 at jsonrpcconnection.cpp:202
    frame #10: 0x0000000100867ff8 libremote.2.6.3.dylib`icinga::JsonRpcConnection::MessageHandlerWrapper(this=0x0000000101d6e800, jsonString=0x0000000101e08c78) + 88 at jsonrpcconnection.cpp:148
    frame #11: 0x000000010086cbd3 libremote.2.6.3.dylib`void boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>::call<boost::intrusive_ptr<icinga::JsonRpcConnection>, icinga::String const>(this=0x0000000101e08c60, u=0x0000000101e08c70, (null)=0x0000000000000000, b1=0x0000000101e08c78) const + 131 at mem_fn_template.hpp:156
    frame #12: 0x000000010086cb41 libremote.2.6.3.dylib`void boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>::operator(this=0x0000000101e08c60, u=0x0000000101e08c70, a1=0x0000000101e08c78)<boost::intrusive_ptr<icinga::JsonRpcConnection> >(boost::intrusive_ptr<icinga::JsonRpcConnection>&, icinga::String const&) const + 49 at mem_fn_template.hpp:171
    frame #13: 0x000000010086cadc libremote.2.6.3.dylib`void boost::_bi::list2<boost::_bi::value<boost::intrusive_ptr<icinga::JsonRpcConnection> >, boost::_bi::value<icinga::String> >::operator(this=0x0000000101e08c70, (null)=type<void> @ 0x0000700009016598, f=0x0000000101e08c60, a=0x00007000090165c0, (null)=0)<boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>, boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>&, boost::_bi::list0&, int) + 108 at bind.hpp:319
    frame #14: 0x000000010086ca6a libremote.2.6.3.dylib`boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>, boost::_bi::list2<boost::_bi::value<boost::intrusive_ptr<icinga::JsonRpcConnection> >, boost::_bi::value<icinga::String> > >::operator(this=0x0000000101e08c60)() + 58 at bind.hpp:1294
    frame #15: 0x000000010086c770 libremote.2.6.3.dylib`boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf1<void, icinga::JsonRpcConnection, icinga::String const&>, boost::_bi::list2<boost::_bi::value<boost::intrusive_ptr<icinga::JsonRpcConnection> >, boost::_bi::value<icinga::String> > >, void>::invoke(function_obj_ptr=0x00007000090167d8) + 32 at function_template.hpp:159
    frame #16: 0x0000000100fecfa8 libbase.2.6.3.dylib`boost::function0<void>::operator(this=0x00007000090167d0)() const + 120 at function_template.hpp:770
    frame #17: 0x0000000101234a94 libbase.2.6.3.dylib`icinga::WorkQueue::WorkerThreadProc(this=0x0000000102812c08) + 3364 at workqueue.cpp:233
    frame #18: 0x0000000101237659 libbase.2.6.3.dylib`boost::_mfi::mf0<void, icinga::WorkQueue>::operator(this=0x0000000101d68ce0, p=0x0000000102812c08)(icinga::WorkQueue*) const + 105 at mem_fn_template.hpp:49
    frame #19: 0x0000000101237fa0 libbase.2.6.3.dylib`void boost::_bi::list1<boost::_bi::value<icinga::WorkQueue*> >::operator(this=0x0000000101d68cf0, (null)=type<void> @ 0x0000700009016e48, f=0x0000000101d68ce0, a=0x0000700009016e70, (null)=0)<boost::_mfi::mf0<void, icinga::WorkQueue>, boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf0<void, icinga::WorkQueue>&, boost::_bi::list0&, int) + 80 at bind.hpp:259
    frame #20: 0x0000000101237f4a libbase.2.6.3.dylib`boost::_bi::bind_t<void, boost::_mfi::mf0<void, icinga::WorkQueue>, boost::_bi::list1<boost::_bi::value<icinga::WorkQueue*> > >::operator(this=0x0000000101d68ce0)() + 58 at bind.hpp:1294
    frame #21: 0x0000000101237edc libbase.2.6.3.dylib`boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf0<void, icinga::WorkQueue>, boost::_bi::list1<boost::_bi::value<icinga::WorkQueue*> > > >::run(this=0x0000000101d68ae0) + 28 at thread.hpp:116
    frame #22: 0x000000010010dc14 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 164
    frame #23: 0x00007fff99b86aab libsystem_pthread.dylib`_pthread_body + 180
    frame #24: 0x00007fff99b869f7 libsystem_pthread.dylib`_pthread_start + 286
    frame #25: 0x00007fff99b861fd libsystem_pthread.dylib`thread_start + 13
(lldb) up
frame #1: 0x00007fff99b89787 libsystem_pthread.dylib`pthread_kill + 90
libsystem_pthread.dylib`pthread_kill:
    0x7fff99b89787 <+90>:  cmpl   $-0x1, %eax
    0x7fff99b8978a <+93>:  jne    0x7fff99b89793            ; <+102>
    0x7fff99b8978c <+95>:  callq  0x7fff99b8b1fa            ; symbol stub for: __error
    0x7fff99b89791 <+100>: movl   (%rax), %eax
(lldb)
frame #2: 0x00007fff99a03420 libsystem_c.dylib`abort + 129
libsystem_c.dylib`abort:
    0x7fff99a03420 <+129>: movl   $0x2710, %edi             ; imm = 0x2710
    0x7fff99a03425 <+134>: callq  0x7fff999d4e68            ; usleep$NOCANCEL
    0x7fff99a0342a <+139>: callq  0x7fff99a0342f            ; __abort

libsystem_c.dylib`__abort:
    0x7fff99a0342f <+0>:   cmpq   $0x0, 0x8d95cf1(%rip)     ; gCRAnnotations + 7
(lldb)
frame #3: 0x00007fff999ca893 libsystem_c.dylib`__assert_rtn + 320
libsystem_c.dylib`basename_r:
    0x7fff999ca893 <+0>: pushq  %rbp
    0x7fff999ca894 <+1>: movq   %rsp, %rbp
    0x7fff999ca897 <+4>: pushq  %r15
    0x7fff999ca899 <+6>: pushq  %r14
(lldb)
frame #4: 0x00000001006e89a9 libremote.2.6.3.dylib`boost::intrusive_ptr<icinga::Zone>::operator->(this=0x0000000101e3e0f0) const + 73 at intrusive_ptr.hpp:198
   195
   196 	    T * operator->() const
   197 	    {
-> 198 	        BOOST_ASSERT( px != 0 );
   199 	        return px;
   200 	    }
   201
(lldb)
frame #5: 0x000000010077c3b9 libremote.2.6.3.dylib`icinga::ApiListener::ConfigUpdateHandler(origin=0x0000700009016008, params=0x0000700009015dd8) + 1577 at apilistener-filesync.cpp:287
   284
   285 		Log(LogInformation, "ApiListener")
   286 		    << "Applying config update from endpoint '" << origin->FromClient->GetEndpoint()->GetName() << "' of zone  '"
-> 287 		    << origin->FromZone->GetName() << "'";
   288
   289 		Dictionary::Ptr updateV1 = params->Get("update");
   290 		Dictionary::Ptr updateV2 = params->Get("update_v2");

@dnsmichi dnsmichi reopened this May 12, 2017
@dnsmichi dnsmichi self-assigned this May 12, 2017
dnsmichi pushed a commit that referenced this issue May 12, 2017
dnsmichi pushed a commit that referenced this issue May 12, 2017
@gunnarbeutner gunnarbeutner modified the milestones: 2.6.4, 2.7.0 May 23, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/distributed Distributed monitoring (master, satellites, clients) area/log Logging related enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

3 participants