4

I've got a strange problem in my Clojure app.

I'm using http-kit to write a websocket based chat application.

Client's are rendered using React as a single page app, the first thing they do when they navigate to the home page (after signing in) is create a websocket to receive things like real-time updates and any chat messages. You can see the site here: www.csgoteamfinder.com

The problem I have is after some indeterminate amount of time, it might be 30 minutes after a restart or even 48 hours, the JVM running the chat server suddenly starts consuming all the CPU. When I inspect it with NR (New Relic) I can see that all that time is being used by the garbage collector -- at this stage I have no idea what it's doing.

I've take a number of screenshots where you can see the effect.

New Relic showing memory usage over a 7 day period

More New Relic statistics

You can see a number of spikes, those spikes correspond to large increases in CPU usage because of the garbage collector. To free up CPU I usually have to restart the JVM, I have been relying on receiving a CPU alert from NR in my slack account to make sure I jump on these quickly....but I really need to get to the root of the problem.

My initial thought was that I was possibly holding onto the socket reference when the client closed it at their end, but this is not the case. I've been looking at socket count periodically and it is fairly stable.

Any ideas of where to start?

Kind regards, Jason.

3
  • 1
    The GC normally uses all the CPU while it is running. It does this to minimize the GC pause time. Are you sure it's not just doing a full GC because your tenured space is full? Feb 8, 2016 at 4:12
  • 1
    Your charts are not really conclusive since they have low granularity (spanning days), you should capture GC logs and post regions of interest here.
    – the8472
    Feb 8, 2016 at 4:26
  • Thanks @the8472 I've configured the JVM to GC log and will attach some logs when the anomaly occurs again.
    – JMac
    Feb 8, 2016 at 5:21

4 Answers 4

4

It's hard to imagine what could have caused such an issue. But at first what I would do is taking a heap dump at the time of crash. This can be enabled with -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=<path_to_your_heap_dump> JVM args. As a general practice don't increase heap size more the size of physical memory available on your server machine. In some rare cases JVM is unable to dump heap space because process is doomed; in such cases you can use gcore(if you're on Linux, not sure about Windows).

Once you grab the heap dump, analyse it with mat, I have debugged such applications and this worked perfectly to pin down any memory related issues. Mat allows you to dissect the heap dump in depth so you're sure to find the cause of your memory issue if it is not the case that you have allocated very small heap space.

1
  • Thanks @Bunti I've taken your advice and configured the JVM with those options; I'll report back when I get a heap dump. The tool you've referenced looks very useful.
    – JMac
    Feb 8, 2016 at 5:20
2

If your program is spending a lot of CPU time in garbage collection, that means that your heap is getting full. Usually this means one of two things:

  1. You need to allocate more heap to your program (via -Xmx).
  2. Your program is leaking memory.

Try the former first. Allocate an insane amount of memory to your program (16GB or more, in your case, based on the graphs I'm looking at). See if you still have the same symptoms.

If the symptoms go away, then your program just needed more memory. Otherwise, you have a memory leak. In this case, you need to do some memory profiling. In the JVM, the way this is usually done is to use jmap to generate a heap dump, then use a heap dump analyser (such as jhat or VisualVM) to look at it.

(Fair disclosure: I'm the creator of a jhat fork called fasthat.)

2
  • Thanks @Chris, I can't increase the memory to 16GB at the moment as that exceeds the total size of the machine I'm running on. I have to share the box with another JVM and 4 Node JS processes. That might be the problem! I've turned on GC logging and will attach logs when I have them.
    – JMac
    Feb 8, 2016 at 5:23
  • @JMac -- too much memory sometimes can be a problem too :) try reduce it to 1G or 2G and see what happens.
    – ZhongYu
    Feb 8, 2016 at 7:56
2

Most likely your tenure space is filling up triggering a full collection. At this time the GC uses all the CPUS for sometime seconds at time.

To diagnose why this is happening you need to look at your rate of promotion (how much data is moving from young generation to tenured space)

I would look at increasing the young generation size to decrease rate of promotion. You could also look at using CMS as this has shorter pause times (though it uses more CPU)

1
  • Thanks @Peter I've added a number of flags reference by other answers to see how memory is moving from the young to the older generation over time. I'll report back when I have more data.
    – JMac
    Feb 8, 2016 at 5:21
2

Things to try in order:

  1. Reduce the heap size
  2. Count the number of objects of each class, and see if the numbers makes sense
  3. Do you have big byte[] that lives past generation 1?
  4. Change or tune GC algorithm
  5. Use high-availability, i.e. more than one JVM
  6. Switch to Erlang

You have triggered a global GC. The GC time grows faster-than-linear depending on the amount of memory, so actually reducing the heap space will trigger the global GC more often and make it faster.

You can also experiment with changing GC algorithm. We had a system where the global GC went down from 200s (happened 1-2 times per 24 hours) to 12s. Yes, the system was at a complete stand still for 3 minutes, no the users were not happy :-) You could try -XX:+UseConcMarkSweepGC

http://www.fasterj.com/articles/oraclecollectors1.shtml

You will always have stops like this for JVM and similar; it is more about how often you will get it, and how fast the global GC will be. You should make a heap dump and get the count of the different objects of each class. Most likely, you will see that you have millions of one of them, somehow, you are keeping a pointer to them unnecessary in a ever growing cache or sessions or similar.

http://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/memleaks001.html#CIHCAEIH

You can also start using a high-availability solution with at least 2 nodes, so that when one node is busy doing GC, the other node will have to handle the total load for a time. Hopefully, you will not get the global GC on both systems at the same time.

Big binary objects like byte[] and similar is a real problem. Do you have those?

At some time, these needs to be compacted by the global GC, and this is a slow operation. Many of the data-processing JVM based solution actually avoid to store all data as plain POJOs on the heap, and implement heaps themselves in order to overcome this problem.

Another solution is to switch from JVM to Erlang. Erlang is near real time, and they got by not having the concept of a global GC of the whole heap. Erlang has many small heaps. You can read a little about it at

https://hamidreza-s.github.io/erlang%20garbage%20collection%20memory%20layout%20soft%20realtime/2015/08/24/erlang-garbage-collection-details-and-why-it-matters.html

Erlang is slower than JVM, since it copies data, but the performance is much more predictable. It is difficult to have both. I have a websocket Erlang based solution, and it really works well.

So you run into a problem that is expected and normal for JVM, Microsoft CLR and similar. It will get worse and more common during the next couple of years when heap sizes grows.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.