2

Our application is latency critical. In order to reduce GC pauses, we reuse objects. In beginning of the process we allocate a lot of small objects and then (almost) no memory allocated. However, I still see following log of gc: 

2016-12-18T13:51:48.650+0200: 1.085: Total time for which application threads were stopped: 0.0001411 seconds, Stopping threads took: 0.0000203 seconds
2016-12-18T13:51:48.776+0200: 1.210: Total time for which application threads were stopped: 0.0002027 seconds, Stopping threads took: 0.0000183 seconds
2016-12-18T13:51:48.894+0200: 1.328: Total time for which application threads were stopped: 0.0002559 seconds, Stopping threads took: 0.0000194 seconds
2016-12-18T13:51:48.906+0200: 1.341: Total time for which application threads were stopped: 0.0002159 seconds, Stopping threads took: 0.0000199 seconds
2016-12-18T13:51:49.047+0200: 1.482: Total time for which application threads were stopped: 0.0002842 seconds, Stopping threads took: 0.0000208 seconds

As far, as I understood, JVM stops process to run over all references and mark objects. Is it correct?

Also I see that frequency of such logs decrease with a time. So i think GC tunes some internal parameters and I wish to provide them on the start. Now I run process with following arguments:

-Xms10240m
-Xmx10240m
-server
-XX:+UseG1GC
-noclassgc

All rest arguments related to verbosing GC. Our machine have enough memory to completely avoid gc. How can I explain it to java?

OS: Linux, JVM either oracle or openJDK.

Thank you.

  • 0.0002842 seconds is too long?? – Andreas Dec 18 '16 at 12:17
  • 280 mills, its too long for us. –  Dec 18 '16 at 12:59
  • 2
    0.0002842 seconds is **not** 280 milliseconds. It's 280 **microseconds**, aka 0.28 milliseconds. – Andreas Dec 18 '16 at 13:02
  • Oh! you are right, sorry. 280 micro is much better, but we prefer to disable it at completely. –  Dec 18 '16 at 13:07
  • The G1GC collector are continuously running those micro-collections to **prevent** a long GC run. If you disable those, it'll eventually run out of memory and have to run a full GC, which will be **long** with a 10 Gb heap *(relatively speaking, e.g. many seconds maybe even minutes)*. You'll definitely be feeling *that* when it happens, and it will, eventually and unpredictably. Those micro-collection are exactly what you want in a latency critical system, because a 10+ seconds GC run would kill you. – Andreas Dec 18 '16 at 13:17
  • Not necessarily. It might very well be the case that you want to avoid these continuous micro collections and do a bigger collection at a time of your choosing. If you have a trading system that runs from 7am to 6pm and can do that without triggering a GC then you might want this optimization and clean up after market hours. Just to give an example – Jeroen Vannevel Dec 18 '16 at 17:51
  • Its exactly trading system. –  Dec 18 '16 at 18:01
  • if you're concerned about microseconds you'll have a lot more work cut out of your than just flipping some JVM flags. You might want to look into jhiccup, azul's zing VM, CPU-pinning, wait-free data structures etc. etc. otoh if you're working in HFT i would expect you would already know this... – the8472 Dec 18 '16 at 18:23
  • @the8472 Azul is too expensive, dedicated cpu per thread - implemented, locking free techniques introduced where the current architecture allows. My main concern now is STW. I though if I will not consume the memory, stw will not happen, but it is. So i asked the help from the community. BTW, there is shenandoah gc, which is "almost concurrent" and free alternative to Azul's C4. May be we will migrate on it. –  Dec 19 '16 at 00:56

1 Answers1

3

These are not necessarily garbage collections.

There is a number of other cases (not related to GC) when JVM prints Total time for which application threads were stopped. See the related answer for details.

Non-GC safepoints are especially frequent at application start-up time due to class loading and recompilation.

If you want to track GC pauses, use -XX:+PrintGCDetails.

Update

A few tricks to decrease number of non-GC safepoints:

  • -XX:-UseBiasedLocking completely disables bias revocation pauses;
  • -XX:+UnlockDiagnosticVMOptions -XX:GuaranteedSafepointInterval=0 disables an obligatory safepoint every second;
  • -XX:-TieredCompilation disables multi-tier compilation thus reducing number of recompilation-related safepoints.

Note: this is just a hint, not a suggestion for production use. The above options may have performance side effects.

Community
  • 1
  • 1
apangin
  • 92,924
  • 10
  • 193
  • 247