Cache Workers getting stuck?

I saw this problem in version 2.3.1, via VisualVm, when after a few hours that a bunch of ForkJoinWorkers would be stuck on the WriteBuffer.poll() function in RUNNABLE state. Even hit an OOM when the cpu utilization became too high and my events started to get backed up. I recently upgraded to 2.3.3 and thought the problem was fixed until the below screenshots.

When I started up the application (10/19, 7:34 am) there is one FJW in the writebuffer.poll, which is fine.

This morning (10/20, 9:34am) and this is in constant RUNNABLE state. The number of workers that will be in this stuck runnable state will slowly grow over time too because I have seen this behavior happen with 2.3.1.

The cpu utilization and cpu load metrics in Grafana support an overall increase work as if the workers are busy waiting/spinlooping or something.

There are maybe 1k or so instances of the cache data structure in the application. This server has the most instances of the cache and the issue appears to manifest faster than the other servers. All of the servers have a 64GB heap.

I will have to switch back to Guava considering this is a production application.

Thanks for your effort though!

[ben-manes]

Thanks for the detailed report. I'm sorry for the inconvenience this caused.

The previous challenges with the write buffer were around scheduling the task when it is being added. Some of that was due to a FJP bug, and then later mistakes when I tried to make the logic more robust. Despite a lot of effort put into testing, its hard to predict some of these concurrency bugs.

This case is different because only 1 thread (for a given cache) can poll the write buffer. This drains and replays the changes onto the eviction policy. That polls up to a maximum, so the spin loop causing the failure is inside the WriteBuffer. That's a stripped down version of JCTools' MpscChunkedArrayQueue.

I think the first step is try to reproduce the live lock, then re-sync with the latest JCTools version, and if broken then work with @nitsanw on a fix.

Thanks for acknowledging the issue! I hope you can reproduce it. If you need any more info, I'll try my best to help.

[ben-manes]

I probably won't have time until this weekend to dig in too much. I think that I can weaken JCTool's spin loop safely, because the element will be consumed on the next maintenance cycle. That is scheduled after the write buffer is appended to. So assuming the buffer isn't losing the element, it should be visible the next time around.

If you're able to reproduce it in a test case that would be very helpful. I'll try to adapt my Stresser to see if I can give @nitsanw a useful failure report.

[nitsanw]

@ben-manes "I think that I can weaken JCTool's spin loop safely, because the element will be consumed on the next maintenance cycle. That is scheduled after the write buffer is appended to. So assuming the buffer isn't losing the element, it should be visible the next time around." - this approach will not work. If producerIndex is not consumerIndex, and the consumer is not making progress then they cannot be equal on the next cycle, which brings you back to looking for the next element in the array, which is not there because if it was you'd not be stuck in that loop.

@normanuber Can you please quote the JVM version (java -version output) and OS? it's a long shot, but certain JVM builds have concurrency bugs and it's a variable that is easy to eliminate.

At a glance the code seems very similar to the original, I would have to diff line by line to verify. Is there absolutely no way that 2 different threads are acting as consumers?

[nitsanw]

@normanuber would you be able to run a hacked caffeine build to help narrow down the source of this issue?

[ben-manes]

The polling occurs in drainWriteBuffer() which is guarded by evictionLock. In addition to my own tests, static analysis performed by ErrorProne should be asserting this behavior. So only a single thread should be able to consume the write buffer.

@nitsanw

java -version
OpenJDK Runtime Environment (build 1.8.0_102-8u102-b14.1-1~bpo8+1-b14)
OpenJDK 64-Bit Server VM (build 25.102-b14, mixed mode)

lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description: Debian GNU/Linux 8.6 (jessie)
Release: 8.6
Codename: jessie

To answer your question, I suppose I can run a hacked build as long as it is through maven central (using SNAPSHOT versions is fine).

[ben-manes]

I created a SNAPSHOT version that adds jctools as a dependency and uses MpscChunkedArrayQueue directly. That should avoid any surprises if I incorrectly embedded the code. See the jctools branch for this commit.

While that is running on travis, I've manually pushed a new SNAPSHOT. The travis build will take about an hour to verify against the tests before releasing a snapshot.

[nitsanw]

@ben-manes Thanks!

[ben-manes]

@normanuber Since you are using a high number of caches (1,000) it might be good to quickly discuss the use-case. For example if these are per-request, quickly populated and discarded, it could lead to a pile-up of cache instances and async processing tasks scheduled. The concurrency and hit-rate focus of this cache leads to a design towards long lasting instances with high utilization. It may be that this is mitigated using Caffeine.executor(Runnable::run) to penalize the caller or, if low concurrency, a LinkedHashMap in LRU mode is a better match.

It may be that we need to better handle high instance churn, which is observable as a filling up FJP with stale write tasks and we'd mistakenly focus trying to break the queue.

[nitsanw]

@normanuber please report back if the issue is still present with vanilla JCTools 1.2.1
I'm holding off a release on the chance that this is an issue I need to resolve.
Thanks!

Looks like the email didn't make it here.

I've already switched my production application back to Guava since I require removal notifications or else I would use a CHM.

There are different levels of the cache, but the most threads touching any of the caches is below 10. 4 dedicated writers for the highest level cache while less than 6 readers at any time reading from it. The highest level cache is a permanent data structure while the child data structures containing a cache last as long as the child element will last (these children can last for weeks). A few hundred of these datastructures are expired/created per day from what my stats say.

I will setup a test environment around the application and attempt to include your library when github is back up.

Is the snapshot version in Maven Central? If not can you push one out there? or can you get me pom directive to add your dev version?

[ben-manes]

So far I have been unable to construct a test case that breaks WriteBuffer. It could be a OS/JVM/hardware match-up causing a visibility problem.

My best alternative guess is that you're workload is causing the cache to flood FJP. That's used to avoid penalizing the caller for policy maintenance, e.g. writes triggering eviction, and removal notifications. If you configure with Caffeine.executor(Runnable::run) then it will behave similarly to Guava by amortizing the cost on the callers. The only difference is that Guava uses a notification queue to process outside of any lock, whereas with an executor we assume it can be delegated to inside the policy's lock. So unless your removal listener is very expensive this won't make a big difference.

---

Maven Central does not allow snapshots and has a dedicated repository for that workflow instead. You need to add that repository to your pom as,

<repositories>
  <repository>
    <id>snapshots</id>
    <url>http://oss.sonatype.org/content/repositories/snapshots</url>
    <releases>
      <enabled>false</enabled>
    </releases>
    <snapshots>
      <enabled>true</enabled>
    </snapshots>
  </repository>
</repositories>