JBR-5480 Include more information in OOME crash reports

This commit is contained in:
Maxim Kartashev
2023-04-11 19:14:03 +04:00
committed by jbrbot
parent e511c26794
commit 44f8dc85da
7 changed files with 330 additions and 0 deletions

View File

@@ -86,6 +86,7 @@
#include "utilities/macros.hpp"
#include "utilities/ostream.hpp"
#include "utilities/preserveException.hpp"
#include "utilities/vmError.hpp"
// A helper class for caching a Method* when the user of the cache
// only cares about the latest version of the Method*. This cache safely
@@ -909,6 +910,8 @@ jint universe_init() {
ResolvedMethodTable::create_table();
VMError::init();
return JNI_OK;
}

View File

@@ -155,6 +155,8 @@ Monitor* JVMCI_lock = nullptr;
Monitor* JVMCIRuntime_lock = nullptr;
#endif
Mutex* OOMEStacks_lock = nullptr;
// Only one RecursiveMutex
RecursiveMutex* MultiArray_lock = nullptr;
@@ -354,6 +356,7 @@ void mutex_init() {
MUTEX_DEFL(JVMCI_lock , PaddedMonitor, JVMCIRuntime_lock);
#endif
MUTEX_DEFL(JvmtiThreadState_lock , PaddedMutex , JvmtiVTMSTransition_lock); // Used by JvmtiThreadState/JvmtiEventController
MUTEX_DEFN(OOMEStacks_lock , PaddedMutex , safepoint);
// Allocate RecursiveMutex
MultiArray_lock = new RecursiveMutex();

View File

@@ -157,6 +157,8 @@ extern Mutex* Bootclasspath_lock;
extern Mutex* tty_lock; // lock to synchronize output.
extern Mutex* OOMEStacks_lock;
// A MutexLocker provides mutual exclusion with respect to a given mutex
// for the scope which contains the locker. The lock is an OS lock, not
// an object lock, and the two do not interoperate. Do not use Mutex-based

View File

@@ -253,6 +253,8 @@ void report_untested(const char* file, int line, const char* message) {
void report_java_out_of_memory(const char* message) {
static int out_of_memory_reported = 0;
VMError::record_oome_stack(message);
// A number of threads may attempt to report OutOfMemoryError at around the
// same time. To avoid dumping the heap or executing the data collection
// commands multiple times we just do it once when the first threads reports

View File

@@ -26,6 +26,7 @@
#include "precompiled.hpp"
#include "cds/metaspaceShared.hpp"
#include "classfile/classLoaderDataGraph.hpp"
#include "code/codeCache.hpp"
#include "compiler/compilationFailureInfo.hpp"
#include "compiler/compileBroker.hpp"
@@ -1327,6 +1328,17 @@ void VMError::report(outputStream* st, bool _verbose) {
JNIHandles::print_on_unsafe(st);
JNIHandles::print_memory_usage_on(st);
STEP("OOME stack traces")
st->print_cr("OOME stack traces (most recent first):");
print_oome_stacks(st);
STEP("Classloader stats")
st->print_cr("Classloader memory used:");
FREE_C_HEAP_ARRAY(void*, _ballast_memory);
_ballast_memory = nullptr;
print_classloaders_stats(st);
print_dup_classes(st); // do it separately in case we're low on memory
STEP_IF("printing system", _verbose)
st->print_cr("--------------- S Y S T E M ---------------");
st->cr();
@@ -2175,3 +2187,179 @@ VMErrorCallbackMark::~VMErrorCallbackMark() {
assert(_thread->_vm_error_callbacks != nullptr, "Popped too far");
_thread->_vm_error_callbacks = _thread->_vm_error_callbacks->_next;
}
char VMError::_oome_stacktrace[OOME_STACKTRACE_COUNT][OOME_STACKTRACE_BUFSIZE];
int VMError::_oome_free_index;
void * VMError::_ballast_memory;
void VMError::init() {
_oome_free_index = 0;
// This will be released before dumping classes statistics as the latter
// may need to allocate some memory in an OOME situation.
_ballast_memory = NEW_C_HEAP_ARRAY(void*, 36000*4, mtStatistics);
}
void VMError::record_oome_stack(const char *message) {
MutexLocker ml(OOMEStacks_lock);
static char buf[O_BUFLEN];
stringStream st(_oome_stacktrace[_oome_free_index], OOME_STACKTRACE_BUFSIZE);
st.print_cr("OutOfMemoryError(\"%s\"):", message);
if (os::platform_print_native_stack(&st, _context, buf, sizeof(buf))) {
// We have printed the native stack in platform-specific code
// Windows/x64 needs special handling.
} else {
print_native_stack(&st, os::current_frame(), Thread::current(), true, -1, buf, sizeof(buf));
_print_native_stack_used = true;
}
st.cr();
if (Thread::current()->is_Java_thread()) {
print_stack_trace(&st, JavaThread::current(), buf, sizeof(buf));
}
_oome_free_index = (_oome_free_index + 1) % OOME_STACKTRACE_COUNT;
}
void VMError::print_oome_stacks(outputStream *st) {
int index = _oome_free_index == 0 ? OOME_STACKTRACE_COUNT - 1 : _oome_free_index - 1;
for (int i = 0; i < OOME_STACKTRACE_COUNT; i++) {
const char * const trace = _oome_stacktrace[index];
if (strcmp(trace, "") != 0) st->print_raw_cr(trace);
index = index == 0 ? OOME_STACKTRACE_COUNT - 1 : index - 1;
}
}
class CLDCounterClosure : public CLDClosure {
public:
// Loader Klass -> memory used in words
using TABLE = ResizeableResourceHashtable<Klass*, size_t, AnyObj::C_HEAP, mtStatistics>;
private:
TABLE& _loaded_size;
public:
explicit CLDCounterClosure(TABLE& loaded_size) : _loaded_size(loaded_size) {}
void do_cld(ClassLoaderData* cld) override {
Klass * const loader = cld->class_loader_klass();
ClassLoaderMetaspace * const ms = cld->metaspace_or_null();
if (ms != nullptr) {
size_t used_words = 0;
ms->usage_numbers(&used_words, nullptr, nullptr);
const size_t * const new_size_ptr = _loaded_size.get(loader);
size_t new_size = new_size_ptr == nullptr
? used_words
: *new_size_ptr + used_words;
_loaded_size.put(loader, new_size);
}
}
};
static int compare_by_size(Pair<Klass *, size_t>* p1, Pair<Klass *, size_t>* p2) {
return p2->second == p1->second
? 0
: p2->second > p1->second ? 1 : -1;
}
void VMError::print_classloaders_stats(outputStream *st) {
if (_thread) {
ResourceMark rm(_thread);
MutexLocker ml(_thread, ClassLoaderDataGraph_lock);
CLDCounterClosure::TABLE sizes(10, 100);
CLDCounterClosure counter(sizes);
ClassLoaderDataGraph::cld_do(&counter);
GrowableArray<Pair<Klass *, size_t>> loaders_stats;
sizes.iterate_all([&] (Klass* loader_klass, size_t total_words) {
loaders_stats.push(Pair<Klass *, size_t>(loader_klass, total_words));
});
loaders_stats.sort(compare_by_size);
for (const auto loaders_stat : loaders_stats) {
Klass * const loader_klass = loaders_stat.first;
const size_t total_words = loaders_stat.second;
const char *name = loader_klass != nullptr
? loader_klass->external_name()
: BOOTSTRAP_LOADER_NAME;
const size_t total_bytes = total_words * BytesPerWord;
st->print_cr("Loader %-80s: " SIZE_FORMAT "%s",
name,
byte_size_in_proper_unit(total_bytes),
proper_unit_for_byte_size(total_bytes));
}
st->cr();
} else {
st->print_cr("Not available (crashed in non-Java thread)");
}
}
class DuplicateKlassClosure : public KlassClosure {
static bool klass_equals(Klass* const & klass1, Klass* const & klass2) {
return strcmp(klass1->external_name(), klass2->external_name()) == 0;
}
static unsigned klass_hash(Klass* const & k) {
int h = 0;
const char* p = k->external_name();
while (*p != '\0') {
h = 31 * h + *p;
p++;
}
return h;
}
public:
// Klass -> number times loaded
using TABLE = ResizeableResourceHashtable<Klass*, size_t, AnyObj::C_HEAP,
mtStatistics, &klass_hash, &klass_equals>;
private:
TABLE& _classes_count;
public:
explicit DuplicateKlassClosure(TABLE& classes_count) : _classes_count(classes_count) {}
void do_klass(Klass* klass) override {
const size_t * const new_count_ptr = _classes_count.get(klass);
const size_t new_count = new_count_ptr != nullptr ? *new_count_ptr + 1 : 1;
_classes_count.put(klass, new_count);
}
};
void VMError::print_dup_classes(outputStream *st) {
if (_thread) {
ResourceMark rm(_thread);
RecursiveLocker rl(MultiArray_lock, _thread);
MutexLocker mcld(_thread, ClassLoaderDataGraph_lock);
DuplicateKlassClosure::TABLE classes_count(100, 200);
DuplicateKlassClosure counter(classes_count);
ClassLoaderDataGraph::loaded_classes_do_keepalive(&counter);
GrowableArray<Pair<Klass *, size_t>> dup_classes;
classes_count.iterate_all([&] (Klass* const name, size_t count) {
if (count > 1) dup_classes.push(Pair<Klass *, size_t>(name, count));
});
if (dup_classes.length() > 0) {
st->print_cr("Classes loaded by more than one classloader:");
dup_classes.sort(compare_by_size);
for (const auto dup : dup_classes) {
const char * const name = dup.first->external_name();
const size_t size = dup.first->size();
const size_t count = dup.second;
st->print_cr("Class %-80s: loaded " SIZE_FORMAT " times (x " SIZE_FORMAT "B)",
name, count, size);
}
st->cr();
}
}
}

View File

@@ -69,6 +69,12 @@ class VMError : public AllStatic {
// used for reattempt step logic
static const size_t _reattempt_required_stack_headroom;
static const int OOME_STACKTRACE_BUFSIZE = 16*K;
static const int OOME_STACKTRACE_COUNT = 4;
static char _oome_stacktrace[OOME_STACKTRACE_COUNT][OOME_STACKTRACE_BUFSIZE];
static int _oome_free_index;
static void * _ballast_memory;
// Thread id of the first error. We must be able to handle native thread,
// so use thread id instead of Thread* to identify thread.
static volatile intptr_t _first_error_tid;
@@ -225,6 +231,11 @@ public:
// permissions.
static int prepare_log_file(const char* pattern, const char* default_pattern, bool overwrite_existing, char* buf, size_t buflen);
static void init();
static void record_oome_stack(const char *message);
static void print_oome_stacks(outputStream *st);
static void print_classloaders_stats(outputStream *st);
static void print_dup_classes(outputStream *st);
};
class VMErrorCallback {

View File

@@ -0,0 +1,121 @@
/*
* Copyright 2023 JetBrains s.r.o.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
/**
* @test
* @summary Verifies that the HotSpot crash log includes recent OOME
* stack traces and some classloader statistics.
* @library /test/lib
* @modules java.base/jdk.internal.misc
* @run main OOMEStacksInCrashLog
*/
import jdk.test.lib.process.ProcessTools;
import jdk.test.lib.process.OutputAnalyzer;
import java.io.IOException;
import java.io.InputStream;
import java.util.ArrayList;
public class OOMEStacksInCrashLog {
public static void main(String args[]) throws Exception {
if (args.length > 0 && args[0].equals("--test")) {
loadClasses();
System.out.println("Proceeding to crash JVM with OOME");
crashJVM();
System.out.println("...shouldn't reach here");
} else {
generateAndVerifyCrashLogContents();
}
}
static void crashJVM() {
System.out.println("------- first attempt to crash -------");
long[][][] array = new long[100][][];
for (int i = 0; i < 100; i++) {
System.out.println("------- crash attempt #" + i + "-------");
array[i] = new long[1000][1000];
}
int random = (int) (Math.random() * 100);
System.out.println(array[random][42][0]);
System.out.println(class1);
System.out.println(class2);
System.out.println(class3);
}
static class MyClassLoader extends ClassLoader {
public MyClassLoader(ClassLoader parent) {
super("my test classloader", parent);
}
@Override
protected Class<?> findClass(String name) throws ClassNotFoundException {
if (name.equals("OOMEStacksInCrashLog")) {
try (final InputStream classStream = OOMEStacksInCrashLog.class.getClassLoader()
.getResourceAsStream("OOMEStacksInCrashLog.class")) {
byte[] classBytes = classStream.readAllBytes();
final Class<?> c = defineClass(name, classBytes, 0, classBytes.length);
resolveClass(c);
return c;
} catch (IOException e) {
throw new RuntimeException(e);
}
} else {
return super.findClass(name);
}
}
}
static Class<?> class1;
static Class<?> class2;
static Class<?> class3;
static void loadClasses() throws Exception {
MyClassLoader loader1 = new MyClassLoader(OOMEStacksInCrashLog.class.getClassLoader());
class1 = loader1.findClass("OOMEStacksInCrashLog");
MyClassLoader loader2 = new MyClassLoader(OOMEStacksInCrashLog.class.getClassLoader());
class2 = loader2.findClass("OOMEStacksInCrashLog");
MyClassLoader loader3 = new MyClassLoader(OOMEStacksInCrashLog.class.getClassLoader());
class3 = loader3.findClass("OOMEStacksInCrashLog");
}
public static void generateAndVerifyCrashLogContents() throws Exception {
ArrayList<String> opts = new ArrayList<>();
opts.add("--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED");
opts.add("-Xmx20m");
opts.add("-XX:-CreateCoredumpOnCrash");
opts.add("-XX:+CrashOnOutOfMemoryError");
opts.add("-XX:+ErrorFileToStdout");
opts.add(OOMEStacksInCrashLog.class.getName());
opts.add("--test");
ProcessBuilder pb = ProcessTools.createTestJvm(opts);
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.outputTo(System.out);
output.shouldContain("OOME stack traces (most recent first)");
output.shouldContain("OOMEStacksInCrashLog.crashJVM()");
output.shouldContain("Loader bootstrap");
output.shouldContain("Loader OOMEStacksInCrashLog$MyClassLoader");
output.shouldContain("Classloader memory used:");
output.shouldContain("OOMEStacksInCrashLog : loaded 4 times");
}
}