Re: High System CPU Usage

[Salvatore Sanfilippo]

Hello, at 35k ops/sec on EC2 you are likely saturating the CPU of the
instance without particular reasons if not the 35k figure :-)

In order to reduce the CPU usage you can use pipelining
(http://redis.io/topics/pipelining) or try to avoid
creating/destroying connections if it is practical in your
application.
Another useful thing is actually the output of INFO commandstats,
please could you send it here? Thanks.

Salvatore

On Thu, May 30, 2013 at 12:09 AM, Zach Bailey <zach....@pardot.com> wrote:
> Hi all,
>
> Any tips on diagnosing high redis system CPU usage?
>
> https://s3.amazonaws.com/uploads.hipchat.com/45727/306015/5o9gflh5hyj5aew/Screen%20Shot%202013-05-29%20at%205.03.37%20PM.png
>
> This redis instance is sustaining about 35k ops/sec based on
> instantaneous_ops_per_sec in INFO.
>
> What are the main culprits of system CPU usage? Connection establishment and
> management?
>
> What other information can I get that would help diagnose this issue? Here's
> the output of INFO:
>
> $ redis-cli -h redis-s1 info
>
> # Server
>
> redis_version:2.6.7
>
> redis_git_sha1:00000000
>
> redis_git_dirty:0
>
> redis_mode:standalone
>
> os:Linux 2.6.18-308.13.1.el5 x86_64
>
> arch_bits:64
>
> multiplexing_api:epoll
>
> gcc_version:4.1.2
>
> process_id:8426
>
> run_id:648f38dfa2ad648515adc59dee79dc89d6e77294
>
> tcp_port:6379
>
> uptime_in_seconds:3026758
>
> uptime_in_days:35
>
> lru_clock:671643
>
>
> # Clients
>
> connected_clients:9463
>
> client_longest_output_list:0
>
> client_biggest_input_buf:0
>
> blocked_clients:0
>
>
> # Memory
>
> used_memory:401919616
>
> used_memory_human:383.30M
>
> used_memory_rss:196673536
>
> used_memory_peak:884152040
>
> used_memory_peak_human:843.19M
>
> used_memory_lua:31744
>
> mem_fragmentation_ratio:0.49
>
> mem_allocator:jemalloc-3.2.0
>
>
> # Persistence
>
> loading:0
>
> rdb_changes_since_last_save:79685
>
> rdb_bgsave_in_progress:0
>
> rdb_last_save_time:1369865179
>
> rdb_last_bgsave_status:ok
>
> rdb_last_bgsave_time_sec:0
>
> 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:946110506
>
> total_commands_processed:12402136005
>
> instantaneous_ops_per_sec:38644
>
> rejected_connections:93544
>
> expired_keys:7438733
>
> evicted_keys:0
>
> keyspace_hits:9838358834
>
> keyspace_misses:32820668
>
> pubsub_channels:0
>
> pubsub_patterns:0
>
> latest_fork_usec:12261
>
>
> # Replication
>
> role:master
>
> connected_slaves:1
>
> slave0:10.21.240.229,6379,online
>
>
> # CPU
>
> used_cpu_sys:203242.38
>
> used_cpu_user:645112.38
>
> used_cpu_sys_children:1254.68
>
> used_cpu_user_children:2639.51
>
>
> # Keyspace
>
> db0:keys=139,expires=139
>
> db11:keys=72,expires=72
>
> db12:keys=3085,expires=3085
>
> db15:keys=9,expires=0
>
> Thanks so much in advance for any help anyone is able to provide!
>
> -Zach
>
> --
> 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?hl=en.
> For more options, visit https://groups.google.com/groups/opt_out.
>
>



--
Salvatore 'antirez' Sanfilippo
open source developer - GoPivotal
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

[Salvatore Sanfilippo]

p.s. however note that you are using a single CPU. So if you run 4
Redis instances and modify your app to split keys evenly across them,
you can add a lot of capacity without more costs.

[Yiftach Shoolman]

And the output of your slowlog ...

On Thu, May 30, 2013 at 9:59 AM, Salvatore Sanfilippo <ant...@gmail.com> wrote:

--

Yiftach Shoolman
+972-54-7634621

[Zach Bailey]

Thanks, antirez and Yiftach.

@antirez - we're running bare metal (E5430 @ 2.66GHz), how much more performance should we expect over EC2? I agree that we are probably close to hitting our max ops without pipelining, etc. We're definitely looking at hashing out our keys across multiple instances as we continue to grow our usage of redis!

The main thing I was wondering was the high system CPU usage - could this be due to connection management overhead or spending a lot of time in the kernel sending data to clients? Are there any options for optimizing things there?

@Yiftach SLOWLOG looks like:

 1) 1) (integer) 22

    2) (integer) 1369943502

    3) (integer) 24067

    4) 1) "INFO"

 2) 1) (integer) 21

    2) (integer) 1369863001

    3) (integer) 10032

    4) 1) "INFO"

 3) 1) (integer) 20

    2) (integer) 1369857697

    3) (integer) 15720

    4) 1) "INFO"

 4) 1) (integer) 19

    2) (integer) 1369853745

    3) (integer) 24976

    4) 1) "GET"

       2) "disable_AutomationQueueBroker"

 5) 1) (integer) 18

    2) (integer) 1369849981

    3) (integer) 37818

    4) 1) "INFO"

 6) 1) (integer) 17

    2) (integer) 1369849327

    3) (integer) 28039

    4) 1) "INFO"

 7) 1) (integer) 16

    2) (integer) 1368612630

    3) (integer) 20949

    4) 1) "INFO"

 8) 1) (integer) 15

    2) (integer) 1368575152

    3) (integer) 14473

    4) 1) "INFO"

 9) 1) (integer) 14

    2) (integer) 1368482649

    3) (integer) 18967

    4) 1) "INFO"

