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

[dev.icinga.com #11807] Command Pipe thread 100% CPU Usage #4225

Closed
icinga-migration opened this issue May 18, 2016 · 6 comments

Comments

Projects
None yet
1 participant
@icinga-migration
Copy link
Member

commented May 18, 2016

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

Created by mfrosch on 2016-05-18 13:29:01 +00:00

Assignee: mfrosch
Status: Resolved (closed on 2016-05-19 07:45:37 +00:00)
Target Version: 2.4.9
Last Update: 2016-05-19 07:45:37 +00:00 (in Redmine)

Icinga Version: 2.4.8
Backport?: Not yet backported
Include in Changelog: 1

Seems that the CommandPipe Thread is running a busy loop after submitting a few commands:

#0  0x00002b060a187add in read () at ../sysdeps/unix/syscall-template.S:81

No locals.

#1  0x00002b060a4706aa in read (__nbytes=8192, __buf=0x2b062df4de80, __fd=) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44

No locals.

#2  icinga::Socket::Read (this=this@entry=0x2b0640000bb0, buffer=buffer@entry=0x2b062df4de80, count=count@entry=8192) at /build/icinga2-2.4.8/lib/base/socket.cpp:302

rc =

PRETTY_FUNCTION = "size_t icinga::Socket::Read(void*, size_t)"

#3  0x00002b062177609e in icinga::ExternalCommandListener::CommandPipeThread (this=, commandPath=...) at /build/icinga2-2.4.8/lib/compat/externalcommandlistener.cpp:116

buffer = "[1463577735] SCHEDULE_FORCED_SVC_CHECK;muria;https cert horde.lazyfrosch.de;1463577735\n", '\000' <repeats 8104 times>
rc =
fd =
fifo = {px = 0x2b0640000960}
sock = {px = 0x2b0640000bb0}
src = {Buffer = 0x2b0640000e40 "[1463577735] SCHEDULE_FORCED_SVC_CHECK;muria;https cert horde.lazyfrosch.de;1463577735\n", Size = 0, MustRead = true, Eof = false}
statbuf = {st_dev = 15, st_ino = 19188, st_nlink = 1, st_mode = 4528, st_uid = 108, st_gid = 33, __pad0 = 0, st_rdev = 0, st_size = 0, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1463574270, tv_nsec = 832464975}, st_mtim = {tv_sec = 1463574270,
tv_nsec = 372488893}, st_ctim = {tv_sec = 1463574373, tv_nsec = 83147659}, __glibc_reserved = {0, 0, 0}}
fifo_ok =

PRETTY_FUNCTION = "void icinga::ExternalCommandListener::CommandPipeThread(const icinga::String&)"
mode =

#4  0x00002b06097dbaea in ?? () from /usr/lib/x86_64-linux-gnu/libboost_thread.so.1.55.0

No symbol table info available.

#5  0x00002b060a1810a4 in start_thread (arg=0x2b062df50700) at pthread_create.c:309

__res =
pd = 0x2b062df50700
now =
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {47305540830976, -2871906052433176024, 0, 47304928968800, 47305534523840, 47305540830976, -8203118426899801560, -8203055373650290136}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {
prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call =
pagesize_m1 =
sp =
freesize =

PRETTY_FUNCTION = "start_thread"

#6  0x00002b060cd0187d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Changesets

2016-05-18 13:52:29 +00:00 by gbeutner 78705e7

Open the command pipe with O_RDWR

fixes #11807

2016-05-19 07:50:55 +00:00 by gbeutner 3746374

Open the command pipe with O_RDWR

fixes #11807
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 18, 2016

Updated by gbeutner on 2016-05-18 13:51:08 +00:00

  • Status changed from New to Assigned

  • Assigned to set to gbeutner

    read(14, "", 8192) = 0
    poll([{fd=14, events=POLLIN}], 1, 4294967295) = 1 ([{fd=14, revents=POLLHUP}])

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 18, 2016

Updated by gbeutner on 2016-05-18 13:55:03 +00:00

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

Applied in changeset 78705e7.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 18, 2016

Updated by mfrosch on 2016-05-18 17:29:11 +00:00

  • Status changed from Resolved to Feedback

Running on v2.4.8-413-g4af6bde

a single "check now" command will cause the CommandListener Thread got haywire, 100% CPU usage.

#0  0x00007f7aacd20d3d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f7aafe17f80 in icinga::Socket::Poll (this=0x7f7a6c000bb0, read=true, write=false, timeout=0x0) at ../../../lib/base/socket.cpp:394
#2  0x00007f7aa86e2034 in icinga::ExternalCommandListener::CommandPipeThread (this=0x7f7a88010c90, commandPath=...) at ../../../lib/compat/externalcommandlistener.cpp:110
#3  0x00007f7aa8778bf6 in boost::_mfi::mf1::operator() (this=0x7f7a80036ed8, p=0x7f7a88010c90, a1=...) at /usr/include/boost/bind/mem_fn_template.hpp:165
#4  0x00007f7aa87784ed in boost::_bi::list2, boost::_bi::value >::operator(), boost::_bi::list0> (

this=0x7f7a80036ee8, f=..., a=...) at /usr/include/boost/bind/bind.hpp:313

#5  0x00007f7aa8776c2f in boost::_bi::bind_t, boost::_bi::list2, boost::_bi::value > >::operator() (

this=0x7f7a80036ed8) at /usr/include/boost/bind/bind_template.hpp:20
...

Same goes for the thread of the main event loop in that case:
#0  0x00007f7aaccfaf2d in nanosleep () at ../sysdeps/unix/syscall-template.S:81

No locals.

#1  0x00007f7aacd23204 in usleep (useconds=) at ../sysdeps/unix/sysv/linux/usleep.c:32

ts = {tv_sec = 2, tv_nsec = 500000000}

#2  0x00007f7aafe2aeac in icinga::Utility::Sleep (timeout=2.5) at ../../../lib/base/utility.cpp:391

No locals.

#3  0x00007f7aafde3c97 in icinga::Application::RunEventLoop (this=0x7f7a7c00ca30) at ../../../lib/base/application.cpp:282

now = 1463592450.8741579
timeDiff = -2.5000579357147217
lastLoop = 1463592450.8741579

#4  0x00007f7aa985fa28 in icinga::IcingaApplication::Main (this=0x7f7a7c00ca30) at ../../../lib/icinga/icingaapplication.cpp:119

...

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 18, 2016

Updated by mfrosch on 2016-05-18 17:29:19 +00:00

  • Status changed from Feedback to New
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 19, 2016

Updated by gbeutner on 2016-05-19 05:05:44 +00:00

  • Status changed from New to Feedback
  • Assigned to changed from gbeutner to mfrosch

That's not the latest commit. Please test with 78705e7 or later.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented May 19, 2016

Updated by mfrosch on 2016-05-19 07:45:37 +00:00

  • Status changed from Feedback to Resolved

Had to trigger Jenkins, seems to work fine now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.