Retryer: send unwait signal to consumer. Logstash overload?

Elastic Stack Logstash
1

Hi everybody,
I have a 3 cluster node used to collect logs from several services (received using Filebeat clients).
On those nodes, I have installed also Logstash (for each node) with the same configuration and pipelines.
every Logstash instance has:

  • 6 pipelines not really heavy or complicated (there is just grok plugin).
  • 4 GB for JVM

One of these pipelines is receiving maybe really too many messages from Filebeat. I can say this since I saw in the Filebeat's logs this message:

retryer: send unwait signal to consumer

after it, Filebeat client will not send any other message. To unlock it I have to restart it but after the first rush, it stuck again.

So, I decided to isolate a Logstash instance, enabling only one pipeline on it. After that, Filebeat seems able to continue to send a message.

I know that error above means that Filebeat did not receive an ACK from Logstash, probably due to overload so is there anything that I can do?

2

Can you enable debug logs in filebeat and see if that adds any more informative messages?

3

I didn't see anything special unfortunately

4

@Badger
Hi everyone please let me join this convo since I have similiar problem.
Here is what i've tried:

filebeat -e -d "*"

2020-10-13T15:30:40.620+0700    DEBUG   [harvester]     log/log.go:107  End of file reached: directory; Backoff now.
2020-10-13T15:30:41.601+0700    INFO    [publisher_pipeline_output]     pipeline/output.go:143    Connecting to backoff(async(tcp://beat:5045))
2020-10-13T15:30:41.601+0700    DEBUG   [logstash]      logstash/async.go:120   connect
2020-10-13T15:30:41.601+0700    INFO    [publisher]     pipeline/retry.go:219   retryer: send unwait signal to consumer
2020-10-13T15:30:41.601+0700    INFO    [publisher]     pipeline/retry.go:223     done
2020-10-13T15:30:41.611+0700    DEBUG   [harvester]     log/log.go:107  End of file reached: directory; Backoff now.
2020-10-13T15:30:41.620+0700    DEBUG   [harvester]     log/log.go:107  End of file reached: directory; Backoff now.
2020-10-13T15:30:43.130+0700    ERROR   [publisher_pipeline_output]     pipeline/output.go:154    Failed to connect to backoff(async(tcp://beat:5045)): dial tcp beat:5045: connect: no route to host

/usr/share/logstash/bin/logstash -f logstash.conf

WARNING: Could not find logstash.yml which is typically located in $LS_HOME/config or /etc/logstash. You can specify the path using --path.settings. Continuing using the defaults
Could not find log4j2 configuration at path /usr/share/logstash/config/log4j2.properties. Using default config which logs errors to the console
[WARN ] 2020-10-13 15:44:45.460 [LogStash::Runner] multilocal - Ignoring the 'pipelines.yml' file because modules or command line options are specified
[INFO ] 2020-10-13 15:44:45.480 [LogStash::Runner] runner - Starting Logstash {"logstash.version"=>"7.6.1"}
[INFO ] 2020-10-13 15:44:49.553 [Converge PipelineAction::Create<main>] Reflections - Reflections took 156 ms to scan 1 urls, producing 20 keys and 40 values
[INFO ] 2020-10-13 15:44:55.229 [[main]-pipeline-manager] elasticsearch - Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>[http://127.0.0.1:9200/]}}
[WARN ] 2020-10-13 15:44:55.870 [[main]-pipeline-manager] elasticsearch - Restored connection to ES instance {:url=>"http://127.0.0.1:9200/"}
[INFO ] 2020-10-13 15:44:56.458 [[main]-pipeline-manager] elasticsearch - ES Output version determined {:es_version=>7}
[WARN ] 2020-10-13 15:44:56.466 [[main]-pipeline-manager] elasticsearch - Detected a 6.x and above cluster: the `type` event field won't be used to determine the document _type {:es_version=>7}
[INFO ] 2020-10-13 15:44:56.694 [[main]-pipeline-manager] elasticsearch - New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["//127.0.0.1:9200"]}
[INFO ] 2020-10-13 15:44:56.747 [[main]-pipeline-manager] elasticsearch - Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>[http://127.0.0.1:9200/]}}
[WARN ] 2020-10-13 15:44:56.761 [[main]-pipeline-manager] elasticsearch - Restored connection to ES instance {:url=>"http://127.0.0.1:9200/"}
[INFO ] 2020-10-13 15:44:56.770 [[main]-pipeline-manager] elasticsearch - ES Output version determined {:es_version=>7}
[WARN ] 2020-10-13 15:44:56.770 [[main]-pipeline-manager] elasticsearch - Detected a 6.x and above cluster: the `type` event field won't be used to determine the document _type {:es_version=>7}
[INFO ] 2020-10-13 15:44:56.893 [[main]-pipeline-manager] elasticsearch - New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["//127.0.0.1:9200"]}
[INFO ] 2020-10-13 15:44:56.916 [Ruby-0-Thread-8: :1] elasticsearch - Using default mapping template
[INFO ] 2020-10-13 15:44:56.954 [Ruby-0-Thread-6: :1] elasticsearch - Using default mapping template
[INFO ] 2020-10-13 15:44:57.240 [Ruby-0-Thread-6: :1] elasticsearch - Attempting to install template {:manage_template=>{"index_patterns"=>"logstash-*", "version"=>60001, "settings"=>{"index.refresh_interval"=>"5s", "number_of_shards"=>1}, "mappings"=>{"dynamic_templates"=>[{"message_field"=>{"path_match"=>"message", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false}}}, {"string_fields"=>{"match"=>"*", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false, "fields"=>{"keyword"=>{"type"=>"keyword", "ignore_above"=>256}}}}}], "properties"=>{"@timestamp"=>{"type"=>"date"}, "@version"=>{"type"=>"keyword"}, "geoip"=>{"dynamic"=>true, "properties"=>{"ip"=>{"type"=>"ip"}, "location"=>{"type"=>"geo_point"}, "latitude"=>{"type"=>"half_float"}, "longitude"=>{"type"=>"half_float"}}}}}}}
[INFO ] 2020-10-13 15:44:57.249 [Ruby-0-Thread-8: :1] elasticsearch - Attempting to install template {:manage_template=>{"index_patterns"=>"logstash-*", "version"=>60001, "settings"=>{"index.refresh_interval"=>"5s", "number_of_shards"=>1}, "mappings"=>{"dynamic_templates"=>[{"message_field"=>{"path_match"=>"message", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false}}}, {"string_fields"=>{"match"=>"*", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false, "fields"=>{"keyword"=>{"type"=>"keyword", "ignore_above"=>256}}}}}], "properties"=>{"@timestamp"=>{"type"=>"date"}, "@version"=>{"type"=>"keyword"}, "geoip"=>{"dynamic"=>true, "properties"=>{"ip"=>{"type"=>"ip"}, "location"=>{"type"=>"geo_point"}, "latitude"=>{"type"=>"half_float"}, "longitude"=>{"type"=>"half_float"}}}}}}}
[WARN ] 2020-10-13 15:44:57.951 [[main]-pipeline-manager] LazyDelegatingGauge - A gauge metric of an unknown type (org.jruby.specialized.RubyArrayOneObject) has been create for key: cluster_uuids. This may result in invalid serialization.  It is recommended to log an issue to the responsible developer/development team.
[INFO ] 2020-10-13 15:44:57.965 [[main]-pipeline-manager] javapipeline - Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50, "pipeline.max_inflight"=>500, "pipeline.sources"=>["/etc/logstash/vpn/vpn_wfh.conf"], :thread=>"#<Thread:0x766742a2 run>"}
[INFO ] 2020-10-13 15:44:59.979 [[main]-pipeline-manager] beats - Beats inputs: Starting input listener {:address=>"0.0.0.0:5045"}
[INFO ] 2020-10-13 15:45:00.033 [[main]-pipeline-manager] javapipeline - Pipeline started {"pipeline.id"=>"main"}
[INFO ] 2020-10-13 15:45:00.365 [[main]<beats] Server - Starting server on port: 5045
[INFO ] 2020-10-13 15:45:00.385 [Agent thread] agent - Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>[]}
[INFO ] 2020-10-13 15:45:01.329 [Api Webserver] agent - Successfully started Logstash API endpoint {:port=>9601}

each of machine can ping each other. Both communicate it 5045. But logstash never got the message. I would like to know more about this.

5

regarding my issue, I fixed it temporarily increasing logstash pipeline's workers.

6

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