Redis Cpu Usage

[G]

I use Redis as a a queue. I use a key `my_queue` and I consume the
queuu with the following code:

while True:
msg = self.__redis.blpop(self.key)


I use the above code in 20 clients which they are consuming the queue.

I have noticed that sometimes the redis server cpu usage raises up to
99%.

This happened today althought the queue was empty.
I suppose that all 20 clients where waiting.
Is the blpop command loads tha server?

Thanks

[Salvatore Sanfilippo]

The CPU spike is another Redis thread persisting on disk, the instance
handling clients is likely using a minmal fraction of your CPU.

Cheers,
Salvatore

> --
> You received this message because you are subscribed to the Google Groups "Redis DB" group.
> To post to this group, send email to redi...@googlegroups.com.
> To unsubscribe from this group, send email to redis-db+u...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/redis-db?hl=en.
>



--
Salvatore 'antirez' Sanfilippo
open source developer - VMware
http://invece.org

Beauty is more important in computing than anywhere else in technology
because software is so complicated. Beauty is the ultimate defence
against complexity.
— David Gelernter

[G]

My redis.conf has :


#   It is also possible to remove all the previously configured save
#   points by adding a save directive with a single empty string argument
#   like in the following example:
#
#   save ""

#save 900 1
#save 300 10
#save 60 10000

so it should not persist on the db. Or it still persists?

[Yiftach Shoolman]

What is the config get in your redis-cli ? 

To view this discussion on the web visit https://groups.google.com/d/msg/redis-db/-/xRLwOM8Ojt0J.

To post to this group, send email to redi...@googlegroups.com.
To unsubscribe from this group, send email to redis-db+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/redis-db?hl=en.

--

Yiftach Shoolman
+972-54-7634621

[G]

redis 127.0.0.1:6380> config get *

 1) "dbfilename"
 2) "dump.rdb"
 3) "requirepass"
 4) ""
 5) "masterauth"
 6) ""
 7) "bind"
 8) ""
 9) "unixsocket"
10) ""
11) "logfile"
12) ""
13) "pidfile"
14) "/var/run/redis.pid"
15) "maxmemory"
16) "0"
17) "maxmemory-samples"
18) "3"
19) "timeout"
20) "200"
21) "auto-aof-rewrite-percentage"
22) "100"
23) "auto-aof-rewrite-min-size"
24) "67108864"
25) "hash-max-ziplist-entries"
26) "512"
27) "hash-max-ziplist-value"
28) "64"
29) "list-max-ziplist-entries"
30) "512"
31) "list-max-ziplist-value"
32) "64"
33) "set-max-intset-entries"
34) "512"
35) "zset-max-ziplist-entries"
36) "128"
37) "zset-max-ziplist-value"
38) "64"
39) "lua-time-limit"
40) "5000"
41) "slowlog-log-slower-than"
42) "10000"
43) "slowlog-max-len"
44) "128"
45) "port"
46) "6380"
47) "databases"
48) "16"
49) "repl-ping-slave-period"
50) "10"
51) "repl-timeout"
52) "60"
53) "maxclients"
54) "10000"
55) "watchdog-period"
56) "0"
57) "slave-priority"
58) "100"
59) "no-appendfsync-on-rewrite"
60) "no"
61) "slave-serve-stale-data"
62) "yes"
63) "slave-read-only"
64) "yes"
65) "stop-writes-on-bgsave-error"
66) "yes"
67) "daemonize"
68) "yes"
69) "rdbcompression"
70) "yes"
71) "rdbchecksum"
72) "yes"
73) "activerehashing"
74) "yes"
75) "appendonly"
76) "no"
77) "dir"
78) "/mnt/cx/redis"
79) "maxmemory-policy"
80) "volatile-lru"
81) "appendfsync"
82) "everysec"
83) "save"
84) ""
85) "loglevel"
86) "notice"
87) "client-output-buffer-limit"
88) "normal 0 0 0 slave 268435456 67108864 60 pubsub 33554432 8388608 60"
89) "unixsocketperm"
90) "0"
91) "slaveof"
92) ""

