Parent circuit breaker calculation seems to be wrong with version 7.x

Elastic Stack Elasticsearch
6

Hi Eli,

The garbage collector is triggered when the heap usage reaches 75% -XX:InitiatingHeapOccupancyPercent=75. However, the garbage collector is running concurrently with the application so it can (and will) happen that the application allocates additional heap memory while the heap is being cleaned up. The default garbage collector for Elasticsearch (concurrent mark-sweep (CMS)) also runs concurrently with the application but both garbage collectors have different runtime characteristics so if the concurrent phase takes longer for G1, it will report the higher heap usage until the end of its concurrent cycle and thus the chance is higher that the real memory circuit breaker is tripped. Once the GC cycle finishes, heap usage as seen by the real memory circuit breaker should drop. So you can do a couple of things:

  • Switch to the CMS garbage collector.
  • Stay with G1 but trigger the concurrent cycle sooner (i.e. reducing -XX:InitiatingHeapOccupancyPercent from 75 to a lower value, e.g. 65). Note that this means the garbage collector will run sooner and thus you will see more GC events which might negatively impact performance. It's best that you thoroughly test this change with a representative benchmark before doing this in production.
  • Increase the threshold when the real memory circuit breaker trips by changing indices.breaker.total.limit from 95% to a higher value. In our experiments we've seen though that if we set the threshold too high, we end up in situations where the circuit breaker is ineffective because it triggers too late.
  • Turn off the real memory circuit breaker by setting indices.breaker.total.use_real_memory to false. I'd advise against it because this increases your risk of running into out of memory errors by overloading the node. The real memory circuit breaker enables the node to actually push back without falling over if too much traffic is hitting the node.

Daniel

2 Likes
7

Hi,

In my previous response I missed that you've mentioned this. This is a bit odd but I suggest you look at the output of the garbage collection log (logs/gc.log). This file contains a lot of details about GC behavior (when was it triggered? how much memory has been reclaimed? how long did it run? etc.) and I recommend this as a starting point for GC analysis in general.

Daniel

8

I am so relieved someone else ran into this. I thought I was somehow seeing that bug from 5.6 reappear. I was pretty confused when I ran into this and ended up using that workaround from the bug where I set the parent limit_size to, uh, 8 exabytes :scream_cat:. While this did not feel great, the problem went away and I was able to resume indexing documents.

I am also using JDK12 and G1GC with the defaults on a 8GB heap. I'm only bulk indexing docs in a single thread with some occasional mget's. No searches or aggs. GC's are very effective when they run, taking the heap from 75% down to 25%.

It seems like sending a bulk insert when G1GC's heap is near 75% temporarily puts it over the edge, which I think is what Daniel is suggesting here:

