JVM crashing for Tomcat in Solaris server

2968813

Our Tomcat processes (in two different servers) which are usually very stable started crashing everyday since last week. Prior to last week, we never had any issue with this process and it used to be up and running for months at a time without any need to restart. We have not made any changes to our application which could be causing this. Our Unix team also has not applied any patches lately. We are puzzled that this is happening on two different servers. JVM is producing hs_err_pid log file prior to crash and it says out of memory error. We have enough memory available in our server and we are on 64-bit Solaris and using 64-bit version of Java. What's puzzling is that this issue started happening simultaneously in two different servers.

Following are the errors in different hs_err_pid files:

hs_err_pid13798.log:# Native memory allocation (malloc) failed to allocate 280 bytes for AllocateHeap

hs_err_pid2354.log:# Native memory allocation (malloc) failed to allocate 280 bytes for AllocateHeap

hs_err_pid23886.log:# Native memory allocation (malloc) failed to allocate 280 bytes for AllocateHeap

hs_err_pid4302.log:# Native memory allocation (malloc) failed to allocate 280 bytes for AllocateHeap

hs_err_pid3766.log:# Native memory allocation (malloc) failed to allocate 32744 bytes for ChunkPool::allocate

GC details from one of the log files:

Event: 72408.229 GC heap before

{Heap before GC invocations=281 (full 22):

PSYoungGen      total 98304K, used 98303K [0x00000005d5700000, 0x00000005e0900000, 0x0000000800000000)

  eden space 96768K, 100% used [0x00000005d5700000,0x00000005db580000,0x00000005db580000)

  from space 1536K, 99% used [0x00000005e0780000,0x00000005e08fff70,0x00000005e0900000)

  to   space 2560K, 0% used [0x00000005e0400000,0x00000005e0400000,0x00000005e0680000)

ParOldGen       total 848896K, used 17162K [0x0000000180400000, 0x00000001b4100000, 0x00000005d5700000)

  object space 848896K, 2% used [0x0000000180400000,0x00000001814c2bb0,0x00000001b4100000)

Metaspace       used 27860K, capacity 28290K, committed 28800K, reserved 1075200K

  class space    used 2982K, capacity 3134K, committed 3200K, reserved 1048576K

Event: 72408.234 GC heap after

Heap after GC invocations=281 (full 22):

PSYoungGen      total 99328K, used 2153K [0x00000005d5700000, 0x00000005e0800000, 0x0000000800000000)

  eden space 96768K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005db580000)

  from space 2560K, 84% used [0x00000005e0400000,0x00000005e061a6d0,0x00000005e0680000)

  to   space 1536K, 0% used [0x00000005e0680000,0x00000005e0680000,0x00000005e0800000)

ParOldGen       total 848896K, used 17162K [0x0000000180400000, 0x00000001b4100000, 0x00000005d5700000)

  object space 848896K, 2% used [0x0000000180400000,0x00000001814c2bb0,0x00000001b4100000)

Metaspace       used 27860K, capacity 28290K, committed 28800K, reserved 1075200K

  class space    used 2982K, capacity 3134K, committed 3200K, reserved 1048576K

}

karianna

Which version of Tomcat and Java is this and can you attach the GC log?  Make sure -XX:PrintGCDetails and -XX:+PrintTenuringDistribution are on.

2968813

Our Tomcat version is 7.0.23. Java version is Java HotSpot(TM) 64-Bit Server VM (25.60-b23) for solaris-sparc JRE (1.8.0_60-b27).

I do not have the GC logs as we are running Tomcat with flags to produce GC details in production. The JVM crash file has some details as shown below:

GC Heap History (10 events):

Event: 58964.566 GC heap before