[Salvatore Sanfilippo]

Persistence is off indeed.

BLPOP does not load the server at all, it will be completely idle. It
is very strange you are seeing the 100% CPU thing. IMHO there is
something hitting the server in some way.

Please could you send us the INFO output? Unlikely to show the cause
but well a bit more info will be good.

Salvatore

> https://groups.google.com/d/msg/redis-db/-/WRMVQgTR2x8J.

[G]

# Server
redis_version:2.6.4
redis_git_sha1:00000000
redis_git_dirty:0
redis_mode:standalone
os:Linux 2.6.32-279.el6.x86_64 x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:4.4.6
process_id:9104
run_id:93adecd72677613e50e2c33b821201db5853d765
tcp_port:6380
uptime_in_seconds:844880
uptime_in_days:9
lru_clock:1261060

# Clients
connected_clients:298
client_longest_output_list:1
client_biggest_input_buf:76695
blocked_clients:32

# Memory
used_memory:11866112
used_memory_human:11.32M
used_memory_rss:17694720
used_memory_peak:18280394728
used_memory_peak_human:17.02G
used_memory_lua:31744
mem_fragmentation_ratio:1.49
mem_allocator:jemalloc-3.0.0

# Persistence
loading:0
rdb_changes_since_last_save:253947841
rdb_bgsave_in_progress:0
rdb_last_save_time:1353943008
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

# Stats
total_connections_received:235494
total_commands_processed:4245183919
instantaneous_ops_per_sec:707
rejected_connections:0
expired_keys:0
evicted_keys:0
keyspace_hits:859152
keyspace_misses:3933170953
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0

# Replication
role:master
connected_slaves:0

# CPU
used_cpu_sys:107020.86
used_cpu_user:21523.71
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Keyspace
db2:keys=2,expires=0
db3:keys=1,expires=0


Now the redis uses 10% of the cpu. This is the normal.

The 99% cpu usage happens at random time ( I mean I cannot find a specific reason why the cpu usage raises).

I check munin and I notice that also sometimes the connected_clients goes up to 1475 ( max according to munin).
Now it has 307 connected clients and average 617.

I think the problem is related to connected clients.
Why the connected clients goes up ? I use a constant number of running scripts. Now with 300 connected_clients
all my programs running. The same when I have 1000 connected_clients.

Thanks for the help

[Salvatore Sanfilippo]

On Thu, Dec 6, 2012 at 11:05 AM, G <g...@alpha9marketing.com> wrote:
> Why the connected clients goes up ? I use a constant number of running
> scripts. Now with 300 connected_clients
> all my programs running. The same when I have 1000 connected_clients.

My bet is that there is a bug in your application or client library
that under certain conditions will create new links to the Redis
instance without closing the old one or alike.

However 1000 connected clients are still not enough to cause a CPU
spike so there must be some other problem, like data accumulating in
your queue with the workers blocked for some reason, and then the
workers suddenly starting to fetch all the data at the same time
maximizing the server load.

Cheers,
Salvatore

[Salvatore Sanfilippo]

p.s. please also send the output of INFO commandstats. Thanks!

[G]

# Commandstats
cmdstat_get:calls=192,usec=711,usec_per_call=3.70
cmdstat_set:calls=177,usec=842,usec_per_call=4.76
cmdstat_del:calls=5,usec=596,usec_per_call=119.20
cmdstat_rpush:calls=155470507,usec=715807766,usec_per_call=4.60
cmdstat_lpop:calls=98746044,usec=781490754,usec_per_call=7.91
cmdstat_blpop:calls=57054345,usec=158249311,usec_per_call=2.77
cmdstat_llen:calls=3968244289,usec=6099763709,usec_per_call=1.54
cmdstat_select:calls=195075,usec=583719,usec_per_call=2.99
cmdstat_keys:calls=60,usec=670,usec_per_call=11.17
cmdstat_ping:calls=11276,usec=21831,usec_per_call=1.94
cmdstat_flushdb:calls=1,usec=20,usec_per_call=20.00
cmdstat_flushall:calls=6,usec=112562,usec_per_call=18760.33
cmdstat_info:calls=33827,usec=9858377,usec_per_call=291.44
cmdstat_config:calls=2,usec=3725,usec_per_call=1862.50

