Hikaricp: High CPU usage when there are lots of pending connection pool requests

[wvuong]

Environment

HikariCP version: 2.6.0
JDK version     : 1.8.0_40-b26
Database        : Oracle
Driver version  : 11.2.0.3.0

---

Hi,

We've recently upgraded to 2.6.0 from 2.4.7 and noticed that when our pool saturates and requests start to queue up, then our app CPU usage spikes pretty high (from 10%-15% to 90%). We've traced it back to this change (https://github.com/brettwooldridge/HikariCP/commit/f0b3c520c9d8f5cce3ff04b811165ec61d9ef364#diff-0dac8ca2574085e5192a8188ca22d42eR181) in 2.6.0 where the ConcurrentBag implementation has a yield() that causes a tight spin loop that will eat CPU until either a timeout or a connection is handed off. In our case, all of our pending threads spinned and ate CPU until the timeout whilst slowing down the application recovery and GC. The app went into a death spiral until it recovered. Our application is very high traffic and dropped requests are not good. We are going to revert back to 2.4.7 to be safe.

Is this something that can be looked at again? We're thinking that:

1. The ConcurrentBag could spin for a bit but then block or sleep until a handoff or timeout. I suppose this could be configurable.
2. Or, if the API could be modified so that we could provide our own ConcurrentBag implementation.

Interested in your thoughts. Thanks!

[brettwooldridge]

Would you mind cloning the repo and trying 2.6.1-SNAPSHOT? Building is easy: mvn package. The jar will be in the target subdirectory.

EDIT: v2.6.1-SNAPSHOT contains a change to reduce "barging" of active threads over waiting threads. We actually have a better fix in mind, but would like to test it more before committing it.

[brettwooldridge]

Snapshot JAR available here. Can you test it can give us feedback as to whether the CPU usage declines?

[wvuong]

Thanks, we'll give it a try on Monday or Tuesday. We'll try a load test to reproduce it on 2.6.0 and then rerun on 2.6.1 to see what happens.

[wvuong]

FYI, here are some profiler snapshots during peak load this past week with 2.6.0 in production:

[johnou]

@wvuong how's 2.6.1.SNAPSHOT look?

[brettwooldridge]

@wvuong We are holding the 2.6.1 release pending the results of your load testing. Any results that you can share?

[wvuong]

Hi all, I've been working on it when I can. I can't do this with live bullets in production, of course. :) I spent some time yesterday trying to construct an artificial test to resurface the CPU issue. I'll spend some time today working on it too.

[wvuong]

Did some testing. 2.6.1 is a bit better overall than 2.6.0 (didn't have time tonight to use 2.4.x as my baseline). I can't say definitively that it solved our problem without real production loads but it looks like a good step in that direction. Thanks all!

[brettwooldridge]

@wvuong I have deployed a new snapshot, available at the same download link as that above.

Here is a brief description of the change.

In v2.6.0 the code in ConcurrentBag.requite() looked like this (basically):

public void requite(final T bagEntry) {
   bagEntry.setState(STATE_NOT_IN_USE);

   while (waiters.get() > 0) {
      if (handoffQueue.offer(bagEntry)) {
         return;
      }
      yield();
   }
   ...

First, the bagEntry is set as not-in-use. Then, as long as there are any threads waiting in borrow(), the requiting thread attempts a direct hand-off, and spins until it is successful.

Several observations on this approach and its problems:

1. As soon as the bagEntry is marked not-in-use, it can be claimed by a borrowing thread even before that thread reaches the handoffQueue.poll(). This is because borrowing threads first scan the pool for a not-in-use entry, before entering the poll(). This turns out to be far more efficient under load (on the borrow() side).
2. If that occurs often under load, the requiting thread "never" makes a successful offer, and keeps spinning. Worse, it continues to spin even if the bagEntry it was returning is claimed. "Never" is used here figuratively, in reality it is likely tens or hundreds of microseconds, but the thread is consuming CPU during that time.
3. The loop is exited under one of two conditions. One, the number of waiting threads hits zero. Or two, the requiting thread successfully makes an offer.
4. Another downside is, if the bagEntry was claimed by a scan of a borrowing thread, the requiting thread will eventually hand-off the bagEntry which is now marked as in-use, and whatever borrowing thread received it simply discards it and waits longer. In this case, all of the spinning was simply wasted effort.

In v2.6.1 the code was changed as follows:

public void requite(final T bagEntry) {
   bagEntry.setState(STATE_NOT_IN_USE);

   for (int i = 0; waiters.get() > 0; i++) {
      if (bagEntry.getState() != STATE_NOT_IN_USE || handoffQueue.offer(bagEntry)) {
         return;
      }
      else if ((i & 0x100) == 0x100) {
         parkNanos(MICROSECONDS.toNanos(10));
      }
      else {
         yield();
      }
   }
   ...

This code improves the efficiency in several ways:

1. If a borrowing thread acquires the bagEntry during its scan of the pool, before entering its own handoffQueue.poll(), then the requiting thread will exit the loop because the state of the bagEntry transitions from not-in-use to in-use.
2. Every 256 iterations, the requiting thread will enter a 10 microsecond sleep. In CPU-time, a 10 microsecond sleep is an eternity, during which several million instructions can execute on modern hardware. Additionally, unlike yield() which is a hint to the scheduler (heeded or not), the parkNanos() call will unconditionally de-schedule the thread.

I would expect this change to result in a fairly substantial decrease in CPU consumption when the pool is over-saturated.

[johnou]

@brettwooldridge good for release or still working on the "better" fix?

[brettwooldridge]

@johnou HikariCP v2.6.1 has been published.

[johnou]

@brettwooldridge thanks!

[johnou]

@brettwooldridge problems with the release?

[brettwooldridge]

@johnou Should be there now. Takes a while for Sonatype to process sometimes.

[johnou]

@brettwooldridge for Java 9 https://docs.oracle.com/javase/9/docs/api/java/lang/Thread.html#onSpinWait-- might make more sense?

[brettwooldridge]

It is certainly a possibility for Java 11, neither Java 9 nor Java 10 are LTS releases.

[mayras]

This issue is still presented, any fix for that?