Error starting Logstash

steevhise · September 1, 2022, 5:51pm

Logstash is exiting with an error when starting up:

[ERROR] 2022-09-01 17:35:32.473 [Converge PipelineAction::Create<main>] agent - Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:main, :exception=>"LogStash::ConfigurationError", :message=>"Expected one of [ \\t\\r\\n], \"#\", \"input\", \"filter\", \"output\" at line 1, column 1 (byte 1)", :backtrace=>["/usr/share/logstash/logstash-core/lib/logstash/compiler.rb:32:in `compile_imperative'", "org/logstash/execution/AbstractPipelineExt.java:189:in `initialize'", "org/logstash/execution/JavaBasePipelineExt.java:72:in `initialize'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:47:in `initialize'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline_action/create.rb:52:in `execute'", "/usr/share/logstash/logstash-core/lib/logstash/agent.rb:383:in `block in converge_state'"]}

This is when starting on command line like so:

/usr/share/logstash/bin/logstash  -f /etc/logstash/logstash.yml -f /etc/logstash/conf.d/logstash.conf  -f /etc/logstash/jvm.options

If i leave off the jvm.options file, I don't get an error.

the contents of the jvm.options file:

-Xms2g
-Xmx8g

## GC configuration
8-13:-XX:CMSInitiatingOccupancyFraction=75
8-13:-XX:+UseCMSInitiatingOccupancyOnly



-Djava.awt.headless=true
-Dfile.encoding=UTF-8
-Djruby.compile.invokedynamic=true
-Djruby.jit.threshold=0
-Djruby.regexp.interruptible=true
-XX:+HeapDumpOnOutOfMemoryError
-Djava.security.egd=file:/dev/urandom

oddly, replacing it with the jvm.options.dpkg-dist (the file directly from the installed debian package) also results in the same error.

also, the error message seems to refer to something in the logstash.conf - but why does it work fine when i leave out the jvm options?

This started happening within the last couple of weeks. thinking it might have been because of a recent version update, i tried downgrading, and currently running 7.17.3, but also have tried with 7.17.5 and 7.17.6, with same results.

Again, NOT mentioning the jvm options on the command line at all make the command succeed. BUT, if I DO mention the file but COMMENT OUT EVERY LINE of it, startup fails (with other errors that are probably irrelevant) Just grasping at straws. any hints?

MORE INFO: when trying to start it with systemctl, I get a different error:

[2022-09-01T18:14:29,643][FATAL][org.logstash.Logstash    ] Logstash stopped processing because of an error: (SystemExit) exit
org.jruby.exceptions.SystemExit: (SystemExit) exit
	at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:747) ~[jruby-complete-9.2.20.1.jar:?]
	at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:710) ~[jruby-complete-9.2.20.1.jar:?]

i'm tearing my hair out. why can't logstash give more informative details when it errors? like exactly what line is causing the error?

Badger · September 1, 2022, 6:37pm

Leave it off, you should not add jvm.options on the command line.

It could, but I wouldn't hold your breath waiting for that to be implemented.

The compiler is reading "-Xms2g" and telling you that you cannot have a - at that point in a configuration.

steevhise · September 1, 2022, 6:56pm

ok but the reason i'm trying it from the command line is because it doesnt run from systemctl either and i thought i'd get more descriptive error messaging from the CL. how do i leave out the jvm.options from the systemd service?

steevhise · September 1, 2022, 8:26pm

to provide more detail, again, starting logstash under systemd gives a fatal error also, though a different one.
this is the entire text of the log upon startup (it repeats over and over every minute or so)