I use the redis-py ( https://github.com/andymccurdy/redis-py ).

[Salvatore Sanfilippo]

The worse in the list is:

cmdstat_flushall:calls=6,usec=112562,usec_per_call=18760.33

But still we are talking about 18 milliseconds of 100% CPU...

It really seems like the problem is just a load of commands in a very
short time or something like that.

Another thing you could try is the software watchdog
(http://redis.io/topics/latency) if you notice that while there is the
100% CPU spike the server seems to block. If it works as expected even
during the spikes than it's not worth to try this.

Cheers
Salvatore

On Thu, Dec 6, 2012 at 11:24 AM, G <g...@alpha9marketing.com> wrote:
> cmdstat_flushall:calls=6,usec=112562,usec_per_call=18760.33

[G]

The fulshall is not on the program , I have called it manually sometimes.

I will try to check the stats when the cpu is 100%.

Thanks for helping,
Giorgos

[Yiftach Shoolman]

Can you send the slowlog ?

E.g.:

slowlog get 100

--

You received this message because you are subscribed to the Google Groups "Redis DB" group.

To view this discussion on the web visit https://groups.google.com/d/msg/redis-db/-/hXTTMF-9DC8J.

To post to this group, send email to redi...@googlegroups.com.
To unsubscribe from this group, send email to redis-db+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/redis-db?hl=en.

--

Yiftach Shoolman
+972-54-7634621

[G]

# Commandstats
cmdstat_get:calls=194,usec=743,usec_per_call=3.83
cmdstat_set:calls=179,usec=850,usec_per_call=4.75
cmdstat_del:calls=5,usec=596,usec_per_call=119.20
cmdstat_rpush:calls=158312407,usec=728027940,usec_per_call=4.60
cmdstat_lpop:calls=100333058,usec=791658734,usec_per_call=7.89
cmdstat_blpop:calls=58312844,usec=161092425,usec_per_call=2.76
cmdstat_llen:calls=4000114062,usec=6149847157,usec_per_call=1.54
cmdstat_select:calls=204877,usec=611360,usec_per_call=2.98
cmdstat_keys:calls=60,usec=670,usec_per_call=11.17
cmdstat_ping:calls=11280,usec=21837,usec_per_call=1.94
cmdstat_flushdb:calls=1,usec=20,usec_per_call=20.00
cmdstat_flushall:calls=6,usec=112562,usec_per_call=18760.33
cmdstat_info:calls=34358,usec=9994575,usec_per_call=290.90
cmdstat_config:calls=2,usec=3725,usec_per_call=1862.50

 Server
redis_version:2.6.4
redis_git_sha1:00000000
redis_git_dirty:0
redis_mode:standalone
os:Linux 2.6.32-279.el6.x86_64 x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:4.4.6
process_id:9104
run_id:93adecd72677613e50e2c33b821201db5853d765
tcp_port:6380

uptime_in_seconds:859434
uptime_in_days:9
lru_clock:1262516

# Clients
connected_clients:1399
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:45

# Memory
used_memory:53738000
used_memory_human:51.25M
used_memory_rss:24829952

used_memory_peak:18280394728
used_memory_peak_human:17.02G
used_memory_lua:31744

mem_fragmentation_ratio:0.46

mem_allocator:jemalloc-3.0.0

# Persistence
loading:0

rdb_changes_since_last_save:258645679

rdb_bgsave_in_progress:0
rdb_last_save_time:1353943008
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

# Stats

total_connections_received:247760
total_commands_processed:4318817993
instantaneous_ops_per_sec:62811

rejected_connections:0
expired_keys:0
evicted_keys:0

keyspace_hits:936468
keyspace_misses:4000672408

pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0

# Replication
role:master
connected_slaves:0

# CPU

used_cpu_sys:108977.48
used_cpu_user:21918.19

used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Keyspace
db2:keys=2,expires=0

SLOWLOG get 50


 9) 1) (integer) 91
    2) (integer) 1354542263
    3) (integer) 12746
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL16972841L\nsS'html'\np4\nS'x^\\xec\\xbdk{\\xdb\\xb8\\xae0\\xfa}\\xfd\\n\\xd7yw\\xc7\\x9e\\xc8\\x8a... (135928 more bytes)"
10) 1) (integer) 90
    2) (integer) 1354541106
    3) (integer) 15391
    4) 1) "INFO"
