Wednesday, October 1, 2014

Debugging java.lang.OutOfMemoryError: unable to create new native thread on Cloud Foundry

Within a multi-threaded Java application running on Cloud Foundry we started seeing the following error during our performance tests:
[App/0]  ERR java.lang.OutOfMemoryError: unable to create new native thread
Doing some basic troubleshooting the testers observed the following:
  • Increasing the memory allocated to the application did not resolve the error.
  • Running the same Java application on a Linux VM we did not see the error.
So the question arises what is different between a Cloud Foundry Linux Container and a Linux VM that precipitates these errors?

Research

This article on plumber.eu does a great job of describing the unable to create new native thread error. In short the error occurs when we exhaust the available user processes and then continue trying to create processes from within Java.
The article also describes how to resolve the error on a Linux VM, by increasing the number of user processes using ulimit -u. This is a scale-up solution and Cloud Foundry is a scale-out environment thus the higher user process limits are not made available within containers rendering this solution a non-starter.

Investigation

For us the solution needed to be scale-out run multiple Linux Containers each with fewer threads. To implement this solution effectively we needed to know the following:
  • How many user processes were available within each Linux Container.
  • How many of those processes are available for us to use as Java threads.
Additionally we wanted to understand why our testers had not seen the error on the Linux VM.

Determining the number of user processes

On a Linux VM to determine the number of user processes available to a user we simply run ulimit -a and look at the max user processes value. However on Cloud Foundry developers do not have an interactive Shell into the Linux Container.
James Bayer came up with a neat hack to work around this using websocketd so I used his hack to create an interactive shell into the Linux Container.

Using the interactive Shell we can easily observe the max user processes available to us is 512:
$ whoami 
vcap

$ ulimit -a
core file size (blocks, -c) 0 
 data seg size (kbytes, -d) unlimited 
 scheduling priority (-e) 0 
 file size (blocks, -f) unlimited 
 pending signals (-i) 1024 
 max locked memory (kbytes, -l) 64 
 max memory size (kbytes, -m) unlimited 
 open files (-n) 16384 
 pipe size (512 bytes, -p) 8 
 POSIX message queues (bytes, -q) 819200 
 real-time priority (-r) 0 
 stack size (kbytes, -s) 8192 
 cpu time (seconds, -t) unlimited 
 max user processes (-u) 512 
 virtual memory (kbytes, -v) unlimited 
 file locks (-x) unlimited  

Determining how many of user processes are available for Java threads

At a guess from the max user processes processes value we should be able to run about 500 threads within each Linux container (this will vary based on your Stack, we are currently using Ubuntu Lucid).
To test this I threw together a basic Java application to exhaust the available threads. Running the application in Cloud Foundry I see the following:
tastle@TASTLE-M-W03P tgobbler (master) $ cf logs tgobbler --recent
Connected, dumping recent logs for app tgobbler in org COL-DEV-FT / space Development as taste...
[DEA]     OUT Starting app instance (index 0) with guid 34c88014-fdf0-4f25-b555-b58291d6f879
[App/0]   OUT Threads started: 1
...
[App/0]   OUT Threads started: 490
[App/0]   ERR Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
...
[DEA]     OUT Starting app instance (index 0) with guid 34c88014-fdf0-4f25-b555-b58291d6f879
[App/0]   OUT Threads started: 1
...
[App/0]   OUT Threads started: 490
[App/0]   ERR Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
[App/0]   ERR  at java.lang.Thread.start0(Native Method)
[App/0]   ERR  at java.lang.Thread.start(Thread.java:714)
[App/0]   ERR  at org.trastle.App.main(App.java:12)
So we can see the following:

  1. The application starts a first time, then consumes 490 threads, then dies.
  2. Cloud Foundry notices, then restarts the failing application.
  3. The application starts a second time, then consumes 490 threads, then dies.
After a few more runs it became clear that 490 threads was a consistent max.

Why do we not see this error on an Ubuntu Linux VM?

The Stack we use in Cloud Foundry is Ubuntu Linux so testing this on a Debian VM we should be able to reproduce the failure. However our testers had already observed this was not the case.
So lets look at the max user processes available on the VM:
tastle@tastle-debian:~$ ulimit -a
 core file size          (blocks, -c) 0
 data seg size           (kbytes, -d) unlimited
 scheduling priority             (-e) 0
 file size               (blocks, -f) unlimited
 pending signals                 (-i) 3824
 max locked memory       (kbytes, -l) 64
 max memory size         (kbytes, -m) unlimited
 open files                      (-n) 1024
 pipe size            (512 bytes, -p) 8
 POSIX message queues     (bytes, -q) 819200
 real-time priority              (-r) 0
 stack size              (kbytes, -s) 8192
 cpu time               (seconds, -t) unlimited
 max user processes              (-u) 3824
 virtual memory          (kbytes, -v) unlimited
 file locks                      (-x) unlimited
There are roughly 7x the user processes available to us on on the VM explaining why we could not see the issue. This is largely because the VM is tuned for a lower level of multi-tenancy the the Cloud Foundry Linux Container. In order to reproduce the error on the VM we can reduce the max user processes
tastle@tastle-debian:~$ ulimit -u 512
tastle@tastle-debian:~$ ulimit -a
 core file size          (blocks, -c) 0
 data seg size           (kbytes, -d) unlimited
 scheduling priority             (-e) 0
 file size               (blocks, -f) unlimited
 pending signals                 (-i) 3824
 max locked memory       (kbytes, -l) 64
 max memory size         (kbytes, -m) unlimited
 open files                      (-n) 1024
 pipe size            (512 bytes, -p) 8
 POSIX message queues     (bytes, -q) 819200
 real-time priority              (-r) 0
 stack size              (kbytes, -s) 8192
 cpu time               (seconds, -t) unlimited
 max user processes              (-u) 512
 virtual memory          (kbytes, -v) unlimited
 file locks                      (-x) unlimited
Running the same test application now we see the following:
tastle@tastle-debian:~$ java -jar tgobbler-1.0.jar
...
Threads started: 500
Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
The result largely similar to what we saw in the Cloud Foundry Linux Container. The difference exists because the user processes available represent everything running as that user not just the Java application.

Resolution

We now know we will always be able to create roughly 490 Java threads within a single Cloud Foundry Linux Container.
It makes sense to leave some head room in each container so we will aim to utilise a maximum of 90% of the available threads. This leaves us with a target maximum of 450 threads per Linux Container. When more threads are required we will scale out to multiple containers.

Update: Changes to the Java Buildpack

After discussing this issue, the Cloud Foundry team have very kindly integrated a call to ulimit -a and df -h into the kill script used in the Java Buildpack. The output of this script will also be surfaced over Loggregator making the information readily available.



1 comments:

Lari Hotari said...

To minimize the resident memory usage of Java, you might want to set the MALLOC_ARENA_MAX environment value to a low value like 1, 2 or 4. See my PR for details https://github.com/cloudfoundry/java-buildpack/pull/160 . This also helped reduce RSS memory usage: https://github.com/cloudfoundry/java-buildpack/pull/159 .
I have created a tool for gathering more information from a running app: https://github.com/lhotari/java-buildpack-diagnostics-app