Is there any chance of Redis send "ERR Connection timed out" instead of disconnect client?

[HeartSaVioR]

Hello all!

While I was reading Jedis google groups, I read strange things I never met before.

(https://groups.google.com/d/msg/jedis_redis/jN5BPM-Fpyw/NxRpxSuhb-4J)

Some users complain they receive "ERR Connection timed out" and Jedis treat this as JedisDataException.

I skimmed Redis source code (unstable, 2.6.16) to find this message but no luck.

Instead, Redis just marks disconnect flag to client when it's timed out. (and maybe sometimes Redis disconnects client)

Same things happened earlier.

(https://github.com/xetorthio/jedis/issues/473)

Jedis use case lets user to treat JedisConnectionException to invalid connection.

If Redis is able to send "ERR Connection timed out" and it means connection is invalid, Jedis should parse message and treat this message to JedisConnectionException.

So I'm curious of possibilities about sending this message.

Thanks!

Sincerely.

Jungtaek Lim (HeartSaVioR)

[Josiah Carlson]

Redis is not sending any "ERR Connection timed out" message to Jedis. What is happening is that Jedis is trying to do something (like execute a command), but because the command doesn't return in a short enough period of time (maybe due to short timeout, busy Redis, slow network, ...), Jedis itself decides that the command times out and raises a JedisDataException("ERR Connection timed out"). There was a thread here a few weeks ago that talked about Jedis' default timeout being 2 seconds, which is probably too short in a lot of cases.

So yeah, not a Redis problem. If you want Jedis to return a proper exception, you're going to have to get the Jedis authors to do it, or fork the library yourself.

 - Josiah

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.
To unsubscribe from this group and stop receiving emails from it, send an email to redis-db+u...@googlegroups.com.
To post to this group, send email to redi...@googlegroups.com.
Visit this group at http://groups.google.com/group/redis-db.
For more options, visit https://groups.google.com/groups/opt_out.

[HeartSaVioR]

Hello Josiah.

Thanks for commenting!

Actually I've been contributing to Jedis, so I did ask a question for fixing this.

Really strange thing is, Jedis doesn't make "ERR" message itself.

If Jedis should throw Exception with custom message, Jedis never includes "ERR" prefix.

If IOException occurs (maybe you described), Jedis just throws JedisConnectionException.

I tried to find creation part of "ERR" message from Jedis master branch, v2.2.0, v2.1.0(reported version), v2.0.0 with no luck.

(It's easy to find, just find "ERR" & case insensible with all files. I've tried to find just "JedisDataException" with no luck too.)

I also tried to find from Redis unstable branch, 2.8.16 (reported version) with no luck.

Redis itself seems to disconnect without notified when timeout occurs. (Am I right?)

So I've posted "possibilities" of sending "ERR Connection timed out", since it's strange things to both Redis and Jedis.

Thanks!

Regards.

Jungtaek Lim (HeartSaVioR)

2014년 3월 5일 수요일 오전 1시 16분 8초 UTC+9, Josiah Carlson 님의 말:

[HeartSaVioR]

Hello!

I'm appending some more description on this.

Below is stack trace of corresponding situation.

(from https://github.com/xetorthio/jedis/issues/473)

2013-11-01 16:01:57,837 ERROR org.apache.catalina.core.ContainerBase.[jboss.web].[localhost].[/].[springmvc] Servlet.service() for servlet springmvc threw exception
redis.clients.jedis.exceptions.JedisDataException: ERR Connection timed out
at redis.clients.jedis.Protocol.processError(Protocol.java:59)
at redis.clients.jedis.Protocol.process(Protocol.java:66)
at redis.clients.jedis.Protocol.read(Protocol.java:131)
at redis.clients.jedis.Connection.getBinaryBulkReply(Connection.java:182)
at redis.clients.jedis.BinaryJedis.hget(BinaryJedis.java:698)
at org.springframework.data.redis.connection.jedis.JedisConnection.hGet(JedisConnection.java:2205)
...

Protocol.read() reads Redis response. If some problems occurred, Jedis just handle this to JedisConnectionException.

Process.process() just route response to approved handler, calling Process.processError() means response starts with '-' sign.

Process.processError() just wrap message with JedisDataException.

https://github.com/xetorthio/jedis/blob/jedis-2.1.0/src/main/java/redis/clients/jedis/Connection.java

https://github.com/xetorthio/jedis/blob/jedis-2.1.0/src/main/java/redis/clients/jedis/Protocol.java

So I think this message is received outside of Jedis, especially Redis (starts with "-ERR" sign).

Please comment it if I am wrong with this situation or it's possible for Redis to sending this message.

Thanks!

2014년 3월 5일 수요일 오전 1시 16분 8초 UTC+9, Josiah Carlson 님의 말:

Redis is not sending any "ERR Connection timed out" message to Jedis. What is happening is that Jedis is trying to do something (like execute a command), but because the command doesn't return in a short enough period of time (maybe due to short timeout, busy Redis, slow network, ...), Jedis itself decides that the command times out and raises a JedisDataException("ERR Connection timed out"). There was a thread here a few weeks ago that talked about Jedis' default timeout being 2 seconds, which is probably too short in a lot of cases.

[임정택]

Sorry for confusing, Reported Redis version is 2.6.16.

--
You received this message because you are subscribed to a topic in the Google Groups "Redis DB" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/redis-db/Aol6OuDsf_Q/unsubscribe.
To unsubscribe from this group and all its topics, send an email to redis-db+u...@googlegroups.com.

To post to this group, send email to redi...@googlegroups.com.
Visit this group at http://groups.google.com/group/redis-db.
For more options, visit https://groups.google.com/groups/opt_out.

--

Name : 임 정택
Blog : http://www.heartsavior.net / http://dev.heartsavior.net
Twitter : http://twitter.com/heartsavior

LinkedIn : http://www.linkedin.com/in/heartsavior

[Josiah Carlson]

Now that we've both established that it's not Redis, the only question remaining is "where do you patch Jedis to fix your issue?"

Are you seeing this error on established connections? Is it on a new connection? What is your timeout set at? Have you measured how long it takes for a timeout to occur?

 - Josiah

[HeartSaVioR]

Hello!

It seems that there's a miscommunication between us.

Have you seen stack trace and meaning from previous post I've written?

I'm not 100% sure Redis never sends "ERR Connection timed out", but Jedis never makes message with "ERR" prefix.

(If "Connection timed out" may not Redis message - for example, C API's error message, chance of Redis sending this message may left.)

If "connection timed out" message may be a reply, what's state of connection?

I can fix this issue simply without tracking, just parse message and convert to JedisConnectionException.

But it would be meaningless because I'm not sure about connection's state. (connected? disconnected?)

And actually there is other reporter.

(https://groups.google.com/forum/#!topic/jedis_redis/jN5BPM-Fpyw)

We can ask reporter from details. I've mailed about this post.

Thanks for following this post!

Sincerely.

Jungtaek Lim (HeartSaVioR)

2014년 3월 5일 수요일 오전 10시 42분 11초 UTC+9, Josiah Carlson 님의 말:

[Greg Andrews]

On Tue, Mar 4, 2014 at 8:04 PM, HeartSaVioR <kab...@gmail.com> wrote:

I'm not 100% sure Redis never sends "ERR Connection timed out", but Jedis never makes message with "ERR" prefix.

Simple test:  While your Jedis client is running and connected to your Redis server, stop the Redis server.

What error message does Jedis return?  Does it begin with "ERR"?

  -Greg

[HeartSaVioR]

Hello GregA!

I've tested it with your direction.

* Simple Test code : https://gist.github.com/HeartSaVioR/9366408

* Test sequence : 

1. Client (Jedis) just send set command to Redis infinitely.

2. Shutdown Redis with debug segfault.

3. See Exceptions from Jedis

Below is test result.

with Jedis 2.1.0 (reported version) and Redis 2.9.x (recent unstable)

0

10000

20000

...

140000

// do debug segfault

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: It seems like server has closed the connection.

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: Unknown reply: O

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketException: Broken pipe

...

Exception - exc: java.lang.ArrayIndexOutOfBoundsException: 8192

Exception - exc: java.lang.ArrayIndexOutOfBoundsException: 8193

...

with Jedis 2.1.0 (reported version) and Redis 2.6.16 (reported version)

0

10000

20000

...

130000

// do debug segfault

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: It seems like server has closed the connection.

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: Unknown reply: O

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketException: Broken pipe

...

JedisConnectionException - exc: redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketException: Broken pipe

Exception - exc: java.lang.ArrayIndexOutOfBoundsException: 8192

Exception - exc: java.lang.ArrayIndexOutOfBoundsException: 8193

...

You can just ignore Unknown reply and ArrayIndexOutOfBoundsEception. Actually connection should be closed if I receive JedisConnectionException but I reused connection continuously for maximizing probabilities.

There is no ERR message from Jedis. But there is no ERR message from Redis.

(It can be, because I tried to find it from both Jedis and Redis source codes.)

Maybe it can hardly reproduce?

Btw, Issue reporter will try to reproduce later this week.

We can wait a moment to reproduce.

Thanks all!

Sincerely.

Jungtaek Lim (HeartSaVioR)

2014년 3월 5일 수요일 오후 5시 21분 8초 UTC+9, GregA 님의 말:

[Josiah Carlson]

I read the stacktrace, and I went through the Jedis source code.

But here's the thing: Redis would never return "Connection timed out", because aside from "slaveof host port" (which will should return OK if you've given it reasonable arguments, IIRC) or cluster interconnections, Redis doesn't try to connect to anything else, and when it does, doesn't produce error logs to the client.

The other thing is that "Connection timed out" is seen from clients of most languages (Ruby, Java, Python, ...), so is most likely a message produced by the underlying platform libraries on attempt to connect to the server, attempt to write data to the server, or attempt to read data from the server. It could be caused by an intermittent network connection, overloaded network connection, an overloaded server, or an overloaded client. (note that "Connection timed out" is different from "Connection refused", which you would see if the server was not running) Others have reported the error during Redis snapshot operations (where a fork occurs, blocking Redis from doing anything), sometimes on VPC hosting in Amazon or similar, and sometimes when running Redis with other services on the same machine.

If you can get more information from the user, in particular when he's seeing the issue, that would go a long way towards us pinpointing what was the original source of the error, and how you can fix the client to do what you want it to do.

 - Josiah

On Tue, Mar 4, 2014 at 8:04 PM, HeartSaVioR <kab...@gmail.com> wrote:

[HeartSaVioR]

Yes, it may need some more information about situation, reproduce needed.

Thanks for following up!

Sincerely.

Jungtaek Lim (HeartSaVioR)

ps. I read "Redis in action" from MEAP last year, and it's amazing book!

2014년 3월 6일 목요일 오전 2시 57분 38초 UTC+9, Josiah Carlson 님의 말:

[Rintcius Blok]

Hi, I am one of the users who saw this behavior. I replied in the jedis group: https://groups.google.com/forum/#!topic/jedis_redis/jN5BPM-Fpyw

[Jonathan Leibiusky]

It seems like there was another variable here: twemproxy.
Just checked the docs and it seems it is the one throwing this error.

For more options, visit https://groups.google.com/d/optout.

[Josiah Carlson]

Awesome, then it's still not a bug in Redis.

 - Josiah

[HeartSaVioR]

Yes, this is not a bug in Redis.

There's simple problem here: Twemproxy is sending error message like Memcache / Redis made by itself.

https://github.com/twitter/twemproxy/blob/master/notes/recommendation.md

2014년 3월 8일 토요일 오전 9시 17분 15초 UTC+9, Josiah Carlson 님의 말:

[Josiah Carlson]

If you are getting a "Connection refused" message trying to connect to Redis, that could be caused by one of several issues:

1. Redis is not running

2. Redis is listening on the wrong interface/port

3. Redis is overloaded (CPU, disk, or network interface), possibly due to fork to slave, snapshot, and/or rewrite the AOF

4. Redis has hit its incoming connection limit

5. Your OS has not been configured to let Redis accept more connections

6. Your network is overloaded/otherwise broken

7. Any one of a dozen other issues that are completely unrelated to Redis

Have you tried connecting to the server with redis-cli? From the Redis server itself machine? From your proxy machine? From *any* other machine that should have access?

 - Josiah

For more options, visit https://groups.google.com/d/optout.

[Rintcius Blok]

Hi Josiah,

Just to be clear, in my case it's point 1: I tested with a deliberately stopped redis server in order to test if twemproxy has anything to do with this "JedisDataException which looks like a disguised JedisConnectionException" problem. My update on the jedis forum ( https://groups.google.com/forum/#!topic/jedis_redis/jN5BPM-Fpyw ) was just to show that it indeed looks like this problem is caused by twemproxy. 

Rintcius

[Josiah Carlson]

Next time, before you are going to report a bug to any project, make sure you include *all* of the relevant information about your setup that could/would help diagnose the issue. Had you reported initially that you had turned off Redis, then connected to twemproxy via Jedis, and received the error, that would have saved several people time trying to look for the actual source of the error.

 - Josiah

[Rintcius Blok]

Ok, granted that I should have added that twemproxy was involved

(I would have, had I realized it; also as soon as I realized it was, I did mention it).

I think you are also mixing up a couple of things.

First off, it wasn't me who filed a bug report, that was someone else.

I just noted that some bug report looked similar to our situation and was asking a question on the jedis forum.

Second, that situation that you are describing (turning off redis etc) is how I managed to reproduce a similar situation later in the week 

(that similar situation was basically following GregA's suggestion, so with extra info I got from this forum).

It was definitely not the same situation as the initial one that I posted; the initial one happened in prod and we didn't stop redis there. 

(Also I still don't know how to reproduce exactly that initial situation we had in prod) 

Had I known how to reproduce the situation or anything similar, then obviously I would have mentioned. But I asked on the forum because it looked mysterious to me. 

In fact I said in that jedis thread that I was going to follow up and put some effort in trying to reproduce it with the extra info that I got as soon as I had time for it, and I did follow up.

All in all, to me it looks like a pretty mysterious situation got resolved in a pretty smooth manner.