Re: Two Servers, One high CPU usage, other minimal CPU usage?

[Dvir Volk]

why is their memory footprint so different? one has X7 the memory consumption on almost the same amount of keys.

sounds like you might have big lists or sets on one, that make it consume more CPU per query.

On Wed, Nov 14, 2012 at 11:30 AM, Kunjan Aggarwal <kunjan....@gmail.com> wrote:

I am using redis 2.4.10 server on two identical amazon ec-2 instances.
Both are handling same kind of load and have the same redis configuration ( attached).

While one server shows very low CPU usage:
  PID    PR  NI  VIRT   RES  SHR S %CPU %MEM    TIME+  COMMAND           
31063   20   0  159m  100m  924  S  0.0          2.7   13:54.86  redis-server      
31064   20   0  159m  100m  924  S  0.0          2.7    0:00.00   redis-server      
31065   20   0  159m  100m  924  S  0.0          2.7    0:00.00   redis-server

The other server is constantly using CPU heavily:
  PID  PR  NI  VIRT    RES   SHR S  %CPU %MEM    TIME+  COMMAND           
25142  20   0  751m   719m  908  S  50.9      19.2    1391:02  redis-server      
25143  20   0  751m   719m  908  S   0.0       19.2    0:00.00   redis-server      
25144  20   0  751m   719m  908  S   0.0       19.2    0:00.00   redis-server

I have attached the output from redis-cli info for both the servers.

Please suggest what could be the possible reasons for such high resource usage by one of the servers?

--
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/-/wPn0wFincKcJ.
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.

--

Dvir Volk

Chief Architect, Everything.me

http://everything.me 

[Greg Andrews]

I noticed that although the two processes had been running for similar lengths of time (12 days vs 14 days), there was a huge difference visible in a couple of parts of the info outputs.  The first part is near the top:

Low cpu usage machine:

  used_cpu_sys:647.58
  used_cpu_user:187.06
  used_cpu_sys_children:86.12
  used_cpu_user_children:384.26

High cpu usage machine:

  used_cpu_sys:83170.52
  used_cpu_user:153.97
  used_cpu_sys_children:13901.79
  used_cpu_user_children:56.93

The used_cpu_user numbers (the second line in each group) are very similar, but the used_cpu_sys numbers (first line) are vastly different.  The used_cpu_sys_children lines also show a big difference.  This tells us the Redis instance that's using so much more cpu is using it in system calls, not in its own processing of commands and reading/writing its database.

The second part is farther down the info output:

Low cpu usage machine:

  changes_since_last_save:533
  bgsave_in_progress:0
  last_save_time:1351778560

High cpu usage machine:

  changes_since_last_save:1528127

  bgsave_in_progress:1
  last_save_time:1351778560

The last_save_time in the low cpu instance was within the past 24 hours.  In the high cpu instance, it was about 2 weeks ago, and when you took your info output, the instance was in the middle of trying to perform a save.  The many days since the last successful save can account for the large number in the changes_since_last_save on the high cpu instance.

When I compare the two groups of lines above, I think your high cpu instance is having trouble performing background saves to disk, while your low cpu instance is not.  The last_save_time suggests that the high cpu instance has not been able to save at all for two weeks.  The Redis logfile should have complaints about background saves.

Why would the two EC2 virtual servers be different when it comes to saving data to disk?  I don't know.  You'll have to compare their configurations and other workloads running on them to see.

Hope this helps,

  -Greg

[Greg Andrews]

Oops, I bungled my copy and paste of the last_save_time lines.  Here is the difference I was talking about:

Low cpu instance:

  last_save_time:1352879890

High cpu instance:

  last_save_time:1351778560

The low cpu instance's last save time was around 24 hours ago, but the high cpu instance's save time was almost 2 weeks ago.


  -Greg

[Tim Lossen]

so maybe the high cpu instance cannot save to disk any more due to something like file permissions, or disk space?

--
http://tim.lossen.de

[Greg Andrews]

A permissions error should show up quickly in the process, so I wouldn't expect it to accumulate system cpu.  When I imagine the virtual server having free disk space at the start of a save, but running out of space in the middle, I think it could cause similar patterns in the child processes system cpu usage.  Maybe the main process too.

The main discrepancies in the info output seem to be the system cpu and the time since the last successful save[1], so I think they're connected to the cause.  Enabling the Redis logfile and/or monitoring the virtual server's ram and disk will probably reveal more clues.

  -Greg

[1] Dvir pointed out a 7x difference in memory usage, but I have a theory that might be caused by temporary copy-on-write inflation because the Redis instance was in the middle of a save.

[Josiah Carlson]

I've had a machine running Redis run out of disk.

The process forks, tries to write, fails, then tries again. My CPU
usage looked *exactly* like what the OP reported. Also, the
preponderance of evidence (last save time, number of unsaved changes
since last save, etc.) says that something is stopping the child
process from finishing the snapshot.

- Josiah

[Kunjan Aggarwal]

Thanks for the wonderful observations.
I noticed that in the redis server config, field "dir" has no value associated with it.

Could this be the reason that db is not getting saved or does it save at some default location?
Also would it impact the currently runnig redis server if I set the "dir" field while the redis server is running using "CONFIG SET" ?

[Josiah Carlson]

The default path is, I believe, the current working directory
(whatever that was when Redis was started, maybe check your init.d
script).

You can always try to set the directory with 'config set dir ...', the
worst that could happen is that it not work :P

If you do a 'sudo updatedb', you should be able to find the location
of the existing snapshot, which will then let you discover why it
stopped saving.

Regards,
- Josiah

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

[Kunjan Aggarwal]

Thanks a ton.
After setting the field 'dir' the CPU usage has drastically gone down, in fact its almost 0.

Thanks again to all of you.