Logstash ES plugin occasionally can't reach server


(Rsteckler) #1

I'm using Logsene as a hosted ELK provider. I log directly to logsene from Node.js using winston-logsene and I tail some logs to them via Logstash.

The node.js integration works perfectly. The problem is that the logstash integration drops maybe 5% of log lines.

Here's what I know:

  1. If I add a file output next to the ES output, all of the messages show up in the file correctly.

  2. The ES plugin puts the following in the logstash.log:

    {
    :timestamp=>"2015-11-06T15:56:56.792000+0000", 
    :message=>"Attempted to send a bulk request to Elasticsearch configured at '[\"http://logsene-receiver.sematext.com:80/\"]', but an error occurred and it failed! Are you sure you can reach elasticsearch from this machine using the configuration provided?", 
    :client_config=>{:hosts=>["http://logsene-receiver.sematext.com:80/"], 
    :ssl=>nil, 
    :transport_options=>{:socket_timeout=>0, 
    :request_timeout=>0, 
    :proxy=>nil, 
    :ssl=>{}}, 
    :transport_class=>Elasticsearch::Transport::Transport::HTTP::Manticore, 
    :logger=>nil,
    :tracer=>nil, 
    :reload_connections=>false, 
    :retry_on_failure=>false, 
    :reload_on_failure=>false, 
    :randomize_hosts=>false}, 
    :error_message=>"logsene-receiver.sematext.com:80 failed to respond", 
    :error_class=>"Manticore::ClientProtocolException", 
    :backtrace=>[
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.4.4-java/lib/manticore/response.rb:35:in `initialize'", 
    	"org/jruby/RubyProc.java:271:in `call'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.4.4-java/lib/manticore/response.rb:70:in `call'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.4.4-java/lib/manticore/response.rb:245:in `call_once'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/manticore-0.4.4-java/lib/manticore/response.rb:148:in `code'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/elasticsearch-transport-1.0.14/lib/elasticsearch/transport/transport/http/manticore.rb:71:in `perform_request'", 
    	"org/jruby/RubyProc.java:271:in `call'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/elasticsearch-transport-1.0.14/lib/elasticsearch/transport/transport/base.rb:191:in `perform_request'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/elasticsearch-transport-1.0.14/lib/elasticsearch/transport/transport/http/manticore.rb:54:in `perform_request'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/elasticsearch-transport-1.0.14/lib/elasticsearch/transport/client.rb:119:in `perform_request'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/elasticsearch-api-1.0.14/lib/elasticsearch/api/actions/bulk.rb:87:in `bulk'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-2.1.2-java/lib/logstash/outputs/elasticsearch/http_client.rb:56:in `bulk'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-2.1.2-java/lib/logstash/outputs/elasticsearch.rb:353:in `submit'", 
    	"org/jruby/ext/thread/Mutex.java:149:in `synchronize'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-2.1.2-java/lib/logstash/outputs/elasticsearch.rb:350:in `submit'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-2.1.2-java/lib/logstash/outputs/elasticsearch.rb:382:in `flush'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/buffer.rb:219:in `buffer_flush'",
    	"org/jruby/RubyHash.java:1342:in `each'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/buffer.rb:216:in `buffer_flush'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/buffer.rb:193:in `buffer_flush'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.22/lib/stud/buffer.rb:159:in `buffer_receive'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-2.1.2-java/lib/logstash/outputs/elasticsearch.rb:343:in `receive'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.0.0-java/lib/logstash/outputs/base.rb:80:in `handle'", 
    	"(eval):59:in `output_func'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.0.0-java/lib/logstash/pipeline.rb:252:in `outputworker'", 
    	"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.0.0-java/lib/logstash/pipeline.rb:169:in `start_outputs'"
    ], 
    :level=>:error
    

    }

  3. If I try to resend the failed message (by pulling it out of the file output, and curling it over to logsene), that manual retry works perfectly and the log line shows up correctly in Kibana.

  4. I've never seen a failure by curling line logs manually over to logsene. I've only ever seen the failure when the ES plugin tries to send the messages.

  5. Increasing the ES plugin max_retries and retry_max_interval doesn't seem to impact the failure rate, interestingly.

This all leads me to believe it's not a networking problem, despite the error message. It's not a data issue because a retry works. I'm not sure where to go from here.

Thanks for any advice on troubleshooting further.

Ryan


(Magnus B├Ąck) #2

Does Logstash recover automatically after a while, i.e. could it be a temporary glitch? A connection problem shouldn't cause messages to get dropped, it should stall the pipeline.

You're not the only one reporting this error since Logstash 2.0 was released.


(Rsteckler) #3

Logstash continues to run perfectly. It just drops one or two messages,
and everything else works. It's only "down" for a fraction of a second.
I've also don't think it's retrying the message. When I append a line to
the log file, there exception shows up immediately. I would expect it to
wait at least 15 second before failing in network communications because of
the 3 retries at a 5 second interval.

Sounds like it may not just be me. If you need any debugging help, please
let me know.

Thanks,
Ryan


(system) #4