JRE memory calculation doesn't take the maximum number of threads in to account

[lhotari]

Our application gets killed under load with this error message in events log index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255 .
After digging in to it, I think it's caused by a bug in the JVM memory calculation. A process in the warden container gets killed by Linux cgroups OOM killer when it goes over it's resource limits. I found the location where the "out of memory" event is created. I also found the docs for cgroups memory limits. This behaviour is also defined in the Warden protocol.

Back to the actual issue:

I'd expect that the formula for calculation the total amount of memory is something like this:
heap + metasize/permgen + native + (thread_stack_size * maximum_number_of_threads)

However there isn't a documented way to specify the maximum number of threads.
In Tomcat configuration, the default maxThreads settings is 200.

There is this comment in stack_memory_bucket.rb

   # This class represents a memory bucket for stack memory. This is treated differently to other memory buckets
   # which have absolute sizes since stack memory is specified in terms of the size of an individual stack with no
   # definition of how many stacks may exist.

I found a reference to num_threads in the source code:

java-buildpack/lib/java_buildpack/jre/memory/weight_balancing_memory_heuristic.rb

Lines 110 to 116 in 623c428

	def normalise_stack_bucket(stack_bucket, buckets)
	stack_memory = weighted_proportion(stack_bucket, buckets)
	num_threads = [stack_memory / stack_bucket.default_size, 1].max
	normalised_bucket = MemoryBucket.new('normalised stack', stack_bucket.weighting,
	stack_bucket.range * num_threads)
	[normalised_bucket, num_threads]
	end

. This doesn't make sense to me. Is something missing?

I'd like to be able to specify the maximum number of threads in the JRE memory configuration. The memory calculation could then take this in to account when calculation the memory limits and doing the heuristics.

Maximum thread limits should be adjusted accordingly in the Tomcat configuration so that you don't run in to trouble with the default java-buildpack configuration.

---

Some comments about how Warden handles memory limits:
It would be nice if the application got some pre-notification about going over the memory limit. Linux cgroups supports memory threshold notifications. Technically it would be possible to implement Warden in a way that it doesn't use OOM killer to kill processes (Lwn.net "Toward reliable user-space OOM handling"). In that case it would be possible to get better crash reports and logging when there would be a grace time before the process is killed.
Currently this is defined in the Warden protocol and probably won't change:

The memory limit is specified in number of bytes. It is enforced using the control group associated with the container. When a container exceeds this limit, one or more of its processes will be killed by the kernel. Additionally, the Warden will be notified that an OOM happened and it subsequently tears down the container.

I don't like that OOM killer just goes and kills a process and then the container is teared down. Where should I issue my complaint about the Warden protocol? :)

[lhotari]

example output from cf events my-app-name

time                          event                   actor         description
2015-03-06T08:40:51.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-06T06:12:51.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-06T03:12:09.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-06T01:05:59.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-05T22:39:23.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-05T20:30:06.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255
2015-03-05T18:19:04.00-0500   app.crash               my-app-name   index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255

(app name changed from the real one)

This is the reason I'm actively looking for a solution.

[lhotari]

I made a PR #158 to change Tomcat config. We might have had some hanging connections (or slow clients) and that has caused the Tomcat thread pool to grow and hit some boundary that triggers the OOM killer. I'm currently restaging our app to production with these changes and I'll soon see if it helps.

As a workaround to the memory calculation problem, I added some safe boundary by setting the "native" size in the config/open_jdk_jre.yml file of my java-buildpack fork.

---
repository_root: "{default.repository.root}/openjdk/{platform}/{architecture}"
version: 1.8.0_+
memory_sizes:
  metaspace: 140m..200m
  # workaround for https://github.com/cloudfoundry/java-buildpack/issues/157
  native: 250m
  # permgen: 64m..
memory_heuristics:
  heap: 70
  metaspace: 15
  # permgen: 10
  stack: 5
  native: 10

I'll soon find out if these mitigations help preventing the OOM killer from killing our app a few times a day under load.

I changed the meminfo servlet in the java-buildpack-diagnostics-app to include OS memory report in this format

OS memory report

Memory usage of current process (pid 31):
Resident set size (rss): 1753M
Virtual size (vsz): 3622M

Total RSS of all listed processes: 1755M - 1797732K

It parses that information from /bin/ps -o pid,ppid,rss,vsz,pmem,cpu,cputime,comm -e --sort=-rss command output.

It's easy to see from this output if the RSS goes too close to the memory limit.
Here is an an example output of the whole meminfo report.

[lhotari]

I've been logging memory usage reports to files and the RSS of the Java process is now very close to the 2GB limit. I have a few heap dumps and I didn't find memory leaks from the previous dumps.

The problem of going over the 2GB memory limit could have something to do with native memory allocation in Java. I noticed that Oracle JDK 8u40 now has a facility for native memory tracking, it's JEP 195. That tool might give some insight about how JDK8 allocates native (off-heap) memory.

In this example

JVM memory usage
Heap                                used:  335M committed: 1476M max: 1476M
Non-Heap                            used:  254M committed:  273M max: 1499M