11) 1) (integer) 89
    2) (integer) 1354536990
    3) (integer) 11119
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\nNsS'old'\np3\nI00\nsS'city_id'\np4\nL16875L\nsS'keyword_name'\np5\nVregelgetriebe paderborn\np6\nsS'status_table'\np7\nS'... (218 more bytes)"
12) 1) (integer) 88
    2) (integer) 1354532517
    3) (integer) 10644
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\nNsS'old'\np3\nS'no'\np4\nsS'city_id'\np5\nI0\nsS'keyword_name'\np6\nVbahnhof stuttgart\np7\nsS'status_table'\np8\nS'status... (211 more bytes)"
13) 1) (integer) 87
    2) (integer) 1354373440
    3) (integer) 10279
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\n(lp3\n(icookielib\nCookie\np4\n(dp5\nS'comment'\np6\nNsS'domain'\np7\nS'.google.de'\np8\nsS'secure'\np9\nI00\nsS'expires'\np... (1081 more bytes)"
14) 1) (integer) 86
    2) (integer) 1354330870
    3) (integer) 10378
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
15) 1) (integer) 85
    2) (integer) 1354286396
    3) (integer) 29047
    4) 1) "FLUSHALL"
16) 1) (integer) 84
    2) (integer) 1354274784
    3) (integer) 71798
    4) 1) "FLUSHALL"
17) 1) (integer) 83
    2) (integer) 1354078565
    3) (integer) 23793
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
18) 1) (integer) 82
    2) (integer) 1354040025
    3) (integer) 10782
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL15256481L\nsS'html'\np4\nS'x^\\xec}\\xd9z\\xdbF\\xd6\\xe0}\\x9e\\x02\\xa6\\xba\\x152\\x02!\\xaeZH... (114406 more bytes)"
19) 1) (integer) 81
    2) (integer) 1354022582
    3) (integer) 11376
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
20) 1) (integer) 80
    2) (integer) 1354014766
    3) (integer) 10275
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
21) 1) (integer) 79
    2) (integer) 1354011335
    3) (integer) 11118
    4) 1) "LPOP"
       2) "hotqueue:result_de"
