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

Jump to bottom

[dev.icinga.com #11224] Socket Exceptions (Operation not permitted) while reading from API #3970

Closed
icinga-migration opened this issue Feb 24, 2016 · 13 comments
Closed

[dev.icinga.com #11224] Socket Exceptions (Operation not permitted) while reading from API #3970

icinga-migration opened this issue Feb 24, 2016 · 13 comments
Labels
area/api REST API bug Something isn't working
Milestone
2.4.5

Comments

@icinga-migration
Copy link

This issue has been migrated from Redmine: https://dev.icinga.com/issues/11224

Created by bashgeek on 2016-02-24 16:54:38 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2016-03-29 11:55:03 +00:00)
Target Version: 2.4.5
Last Update: 2016-05-09 11:38:46 +00:00 (in Redmine)

Icinga Version: 2.4.3
Backport?: Already backported
Include in Changelog: 1

This is happening since yesterdays upgrade to 2.4.2 (using the Debian Jessie package).

I'm not quite sure why this is happening, it didn't before but now these logs come up with every request made to the API (no client-certificates, just basic login):

Feb 24 17:52:48 june icinga2[10094]: [2016-02-24 17:52:48 +0100] information/HttpServerConnection: Request: GET /v1/objects/services (root)
Feb 24 17:52:48 june icinga2[10094]: [2016-02-24 17:52:48 +0100] critical/SocketEvents: Exception thrown in socket I/O handler:
Feb 24 17:52:48 june icinga2[10094]: Error: boost unique_lock doesn't own the mutex: Operation not permitted
Feb 24 17:52:48 june icinga2[10094]: (0) libbase.so: void boost::throw_exception(boost::lock_error const&) (+0x16d) [0x7f30c114d4bd]
Feb 24 17:52:48 june icinga2[10094]: (1) libbase.so: boost::unique_lock::unlock() (+0xad) [0x7f30c114d80d]
Feb 24 17:52:49 june icinga2[10094]: (2) libbase.so: icinga::TlsStream::OnEvent(int) (+0x310) [0x7f30c11306a0]
Feb 24 17:52:49 june icinga2[10094]: (3) libbase.so: icinga::SocketEvents::ThreadProc(int) (+0x423) [0x7f30c1112483]
Feb 24 17:52:49 june icinga2[10094]: (4) libboost_thread.so.1.55.0:  (+0xdaea) [0x7f30c1dbeaea]
Feb 24 17:52:49 june icinga2[10094]: (5) libpthread.so.0:  (+0x80a4) [0x7f30c140c0a4]
Feb 24 17:52:49 june icinga2[10094]: (6) libc.so.6: clone (+0x6d) [0x7f30be8c687d]

It's a standalone setup without any satellites and/or special configurations.

If you need any more information I'm happy to provide it.

Changesets

2016-03-29 11:52:37 +00:00 by mfriedrich 5dd685c

Fix socket exceptions while querying the API

fixes #11224

2016-04-20 08:07:24 +00:00 by mfriedrich 98eef33

Fix socket exceptions while querying the API

fixes #11224
@icinga-migration
Copy link
Author

Updated by bashgeek on 2016-02-24 16:56:50 +00:00

The requests finish properly with correct data though.

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-02-24 19:24:41 +00:00

Is it specific to GET requests and/or /v1/objects/services (I guess not, just to be sure)?

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-02-24 22:35:07 +00:00

Just stumbled over this when testing a different patch.

$ /usr/local/sbin/check_http localhost -S1 -p 5665

[2016-02-24 23:33:15 +0100] information/HttpServerConnection: Request: GET / ()
[2016-02-24 23:33:15 +0100] warning/HttpServerConnection: Unauthorized request: GET /
[2016-02-24 23:33:15 +0100] critical/SocketEvents: Exception thrown in socket I/O handler:
Error: boost unique_lock doesn't own the mutex: Operation not permitted


    (0) 2   libbase.dylib                       0x000000010f02e6a6 __cxa_throw + 214
    (1) 3   libbase.dylib                       0x000000010eff1097 _ZN5boost15throw_exceptionINS_10lock_errorEEEvRKT_ + 119
    (2) 4   libbase.dylib                       0x000000010f043000 _ZN5boost11unique_lockINS_5mutexEE6unlockEv + 176
    (3) 5   libbase.dylib                       0x000000010f142c81 _ZN6icinga9TlsStream7OnEventEi + 2593
    (4) 6   libbase.dylib                       0x000000010f142d22 _ZThn232_N6icinga9TlsStream7OnEventEi + 34
    (5) 7   libbase.dylib                       0x000000010f0edec5 _ZN6icinga12SocketEvents10ThreadProcEi + 4229
    (6) 8   libbase.dylib                       0x000000010f0c596f _ZN5boost3_bi5list1INS0_5valueIiEEEclIPFviENS0_5list0EEEvNS0_4typeIvEERT_RT0_i + 79
    (7) 9   libbase.dylib                       0x000000010f0c590c _ZN5boost3_bi6bind_tIvPFviENS0_5list1INS0_5valueIiEEEEEclEv + 60
    (8) 10  libbase.dylib                       0x000000010f0c589c _ZN5boost6detail11thread_dataINS_3_bi6bind_tIvPFviENS2_5list1INS2_5valueIiEEEEEEE3runEv + 28
    (9) 11  libboost_thread-mt.dylib            0x000000010e02d5e9 _ZN5boost12_GLOBAL__N_112thread_proxyEPv + 185
    (10) 12  libsystem_pthread.dylib             0x00007fff90171c13 _pthread_body + 131
    (11) 13  libsystem_pthread.dylib             0x00007fff90171b90 _pthread_body + 0
    (12) 14  libsystem_pthread.dylib             0x00007fff9016f375 thread_start + 13

@icinga-migration
Copy link
Author

Updated by bashgeek on 2016-02-25 04:55:46 +00:00

dnsmichi wrote:

Is it specific to GET requests and/or /v1/objects/services (I guess not, just to be sure)?

Nope, seems to happen for every request here.

@icinga-migration
Copy link
Author

Updated by tobiasvdk on 2016-03-07 16:42:21 +00:00

I get the same error when using the icingaweb2 director kickstart and no data is returned when trying to get "/v1/objects/zones". A manual "curl" command succeeds without an error

curl -s -u  "user:pass" https://my-host:5665/v1/objects/zones

I'm using icinga 2 r2.4.3-229-gd14477c

@icinga-migration
Copy link
Author

Updated by tobiasvdk on 2016-03-09 07:55:00 +00:00

After updating icinga 2 director no error message is shown during kickstart run.

@icinga-migration
Copy link
Author

Updated by tobiasvdk on 2016-03-09 10:47:49 +00:00

I stumbled over this error again today while using Chrome to test some API GET requests.

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-03-18 11:10:34 +00:00

  • Parent Id set to 11415

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-03-29 11:09:54 +00:00

[2016-03-29 13:02:05 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host ()
[2016-03-29 13:02:05 +0200] warning/HttpServerConnection: Unauthorized request: GET /v1/objects/hosts/flapping-host
[2016-03-29 13:02:05 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:06 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:08 +0200] information/IdoMysqlConnection: Query queue items: 0, query rate: 50.4667/s (3028/min 3028/5min 3028/15min);
[2016-03-29 13:02:09 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:10 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:11 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:11 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:12 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:12 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:13 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:20 +0200] information/ExternalCommandListener: Executing external command: [1459249340] PROCESS_HOST_CHECK_RESULT;flapping-host;1;dfdfsfdsd
[2016-03-29 13:02:23 +0200] information/IdoMysqlConnection: Query queue items: 0, query rate: 51.15/s (3069/min 3069/5min 3069/15min);
[2016-03-29 13:02:23 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
[2016-03-29 13:02:35 +0200] information/HttpServerConnection: No messages for Http connection have been received in the last 10 seconds.
[2016-03-29 13:02:38 +0200] information/ExternalCommandListener: Executing external command: [1459249358] PROCESS_HOST_CHECK_RESULT;flapping-host;0;dfdsf
[2016-03-29 13:02:38 +0200] information/IdoMysqlConnection: Query queue items: 0, query rate: 51.8833/s (3113/min 3113/5min 3113/15min);
[2016-03-29 13:02:40 +0200] information/HttpServerConnection: Request: GET /v1/objects/hosts/flapping-host (root)
Process 38200 stopped
* thread #12: tid = 0x129d11, 0x0000000100fee77e libbase.dylib`::__cxa_throw(obj=0x0000000106f14b28, pvtinfo=0x000000010008c900, dest=(libbase.dylib`boost::exception_detail::clone_impl >::~clone_impl() at exception.hpp:463))(void *)) + 30 at exception.cpp:65, stop reason = breakpoint 1.2
    frame #0: 0x0000000100fee77e libbase.dylib`::__cxa_throw(obj=0x0000000106f14b28, pvtinfo=0x000000010008c900, dest=(libbase.dylib`boost::exception_detail::clone_impl >::~clone_impl() at exception.hpp:463))(void *)) + 30 at exception.cpp:65
   62   extern "C"
   63   void __cxa_throw(void *obj, TYPEINFO_TYPE *pvtinfo, void (*dest)(void *))
   64   {
-> 65       std::type_info *tinfo = static_cast(pvtinfo);
   66
   67       typedef void (*cxa_throw_fn)(void *, std::type_info *, void (*)(void *)) __attribute__((noreturn));
   68       static cxa_throw_fn real_cxa_throw;
(lldb) bt
* thread #12: tid = 0x129d11, 0x0000000100fee77e libbase.dylib`::__cxa_throw(obj=0x0000000106f14b28, pvtinfo=0x000000010008c900, dest=(libbase.dylib`boost::exception_detail::clone_impl >::~clone_impl() at exception.hpp:463))(void *)) + 30 at exception.cpp:65, stop reason = breakpoint 1.2
  * frame #0: 0x0000000100fee77e libbase.dylib`::__cxa_throw(obj=0x0000000106f14b28, pvtinfo=0x000000010008c900, dest=(libbase.dylib`boost::exception_detail::clone_impl >::~clone_impl() at exception.hpp:463))(void *)) + 30 at exception.cpp:65
    frame #1: 0x0000000100fb66a7 libbase.dylib`void boost::throw_exception(e=0x0000700000487df8) + 119 at throw_exception.hpp:69
    frame #2: 0x0000000101001ced libbase.dylib`boost::unique_lock::unlock(this=0x0000700000488248) + 173 at lock_types.hpp:448
    frame #3: 0x00000001010f09d0 libbase.dylib`icinga::TlsStream::OnEvent(this=0x0000000101d95620, revents=1) + 2560 at tlsstream.cpp:248
    frame #4: 0x00000001010a0fe6 libbase.dylib`icinga::SocketEvents::ThreadProc(tid=0) + 4182 at socketevents.cpp:249
    frame #5: 0x000000010107abbf libbase.dylib`void boost::_bi::list1 >::operator(this=0x0000000101d95a38, (null)=type @ 0x0000700000498e48, f=0x0000000101d95a30, a=0x0000700000498e70, (null)=0)(boost::_bi::type, void (*&)(int), boost::_bi::list0&, int) + 79 at bind.hpp:259
    frame #6: 0x000000010107ab6a libbase.dylib`boost::_bi::bind_t > >::operator(this=0x0000000101d95a30)() + 58 at bind.hpp:1222
    frame #7: 0x000000010107aafc libbase.dylib`boost::detail::thread_data > > >::run(this=0x0000000101d95830) + 28 at thread.hpp:116
    frame #8: 0x000000010007f5e9 libboost_thread-mt.dylib`boost::(anonymous namespace)::thread_proxy(void*) + 185
    frame #9: 0x00007fff988c099d libsystem_pthread.dylib`_pthread_body + 131
    frame #10: 0x00007fff988c091a libsystem_pthread.dylib`_pthread_start + 168
    frame #11: 0x00007fff988be351 libsystem_pthread.dylib`thread_start + 13
(lldb) up
frame #1: 0x0000000100fb66a7 libbase.dylib`void boost::throw_exception(e=0x0000700000487df8) + 119 at throw_exception.hpp:69
   66       throw_exception_assert_compatibility(e);
   67
   68   #ifndef BOOST_EXCEPTION_DISABLE
-> 69       throw enable_current_exception(enable_error_info(e));
   70   #else
   71       throw e;
   72   #endif
(lldb)
frame #2: 0x0000000101001ced libbase.dylib`boost::unique_lock::unlock(this=0x0000700000488248) + 173 at lock_types.hpp:448
   445        }
   446        if (!owns_lock())
   447        {
-> 448          boost::throw_exception(
   449              boost::lock_error(static_cast(system::errc::operation_not_permitted), "boost unique_lock doesn't own the mutex"));
   450        }
   451        m->unlock();
(lldb)
frame #3: 0x00000001010f09d0 libbase.dylib`icinga::TlsStream::OnEvent(this=0x0000000101d95620, revents=1) + 2560 at tlsstream.cpp:248
   245      }
   246
   247      if (m_Shutdown && !m_SendQ->IsDataAvailable()) {
-> 248          lock.unlock();
   249          Close();
   250      }
   251  }

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-03-29 11:49:29 +00:00

  • Status changed from New to Assigned
  • Assigned to set to mfriedrich
  • Target Version set to 2.4.5

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-03-29 11:55:03 +00:00

  • Status changed from Assigned to Resolved
  • Done % changed from 0 to 100

Applied in changeset 5dd685c.

@icinga-migration
Copy link
Author

Updated by gbeutner on 2016-04-20 08:15:59 +00:00

  • Backport? changed from Not yet backported to Already backported

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2016-05-09 11:38:47 +00:00

  • Parent Id deleted 11415

@icinga-migration icinga-migration added bug Something isn't working area/api REST API labels Jan 17, 2017
@icinga-migration icinga-migration added this to the 2.4.5 milestone Jan 17, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/api REST API bug Something isn't working
Projects
None yet
Milestone
2.4.5
Development

No branches or pull requests
1 participant
@icinga-migration