Memory pools
PS Eden Space                       used:    6M committed:  427M max:  435M
PS Eden Space peak                  used:  479M committed:  479M max:  480M
PS Survivor Space                   used:    0M committed:   30M max:   30M
PS Survivor Space peak              used:   63M committed:  150M max:  150M
PS Old Gen                          used:  329M committed: 1018M max: 1018M
PS Old Gen peak                     used:  861M committed: 1018M max: 1018M
Code Cache                          used:  100M committed:  101M max:  245M
Code Cache peak                     used:  100M committed:  101M max:  245M
Metaspace                           used:  139M committed:  152M max:  204M
Metaspace peak                      used:  142M committed:  152M max:  204M
Compressed Class Space              used:   15M committed:   18M max: 1048M
Compressed Class Space peak         used:   15M committed:   18M max: 1048M

OS memory report

Memory usage of current process (pid 31):
Resident set size (rss): 2037M
Virtual size (vsz): 3719M

Heap 1476M + Non Heap 273M = Total 1749M
RSS reports 2037M
2037M - 1749M = 288M is used outside Heap + Non Heap. That's a large percentage of the maximum heap size.

This application has these memory related JVM options in staging_info.yml file:
-Xmx1527261K -Xms1527261K -XX:MaxMetaspaceSize=200M -XX:MetaspaceSize=200M -Xss1065K

[lhotari]

I was now able to record the memory information just before a crash:
2015-03-06T17:38:11.00-0500 app.crash [*my-app-name-replace*] index: 0, reason: CRASHED, exit_description: out of memory, exit_status: 255

Last meminfo before crash
First meminfo after crash

The maximum threads are now limited in the tomcat config to 30 so it cannot be a memory sizing issue caused by stack memory about as what I originally reported.
It looks like the JVM has just been allocating more native memory.
I guess I'll have to reserve enough memory for native memory, but why does it keep growing? Do I have to set -XX:ReservedCodeCacheSize= or do some other tweaking to limit the memory usage?

I have NewRelic enabled in the instance, but that doesn't give any better insight.

[lhotari]

The JVM also has the MaxDirectMemorySize option. The app doesn't do anything special, but I wonder if setting that would help limit native memory use.

There is some problem in my case that the JVM consumes more and more native memory. I'm going to check the heapdump for signs of java.util.zip.* classes since the invalid use (not closing resources) of those can cause native memory leaks in Java apps.

I also created PR #159 since I think setting MetaspaceSize could prevent some cleanup from happening. The app is a Grails app . Groovy causes a lot more class compilation (hotspot) than plain Java apps so I'm thinking that perhaps that just needs clean up and setting MetaspaceSize == MaxMetaspaceSize could be causing harm. I'm testing if that change helps at all. This is a good opportunity to do different tests since the app is crashing often.

[lhotari]

I also found out that specifying MALLOC_ARENA_MAX env might help reducing the memory overhead of 64-bit Java processes. Some recommend using a value of 2 or 4.

Heroku guide:
https://devcenter.heroku.com/articles/tuning-glibc-memory-behavior#what-value-to-choose-for-malloc_arena_max
Hadoop:
https://issues.apache.org/jira/browse/HADOOP-7154

[lhotari]

I created #160 for the MALLOC_ARENA_MAX change.

[lhotari]

This blog post about MALLOC_ARENA_MAX setting in glibc says "In addition, resident memory has been known to creep in a manner similar to a memory leak or memory fragmentation." . It might explain some of the behaviour I was seeing in the application I've been concentrating on.

[nebhale]

@lhotari Any further insight into this? Does the MALLOC_ARENA_MAX solution (setting it with cf set-env) render this issue un-needed?

[lhotari]

@nebhale I think there still is the original bug that I reported in the description. There isn't a way to specify the number of threads to allocate memory for. MALLOC_ARENA_MAX does help in reducing memory use but I don't think that it renders this issue un-needed.

I'd like to be able to specify the maximum number of threads in the JRE memory configuration. The memory calculation could then take this in to account when calculation the memory limits and doing the heuristics.

I found a reference to num_threads in the source code:

java-buildpack/lib/java_buildpack/jre/memory/weight_balancing_memory_heuristic.rb

Lines 110 to 116 in 623c428

	def normalise_stack_bucket(stack_bucket, buckets)
	stack_memory = weighted_proportion(stack_bucket, buckets)
	num_threads = [stack_memory / stack_bucket.default_size, 1].max
	normalised_bucket = MemoryBucket.new('normalised stack', stack_bucket.weighting,
	stack_bucket.range * num_threads)
	[normalised_bucket, num_threads]
	end

. This doesn't make sense to me. Is something missing?

[nebhale]

Man that's a blast from the past; we haven't been in there in years. I believe that what happens there is that we attempt to derive the number of threads that are possible given the inputs that you've specified and then do something (?) with that. I'm with you that there's probably room for something more explicit. Tracker Issue

[cgfrost]

@lhotari FYI, this issue should get looked at (potentially implemented in the not too distant future). I don't believe any recent developments have removed the justification for this work.