logstash-output-redis: Failed to flush outgoing items / Failed to send backlog of events to Redis (Logstash 1.5.6)
- Dominant language
- Java
- Stars
- 14.9k
- Forks
- 3.5k
- Avg merge
- 19h 14m
- Merged PRs (30d)
- 63
Description
Hello,
We are running Logstash 1.5.6, and are storing certain intermediate values in Redis.
Since we rebooted the machine, one of the jobs, which stores processed values in Redis, starts to fail after roughly two minutes of operation.
According to redis-server's log, this is due to a protocol error. I'm using the most recent version of Redis available. (3.0.7).
Any idea what might be the cause of this?
I've already asked on the issue tracker of the gem you're using to connect to Redis, and he meant that this is due to a malformed string. Perhaps some data which is not escaped properly?
(https://github.com/redis/redis-rb/issues/589)
```
Logstash output, verbosity = debug:
{:timestamp=>"2016-02-29T13:56:47.474000+0000", :message=>"Failed to flush outgoing items", :outgoing_count=>1, :exception=>"Redis::ConnectionError", :backtrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:244:in `io'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:237:in `io'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:256:in `write'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:215:in `process'", "org/jruby/RubyArray.java:1613:in `each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:209:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:354:in `ensure_connected'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:208:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:293:in `logging'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:207:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:113:in `call'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:1030:in `rpush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:57:in `synchronize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/monitor.rb:211:in `mon_synchronize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/monitor.rb:210:in `mon_synchronize'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:57:in `synchronize'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:1029:in `rpush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-redis-1.0.0/lib/logstash/outputs/redis.rb:200:in `flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:221:in `buffer_flush'", "org/jruby/RubyHash.java:1342:in `each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:216:in `buffer_flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:193:in `buffer_flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:159:in `buffer_receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-redis-1.0.0/lib/logstash/outputs/redis.rb:147:in `receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/outputs/base.rb:88:in `handle'", "(eval):285:in `output_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/pipeline.rb:244:in `outputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/pipeline.rb:166:in `start_outputs'"], :level=>:warn, :file=>"stud/buffer.rb", :line=>"231", :method=>"buffer_flush"}
{:timestamp=>"2016-02-29T13:56:47.475000+0000", :message=>"Failed to send backlog of events to Redis", :identity=>"default", :exception=>#, :backtrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:244:in `io'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:237:in `io'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:256:in `write'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:215:in `process'", "org/jruby/RubyArray.java:1613:in `each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:209:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:354:in `ensure_connected'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:208:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:293:in `logging'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:207:in `process'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis/client.rb:113:in `call'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:1030:in `rpush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:57:in `synchronize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/monitor.rb:211:in `mon_synchronize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/monitor.rb:210:in `mon_synchronize'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:57:in `synchronize'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/redis-3.2.2/lib/redis.rb:1029:in `rpush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-redis-1.0.0/lib/logstash/outputs/redis.rb:200:in `flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:221:in `buffer_flush'", "org/jruby/RubyHash.java:1342:in `each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:216:in `buffer_flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:193:in `buffer_flush'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/stud-0.0.21/lib/stud/buffer.rb:159:in `buffer_receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-redis-1.0.0/lib/logstash/outputs/redis.rb:147:in `receive'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/outputs/base.rb:88:in `handle'", "(eval):285:in `output_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/pipeline.rb:244:in `outputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.6-java/lib/logstash/pipeline.rb:166:in `start_outputs'"], :level=>:warn, :file=>"logstash/outputs/redis.rb", :line=>"204", :method=>"on_flush_error"}
{:timestamp=>"2016-02-29T13:56:47.475000+0000", :level=>:debug, :host=>"127.0.0.1", :port=>6379, :timeout=>5, :db=>0, :file=>"logstash/outputs/redis.rb", :line=>"237", :method=>"connect"}
{:timestamp=>"2016-02-29T13:56:47.720000+0000", :message=>"Lumberjack input: the pipeline is blocked, temporary refusing new connection.", :level=>:warn, :file=>"logstash/inputs/lumberjack.rb", :line=>"88", :method=>"run"}
```
```
Redis server debugging output:
5791:M 29 Feb 12:42:08.898 - Accepted 127.0.0.1:57426
5791:M 29 Feb 12:42:09.517 - Protocol error from client: id=654 addr=127.0.0.1:57426 fd=5 name= age=1 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=16384 qbuf-free=16384 obl=42 oll=0 omem=0 events=rw cmd=NULL
5791:M 29 Feb 12:42:09.538 - DB 0: 2 keys (0 volatile) in 4 slots HT.
5791:M 29 Feb 12:42:09.538 - 0 clients connected (0 slaves), 2075778960 bytes in use
5791:M 29 Feb 12:42:10.643 - Accepted 127.0.0.1:57427
5791:M 29 Feb 12:42:10.963 - Protocol error from client: id=655 addr=127.0.0.1:57427 fd=5 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=16384 qbuf-free=16384 obl=42 oll=0 omem=0 events=rw cmd=llen
5791:M 29 Feb 12:42:11.084 - Accepted 127.0.0.1:57428
5791:M 29 Feb 12:42:11.735 - Protocol error from client: id=656 addr=127.0.0.1:57428 fd=5 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=16384 qbuf-free=16384 obl=42 oll=0 omem=0 events=rw cmd=NULL
```
```
Used software:
Redis gem: 3.2.2
Redis: Redis server v=3.0.7 sha=00000000:0 malloc=jemalloc-3.6.0 bits=64 build=6afb1e1f0d80abd0
Logstash: 1.5.6
JRuby: jruby 1.7.23 (1.9.3p551) 2015-11-24 f496dd5 on OpenJDK 64-Bit Server VM 1.7.0_79-b14 +jit [linux-amd64]
OS:
Distributor ID: Debian
Description: Debian GNU/Linux 8.2 (jessie)
Release: 8.2
Codename: jessie
```
Contributor guide
Assessment
This issue has not been assessed yet.