Fresh Logstash installation crashes periodically, has high CPU load, returns "active:failed" and "status=143" after stopping

System

Logstash version: 5.2.1, installed with .deb package. Although this problem has occured on Logstash 5.1.2 as well.
OS: Debian 8.7
Java Version:

$ java -version
openjdk version "1.8.0_111"
OpenJDK Runtime Environment (build 1.8.0_111-8u111-b14-2~bpo8+1-b14)
OpenJDK 64-Bit Server VM (build 25.111-b14, mixed mode)

Problem

If I start Logstash using sudo systemstl start logstash and then do systemctl status logstash I get the following expected output:

● logstash.service - logstash
   Loaded: loaded (/etc/systemd/system/logstash.service; enabled)
   Active: active (running) since Wed 2017-02-22 19:57:46 CET; 4s ago
 Main PID: 27939 (java)
   CGroup: /system.slice/logstash.service
           └─27939 /usr/bin/java -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitia...

However, in irregular intervals, usually a few times a minute, Logstash seems to have restarted itself, with a different PID and a new "active since" date each time.

If I stop Logstash with sudo systemctl stop logstash and then do systemctl status logstash I get:

● logstash.service - logstash
   Loaded: loaded (/etc/systemd/system/logstash.service; enabled)
   Active: failed (Result: exit-code) since Wed 2017-02-22 20:07:36 CET; 1s ago
  Process: 28517 ExecStart=/usr/share/logstash/bin/logstash --path.settings /etc/logstash (code=exited, status=143)
 Main PID: 28517 (code=exited, status=143)

This is the output in /var/log/logstash/logstash-plain.log with DEBUG loglevel. Usually about 15 seconds pass until the section pasted here repeats itself:

[2017-02-22T20:22:54,988][DEBUG][logstash.runner          ] -------- Logstash Settings (* means modified) ---------
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] node.name: "0.0.0.0"
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] *path.config: "/etc/logstash/conf.d"
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] *path.data: "/var/lib/logstash" (default: "/usr/share/logstash/data")
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] config.test_and_exit: false
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] config.reload.automatic: false
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] config.reload.interval: 3
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] metric.collect: true
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] pipeline.id: "main"
[2017-02-22T20:22:54,991][DEBUG][logstash.runner          ] pipeline.workers: 2
[2017-02-22T20:22:54,992][DEBUG][logstash.runner          ] pipeline.output.workers: 1
[2017-02-22T20:22:54,992][DEBUG][logstash.runner          ] pipeline.batch.size: 125
[2017-02-22T20:22:54,992][DEBUG][logstash.runner          ] pipeline.batch.delay: 5
[2017-02-22T20:22:54,992][DEBUG][logstash.runner          ] pipeline.unsafe_shutdown: false
[2017-02-22T20:22:54,992][DEBUG][logstash.runner          ] path.plugins: []
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] config.debug: false
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] *log.level: "debug" (default: "info")
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] version: false
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] help: false
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] log.format: "plain"
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] http.host: "127.0.0.1"
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] http.port: 9600..9700
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] http.environment: "production"
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] queue.type: "memory"
[2017-02-22T20:22:54,993][DEBUG][logstash.runner          ] queue.page_capacity: 262144000
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] queue.max_bytes: 1073741824
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] queue.max_events: 0
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] queue.checkpoint.acks: 1024
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] queue.checkpoint.writes: 1024
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] queue.checkpoint.interval: 1000
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] slowlog.threshold.warn: -1
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] slowlog.threshold.info: -1
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] slowlog.threshold.debug: -1
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] slowlog.threshold.trace: -1
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] path.queue: "/usr/share/logstash/data/queue"
[2017-02-22T20:22:54,994][DEBUG][logstash.runner          ] *path.settings: "/etc/logstash" (default: "/usr/share/logstash/config")
[2017-02-22T20:22:54,995][DEBUG][logstash.runner          ] *path.logs: "/var/log/logstash" (default: "/usr/share/logstash/logs")
[2017-02-22T20:22:54,995][DEBUG][logstash.runner          ] --------------- Logstash Settings -------------------
[2017-02-22T20:22:55,009][DEBUG][logstash.agent           ] Agent: Configuring metric collection
[2017-02-22T20:22:55,010][DEBUG][logstash.instrument.periodicpoller.os] PeriodicPoller: Starting {:polling_interval=>5, :polling_timeout=>120}
[2017-02-22T20:22:55,016][DEBUG][logstash.instrument.periodicpoller.cgroup] Error, cannot retrieve cgroups information {:exception=>"Errno::ENOENT", :message=>"No such file or directory - /sys/fs/cgroup/cpuacct/cpu.cfs_period_us"}
[2017-02-22T20:22:55,039][DEBUG][logstash.instrument.periodicpoller.jvm] PeriodicPoller: Starting {:polling_interval=>5, :polling_timeout=>120}
[2017-02-22T20:22:55,090][DEBUG][logstash.instrument.periodicpoller.persistentqueue] PeriodicPoller: Starting {:polling_interval=>5, :polling_timeout=>120}
[2017-02-22T20:22:55,098][INFO ][logstash.agent           ] No config files found in path {:path=>"/etc/logstash/conf.d/*"}
[2017-02-22T20:22:55,103][ERROR][logstash.agent           ] failed to fetch pipeline configuration {:message=>"No config files found: /etc/logstash/conf.d. Can you make sure this path is a logstash config file?"}
[2017-02-22T20:22:55,108][DEBUG][logstash.agent           ] starting agent
[2017-02-22T20:22:55,111][DEBUG][logstash.agent           ] Starting puma
[2017-02-22T20:22:55,112][DEBUG][logstash.instrument.periodicpoller.os] PeriodicPoller: Stopping
[2017-02-22T20:22:55,112][DEBUG][logstash.instrument.periodicpoller.jvm] PeriodicPoller: Stopping
[2017-02-22T20:22:55,113][DEBUG][logstash.instrument.periodicpoller.persistentqueue] PeriodicPoller: Stopping
[2017-02-22T20:22:55,117][DEBUG][logstash.agent           ] Trying to start WebServer {:port=>9600}