[2022-09-01T20:22:44,697][INFO ][logstash.runner          ] Log4j configuration path used is: /etc/logstash/log4j2.properties
[2022-09-01T20:22:44,717][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"7.17.6", "jruby.version"=>"jruby 9.2.20.1 (2.5.8) 2021-11-30 2a2962fbd1 OpenJDK 64-Bit Server VM 11.0.16+8 on 11.0.16+8 +indy +jit [linux-x86_64]"}
[2022-09-01T20:22:44,722][INFO ][logstash.runner          ] JVM bootstrap flags: [-Xms1g, -Xmx1g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djdk.io.File.enableADS=true, -Djruby.compile.invokedynamic=true, -Djruby.jit.threshold=0, -Djruby.regexp.interruptible=true, -XX:+HeapDumpOnOutOfMemoryError, -Djava.security.egd=file:/dev/urandom, -Dlog4j2.isThreadContextMapInheritable=true]
[2022-09-01T20:22:44,730][DEBUG][logstash.modules.scaffold] Found module {:module_name=>"netflow", :directory=>"/usr/share/logstash/modules/netflow/configuration"}
[2022-09-01T20:22:44,732][DEBUG][logstash.plugins.registry] Adding plugin to the registry {:name=>"netflow", :type=>:modules, :class=>#<LogStash::Modules::Scaffold:0x4898cd22 @directory="/usr/share/logstash/modules/netflow/configuration", @module_name="netflow", @kibana_version_parts=["6", "0", "0"]>}
[2022-09-01T20:22:44,734][DEBUG][logstash.modules.scaffold] Found module {:module_name=>"fb_apache", :directory=>"/usr/share/logstash/modules/fb_apache/configuration"}
[2022-09-01T20:22:44,734][DEBUG][logstash.plugins.registry] Adding plugin to the registry {:name=>"fb_apache", :type=>:modules, :class=>#<LogStash::Modules::Scaffold:0xd2eb3a0 @directory="/usr/share/logstash/modules/fb_apache/configuration", @module_name="fb_apache", @kibana_version_parts=["6", "0", "0"]>}
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] -------- Logstash Settings (* means modified) ---------
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] *node.name: "thoth" (default: "vps019")
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] *path.data: "/var/lib/logstash" (default: "/usr/share/logstash/data")
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] modules.cli: <Java::OrgLogstashUtil::ModulesSettingArray:1 []>
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] modules: []
[2022-09-01T20:22:45,190][DEBUG][logstash.runner          ] modules_list: []
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] modules_variable_list: []
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] modules_setup: false
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] config.test_and_exit: false
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] *config.reload.automatic: true (default: false)
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] *config.reload.interval: #<Java::OrgLogstashUtil::TimeValue:0x343418b2> (default: #<Java::OrgLogstashUtil::TimeValue:0x1812086>)
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] config.support_escapes: false
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] config.field_reference.parser: "STRICT"
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] metric.collect: true
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] pipeline.id: "main"
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] pipeline.system: false
[2022-09-01T20:22:45,191][DEBUG][logstash.runner          ] pipeline.workers: 2
[2022-09-01T20:22:45,192][DEBUG][logstash.runner          ] *pipeline.batch.size: 1 (default: 125)
[2022-09-01T20:22:45,192][DEBUG][logstash.runner          ] pipeline.batch.delay: 50
[2022-09-01T20:22:45,200][DEBUG][logstash.runner          ] pipeline.unsafe_shutdown: false
[2022-09-01T20:22:45,201][DEBUG][logstash.runner          ] pipeline.java_execution: true
[2022-09-01T20:22:45,201][DEBUG][logstash.runner          ] pipeline.reloadable: true
[2022-09-01T20:22:45,201][DEBUG][logstash.runner          ] pipeline.plugin_classloaders: false
[2022-09-01T20:22:45,202][DEBUG][logstash.runner          ] pipeline.separate_logs: false
[2022-09-01T20:22:45,202][DEBUG][logstash.runner          ] pipeline.ordered: "auto"
[2022-09-01T20:22:45,204][DEBUG][logstash.runner          ] pipeline.ecs_compatibility: "disabled"
[2022-09-01T20:22:45,205][DEBUG][logstash.runner          ] path.plugins: []
[2022-09-01T20:22:45,208][DEBUG][logstash.runner          ] *config.debug: true (default: false)
[2022-09-01T20:22:45,209][DEBUG][logstash.runner          ] *log.level: "debug" (default: "info")
[2022-09-01T20:22:45,209][DEBUG][logstash.runner          ] version: false
[2022-09-01T20:22:45,209][DEBUG][logstash.runner          ] help: false
[2022-09-01T20:22:45,209][DEBUG][logstash.runner          ] enable-local-plugin-development: false
[2022-09-01T20:22:45,210][DEBUG][logstash.runner          ] log.format: "plain"
[2022-09-01T20:22:45,210][DEBUG][logstash.runner          ] api.enabled: true
[2022-09-01T20:22:45,210][DEBUG][logstash.runner          ] *api.http.host: "127.0.0.1" (via deprecated `http.host`; default: "127.0.0.1")
[2022-09-01T20:22:45,211][DEBUG][logstash.runner          ] *http.host: "127.0.0.1"
[2022-09-01T20:22:45,211][DEBUG][logstash.runner          ] *api.http.port: 9600..9700 (via deprecated `http.port`; default: 9600..9700)
[2022-09-01T20:22:45,211][DEBUG][logstash.runner          ] *http.port: 9600..9700
[2022-09-01T20:22:45,211][DEBUG][logstash.runner          ] api.environment: "production"
[2022-09-01T20:22:45,212][DEBUG][logstash.runner          ] api.auth.type: "none"
[2022-09-01T20:22:45,212][DEBUG][logstash.runner          ] api.ssl.enabled: false
[2022-09-01T20:22:45,212][DEBUG][logstash.runner          ] queue.type: "memory"
[2022-09-01T20:22:45,213][DEBUG][logstash.runner          ] queue.drain: false
[2022-09-01T20:22:45,213][DEBUG][logstash.runner          ] queue.page_capacity: 67108864
[2022-09-01T20:22:45,216][DEBUG][logstash.runner          ] queue.max_bytes: 1073741824
[2022-09-01T20:22:45,217][DEBUG][logstash.runner          ] queue.max_events: 0
[2022-09-01T20:22:45,217][DEBUG][logstash.runner          ] queue.checkpoint.acks: 1024
[2022-09-01T20:22:45,217][DEBUG][logstash.runner          ] queue.checkpoint.writes: 1024
[2022-09-01T20:22:45,217][DEBUG][logstash.runner          ] queue.checkpoint.interval: 1000
[2022-09-01T20:22:45,218][DEBUG][logstash.runner          ] queue.checkpoint.retry: true
[2022-09-01T20:22:45,218][DEBUG][logstash.runner          ] dead_letter_queue.enable: false
[2022-09-01T20:22:45,224][DEBUG][logstash.runner          ] dead_letter_queue.max_bytes: 1073741824
[2022-09-01T20:22:45,224][DEBUG][logstash.runner          ] dead_letter_queue.flush_interval: 5000
[2022-09-01T20:22:45,225][DEBUG][logstash.runner          ] slowlog.threshold.warn: #<Java::OrgLogstashUtil::TimeValue:0x43b60ce1>
[2022-09-01T20:22:45,225][DEBUG][logstash.runner          ] slowlog.threshold.info: #<Java::OrgLogstashUtil::TimeValue:0x4e260e04>
[2022-09-01T20:22:45,225][DEBUG][logstash.runner          ] slowlog.threshold.debug: #<Java::OrgLogstashUtil::TimeValue:0x4f3b5c60>
[2022-09-01T20:22:45,225][DEBUG][logstash.runner          ] slowlog.threshold.trace: #<Java::OrgLogstashUtil::TimeValue:0x5d947961>
[2022-09-01T20:22:45,226][DEBUG][logstash.runner          ] keystore.classname: "org.logstash.secret.store.backend.JavaKeyStore"
[2022-09-01T20:22:45,226][DEBUG][logstash.runner          ] *keystore.file: "/etc/logstash/logstash.keystore" (default: "/usr/share/logstash/config/logstash.keystore")
[2022-09-01T20:22:45,226][DEBUG][logstash.runner          ] *path.queue: "/var/lib/logstash/queue" (default: "/usr/share/logstash/data/queue")
[2022-09-01T20:22:45,226][DEBUG][logstash.runner          ] *path.dead_letter_queue: "/var/lib/logstash/dead_letter_queue" (default: "/usr/share/logstash/data/dead_letter_queue")
[2022-09-01T20:22:45,227][DEBUG][logstash.runner          ] *path.settings: "/etc/logstash" (default: "/usr/share/logstash/config")
[2022-09-01T20:22:45,227][DEBUG][logstash.runner          ] *path.logs: "/var/log/logstash" (default: "/usr/share/logstash/logs")
[2022-09-01T20:22:45,227][DEBUG][logstash.runner          ] xpack.monitoring.enabled: false
[2022-09-01T20:22:45,227][DEBUG][logstash.runner          ] xpack.monitoring.elasticsearch.hosts: ["http://localhost:9200"]
[2022-09-01T20:22:45,228][DEBUG][logstash.runner          ] xpack.monitoring.collection.interval: #<Java::OrgLogstashUtil::TimeValue:0x7b16d337>
[2022-09-01T20:22:45,228][DEBUG][logstash.runner          ] xpack.monitoring.collection.timeout_interval: #<Java::OrgLogstashUtil::TimeValue:0x4155a965>
[2022-09-01T20:22:45,228][DEBUG][logstash.runner          ] xpack.monitoring.elasticsearch.username: "logstash_system"
[2022-09-01T20:22:45,228][DEBUG][logstash.runner          ] xpack.monitoring.elasticsearch.ssl.verification_mode: "certificate"
[2022-09-01T20:22:45,229][DEBUG][logstash.runner          ] xpack.monitoring.elasticsearch.sniffing: false
[2022-09-01T20:22:45,229][DEBUG][logstash.runner          ] xpack.monitoring.collection.pipeline.details.enabled: true
[2022-09-01T20:22:45,229][DEBUG][logstash.runner          ] xpack.monitoring.collection.config.enabled: true
[2022-09-01T20:22:45,229][DEBUG][logstash.runner          ] monitoring.enabled: false
[2022-09-01T20:22:45,230][DEBUG][logstash.runner          ] monitoring.elasticsearch.hosts: ["http://localhost:9200"]
[2022-09-01T20:22:45,230][DEBUG][logstash.runner          ] monitoring.collection.interval: #<Java::OrgLogstashUtil::TimeValue:0xb52d046>
[2022-09-01T20:22:45,231][DEBUG][logstash.runner          ] monitoring.collection.timeout_interval: #<Java::OrgLogstashUtil::TimeValue:0x65bc66bb>
[2022-09-01T20:22:45,231][DEBUG][logstash.runner          ] monitoring.elasticsearch.username: "logstash_system"
[2022-09-01T20:22:45,231][DEBUG][logstash.runner          ] monitoring.elasticsearch.ssl.verification_mode: "certificate"
[2022-09-01T20:22:45,232][DEBUG][logstash.runner          ] monitoring.elasticsearch.sniffing: false
[2022-09-01T20:22:45,233][DEBUG][logstash.runner          ] monitoring.collection.pipeline.details.enabled: true
[2022-09-01T20:22:45,233][DEBUG][logstash.runner          ] monitoring.collection.config.enabled: true
[2022-09-01T20:22:45,233][DEBUG][logstash.runner          ] node.uuid: ""
[2022-09-01T20:22:45,234][DEBUG][logstash.runner          ] xpack.management.enabled: false
[2022-09-01T20:22:45,234][DEBUG][logstash.runner          ] xpack.management.logstash.poll_interval: #<Java::OrgLogstashUtil::TimeValue:0x202b765f>
[2022-09-01T20:22:45,234][DEBUG][logstash.runner          ] xpack.management.pipeline.id: ["main"]
[2022-09-01T20:22:45,234][DEBUG][logstash.runner          ] xpack.management.elasticsearch.username: "logstash_system"
[2022-09-01T20:22:45,235][DEBUG][logstash.runner          ] xpack.management.elasticsearch.hosts: ["https://localhost:9200"]
[2022-09-01T20:22:45,235][DEBUG][logstash.runner          ] xpack.management.elasticsearch.ssl.verification_mode: "certificate"
[2022-09-01T20:22:45,236][DEBUG][logstash.runner          ] xpack.management.elasticsearch.sniffing: false
[2022-09-01T20:22:45,236][DEBUG][logstash.runner          ] --------------- Logstash Settings -------------------
[2022-09-01T20:22:45,279][DEBUG][logstash.config.source.multilocal] Reading pipeline configurations from YAML {:location=>"/etc/logstash/pipelines.yml"}
[2022-09-01T20:22:45,313][FATAL][org.logstash.Logstash    ] Logstash stopped processing because of an error: (SystemExit) exit
org.jruby.exceptions.SystemExit: (SystemExit) exit
	at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:747) ~[jruby-complete-9.2.20.1.jar:?]
	at org.jruby.RubyKernel.exit(org/jruby/RubyKernel.java:710) ~[jruby-complete-9.2.20.1.jar:?]

Our installation is not new, btw. it's been running, in production, for over a year now.

steevhise · September 1, 2022, 11:18pm

so, after 2 days of struggling with this we finally noticed there's some EXTRA log messages that get written to /var/log/daemon.log that complain specifically about the pipelines.yml file.

i had left a single "-" off the beginning of the first line, which i must have changed earlier in attempts to randomly fix logstash.yml...


 - pipeline.id: main
  path.config: "/etc/logstash/conf.d/*.conf"

it's a bit unusual to write the useful explanations of what's wrong to daemon.log and NOT to the application's main log.. WTF?

Badger · September 2, 2022, 12:30am

You are right. The message "ERROR: Failed to read pipelines yaml file. Location: /etc/logstash/pipelines.yml" is written to stderr, not logged using log4j. The module that logs it is initialized very early in the startup process.

The issue for this is 7997, which has been open for five years. An attempt to fix it was made, but initializing log4j that early broke things so it was backed out.

steevhise · September 2, 2022, 4:06pm

So, to sum up, for posterity: if you have a problem with logstash and the regular log isnt helping, be sure to look in daemon.log! And heck, any other logfiles you can think of... who knows?

system · September 30, 2022, 4:07pm

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