ELK deploy no longer pulling in data. Logstash logs error, stops immediately

Elastic Stack Logstash
,
1

Hi,

I'm trying to run a log aggregation system based on ELK called LME [1].

I've pulled most of the text of this post out of the GitHub issue I created [2]. I was hoping maybe the community here would be able to e.g. tell me if the error here is part of the issue I'm seeing, or if e.g. that error is a total red herring, and there's something else to check.

I can confirm the server running winlogbeat should be able to connect to the server running LogStash, there's a firewall rule to allow it, but I'm not sure how to do any further debugging/diganosis

There's no new data in Kibana since 13/03/2020. I don't have any errors from Logstash about "shards", I've seen those being mentioned as a cause for a previously working LME/ELK stack to no longer work.

The Logstash container starts, runs for a few seconds, reports Logstash successfully started and then a few hundred ms later reports that it stops.

Running netcat in a loop on the same server locally does get a tcp connection to the beats port for about 5-10 seconds.

while true; do nc  -z localhost 5044 &&  echo $(date) && echo pass; done;

Each time, it errors the following:
[EICAR@my-elk-server logstash]$ docker service logs lme_logstash --tail 20 --timestamps

2020-04-08T19:47:20.392839754Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | 2020/04/08 19:47:20 Setting 'xpack.monitoring.enabled' from environment.
2020-04-08T19:47:20.418060522Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
2020-04-08T19:47:22.161135090Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | WARNING: An illegal reflective access operation has occurred
2020-04-08T19:47:22.161162744Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | WARNING: Illegal reflective access by com.headius.backport9.modules.Modules (file:/usr/share/logstash/logstash-core/lib/jars/jruby-complete-9.2.8.0.jar) to field java.io.FileDescriptor.fd
2020-04-08T19:47:22.161166070Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | WARNING: Please consider reporting this to the maintainers of com.headius.backport9.modules.Modules
2020-04-08T19:47:22.161168331Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
2020-04-08T19:47:22.170102662Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | WARNING: All illegal access operations will be denied in a future release
2020-04-08T19:47:33.093181531Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | Thread.exclusive is deprecated, use Thread::Mutex
2020-04-08T19:47:35.484161627Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | Sending Logstash logs to /usr/share/logstash/logs which is now configured via log4j2.properties
2020-04-08T19:47:35.750156469Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:35,746][INFO ][logstash.setting.writabledirectory] Creating directory {:setting=>"path.queue", :path=>"/usr/share/logstash/data/queue"}
2020-04-08T19:47:35.769146614Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:35,767][INFO ][logstash.setting.writabledirectory] Creating directory {:setting=>"path.dead_letter_queue", :path=>"/usr/share/logstash/data/dead_letter_queue"}
2020-04-08T19:47:36.220159005Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:36,219][INFO ][logstash.runner] Starting Logstash {"logstash.version"=>"7.4.0"}
2020-04-08T19:47:36.261156843Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:36,258][INFO ][logstash.agent] No persistent UUID file found. Generating new UUID {:uuid=>"8f772019-c2b3-4907-aae0-d9bb20bd873a", :path=>"/usr/share/logstash/data/uuid"}
2020-04-08T19:47:38.161185419Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:38,156][ERROR][logstash.agent] 

Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:                     main, :exception=>"LogStash::ConfigurationError", :message=>"Expected one of #, {, } at line 80, column 19 (byte 2263) after output 
{\n        if \"cloned_logs\" not in [tags] 
{\n  elasticsearch {\n    hosts => \"https://elasticsearch:9200\"\n    
index => \"winlogbeat-%{+dd.MM.YYYY}\"\n    
user => logstash_writer\n    
password => \"\"", 

:backtrace=>["/usr/share/logstash/logstash-core/lib/logstash/compiler.rb:41:in `compile_imperative'", 
"/usr/share/logstash/logstash-core/lib/logstash/compiler.rb:49:in `compile_graph'", 
"/usr/share/logstash/logstash-core/lib/logstash/compiler.rb:11:in `block in compile_sources'", 
"org/jruby/RubyArray.java:2584:in `map'", 
"/usr/share/logstash/logstash-core/lib/logstash/compiler.rb:10:in `compile_sources'", 
"org/logstash/execution/AbstractPipelineExt.java:153:in `initialize'", 
"org/logstash/execution/JavaBasePipelineExt.java:47:in `initialize'", 
"/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:26:in `initialize'", 
"/usr/share/logstash/logstash-core/lib/logstash/pipeline_action/create.rb:36:in `execute'", 
"/usr/share/logstash/logstash-core/lib/logstash/agent.rb:326:in `block in converge_state'"]}

2020-04-08T19:47:38.346155190Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:38,340][INFO ][logstash.agent] Successfully started Logstash API endpoint {:port=>9600}
2020-04-08T19:47:43.386197721Z lme_logstash.1.2yxa5ksufylp@my-elk-server    | [2020-04-08T19:47:43,385][INFO ][logstash.runner] Logstash shut down.

Logstash seems to stop almost as soon as it starts. Timings like:

~]$  docker service logs lme_logstash --tail 5 --timestamps 2>&1 | grep -P '(started|shut)'
2020-04-10T13:30:02.836146295Z lme_logstash.1.0yc7t31fme7x@my-elk-server    | [2020-04-10T13:30:02,832][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
2020-04-10T13:30:07.892725497Z lme_logstash.1.0yc7t31fme7x@my-elk-server    | [2020-04-10T13:30:07,891][INFO ][logstash.runner          ] Logstash shut down.
2020-04-10T13:31:34.685176801Z lme_logstash.1.3e4ebvsz0ale@my-elk-server    | [2020-04-10T13:31:34,683][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
2020-04-10T13:31:39.742369997Z lme_logstash.1.3e4ebvsz0ale@my-elk-server    | [2020-04-10T13:31:39,741][INFO ][logstash.runner          ] Logstash shut down.
2020-04-10T13:31:06.866156599Z lme_logstash.1.ti90qy6z6nnp@my-elk-server    | [2020-04-10T13:31:06,863][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
2020-04-10T13:31:11.915018325Z lme_logstash.1.ti90qy6z6nnp@my-elk-server    | [2020-04-10T13:31:11,913][INFO ][logstash.runner          ] Logstash shut down.
2020-04-10T13:30:35.301920517Z lme_logstash.1.iqf6q4wb7dhb@my-elk-server    | [2020-04-10T13:30:35,299][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
2020-04-10T13:30:40.185109401Z lme_logstash.1.iqf6q4wb7dhb@my-elk-server    | [2020-04-10T13:30:40,181][INFO ][logstash.runner          ] Logstash shut down.

To Reproduce
Steps to reproduce the behavior:

  1. Wait.
  2. run docker service logs lme_logstash --tail 20 --timestamps
  3. See errors and a Logstash container that just shuts down.

Expected behavior
Data to continue to be ingested into Kibana. (Not sure if the errors from Logstash container are a red herring, and the container is shutting down for good/different reasons.

Thanks for your time reading this.

Any pointers as to how to debug this very gratefully received.

[1] https://www.ncsc.gov.uk/blog-post/logging-made-easy
[2] Some more details over on GitHub @ https://github.com/ukncsc/lme/issues/61

2

There is a problem with your logstash configuration file. What does it look like?

3

Hi Badger.

I'm sorry to say, I'm not entirely sure where to find it. I coped the files out of the docker container's ~ as follows:

[user@server logstash]$ ls
bin config CONTRIBUTORS data Gemfile Gemfile.lock lib LICENSE.txt logstash-core logstash-core-plugin-api modules NOTICE.TXT pipeline tools vendor x-pack

Looking for config files:

[user@server logstash]$ find -name "*logstash*conf*"
./config/logstash-sample.conf
./logstash-core/lib/logstash/modules/logstash_config.rb
./pipeline/logstash.conf
./pipeline/logstash_custom.conf

If it's in the logstash.conf in pipeline, then that certainly doesn't look right:

[user@server logstash]$ cat pipeline/logstash.conf
input {
  beats {
    port => 5044
  }
}

output {
  stdout {
    codec => rubydebug
  }
}

To relevant looking files:

[user@server logstash]$ cat config/logstash.yml
http.host: 0.0.0.0
xpack.monitoring.elasticsearch.hosts:
- http://elasticsearch:9200
xpack.monitoring.enabled: false
[user@server logstash]$ cat config/pipelines.yml
# This file is where you define your pipelines. You can define multiple.
# For more information on multiple pipelines, see the documentation:
#   https://www.elastic.co/guide/en/logstash/current/multiple-pipelines.html

- pipeline.id: main
  path.config: "/usr/share/logstash/pipeline"
[user@server logstash]$
4

What are the files in that directory and what are their contents?

5 
[khgillen@elk-hic-ap1 logstash]$ ls pipeline/
logstash.conf  logstash_custom.conf
[khgillen@elk-hic-ap1 logstash]$ cat pipeline/logstash.conf
input {
  beats {
    port => 5044
  }
}

output {
  stdout {
    codec => rubydebug
  }
}

[khgillen@elk-hic-ap1 logstash]$ cat pipeline/logstash_custom.conf
[khgillen@elk-hic-ap1 logstash]$
6 
[user@server logstash]$ ls pipeline/
logstash.conf  logstash_custom.conf
[user@server logstash]$ cat pipeline/logstash.conf
input {
  beats {
    port => 5044
  }
}

output {
  stdout {
    codec => rubydebug
  }
}

[user@server logstash]$ cat pipeline/logstash_custom.conf
[user@server logstash]$

and clearly -> "rubydebug" doesn't sound right to me - the logstash.conf shipped with "LME" sends that data into Elasticsearch. cf https://github.com/ukncsc/lme/blob/master/Chapter%203%20Files/logstash.conf

If that's the place that's supposed to have this config, then clearly something's been re-run and it's not been run correctly.

7

I cannot see how that configuration could result in that error message.

8

Thanks for your time, Badger.

So it turned out that there were double quotes in the "logstash_writer" password in our version of logstash.conf on the server we were running the docker-compose from. cf https://github.com/ukncsc/lme/blob/master/Chapter%203%20Files/logstash.conf#L80

For some reason, this file didn't appear to actually be copied into the logstash container, despite there being errors from the container, or the docker runtime, referencing those lines in the file. It was very odd. :man_shrugging:

Obviously the container had the file somewhere as the error message was pointing at it, but I tried grepping all the files I pulled from the container for keywords in that error message and couldn't see any.

Appreciate you taking me through my first experience of Logstash config!

9

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