A bug fix for Tomcat's automatic shutdown

Preface

Recently, a Java EE web project that has been running for 4 years has often received feedback from customers that the system cannot be opened. I logged into the server to check the service and found that Tomcat was automatically shut down. It basically happens every 3 to 4 days.

The operation and maintenance personnel initially thought that other services killed the Tomcat service and did not take it seriously. The solution was to restart Tomcat directly.

Eventually, things got out of hand and the operation and maintenance personnel were complained by customers and had one month’s performance pay deducted.

The solution to this bug came to me after a lot of twists and turns. Now that you have received the task, just get to work. There is no bug that cannot be solved.

The system's operating environment is as follows:

tomcat6.0
32-bit JDK 7.0
window server2003 32-bit, 32G memory.

Check the logs. If Tomcat crashes, a log file starting with "hs_err" will be generated in the bin directory of Tomcat. Open the latest log file, and the first thing you see is the following paragraph:

# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32756 bytes for ChunkPool::allocate
# Possible reasons:
# The system is out of physical RAM or swap space
# In 32 bit mode, the process size limit was hit
# Possible solutions:
# Reduce memory load on the system
# Increase physical memory or swap space
# Check if swap backing store is full
# Use 64 bit Java on a 64 bit OS
# Decrease Java heap size (-Xmx/-Xms)
# Decrease number of Java threads
# Decrease Java thread stack sizes (-Xss)
# Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
# Out of Memory Error (allocation.cpp:211), pid=7864, tid=6556
#
# JRE version: Java(TM) SE Runtime Environment (7.0_79-b15) (build 1.7.0_79-b15)
# Java VM: Java HotSpot(TM) Server VM (24.79-b02 mixed mode windows-x86 )
# Failed to write core dump.

It probably means that there is not enough memory to allocate 32756 bytes of space. Here are some solutions:

1. Reduce system memory load;

2. Increase physical memory or swap space;

3. Use 64-bit JDK on a 64-bit operating system;

4. Reduce the Java heap size;

5. Reduce the number of Java threads;

6. Reduce the Java thread stack size.

From the above content, it can be concluded that the jvm cannot allocate 32756 bytes of memory space.

From the moment I received the task, I always thought that it was a JVM configuration error that caused insufficient memory, and I only needed to adjust the configuration of the new generation and old generation.

Continue to look at the log file and find the line "GC Heap History (10 events):", which records the changes in the heap during the last 10 garbage collections of the JVM.