22) 1) (integer) 78
    2) (integer) 1354010702
    3) (integer) 25616
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
23) 1) (integer) 77
    2) (integer) 1354010513
    3) (integer) 11421
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL14179230L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xc6\\xd28x\\x9f\\xa7\\x80\\xa9\\xf3)d\\x04B\\x... (185711 more bytes)"
24) 1) (integer) 76
    2) (integer) 1354010337
    3) (integer) 10518
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
25) 1) (integer) 75
    2) (integer) 1354009852
    3) (integer) 73186
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
26) 1) (integer) 74
    2) (integer) 1354009742
    3) (integer) 10321
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\n(lp3\n(icookielib\nCookie\np4\n(dp5\nS'comment'\np6\nNsS'domain'\np7\nS'.google.de'\np8\nsS'secure'\np9\nI00\nsS'expires'\np... (1097 more bytes)"
27) 1) (integer) 73
    2) (integer) 1354009390
    3) (integer) 12110
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL14135390L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xb8\\xd28x\\xdfO\\xc1\\xc8\\xe7sKm\\x8a\\xd6\\... (123025 more bytes)"
28) 1) (integer) 72
    2) (integer) 1354008839
    3) (integer) 10839
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\n(lp3\n(icookielib\nCookie\np4\n(dp5\nS'comment'\np6\nNsS'domain'\np7\nS'.google.de'\np8\nsS'secure'\np9\nI00\nsS'expires'\np... (1090 more bytes)"
29) 1) (integer) 71
    2) (integer) 1354005648
    3) (integer) 10232
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL14043753L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xb8\\xd28x\\x9f\\xa7`\\xe4\\xf3\\xb9\\xa56Ek\\... (183763 more bytes)"
30) 1) (integer) 70
    2) (integer) 1354003696
    3) (integer) 11200
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
31) 1) (integer) 69
    2) (integer) 1354003677
    3) (integer) 15102
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL14004948L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdbF\\xf20z\\x9f\\xa7\\x80\\xa9\\x19\\x85\\x1c\\x81... (116263 more bytes)"
32) 1) (integer) 68
    2) (integer) 1353999969
    3) (integer) 11922
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13928456L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9z\\xdb\\xc6\\xd2(z\\x9f\\xa7\\x80\\xa9,\\x85\\x8c@\\x0... (108908 more bytes)"
33) 1) (integer) 67
    2) (integer) 1353998190
    3) (integer) 11542
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13887717L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xc6\\xd28x\\x9f\\xa7\\x80\\xa9\\xf3)d\\x04B\\\\... (130370 more bytes)"
34) 1) (integer) 66
    2) (integer) 1353998026
    3) (integer) 35602
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13882977L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9z\\xdb\\xc6\\xd2(z\\x9f\\xa7\\x80\\xa9\\xb5\\x142\\x02... (124321 more bytes)"
35) 1) (integer) 65
    2) (integer) 1353997625
    3) (integer) 10085
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
36) 1) (integer) 64
    2) (integer) 1353997310
    3) (integer) 15691
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
37) 1) (integer) 63
    2) (integer) 1353992901
    3) (integer) 11572
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13692110L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xc6\\xd28x\\x9f\\xa7\\x80\\xa9\\xf3)d\\x04B\\x... (135060 more bytes)"
38) 1) (integer) 62
    2) (integer) 1353992211
    3) (integer) 10877
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13665739L\nsS'html'\np4\nS'x^\\xec}\\xd9z\\xdbF\\xd6\\xe0}\\x9e\\x02\\xa6\\xba\\x152\\x02!p\\xd3B... (114240 more bytes)"
39) 1) (integer) 61
    2) (integer) 1353991587
    3) (integer) 13873
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
40) 1) (integer) 60
    2) (integer) 1353991216
    3) (integer) 17919
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13626236L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xb8\\xd28x\\x9f\\xa7`\\xe4\\xf3\\xb9\\xa56ES\\... (117866 more bytes)"
41) 1) (integer) 59
    2) (integer) 1353991064
    3) (integer) 85877
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13619958L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9z\\xdbH\\xd2(x_O\\x01S\\xdd*\\xb2\\x04B\\xe0\\xa6\\x8... (113555 more bytes)"
42) 1) (integer) 58
    2) (integer) 1353990954
    3) (integer) 13004
    4) 1) "RPUSH"
       2) "hotqueue:crawl_queue_de"
       3) "(dp1\nS'cookies'\np2\n(lp3\n(icookielib\nCookie\np4\n(dp5\nS'comment'\np6\nNsS'domain'\np7\nS'.google.de'\np8\nsS'secure'\np9\nI00\nsS'expires'\np... (1094 more bytes)"
43) 1) (integer) 57
    2) (integer) 1353990317
    3) (integer) 15015
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
44) 1) (integer) 56
    2) (integer) 1353989956
    3) (integer) 37957
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
45) 1) (integer) 55
    2) (integer) 1353988344
    3) (integer) 14506
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13512257L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9~\\xdb\\xc6\\xd28x\\x9f\\xa7\\x80\\xa9\\xf3)d\\x04B\\\\... (112998 more bytes)"
46) 1) (integer) 54
    2) (integer) 1353987845
    3) (integer) 15176
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13493211L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9z\\xdb\\xc6\\xd2(z\\x9f\\xa7\\x80\\xa9,\\x85\\x8c@\\x0... (114518 more bytes)"
47) 1) (integer) 53
    2) (integer) 1353987480
    3) (integer) 11729
    4) 1) "LPOP"
       2) "hotqueue:crawl_queue_de"
