New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pub/sub timeout #541

Closed
pengfei-xu opened this Issue Jun 30, 2016 · 7 comments

Comments

3 participants
@pengfei-xu

pengfei-xu commented Jun 30, 2016

500 num cur time
org.redisson.client.RedisTimeoutException: Redis server response timeout (3000 ms) occured for command: (PUBLISH) with params: [dispatch_except, com.corundumstudio.socketio.store.pubsub.DispatchMessage@11dd736] channel: [id: 0xd8161b77, L:/10.1.5.114:9741 - R:10.1.6.20/10.1.6.20:7091]
at org.redisson.command.CommandAsyncService$10.run(CommandAsyncService.java:510) ~[redisson-2.2.17-SNAPSHOT.jar:na]
at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:581) ~[netty-common-4.1.0.Final.jar:4.1.0.Final]
at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:655) ~[netty-common-4.1.0.Final.jar:4.1.0.Final]
at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:367) ~[netty-common-4.1.0.Final.jar:4.1.0.Final]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]

@mrniko

This comment has been minimized.

Show comment
Hide comment
@mrniko

mrniko Jul 6, 2016

Member

Could you provide more details about this issue? have you checked your network and CPU usage?

Member

mrniko commented Jul 6, 2016

Could you provide more details about this issue? have you checked your network and CPU usage?

@Mavlarn

This comment has been minimized.

Show comment
Hide comment
@Mavlarn

Mavlarn Jul 7, 2016

I also met similar problem these days. The error is:

2016-07-07 18:37:32,733 ERROR [pool-4-thread-1] TaskUtils$LoggingErrorHandler: Unexpected error occurred in scheduled task.
org.redisson.client.RedisTimeoutException: Redis server response timeout (15000 ms) occured for command: (EVAL) with params: [if (redis.call('exists', KEYS[1]) == 0) then redis.call('hset', KEYS[1], ARGV[2], 1); redis.call('pexpire', KEYS[1], ARGV[1]); return nil; end; if (redis.call('hexists', KEYS[1], ARGV[2]) == 1) then redis.call('hincrby', KEYS[1], ARGV[2], 1); redis.call('pexpire', KEYS[1], ARGV[1]); return nil; end; return redis.call('pttl', KEYS[1]);, 1, ticket.lock.master_slave, 70000, 623be78d-901f-4b99-9580-3dcc9ca7b860:40] channel: [id: 0xfca13790, L:/127.0.0.1:37426 - R:/127.0.0.1:6379]
        at org.redisson.command.CommandAsyncService$10.run(CommandAsyncService.java:504) ~[redisson-2.2.16.jar:na]
        at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:581) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:655) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:367) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91]

The version I use is 2.2.16, I have 2 redis server, one master and one slave, in sentinel mode. It is in test environment so net work and cpu usage is low.
This error appears about every 5 to 10 minutes.

Mavlarn commented Jul 7, 2016

I also met similar problem these days. The error is:

2016-07-07 18:37:32,733 ERROR [pool-4-thread-1] TaskUtils$LoggingErrorHandler: Unexpected error occurred in scheduled task.
org.redisson.client.RedisTimeoutException: Redis server response timeout (15000 ms) occured for command: (EVAL) with params: [if (redis.call('exists', KEYS[1]) == 0) then redis.call('hset', KEYS[1], ARGV[2], 1); redis.call('pexpire', KEYS[1], ARGV[1]); return nil; end; if (redis.call('hexists', KEYS[1], ARGV[2]) == 1) then redis.call('hincrby', KEYS[1], ARGV[2], 1); redis.call('pexpire', KEYS[1], ARGV[1]); return nil; end; return redis.call('pttl', KEYS[1]);, 1, ticket.lock.master_slave, 70000, 623be78d-901f-4b99-9580-3dcc9ca7b860:40] channel: [id: 0xfca13790, L:/127.0.0.1:37426 - R:/127.0.0.1:6379]
        at org.redisson.command.CommandAsyncService$10.run(CommandAsyncService.java:504) ~[redisson-2.2.16.jar:na]
        at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:581) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:655) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:367) ~[netty-common-4.0.37.Final.jar:4.0.37.Final]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91]

