HIgh CPU usage without processing any data

Trying to config a new logstash instance to handle syslog input, so prepared input, output and a dummy working filter as a starting template from another running instance, but not sending any data to input yet. Even so logstash is burning CPU in one thread #15 running bootstrap environment, wonder why and how to stop this useless CO2 generation :slight_smile:

$ curl -XGET 'http://localhost:9600/_node/hot_threads?pretty'
{
"host" : "",
"version" : "6.8.3",
"http_address" : "127.0.0.1:9600",
"id" : "a6cc457a-1610-4e8d-9309-77ce10c865ab",
"name" : "",
"hot_threads" : {
"time" : "2019-09-11T22:59:14+02:00",
"busiest_threads" : 10,
"threads" : [ {
"name" : "Ruby-0-Thread-1",
"thread_id" : 15,
"percent_of_cpu_time" : 96.31,
"state" : "runnable",
"path" : "/usr/share/logstash/lib/bootstrap/environment.rb:6",
"traces" : [ "java.lang.System.identityHashCode(Native Method)", "java.util.IdentityHashMap.hash(Unknown Source)", "java.util.IdentityHashMap.containsKey(Unknown Source)" ]
}, {
"name" : "LogStash::Runner",
"thread_id" : 1,
"percent_of_cpu_time" : 1.2,
"state" : "timed_waiting",
"traces" : [ "java.lang.Object.wait(Native Method)", "java.lang.Thread.join(Unknown Source)", "org.jruby.internal.runtime.NativeThread.join(NativeThread.java:75)" ]
}, {
"name" : "[main]>worker7",
"thread_id" : 36,
"percent_of_cpu_time" : 0.25,
"state" : "timed_waiting",
"traces" : [ "sun.misc.Unsafe.park(Native Method)", "java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)", "java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)" ]
}, {
...

Nothing shows in the log than the normal start up:

[2019-09-11T22:39:38,662][INFO ][logstash.pipeline ] Pipeline started successfully {:pipeline_id=>"main", :thread=>"#<Thread:0x239ba8cc sleep>"}
[2019-09-11T22:39:38,709][INFO ][logstash.agent ] Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>}
[2019-09-11T22:39:39,119][INFO ][logstash.agent ] Successfully started Logstash API endpoint {:port=>9600}

Any one got an idea how to attack this...

Hm it this just the norm, got other working logstash instances, they also seem to burn one cpu core near 100% in a Ruby-0-Thread... seems like some kind of busy-waiting thread

Top -H from a non-event-processing instance:

Tasks: 425 total, 2 running, 324 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.1%us, 1.0%sy, 6.4%ni, 92.4%id, 0.0%wa, 0.0%hi, 0.0%si, 0.1%st
Mem: 16424228k total, 4932720k used, 11491508k free, 18400k buffers
Swap: 3321852k total, 0k used, 3321852k free, 265600k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3358 logstash 39 19 9.9g 1.7g 19m R 98.3 10.6 1:04.03 LogStash::Runne
3370 logstash 39 19 9.9g 1.7g 19m S 1.3 10.6 0:00.53 [main]>worker0
3372 logstash 39 19 9.9g 1.7g 19m S 1.3 10.6 0:00.48 [main]>worker2
3376 logstash 39 19 9.9g 1.7g 19m S 1.3 10.6 0:00.54 [main]>worker6
3336 logstash 39 19 9.9g 1.7g 19m S 1.0 10.6 0:01.47 java
3337 logstash 39 19 9.9g 1.7g 19m S 1.0 10.6 0:00.64 java
3371 logstash 39 19 9.9g 1.7g 19m S 1.0 10.6 0:00.50 [main]>worker1
3373 logstash 39 19 9.9g 1.7g 19m S 1.0 10.6 0:00.52 [main]>worker3
3375 logstash 39 19 9.9g 1.7g 19m S 1.0 10.6 0:00.54 [main]>worker5
3318 logstash 39 19 9.9g 1.7g 19m S 0.7 10.6 0:00.63 java
3322 logstash 39 19 9.9g 1.7g 19m S 0.7 10.6 0:00.61 java

something most be going on in Userland as strace only shows this:

[root@es-i1 ~]# ps -fulogstash
UID PID PPID C STIME TTY TIME CMD
logstash 3303 1 99 Sep13 ? 2-16:33:40 /usr/bin/java -Xms4g -Xmx4g
[root@es-i1 ~]# strace -p 3303
Process 3303 attached
futex(0x7ff4c6add9d0, FUTEX_WAIT, 3317, NULL^CProcess 3303 detached
<detached ...>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.