I will try reverting to CMS first, and then try setting indices.breaker.total.use_real_memory to false if it's still an issue.

      "breakers" : {
        "request" : {
          "limit_size_in_bytes" : 4986608025,
          "limit_size" : "4.6gb",
          "estimated_size_in_bytes" : 0,
          "estimated_size" : "0b",
          "overhead" : 1.0,
          "tripped" : 0
        },
        "fielddata" : {
          "limit_size_in_bytes" : 3324405350,
          "limit_size" : "3gb",
          "estimated_size_in_bytes" : 3440,
          "estimated_size" : "3.3kb",
          "overhead" : 1.03,
          "tripped" : 0
        },
        "in_flight_requests" : {
          "limit_size_in_bytes" : 8311013376,
          "limit_size" : "7.7gb",
          "estimated_size_in_bytes" : 1860,
          "estimated_size" : "1.8kb",
          "overhead" : 2.0,
          "tripped" : 0
        },
        "accounting" : {
          "limit_size_in_bytes" : 8311013376,
          "limit_size" : "7.7gb",
          "estimated_size_in_bytes" : 51488284,
          "estimated_size" : "49.1mb",
          "overhead" : 1.0,
          "tripped" : 0
        },
        "parent" : {
          "limit_size_in_bytes" : 9223372036854775807,
          "limit_size" : "8192pb",
          "estimated_size_in_bytes" : 6715789312,
          "estimated_size" : "6.2gb",
          "overhead" : 1.0,
          "tripped" : 0
        }
      }```
9

Hello @e-orz

I got issue same you.
But I forgot increase heap size.
After I increased heap size (-Xms/-Xmx) in jvm.options, issue is resolved.
Good luck for you.

Refer: I got issue about "Data too large"

10

Hi @thachnv92,
What garbage collection are you using? I have issues only with G1GC and not with CMS (default config is CMS so if you didn't change it, it will be CMS) ?

11

Hi, @danielmitterdorfer,

Sorry for the late reply, it took me some time to make the tests.

  • Switching to CMS solved the issue. The heap size never got big and the parent circuit breaker was never triggered.

Back to G1GC:
I ran the scenario again, waited for the parent circuit breaker to be triggered and watched the gc.log file. It took it minutes to come back to life. During that time there were not GCs in the gc.log file! It seems that the GC already freed the memory and somehow the process thinks that it's still taken.

I got the feeling you are doing your tests against JDK11 (see this discussion). I replaced the bundled JDK with the 11 version. Things were much better. Even though that the memory was cleaned after 75% it was still cleaned when it ran out of memory and the circuit breaker wasn't triggered. But even with it after several tries it was triggered but only for a short period of time and then the memory was cleaned and the process could process commands.

So my questions are:

  1. Are you using CMS in your internal tests?
  2. Is JDK 12 also used during tests or only JDK 11?
  3. A bit of a different topic, is there a reason why the stats were also affected by the circuit breaker? It makes debugging the issue harder.

Eli

1 Like
12

hi:
I had the same problem
ES version：7.1.0
use G1GC
Here is my configuration：

-Xms31g
-Xmx31g
10-:-XX:-UseConcMarkSweepGC
10-:-XX:-UseCMSInitiatingOccupancyOnly
10-:-XX:+UseG1GC
10-:-XX:InitiatingHeapOccupancyPercent=75
-Des.networkaddress.cache.negative.ttl=10
-XX:+AlwaysPreTouch
-Xss1m
-Djava.awt.headless=true
-Dfile.encoding=UTF-8
-Djna.nosys=true
-XX:-OmitStackTraceInFastThrow
-Dio.netty.noUnsafe=true
-Dio.netty.noKeySetOptimization=true
-Dio.netty.recycler.maxCapacityPerThread=0
-Dlog4j.shutdownHookEnabled=false
-Dlog4j2.disable.jmx=true
-Djava.io.tmpdir=${ES_TMPDIR}
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=data
-XX:ErrorFile=/var/log/elasticsearch/logs/hs_err_pid%p.log
8:-XX:+PrintGCDetails
8:-XX:+PrintGCDateStamps
8:-XX:+PrintTenuringDistribution
8:-XX:+PrintGCApplicationStoppedTime
8:-Xloggc:/export/Logs/elasticsearch/logs/gc.log
8:-XX:+UseGCLogFileRotation
8:-XX:NumberOfGCLogFiles=10
8:-XX:GCLogFileSize=64m
9-:-Xlog:gc*,gc+age=trace,safepoint:file=/var/log/elasticsearch/logs/gc.log:utctime,pid,tags:filecount=10,filesize=64m
COMPAT otherwise

13

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.

14

Hi @e-orz and @liuhaoran

I think below options instead of the default -XX:InitiatingHeapOccupancyPercent=75 should solve the problem when using G1 GC:

10-:-XX:G1ReservePercent=25
10-:-XX:InitiatingHeapOccupancyPercent=30

I hope you are willing to try this out and report back the results here?

15
16

Hi, @HenningAndersen,
Thanks for your answer. I hope to get to it early next week.

Eli

17

We have been having the same problem, and it is exceedingly frustrating. We have a cluster with 26 data nodes that with ES 6.8 was able to index well over 10k docs a second. Now a bulk index of about 1k docs per second trips circuit breakers on nodes that have plenty of heap and for which GC runs easily.

We applied these settings last night, and this morning with an almost idle cluster, one thread pushing a couple thousand documents a second was able to cause nodes to throw circuit breakers.

18

Hi @Jeff_Bolle,

thanks for reporting back here. In order to dig deeper, I hope you can share your elasticsearch.yml, jvm.options and gc log files? Feel free to send them in a PM to me.

19

@HenningAndersen
We are working on pulling all of those files for you now. I will send them via PM.

We just reverted back to the system JVM:

java --version
openjdk 11.0.4 2019-07-16
OpenJDK Runtime Environment (build 11.0.4+11-post-Ubuntu-116.04.1)
OpenJDK 64-Bit Server VM (build 11.0.4+11-post-Ubuntu-116.04.1, mixed mode, sharing)

And things are running like a dream. Heaps are staying in the mid 60% range at maximum on our most active data nodes, no circuit breakers have tripped, and our objects are flowing out of the backlog.

20

Hi @Jeff_Bolle,

thanks for the follow up. It could be interesting to know the previous version of java in use (the bundled one?). Also, your ES version is always good information to have as well.

Sounds good that you have it resolved, but would certainly like to dig one step deeper on this one.

21

The java version information is in my previous message:

openjdk 11.0.4 2019-07-16
OpenJDK Runtime Environment (build 11.0.4+11-post-Ubuntu-116.04.1)
OpenJDK 64-Bit Server VM (build 11.0.4+11-post-Ubuntu-116.04.1, mixed mode, sharing)

We are currently running ES 7.3.0, and previously we were running 6.8.X.
For our 6.8.X install we were using our Java 11 install on the servers. If it helps, we are running in the Google Cloud.

22 
   We exactly facing the same issue,its annoying . Our production clusters are running with ES version 7.1.1 with OpenJDK 12.0.1(bundled version) with 10G of heap allocated. looking at discussion above it seems the problem is with JDK 12 . Also yesterday we have upgraded our Non-prod cluster  from 7.1.1 to 7.4.0 and that comes with JDK 13.

Also seeing from support matrix - https://www.elastic.co/support/matrix#matrix_jvm JDK 12 has been removed for ES version 7.4 which makes sense.

Question is, Does any one know if this issue gets resolved with JDK 13 ? for the past one day cluster seems to be fine and we didn't see any trips but if anyone has additional info with JDK 13, that would be a good information.

23

Hi @pjaikumar,

several other users who have run into this were using G1GC. Is that also the case for your cluster?

If so, the following change is important:


It is worthwhile double checking that the G1 settings are correct compared to that PR, i.e., that you have:

-XX:G1ReservePercent=25
-XX:InitiatingHeapOccupancyPercent=30

in your jvm.options file.

If you are not using G1 or you are using G1 with above settings, I would be interested in seeing your GC logs from Elasticsearch (together with exception info from log file) if this should reoccur.

1 Like
24

Hi @HenningAndersen
Yes correct we were using G1 with IHOP of 75%. Today we changed it to CMS with below default settings and running a test against it, So far the results look pretty good and we haven't seen any Circuit breaker errors.

-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=75
-XX:+UseCMSInitiatingOccupancyOnly

1 Like
26