The version I use is 2.2.16, I have 2 redis server, one master and one slave, in sentinel mode. It is in test environment so net work and cpu usage is low.
This error appears about every 5 to 10 minutes.

@mrniko

This comment has been minimized.

Show comment
Hide comment
@mrniko

mrniko Jul 14, 2016

Member

Do you see disconnected due to failedAttempts substring in logs?

Member

mrniko commented Jul 14, 2016

Do you see disconnected due to failedAttempts substring in logs?

@pengfei-xu

This comment has been minimized.

Show comment
Hide comment
@pengfei-xu

pengfei-xu Jul 16, 2016

I see failedAttempts 3 frequency in logs. but must times do not see this error online . only see it in pressure environment @mrniko

pengfei-xu commented Jul 16, 2016

I see failedAttempts 3 frequency in logs. but must times do not see this error online . only see it in pressure environment @mrniko

@mrniko

This comment has been minimized.

Show comment
Hide comment
@mrniko

mrniko Jul 16, 2016

Member

I see failedAttempts 3 frequency in logs

This means client lost connection with Redis

Member

mrniko commented Jul 16, 2016

I see failedAttempts 3 frequency in logs

This means client lost connection with Redis

@Mavlarn

This comment has been minimized.

Show comment
Hide comment
@Mavlarn

Mavlarn Jul 17, 2016

In my circumstances, I can make sure redis server is accesable, and the connection is not lost.
This error only occers when I use pub/sub. Then I changed it to blocking queue, there is no error more.
My environment is 2 redis servers, master/slave, with sentinal mode.

And during deployment, I found a problem:
For the master redis server, I config its sential like this:

monitor 127.0.0.1 ......

It mean this sentinal will monitor the master on local. For another sential, I set the master with IP addr.

So my suspicion is, if I set sentinal with address like 127.0.0.1, then the connection of redisson will also use 127.0.0.1:6379. Then in pub/sub code, for some reason, the subcriber will be triggered twice. But the second time, it will not get any data from redis. So the timeout error occurs.

I am not sure if the problem can be fixed if I use actual IP in sentinal config. Because I have already modified my solution with queue. And, maybe it is not right to config sentinal monitor ip with 127.0.0.1. I just hope it can help.

Mavlarn commented Jul 17, 2016

In my circumstances, I can make sure redis server is accesable, and the connection is not lost.
This error only occers when I use pub/sub. Then I changed it to blocking queue, there is no error more.
My environment is 2 redis servers, master/slave, with sentinal mode.

And during deployment, I found a problem:
For the master redis server, I config its sential like this:

monitor 127.0.0.1 ......

It mean this sentinal will monitor the master on local. For another sential, I set the master with IP addr.

So my suspicion is, if I set sentinal with address like 127.0.0.1, then the connection of redisson will also use 127.0.0.1:6379. Then in pub/sub code, for some reason, the subcriber will be triggered twice. But the second time, it will not get any data from redis. So the timeout error occurs.

I am not sure if the problem can be fixed if I use actual IP in sentinal config. Because I have already modified my solution with queue. And, maybe it is not right to config sentinal monitor ip with 127.0.0.1. I just hope it can help.

@mrniko

This comment has been minimized.

Show comment
Hide comment
@mrniko

mrniko Jul 17, 2016

Member

if I set sentinal with address like 127.0.0.1, then the connection of redisson will also use 127.0.0.1:6379

You can use any IP for sentinel or master servers. They also could use the same IP, but should be bounded to different ports, of course.

Could you try latest version of Redisson, since I fixed few bugs starting from 2.2.16 version?

Member

mrniko commented Jul 17, 2016

if I set sentinal with address like 127.0.0.1, then the connection of redisson will also use 127.0.0.1:6379

You can use any IP for sentinel or master servers. They also could use the same IP, but should be bounded to different ports, of course.

Could you try latest version of Redisson, since I fixed few bugs starting from 2.2.16 version?

@mrniko mrniko closed this Jul 26, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment