Redis latency spikes and the Linux kernel: a few more details (opens in new tab)

Unfortunately I just spotted that I'm totally wrong, the huge pages apparently are only used by jemalloc: I just mis-read the outputs since this seemed so obvious. So on the contrary, it appears that the high latency is due to the huge pages thing for some unknown reason. So actually it is malloc that, while NOT using huge pages, is going much faster. I've no idea about what is happening here, so please disregard the blog posts conclusions (all the rest is hopefully correct).

EDIT: Oh wait... since the problem is huge pages, this is MUCH better, since we can disable it. And I just verified that it works:

echo never > /sys/kernel/mm/transparent_hugepage/enabled

This means, free latency upgrade for all the Redis users out there during fork... (more or less 20x in my tests) just with this line above.

Dumb question - if problem is a latency spike in the parent, any chance you can continue serving in the child and let the parent do the BGSAVE (and take the latency spike)?

(The child should be able to inherit all open fds?)

Pardon my ignorance - but isn't this a problem that's existed in database software in general, and one that's been dealt with in the past?

This seems to be a similar problem to how to do replication while also serving requests - on one side you want to preserve consistency, on the other side you want to make a full snapshot. It shouldn't matter how long the replication process takes (i.e. how slow fork is), seconds or days, as long as the incoming changes aren't faster than the replication rate. In this case though, your replication target is the disk.

It seems like there should never have to be a full lock of everything.

Your jemalloc case is using 1564672 kB, this means you only have 764 hugepages. Since the RAM access patterns in the parent process are random, you only need ~1000 accesses to trigger multiple COW (copy-on-write) totaling most of the ~1.5GB. redis-benchmark simulates 50 clients by default and you use a pipelining factor of 4, so you have 200 in-flight requests at any one time. I am not familiar with how the redis server prioritizes the requests to be served, but if it is like most network servers it is not deterministic (whatever comes first from the network event loop). So while on average a request may wait for 200 other ones to be served, a small fraction of them will have to wait longer because of this non-deterministic factor. It is not unimaginable that some have to wait for 500, maybe 1000 other requests. Waiting for 1000 requests means waiting for a COW of most of the ~1.5GB which would take a few hundred milliseconds and would absolutely explain your latency spike.

On the other hand your malloc case is using 4kB pages. If a request has to wait for 1000 other in-flight requests to be executed, that means waiting for at most 1000 pages (4MB) to be COW'd, which would take on the order of 0.1-1.0 milliseconds. This is why the latency is much lower.

tl;dr: smaller pages (4kB vs 2MB) allow finer granularity of the COW mechanism, and lead to lower latencies.

I find the back-and-forth ("<this is wrong>", "EDIT", "<wrong advice>"...) to be quite interesting and instructive, better than just editing the whole post with the 'correct' explanation and workaround. Thanks for that!

This is why open-source software is so rad. I suspect that you'd never see an Oracle customer complaining publicly and then an Oracle engineer publicly tracking down the source of their complaints.

PTE = Page Table Entry

I had a similar transparent huge pages issues some time back -- the symptoms were incomprehensible spikes in CPU usage sometimes. Apparently this had something to do with memory allocation pressure when my Python processes restarted. However I thought these were perhaps weird power throttling issues which meant CPU was performing at a lower performance (explaining why a normal startup took 1 cpu minute instead of 0:10 seconds).

I should have spotted this by looking at the split between user and system CPU: when the THP problem happened SYS% spiked, but I was looking at a dozen processes pegged at 100% CPU.

I eventually tracked this down via "perf top" which lets you see what everything on the system is doing: both kernel and user space symbols are tracked. I saw significant kernel-space work in an odd memory-related symbol and found someone else with the same problem.

I'm having trouble figuring out how to disable transparent hugepages without a reboot:

  ># uname -a
  Linux ip-10-214-7-159 3.2.0-36-virtual #57-Ubuntu SMP Tue Jan 8 22:04:49 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

  ># grep TRANSPARENT /boot/config-3.2.0-36-virtual
  CONFIG_TRANSPARENT_HUGEPAGE=y
  # CONFIG_TRANSPARENT_HUGEPAGE_ALWAYS is not set
  CONFIG_TRANSPARENT_HUGEPAGE_MADVISE=y

  ># echo never > /sys/kernel/mm/transparent_hugepage/enabled
  bash: /sys/kernel/mm/transparent_hugepage/enabled: No such file or directory