microsoftarchive / redis

Redis is an in-memory database that persists on disk. The data model is key-value, but many different kind of values are supported: Strings, Lists, Sets, Sorted Sets, Hashes
http://redis.io
Other
20.84k stars 5.38k forks source link

Urgent: After upgrading to 3.0.501 still hangs #422

Open BoasE opened 8 years ago

BoasE commented 8 years ago

Upgraded tp redis 3.0.501. First two hors everything works without any error.

then this error repeated endlessly.

 StackExchange.Redis.RedisServerException: ERR Error running script (call to f_5b8e3b60e050400311bc8b6ef2cbba37bc0b9cb3): @user_script:1: @user_script: 1: -OOM command not allowed when used memory > 'maxmemory'. 
  at Microsoft.AspNet.SignalR.Messaging.ScaleoutStream.Send(Func`2 send, Object state)
  at Microsoft.AspNet.SignalR.Infrastructure.Connection.Send(ConnectionMessage message)
  at Microsoft.AspNet.SignalR.Transports.TransportConnectionExtensions.SendCommand(ITransportConnection connection, String connectionId, CommandType commandType)
  at Microsoft.AspNet.SignalR.Transports.ForeverTransport.<>c__DisplayClass21.<ProcessReceiveRequest>b__1b(ITransportConnection conn, String id)

when I was on the redis server it self I was able to connect to the server with redis desktop client. But all Productions server weren't able to get a connection.

the dump has about 1,4GB

settings: maxmemory 5000mb

The redis log doesn'T show any error.

I can see some logs of this kind (not sure if it is not meant to be there)


[22132] 05 Mar 00:00:02.142 - Accepted 79.133.49.6:17020
[22132] 05 Mar 00:00:02.143 - Accepted 79.133.49.6:17021
[22132] 05 Mar 00:00:02.144 - Accepted 79.133.49.6:17022
[22132] 05 Mar 00:00:02.145 - Accepted 79.133.49.6:17023
[22132] 05 Mar 00:00:02.217 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.217 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.217 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.218 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.218 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.414 - Accepted 79.133.49.6:17024
[22132] 05 Mar 00:00:02.415 - Accepted 79.133.49.6:17025
[22132] 05 Mar 00:00:02.435 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.436 - Reading from client: An existing connection was forcibly closed by the remote host.
[22132] 05 Mar 00:00:02.436 - Reading from client: An existing connection was forcibly closed by the remote host.

Here the output of the info. Strange thing at the end :

avg_ttl=52351615 are this seconds ?? I can't find any key with such a longe ttl in redis and if it redis then there must be a lot...

local:0>info

# Server
redis_version:3.0.501-private
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:e9cf00ecd310a91c
redis_mode:standalone
os:Windows  
arch_bits:64
multiplexing_api:WinSock_IOCP
process_id:17792
run_id:5a90a94018f066ee36089c9f6a7f241e1c468cd1
tcp_port:6379
uptime_in_seconds:124
uptime_in_days:0
hz:10
lru_clock:14296304
config_file:C:\Program Files\Redis\redis.windows-service.conf

# Clients
connected_clients:67
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0

# Memory
used_memory:4306951288
used_memory_human:4.01G
used_memory_rss:4306913512
used_memory_peak:4432940224
used_memory_peak_human:4.13G
used_memory_lua:1053696
mem_fragmentation_ratio:1.00
mem_allocator:jemalloc-3.6.0

# Persistence
loading:0
rdb_changes_since_last_save:4590
rdb_bgsave_in_progress:0
rdb_last_save_time:1457136756
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
aof_enabled:0
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok

# Stats
total_connections_received:549
total_commands_processed:19417
instantaneous_ops_per_sec:151
total_net_input_bytes:56264730
total_net_output_bytes:527112560
instantaneous_input_kbps:856.59
instantaneous_output_kbps:3269.82
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:443
evicted_keys:0
keyspace_hits:1191
keyspace_misses:2581
pubsub_channels:6
pubsub_patterns:0
latest_fork_usec:0
migrate_cached_sockets:0

# Replication
role:master
connected_slaves:0
master_repl_offset:0
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0

# CPU
used_cpu_sys:2.94
used_cpu_user:14.47
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=1072156,expires=1072154,avg_ttl=52351615

Currently using redis is just getting more worse and worse when updating anything :-/

BoasE commented 8 years ago

One more thing I know increased maxmemory a little and now one hour later the redis server even doesn't start anymore. image

BoasE commented 8 years ago

After hours it isn't able to run it. if of any help i've backup the complete folder with binaries, dump, logs and so....

enricogior commented 8 years ago

Hi @Gentlehag the avg_ttl is not a Windows-specific data, you should ask about it in the official Redis community: https://www.reddit.com/r/redis/

The StackExchange.Redis.RedisServerException error may be a client issue or a server issue, if redis-cli.exe can connect to the server and cab execute commands it makes more probable that the problem is with the StackExchange client (what version are you using?).

Regarding the Redis service start failure, can you please provide the Redis log? Thank you.

BoasE commented 8 years ago

here the log

redis.master.zip

looking at the StackExchange. The strange thing is we reference ServiceSTack.Redis. not sure where StackExchange comes from. should have a look at this.

BUT the problem is Always solved when restarting the redis service and the webprocess of the site / api isn't stopped

I Assume stackexchange comes from Microsoft.aspnet.signalR.Redis. ill investigate this further. All SignalR Packes are most curretn stables

enricogior commented 8 years ago

@Gentlehag thanks for sending the log. I don't see any service start error in the log. Try renaming the log and start again the service so we can be sure the service start error is logged in a new empty file.

In the past we experienced problems using the StackExchange client. The client was not correctly releasing the connections until the client or the server was restarted. I can't guarantee that you are experiencing the same issue, but you should verify if resetting the client solves the problem.

BoasE commented 8 years ago

Good to know. Was this problem only related whe nusing Redis 3.0 ?

with redis 2.0 i primarly have only this recurring short time errors but not hangs ( same client)

unfortunately i only try connect. Not adding a key. If I under stand documentation right there are states where redis just denies adds. In this case wouldn't i get the errors like described above?

Do you mean explicit releasing the connections by our code or internal things of the StackExchange client?

We have a scenario where we let the connections just time out and don't close them explicitly

Is there a way to see if there are problem with the signalR client? I thought I saw yesterday night only 64 clients in the redis info console. shouldn't I see much more if the stackexchange client has these problems ?

BoasE commented 8 years ago

I had a look at the default SignalR.Redis assembly and it refrences StackExchange.Redis 1.0.316.0

but the when i log foor stackexchangeredis the most current version is 1.0.488 image

enricogior commented 8 years ago

@Gentlehag latest StackExchange.Redis release is 1.1.553 https://github.com/StackExchange/StackExchange.Redis/releases/tag/1.1.553

Good to know. Was this problem only related whe nusing Redis 3.0 ?

I run into it while testing Redis 3.0.

We have a scenario where we let the connections just time out and don't close them explicitly

That may cause problems, I strongly suggest to explicitly close connections that are not in use, or implement a connection pool.

Is there a way to see if there are problem with the signalR client?

You should refer to the SignalR documentation/community.

I thought I saw yesterday night only 64 clients in the redis info console. shouldn't I see much more if the stackexchange client has these problems?

It may a problem with the client or not, it depends, with the information I have I can't say.

BoasE commented 8 years ago

Just to be clear we don't close the signalR connections. in this scenario we don't create the Redisconnection itself .