GC Heap History (10 events):
Event: 572312.299 GC heap before
{Heap before GC invocations=5046 (full 357):
PSYoungGen total 201472K, used 200685K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 100% used [0x573c0000,0x63540000,0x63540000)
from space 3328K, 76% used [0x63540000,0x637bb528,0x63880000)
to space 3328K, 0% used [0x63880000,0x63880000,0x63bc0000)
ParOldGen total 843776K, used 422602K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d872b18,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
Event: 572312.305 GC heap after
Heap after GC invocations=5046 (full 357):
PSYoungGen total 201472K, used 1103K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 0% used [0x573c0000,0x573c0000,0x63540000)
from space 3328K, 33% used [0x63880000,0x63993c90,0x63bc0000)
to space 3328K, 0% used [0x63540000,0x63540000,0x63880000)
ParOldGen total 843776K, used 423618K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d970b18,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
}
Event: 572351.132 GC heap before
{Heap before GC invocations=5047 (full 357):
PSYoungGen total 201472K, used 199247K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 100% used [0x573c0000,0x63540000,0x63540000)
from space 3328K, 33% used [0x63880000,0x63993c90,0x63bc0000)
to space 3328K, 0% used [0x63540000,0x63540000,0x63880000)
ParOldGen total 843776K, used 423618K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d970b18,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
Event: 572351.137 GC heap after
Heap after GC invocations=5047 (full 357):
PSYoungGen total 201472K, used 1615K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 0% used [0x573c0000,0x573c0000,0x63540000)
from space 3328K, 48% used [0x63540000,0x636d3ec8,0x63880000)
to space 3328K, 0% used [0x63880000,0x63880000,0x63bc0000)
ParOldGen total 843776K, used 423674K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d97eb18,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
}
Event: 572398.649 GC heap before
{Heap before GC invocations=5048 (full 357):
PSYoungGen total 201472K, used 199759K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 100% used [0x573c0000,0x63540000,0x63540000)
from space 3328K, 48% used [0x63540000,0x636d3ec8,0x63880000)
to space 3328K, 0% used [0x63880000,0x63880000,0x63bc0000)
ParOldGen total 843776K, used 423674K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d97eb18,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
Event: 572398.655 GC heap after
Heap after GC invocations=5048 (full 357):
PSYoungGen total 201472K, used 1998K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 0% used [0x573c0000,0x573c0000,0x63540000)
from space 3328K, 60% used [0x63880000,0x63a73830,0x63bc0000)
to space 3328K, 0% used [0x63540000,0x63540000,0x63880000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51848K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62138,0x13bc0000)
}
Event: 576881.689 GC heap before
{Heap before GC invocations=5049 (full 357):
PSYoungGen total 201472K, used 200142K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 100% used [0x573c0000,0x63540000,0x63540000)
from space 3328K, 60% used [0x63880000,0x63a73830,0x63bc0000)
to space 3328K, 0% used [0x63540000,0x63540000,0x63880000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51850K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62850,0x13bc0000)
Event: 576881.696 GC heap after
Heap after GC invocations=5049 (full 357):
PSYoungGen total 201472K, used 3155K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 0% used [0x573c0000,0x573c0000,0x63540000)
from space 3328K, 94% used [0x63540000,0x63854cb0,0x63880000)
to space 3328K, 0% used [0x63880000,0x63880000,0x63bc0000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51850K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e62850,0x13bc0000)
}
Event: 580535.452 GC heap before
{Heap before GC invocations=5050 (full 357):
PSYoungGen total 201472K, used 201299K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 198144K, 100% used [0x573c0000,0x63540000,0x63540000)
from space 3328K, 94% used [0x63540000,0x63854cb0,0x63880000)
to space 3328K, 0% used [0x63880000,0x63880000,0x63bc0000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51856K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e64228,0x13bc0000)
Event: 580535.459 GC heap after
Heap after GC invocations=5050 (full 357):
PSYoungGen total 200960K, used 1858K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 197632K, 0% used [0x573c0000,0x573c0000,0x634c0000)
from space 3328K, 55% used [0x63880000,0x63a50be0,0x63bc0000)
to space 3584K, 0% used [0x634c0000,0x634c0000,0x63840000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51856K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e64228,0x13bc0000)
}

After reading the above content, I did not find that the tomcat flash crash was caused by insufficient space in the old generation, permanent generation, and new generation. There were several full GCs caused by 100% usage of the eden space, but after garbage collection, the space in the eden area returned to normal levels.

The log also records the heap usage when Tomcat crashes:

Heap
PSYoungGen total 200960K, used 95671K [0x573c0000, 0x63bc0000, 0x63bc0000)
eden space 197632K, 47% used [0x573c0000,0x5cf5d230,0x634c0000)
from space 3328K, 55% used [0x63880000,0x63a50be0,0x63bc0000)
to space 3584K, 0% used [0x634c0000,0x634c0000,0x63840000)
ParOldGen total 843776K, used 423703K [0x23bc0000, 0x573c0000, 0x573c0000)
object space 843776K, 50% used [0x23bc0000,0x3d985cc0,0x573c0000)
PSPermGen total 262144K, used 51856K [0x03bc0000, 0x13bc0000, 0x23bc0000)
object space 262144K, 19% used [0x03bc0000,0x06e64228,0x13bc0000)

Everything was so normal, yet so weird at the same time.

I looked through the previous logs and the contents were similar.

I reread the logs a few times, this time focusing on the solutions suggested in the logs:

# Reduce memory load on the system
# Increase physical memory or swap space
# Check if swap backing store is full
# Use 64 bit Java on a 64 bit OS
# Decrease Java heap size (-Xmx/-Xms)
# Decrease number of Java threads
# Decrease Java thread stack sizes (-Xss)

The following solutions are not adopted:

Reduce memory load on the system. The system memory is sufficient. There is 32G of memory, and 20G is left unused. There is no need to reduce the memory.
Increase physical memory or swap space. The system memory is sufficient. There is 32G of memory, and 20G is left unused. There is no need to increase the physical memory.
Use 64 bit Java on a 64 bit OS. 32-bit operating system, 64-bit JDK cannot be used.

Only the following three solutions remain:

Decrease Java heap size (-Xmx/-Xms). If the heap is set too large, it will affect the remaining memory.
Decrease number of Java threads
Decrease Java thread stack sizes (-Xss)

Reducing the number of Java threads requires modifying the code, which is not practical either.

Finally, only

Decrease Java heap size (-Xmx/-Xms)
Decrease Java thread stack sizes (-Xss)

These are the two solutions. Start from here and there will be light ahead.

First look at the Decrease Java thread stack sizes (-Xss) solution

Java threads also require memory space to run. The -Xss parameter specifies the size of each thread stack and the memory size allocated to each thread started by the jvm. In JDK 1.4, it is 256K, and in JDK 1.5 and above, it is 1M.

The parameters of tomcat jvm are set as follows:

JAVA_OPTS=%JAVA_OPTS% -server -Xms1024m -Xmx1024m -Xmn200M -XX:PermSize=256M -XX:MaxPermSize=512m -XX:SurvivorRatio=1 -Xss256k

The stack size of each Java thread has been set to 256K via -Xss.

In Java language, when you create a thread, the virtual machine will create a Thread object in the JVM memory and create an operating system thread at the same time. The memory of this system thread is not JVMMemory, but the remaining memory in the system (MaxProcessMemory - JVMMemory - ReservedOsMemory).

When a thread needs to be created and the remaining memory of the operating system is insufficient to allocate to a Java thread, an Out of Memory Error will be reported.

Since the Java thread stack size has been set to 256K via -Xss, it was decided not to use this solution.

Now the only solution left is Decrease Java heap size (-Xmx/-Xms). By reducing the size of the heap, enough memory space is left for the Java thread stack.

The 32-bit Windows operating system allocates 2G of memory space to each process, minus the maximum capacity of the heap and the maximum capacity of PermSize, and the remaining capacity is reserved for the Java thread stack.

After analyzing the code and previous error logs, it was found that Out of Memory Error usually occurs around 350 threads.
At the time of the error, less than 40% of the heap space was used. Therefore, it was decided to reduce the Java heap from 1G to 768M.

The modified jvm parameters are as follows:

JAVA_OPTS=%JAVA_OPTS% -server -Xms768m -Xmx768m -Xmn200M -XX:PermSize=256M -XX:MaxPermSize=512m -XX:SurvivorRatio=1 -Xss256k

So far, the system has been running stably for one month, and all parameter indicators are within the normal range. The maximum heap usage is only 70%.

Summarize:

1. After solving the bug this time, I have deepened my understanding of the Java virtual machine, especially the concepts of thread stack, memory heap, persistent generation, new generation, etc.

2. Be sure to read the log files carefully and eliminate potential solutions step by step. Consider the operating environment of the comprehensive system and find a reasonable solution.

Well, that’s all for this article. I hope the content of this article will be of certain reference value to your study or work. Thank you for your support of 123WORDPRESS.COM.

You may also be interested in:

How to control Tomcat startup and shutdown in Asp.net
Solve the problem that shutting down Tomcat using shutdown.bat will shut down other Tomcats
How to start/stop Tomcat server in Java
Java code closes the tomcat program and analyzes the problems

<<: Detailed explanation of the error problem of case when statement

>>: Detailed explanation of function classification and examples of this pointing in Javascript