10) 1) (integer) 13

    2) (integer) 1368143804

    3) (integer) 13559

    4) 1) "INFO"

Overall I'd say only 22 entries in the slowlog over 35+ days of uptime means we're not having any problems there - am I reading that right? Though I don't understand why there's is a GET in there that took almost 25 milliseconds...

[Greg Andrews]

A couple of things in your INFO output:

    uptime_in_seconds:3026758

    total_connections_received:946110506

So in 3 million seconds since the process was started, it has received 946 million connections.  Are your clients and slaves really averaging 900 connections per second to this Redis process?

  -Greg 

[Zach Bailey]

Yep, it looks like we're averaging around 312 connections per second. That seems a little overboard! Definitely a good place to start looking at improving things on the client side.

-Zach

--
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/bI9_lpjvdfY/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to redis-db+u...@googlegroups.com.

[Josiah Carlson]

*cough* Connection pooling and pipelining *cough*

On localhost-only connections, using a single client, I see a 2x improvement in performance reusing connections vs. recycling connections. On remote connections, I see closer to 3-5x increases in net performance. Adding properly sized pipelining (where you batch multiple commands together, with or without MULTI/EXEC), I see another 2-10x, depending on the operations. What does all of that that get me? Benchmarking at just about 1 million get/set ops/second using a single Redis server process on a core-2 Duo running at 2.4 ghz. That shakes closer to 400k-500k get/set ops/second without major effort except proper connection pooling and pipelining - no TCP tuning, kernel tuning, or otherwise.

 - Josiah

[George Chilumbu]

I would like to inquire about my average connections per second and if our values are normal or abnormal?

Redis-1-1

uptime_in_seconds:3354431

total_connections_received:217735422

Findings: Redis-1-1 is averaging about 64 connections per second

Redis-1-2

uptime_in_seconds:3444551

total_connections_received:319811076

Findings: Redis-1-2 is averaging about 92 connections per second

Redis-2-1

uptime_in_seconds:3442432

total_connections_received:78116430

Findings: Redis-2-1 is avaraging about 22 connections per second

Redis-2-2

uptime_in_seconds:4049111

total_connections_received:786943733

FIndings: Redis-2-2 is averaging about 194 connections per second

 redis-3-1 

 uptime_in_seconds:3436857

 total_connections_received=247145780

 Findings: Redis 3-1 is averaging about 71 connections per second

 Redis-3-2

 uptime_in_seconds:326421

 total_connections_received:508049

 Findings: Redis-3-2 averaging about 1 connection per second

So with the exception of redis-3-2, are the numbers for ave connections per second ok? What is acceptable when dealing with connections per second?

FYI, i am running a Redis cluster of 3 masters and 3 slaves, version 3.2.0. The slaves are read only. Each redis instance in the cluster has 64GB RAM, and 80% of if committed to axmemory;

Below is my redis.conf config:

activerehashing yes

aof-load-truncated yes

aof-rewrite-incremental-fsync yes

appendfilename "appendonly.aof"

appendfsync everysec

appendonly no

auto-aof-rewrite-min-size 64mb

auto-aof-rewrite-percentage 100

bind 0.0.0.0

client-output-buffer-limit normal 0 0 0

client-output-buffer-limit pubsub 32mb 8mb 60

client-output-buffer-limit slave 512mb 512mb 0

cluster-config-file "node.conf"

cluster-enabled yes

cluster-node-timeout 15000

cluster-require-full-coverage no

cluster-slave-validity-factor 0

daemonize yes

databases 16

dbfilename "dump.rdb"

dir "/srv/redis"

hash-max-ziplist-entries 512

hash-max-ziplist-value 64

hll-sparse-max-bytes 3000

hz 10

latency-monitor-threshold 0

list-max-ziplist-entries 512

list-max-ziplist-value 64

logfile /var/log/redis/redis-server.log

loglevel notice

lua-time-limit 5000

maxclients 1024000

maxmemory 52gb

maxmemory-policy allkeys-lru

min-slaves-max-lag 10

no-appendfsync-on-rewrite yes

notify-keyspace-events ""

pidfile /var/run/redis/redis-server.pid

port 6379

rdbchecksum yes

rdbcompression yes

repl-backlog-size 64mb

repl-backlog-ttl 0

repl-disable-tcp-nodelay no

repl-diskless-sync no

repl-diskless-sync-delay 5

repl-ping-slave-period 10

repl-timeout 360

save 3600 100000

set-max-intset-entries 512

slave-priority 100

slave-read-only yes

slave-serve-stale-data yes

slowlog-log-slower-than 1000000

slowlog-max-len 128

stop-writes-on-bgsave-error no

tcp-backlog 65535

tcp-keepalive 60

timeout 0

zset-max-ziplist-entries 128

zset-max-ziplist-value 64