{Heap before GC invocations=370 (full 17):

PSYoungGen      total 134144K, used 133846K [0x00000005d5700000, 0x00000005e3100000, 0x0000000800000000)

  eden space 132096K, 100% used [0x00000005d5700000,0x00000005dd800000,0x00000005dd800000)

  from space 2048K, 85% used [0x00000005e2f00000,0x00000005e30b5be0,0x00000005e3100000)

  to   space 3072K, 0% used [0x00000005e2b00000,0x00000005e2b00000,0x00000005e2e00000)

ParOldGen       total 1398272K, used 53760K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 3% used [0x0000000180400000,0x00000001838801e0,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

Event: 58964.571 GC heap after

Heap after GC invocations=370 (full 17):

PSYoungGen      total 133120K, used 1896K [0x00000005d5700000, 0x00000005e2f80000, 0x0000000800000000)

  eden space 131072K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005dd700000)

  from space 2048K, 92% used [0x00000005e2b00000,0x00000005e2cda270,0x00000005e2d00000)

  to   space 2560K, 0% used [0x00000005e2d00000,0x00000005e2d00000,0x00000005e2f80000)

ParOldGen       total 1398272K, used 54589K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 3% used [0x0000000180400000,0x000000018394f500,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

}

Event: 59064.864 GC heap before

{Heap before GC invocations=371 (full 17):

PSYoungGen      total 133120K, used 132968K [0x00000005d5700000, 0x00000005e2f80000, 0x0000000800000000)

  eden space 131072K, 100% used [0x00000005d5700000,0x00000005dd700000,0x00000005dd700000)

  from space 2048K, 92% used [0x00000005e2b00000,0x00000005e2cda270,0x00000005e2d00000)

  to   space 2560K, 0% used [0x00000005e2d00000,0x00000005e2d00000,0x00000005e2f80000)

ParOldGen       total 1398272K, used 54589K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 3% used [0x0000000180400000,0x000000018394f500,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

Event: 59064.868 GC heap after

Heap after GC invocations=371 (full 17):

PSYoungGen      total 132096K, used 1782K [0x00000005d5700000, 0x00000005e2f00000, 0x0000000800000000)

  eden space 130048K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005dd600000)

  from space 2048K, 87% used [0x00000005e2d00000,0x00000005e2ebdbe0,0x00000005e2f00000)

  to   space 2560K, 0% used [0x00000005e2a00000,0x00000005e2a00000,0x00000005e2c80000)

ParOldGen       total 1398272K, used 55400K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 3% used [0x0000000180400000,0x0000000183a1a3c0,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

}

Event: 59164.570 GC heap before

{Heap before GC invocations=372 (full 17):

PSYoungGen      total 132096K, used 131830K [0x00000005d5700000, 0x00000005e2f00000, 0x0000000800000000)

  eden space 130048K, 100% used [0x00000005d5700000,0x00000005dd600000,0x00000005dd600000)

  from space 2048K, 87% used [0x00000005e2d00000,0x00000005e2ebdbe0,0x00000005e2f00000)

  to   space 2560K, 0% used [0x00000005e2a00000,0x00000005e2a00000,0x00000005e2c80000)

ParOldGen       total 1398272K, used 55400K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 3% used [0x0000000180400000,0x0000000183a1a3c0,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

Event: 59164.575 GC heap after

Heap after GC invocations=372 (full 17):

PSYoungGen      total 131072K, used 1910K [0x00000005d5700000, 0x00000005e2d80000, 0x0000000800000000)

  eden space 129024K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005dd500000)

  from space 2048K, 93% used [0x00000005e2a00000,0x00000005e2bddbe0,0x00000005e2c00000)

  to   space 1536K, 0% used [0x00000005e2c00000,0x00000005e2c00000,0x00000005e2d80000)

ParOldGen       total 1398272K, used 56204K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 4% used [0x0000000180400000,0x0000000183ae3280,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

}

Event: 59263.622 GC heap before

{Heap before GC invocations=373 (full 17):

PSYoungGen      total 131072K, used 130934K [0x00000005d5700000, 0x00000005e2d80000, 0x0000000800000000)

  eden space 129024K, 100% used [0x00000005d5700000,0x00000005dd500000,0x00000005dd500000)

  from space 2048K, 93% used [0x00000005e2a00000,0x00000005e2bddbe0,0x00000005e2c00000)

  to   space 1536K, 0% used [0x00000005e2c00000,0x00000005e2c00000,0x00000005e2d80000)

ParOldGen       total 1398272K, used 56204K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 4% used [0x0000000180400000,0x0000000183ae3280,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

Event: 59263.626 GC heap after

Heap after GC invocations=373 (full 17):

PSYoungGen      total 129536K, used 1506K [0x00000005d5700000, 0x00000005e2d80000, 0x0000000800000000)

  eden space 128000K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005dd400000)

  from space 1536K, 98% used [0x00000005e2c00000,0x00000005e2d78830,0x00000005e2d80000)

  to   space 3072K, 0% used [0x00000005e2780000,0x00000005e2780000,0x00000005e2a80000)

ParOldGen       total 1398272K, used 57197K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 4% used [0x0000000180400000,0x0000000183bdb720,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

}

Event: 59361.675 GC heap before

{Heap before GC invocations=374 (full 17):

PSYoungGen      total 129536K, used 129506K [0x00000005d5700000, 0x00000005e2d80000, 0x0000000800000000)

  eden space 128000K, 100% used [0x00000005d5700000,0x00000005dd400000,0x00000005dd400000)

  from space 1536K, 98% used [0x00000005e2c00000,0x00000005e2d78830,0x00000005e2d80000)

  to   space 3072K, 0% used [0x00000005e2780000,0x00000005e2780000,0x00000005e2a80000)

ParOldGen       total 1398272K, used 57197K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 4% used [0x0000000180400000,0x0000000183bdb720,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

Event: 59361.680 GC heap after

Heap after GC invocations=374 (full 17):

PSYoungGen      total 129024K, used 1927K [0x00000005d5700000, 0x00000005e2c80000, 0x0000000800000000)

  eden space 126976K, 0% used [0x00000005d5700000,0x00000005d5700000,0x00000005dd300000)

  from space 2048K, 94% used [0x00000005e2780000,0x00000005e2961e10,0x00000005e2980000)

  to   space 2560K, 0% used [0x00000005e2a00000,0x00000005e2a00000,0x00000005e2c80000)

ParOldGen       total 1398272K, used 58025K [0x0000000180400000, 0x00000001d5980000, 0x00000005d5700000)

  object space 1398272K, 4% used [0x0000000180400000,0x0000000183caa5e0,0x00000001d5980000)

Metaspace       used 27184K, capacity 27600K, committed 27904K, reserved 1075200K

  class space    used 2909K, capacity 3036K, committed 3072K, reserved 1048576K

}

karianna

Hi there,

Can you switch on the logging for the next run?

2968813

Hi,

I enabled garbage collection logging. Attached are the latest crash log and gc log files.

Thanks.

karianna

Are you meant to be running this in 32-bit mode? 

2968813

No, we should be running in 64-bit mode. The log file says the same I believe:

vm_info: Java HotSpot(TM) 64-Bit Server VM (25.60-b23) for solaris-sparc JRE (1.8.0_60-b27)

karianna

OK, it's not a regular Java heap issue (you have plenty of space).  So I'm guessing that since this involves SSL sockets that you're either running out of threads or file descriptors.

I'd attach visual vm to the running JMV and see what the thread count is next.  Also check the O/S guide for seeing how many file descriptors you have open and how many you're allowed to have as a max.

2968813

I have been monitoring the process using jconsole and the peak thread count is usually less between 100 and 150. So I don't think that is a problem. The file descriptors limit is set to 1024. I did not see any log messages in Tomcat's log file that this limit has reached.

karianna

I assume there was no upgrade to Tomcat or Java or the app that co-incided with the instability?  If not then I'm leaning towards an O/S or hardware issue.