48) 1) (integer) 52
    2) (integer) 1353987358
    3) (integer) 10311
    4) 1) "BLPOP"
       2) "hotqueue:result_de"
       3) "0"
49) 1) (integer) 51
    2) (integer) 1353987117
    3) (integer) 10128
    4) 1) "RPUSH"
       2) "hotqueue:result_de"
       3) "(dp1\nS'city_id'\np2\nL16875L\nsS'keyword_id'\np3\nL13464408L\nsS'html'\np4\nS'x^\\xec\\xbd\\xd9z\\xdb\\xc6\\xd2(z\\x9f\\xa7\\x80\\xa9\\xb5\\x142\\x02... (115433 more bytes)"
50) 1) (integer) 50
    2) (integer) 1353986597
    3) (integer) 10088
    4) 1) "LPOP"


As I can see there are a lot of RPUSH slow.

The strange thing is that I am doing the same thing for days and this only happens randomly sometimes per day.

[G]

Ps. The above are with cpu 99%

[Josiah Carlson]

Looking at your slowlog, those commands aren't executing slow all the
time. Basically, about every 5-15 minutes, an RPUSH of 100-140k (or
even 1k) takes 10-15ms to execute.

At this particular point in time, Redis is processing 62k commands per
second, and you have almost 1400 clients connected.

My guess:
1. You are moving a lot of data in/out of Redis.
2. There is some sort of network hiccup, your OS doesn't schedule
Redis, you max out your network bandwidth, or something else (do you
have any cron jobs running on your Redis server?), and connections
hang (from the perspective of the remote client).
3. If your client has a timeout, your clients will automatically
reconnect on hang (that's part of how the Python Redis libraries
work), causing the spike in connections.
4. If your client doesn't have a timeout, failure to receive data from
a TCP connection (due to network hiccup, maxed out network bandwidth,
etc.) will cause reads to fail, also causing a reconnect.
5. Just because one end of a connection thinks that a socket is
closed, doesn't mean Redis does, which can cause Redis to continue
trying to send data to connections, causing your network continued
saturation.
6. The nasty thing about network saturation is that as long as a
connection can get even 1 packet out on the network, sockets will be
seen as writable to the OS, until TCP's congestion control cuts in and
restricts them. At the same time, all of those connections will also
still be readable.

Also, if you are on a virtual machine, that could be causing your hiccups.

Conclusion:
Check your Network IO volume, and check top's interrupt usage.

Regards,
- Josiah

On Thu, Dec 6, 2012 at 6:06 AM, G <g...@alpha9marketing.com> wrote:
> Ps. The above are with cpu 99%
>

> --
> You received this message because you are subscribed to the Google Groups
> "Redis DB" group.
> To view this discussion on the web visit

> https://groups.google.com/d/msg/redis-db/-/PiLydPl62EEJ.

[G]

Thanks ,

this is what I am suspecting.
I also have a Mysql Server on this machine,
I noticed that the redis clients increase when the InnoDB Transactions of mysql go high.

Is it "allowed" to have redis to the same host as mysql?

Thanks

[Felix Gallo]

Redis on the same host as mysql, no problem!  As long as they're not competing for resources like cores, RAM, memory or network bandwidth.  Why, then you might start experiencing correlated periods of performance starvation, and you wouldn't want that.

F.

To view this discussion on the web visit https://groups.google.com/d/msg/redis-db/-/m1Hq93P4YMgJ.

[G]

To group administrator:

By mistake I pasted the url from Munin (see below: InnoDb Transactions).

Because you can see the hostname of a database can you please remove the Url?

I would be glad if you did.

Thanks ,
Giorgos

[Javier Guerra Giraldez]

On Fri, Dec 7, 2012 at 5:09 AM, G <g...@alpha9marketing.com> wrote:
> Because you can see the hostname of a database can you please remove the
> Url?

remember that many of us (myself included) get this group's posting as
email. now your gaffe is copied in my inbox and countless others and
there's nothing any group administrator can do to fix that.

I'd advise you to tighten security on that DB server so that
publishing its hostname is meaningless for any hypothetical attacker.

--
Javier