From 3328706a75ae6e7a602de1e3f082d9a00b5ebea8 Mon Sep 17 00:00:00 2001 From: phh Date: Thu, 9 Apr 2020 13:07:11 +0000 Subject: [PATCH] 8191393: Random crashes during cfree+0x1c Summary: Synchronize gcLogFileStream::write/rotate_log Reviewed-by: adinn, phh, snazarki Contributed-by: xxinliu@amazon.com --- src/share/vm/runtime/vmThread.cpp | 3 +- src/share/vm/runtime/vmThread.hpp | 3 ++ src/share/vm/utilities/ostream.cpp | 64 +++++++++++++++++++++++------- src/share/vm/utilities/ostream.hpp | 4 ++ 4 files changed, 58 insertions(+), 16 deletions(-) diff --git a/src/share/vm/runtime/vmThread.cpp b/src/share/vm/runtime/vmThread.cpp index 130d2e0b8..b27c2874b 100644 --- a/src/share/vm/runtime/vmThread.cpp +++ b/src/share/vm/runtime/vmThread.cpp @@ -209,8 +209,9 @@ void VMOperationQueue::oops_do(OopClosure* f) { //------------------------------------------------------------------------------------------------------------------ // Implementation of VMThread stuff -bool VMThread::_should_terminate = false; +bool VMThread::_should_terminate = false; bool VMThread::_terminated = false; +bool VMThread::_gclog_reentry = false; Monitor* VMThread::_terminate_lock = NULL; VMThread* VMThread::_vm_thread = NULL; VM_Operation* VMThread::_cur_vm_operation = NULL; diff --git a/src/share/vm/runtime/vmThread.hpp b/src/share/vm/runtime/vmThread.hpp index 2682d9d5f..a6d1ad316 100644 --- a/src/share/vm/runtime/vmThread.hpp +++ b/src/share/vm/runtime/vmThread.hpp @@ -96,6 +96,7 @@ class VMThread: public NamedThread { static bool _should_terminate; static bool _terminated; + static bool _gclog_reentry; static Monitor * _terminate_lock; static PerfCounter* _perf_accumulated_vm_operation_time; @@ -115,6 +116,8 @@ class VMThread: public NamedThread { static void wait_for_vm_thread_exit(); static bool should_terminate() { return _should_terminate; } static bool is_terminated() { return _terminated == true; } + static bool is_gclog_reentry() { return _gclog_reentry; } + static void set_gclog_reentry(bool reentry) { _gclog_reentry = reentry; } // Execution of vm operation static void execute(VM_Operation* op); diff --git a/src/share/vm/utilities/ostream.cpp b/src/share/vm/utilities/ostream.cpp index 1b00f829a..775fe3cd2 100644 --- a/src/share/vm/utilities/ostream.cpp +++ b/src/share/vm/utilities/ostream.cpp @@ -27,6 +27,7 @@ #include "gc_implementation/shared/gcId.hpp" #include "oops/oop.inline.hpp" #include "runtime/arguments.hpp" +#include "runtime/mutexLocker.hpp" #include "runtime/os.hpp" #include "utilities/defaultStream.hpp" #include "utilities/ostream.hpp" @@ -794,9 +795,11 @@ gcLogFileStream::~gcLogFileStream() { FREE_C_HEAP_ARRAY(char, _file_name, mtInternal); _file_name = NULL; } + + delete _file_lock; } -gcLogFileStream::gcLogFileStream(const char* file_name) { +gcLogFileStream::gcLogFileStream(const char* file_name) : _file_lock(NULL) { _cur_file_num = 0; _bytes_written = 0L; _file_name = make_log_name(file_name, NULL); @@ -819,6 +822,10 @@ gcLogFileStream::gcLogFileStream(const char* file_name) { if (_file != NULL) { _need_close = true; dump_loggc_header(); + + if (UseGCLogFileRotation) { + _file_lock = new Mutex(Mutex::leaf, "GCLogFile"); + } } else { warning("Cannot open file %s due to %s\n", _file_name, strerror(errno)); _need_close = false; @@ -827,21 +834,54 @@ gcLogFileStream::gcLogFileStream(const char* file_name) { void gcLogFileStream::write(const char* s, size_t len) { if (_file != NULL) { - size_t count = fwrite(s, 1, len, _file); - _bytes_written += count; + // we can't use Thread::current() here because thread may be NULL + // in early stage(ostream_init_log) + Thread* thread = ThreadLocalStorage::thread(); + + // avoid the mutex in the following cases + // 1) ThreadLocalStorage::thread() hasn't been initialized + // 2) _file_lock is not in use. + // 3) current() is VMThread and its reentry flag is set + if (!thread || !_file_lock || (thread->is_VM_thread() + && ((VMThread* )thread)->is_gclog_reentry())) { + size_t count = fwrite(s, 1, len, _file); + _bytes_written += count; + } + else { + MutexLockerEx ml(_file_lock, Mutex::_no_safepoint_check_flag); + size_t count = fwrite(s, 1, len, _file); + _bytes_written += count; + } } update_position(s, len); } -// rotate_log must be called from VMThread at safepoint. In case need change parameters +// rotate_log must be called from VMThread at a safepoint. In case need change parameters // for gc log rotation from thread other than VMThread, a sub type of VM_Operation // should be created and be submitted to VMThread's operation queue. DO NOT call this -// function directly. Currently, it is safe to rotate log at safepoint through VMThread. -// That is, no mutator threads and concurrent GC threads run parallel with VMThread to -// write to gc log file at safepoint. If in future, changes made for mutator threads or -// concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log -// must be synchronized. +// function directly. It is safe to rotate log through VMThread because +// no mutator threads run concurrently with the VMThread, and GC threads that run +// concurrently with the VMThread are synchronized in write and rotate_log via _file_lock. +// rotate_log can write log entries, so write supports reentry for it. void gcLogFileStream::rotate_log(bool force, outputStream* out) { + #ifdef ASSERT + Thread *thread = Thread::current(); + assert(thread == NULL || + (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()), + "Must be VMThread at safepoint"); + #endif + + VMThread* vmthread = VMThread::vm_thread(); + { + // nop if _file_lock is NULL. + MutexLockerEx ml(_file_lock, Mutex::_no_safepoint_check_flag); + vmthread->set_gclog_reentry(true); + rotate_log_impl(force, out); + vmthread->set_gclog_reentry(false); + } +} + +void gcLogFileStream::rotate_log_impl(bool force, outputStream* out) { char time_msg[O_BUFLEN]; char time_str[EXTRACHARLEN]; char current_file_name[JVM_MAXPATHLEN]; @@ -851,12 +891,6 @@ void gcLogFileStream::rotate_log(bool force, outputStream* out) { return; } -#ifdef ASSERT - Thread *thread = Thread::current(); - assert(thread == NULL || - (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()), - "Must be VMThread at safepoint"); -#endif if (NumberOfGCLogFiles == 1) { // rotate in same file rewind(); diff --git a/src/share/vm/utilities/ostream.hpp b/src/share/vm/utilities/ostream.hpp index b4e7378cf..fbcb2994d 100644 --- a/src/share/vm/utilities/ostream.hpp +++ b/src/share/vm/utilities/ostream.hpp @@ -235,11 +235,15 @@ class fdStream : public outputStream { void flush() {}; }; +class Mutex; class gcLogFileStream : public fileStream { protected: const char* _file_name; jlong _bytes_written; uintx _cur_file_num; // current logfile rotation number, from 0 to NumberOfGCLogFiles-1 + private: + Mutex* _file_lock; + void rotate_log_impl(bool force, outputStream* out); public: gcLogFileStream(const char* file_name); ~gcLogFileStream(); -- GitLab