If I configure a pipeline in /etc/logstash/conf.d it isn't run, there is no output from the pipeline.

What could be the cause for this? Any help would be greatly appreciated :slight_smile:

Check how many instances of logstash you are running.

ps -elf | grep logstash.

One, apparently:

$ ps -elf | grep logstash
4 S logstash 29487     1 99  99  19 - 861964 -     23:41 ?        00:00:23 /usr/bin/java -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+DisableExplicitGC -Djava.awt.headless=true -Dfile.encoding=UTF-8 -XX:+HeapDumpOnOutOfMemoryError -Xmx1g -Xms256m -Xss2048k -Djffi.boot.library.path=/usr/share/logstash/vendor/jruby/lib/jni -Xbootclasspath/a:/usr/share/logstash/vendor/jruby/lib/jruby.jar -classpath : -Djruby.home=/usr/share/logstash/vendor/jruby -Djruby.lib=/usr/share/logstash/vendor/jruby/lib -Djruby.script=jruby -Djruby.shell=/bin/sh org.jruby.Main /usr/share/logstash/lib/bootstrap/environment.rb logstash/runner.rb --path.settings /etc/logstash

I also noticed that the CPU load of the logstash process when running top seems unreasonably high. It quickly goes up to ~190%+ and stays there until logstash crashes and restarts with a different PID.

top - 16:08:10 up 53 min,  1 user,  load average: 0.87, 0.24, 0.23
Tasks:  68 total,   1 running,  67 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  3.0 sy, 93.1 ni,  3.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:   4057560 total,  3061456 used,   996104 free,    25492 buffers
KiB Swap:        0 total,        0 used,        0 free.   176320 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                         
 2682 logstash  39  19 3450136 380380  18564 S 191.4  9.4   0:15.66 java                                                                                                            
  388 elastic+  20   0 4694128 2.278g  19364 S   0.9 58.9   0:26.77 java
  ...            

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