Metaspace OOM before reaching MaxMetaspaceSize

[Thomas Schatzl]

Hi,

  some random comments:

On Thu, 2019-04-25 at 17:19 -0700, Shengpei Zhang wrote:
> Hi,
> 
> We recently saw a weird Metaspace OOM. The hs_err_pid log showed the
> metaspace usage was 325078K, while the MaxMetaspaceSize was set to
> 4G.
> 
> The machine was running JAVA10.
> 
> Few observations:
> 
> 1. It only happened at one machine, and we were not able to reproduce
> it.
> 
> 2. Error log indicated memory allocation failure in native memory.
> 
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
> Chunkmanager (non-class):
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
>  62578 specialized (128 bytes) chunks, total 64079872 bytes
> [2019-03-29T11:18:01.298-0700][126538][info
> ][gc,metaspace,freelist]   5778
> small (512 bytes) chunks, total 23666688 bytes
> [2019-03-29T11:18:01.298-0700][126538][info
> ][gc,metaspace,freelist]   27
> medium (8192 bytes) chunks, total 1769472 bytes
> [2019-03-29T11:18:01.298-0700][126538][info
> ][gc,metaspace,freelist]   13
> humongous chunks, total 8890368 bytes
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
>  total size: 98406400 bytes.
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
> Chunkmanager (class):
> [2019-03-29T11:18:01.298-0700][126538][info ][gc,metaspace,freelist]
> unavailable.
> java.lang.OutOfMemoryError: Metaspace
> Dumping heap to java_pid240.hprof ...
>           vmop                            [ threads:    total
> initially_running wait_to_block ][ time:    spin   block    sync
> cleanup
> vmop ] page_trap_count
> 66467.977: ICBufferFull                    [              3427
>  154           353 ][             0      60      63       8       0 ]
>         58
> [2019-03-29T11:18:01.308-0700][459   ][info ][safepoint            ]
> Total
> time for which application threads were stopped: 0.0725507 seconds,
> Stopping threads took: 0.0630158 seconds
> [thread 384508 also had an error]
> #
> # There is insufficient memory for the Java Runtime Environment to
> continue.
> # Native memory allocation (mmap) failed to map 16384 bytes for
> committing
> reserved memory.
> # An error report file with more information is saved as:
> # /data/hs_err_pid240.log

In Linux there is a limit on the amount of memory mappings (iirc 65k by
default) if your application maps memory by itself, and does not unmap
in time, you will run out of memory mappings.

If the hs_err log contains lots and lots of memory mappings, this is a
strong indication that this is your issue, not actual native memory
pressure.

See e.g. https://bugs.openjdk.java.net/browse/JDK-8216619 for more
details on another example.

> 
> 3. The hs_err_pid log showed the metaspace memory usage was 325078K,
> it is far less than the reserved size 568176K. Also, the
> MaxMetaspaceSize was set to 4G. I checked the machine had plenty of
> free native memory at that time. If there was a huge allocation, I
> assume JVM would try to reserve more memory first?

Please check if your program leaks memory reservations or not, see
above.

The difference between usage and reservation size may be down to
fragmentation: later VM versions included some patches that improve the
situation.

Thanks,
  Thomas