Logstash.filters.elasticsearch "Read timed out"

Elastic Stack Logstash
1

Hi,

I'm using Logstash 7.17 against Elasticsearch 7.16 cluster.
The filter is working for about 9/10 events, but sometimes it fails with this error:

"Failed to query Elasticsearch for previous event", "Read timed out"
Full log:

[2022-02-17T16:30:47,078][DEBUG][logstash.filters.elasticsearch][vault] Querying elasticsearch for lookup {:params=>{:index=>"vault-2022.02.17", :q=>"context.vaultSecretKey:2ff1f7e8-b6c1-49aa AND auth.claims.client_id:client.inventory AND msg:Retrieve credentials", :size=>1, :sort=>"@timestamp:desc"}}

[2022-02-17T16:30:57,177][WARN ][logstash.filters.elasticsearch][vault] Failed to query elasticsearch for previous event {:index=>"vault-%{+YYYY.MM.dd}", :query=>"context.vaultSecretKey:2ff1f7e8-b6c1-49aa AND auth.claims.client_id:client.inventory AND msg:Retrieve credentials", :event=>{"program"=>"@cee", "lvl"=>"NOTICE", "uid"=>417440, "tracking"=>{"cid"=>"CID-6279a2a9b1b788ebe49b257935879d81", "app"=>"cm_external", "rid"=>"RID-35a863b27b926d037dae7071504688fe", "ip"=>"192.168.3.4"}, "@timestamp"=>2022-02-17T15:30:43.977Z, "logsource"=>"web-cm-extern", "auth"=>{"claims"=>{"client_id"=>"client.inventory", "name"=>"Gregory", "amr"=>"external", "ImpersonatedByUserId"=>nil, "ImpersonatedBy"=>nil, "sub"=>"417440"}, "type"=>"Bearer token"}, "context"=>{"vaultSecretKey"=>"2ff1f7e8-b6c1-49aa"}, "host"=>"secsyslog", "@version"=>"1", "path"=>"/var/log/HOSTS/web-cm-extern/2022/02/17/local1.log", "timestamp"=>"Feb 17 16:30:43", "ts"=>"2022-02-17T16:30:42.3739826+01:00", "msg"=>"read secret"}, :error=>"Read timed out", :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/manticore-0.8.0-java/lib/manticore/response.rb:36:in `block in initialize'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/manticore-0.8.0-java/lib/manticore/response.rb:79:in `call'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/manticore-0.8.0-java/lib/manticore/response.rb:274:in `call_once'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/manticore-0.8.0-java/lib/manticore/response.rb:158:in `code'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-transport-7.16.3/lib/elasticsearch/transport/transport/http/manticore.rb:106:in `block in perform_request'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-transport-7.16.3/lib/elasticsearch/transport/transport/base.rb:289:in `perform_request'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-transport-7.16.3/lib/elasticsearch/transport/transport/http/manticore.rb:85:in `perform_request'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-transport-7.16.3/lib/elasticsearch/transport/client.rb:197:in `perform_request'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-7.16.3/lib/elasticsearch.rb:41:in `method_missing'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/elasticsearch-api-7.16.3/lib/elasticsearch/api/actions/search.rb:104:in `search'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-elasticsearch-3.11.0/lib/logstash/filters/elasticsearch/client.rb:39:in `search'", "/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-elasticsearch-3.11.0/lib/logstash/filters/elasticsearch.rb:133:in `filter'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:159:in `do_filter'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:178:in `block in multi_filter'", "org/jruby/RubyArray.java:1821:in `each'", "/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:175:in `multi_filter'", "org/logstash/config/ir/compiler/AbstractFilterDelegatorExt.java:134:in `multi_filter'", "/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:299:in `block in start_workers'"]}

The filter:

  if [msg] == "read secret" and [auth][claims][client_id] == "client.inventory" {
    elasticsearch {
      hosts => "https://masked:9200"
      ca_file => "/etc/logstash/elastic-ca.pem"
      index => "vault-%{+YYYY.MM.dd}"
      user => "masked"
      password => "masked"
      query => "context.vaultSecretKey:%{[context][vaultSecretKey]} AND auth.claims.client_id:client.inventory AND msg:Retrieve credentials"
      fields => {
        "[context][tag]" => "[context][tag]"
        "[context][login]" => "[context][login]"
        "[context][name]" => "[context][name]"
      }
    }
  }

This filter is triggered about 300 times/24h, the cluster is not heavily used and I don't see any reason why it would take over 10s for this query to return a result. Takes a couple of millisec normally, the index size is only 30-40MB daily.

Can I get more information why it returns a "Read timed out", or is there a way to set a retry when such an error occurs?

2

Though I have no idea about the reason and how to deal with it. Some hints could be found in elasticsearch log or Slow log.

It could be possible by duplicate the filter with if clause on ["_elasticsearch_lookup_failure"] tag.

3

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