Thu, 09 Apr 2020 13:07:11 +0000
8191393: Random crashes during cfree+0x1c
Summary: Synchronize gcLogFileStream::write/rotate_log
Reviewed-by: adinn, phh, snazarki
Contributed-by: xxinliu@amazon.com
1.1 --- a/src/share/vm/runtime/vmThread.cpp Mon Nov 18 23:41:06 2019 -0500 1.2 +++ b/src/share/vm/runtime/vmThread.cpp Thu Apr 09 13:07:11 2020 +0000 1.3 @@ -209,8 +209,9 @@ 1.4 //------------------------------------------------------------------------------------------------------------------ 1.5 // Implementation of VMThread stuff 1.6 1.7 -bool VMThread::_should_terminate = false; 1.8 +bool VMThread::_should_terminate = false; 1.9 bool VMThread::_terminated = false; 1.10 +bool VMThread::_gclog_reentry = false; 1.11 Monitor* VMThread::_terminate_lock = NULL; 1.12 VMThread* VMThread::_vm_thread = NULL; 1.13 VM_Operation* VMThread::_cur_vm_operation = NULL;
2.1 --- a/src/share/vm/runtime/vmThread.hpp Mon Nov 18 23:41:06 2019 -0500 2.2 +++ b/src/share/vm/runtime/vmThread.hpp Thu Apr 09 13:07:11 2020 +0000 2.3 @@ -96,6 +96,7 @@ 2.4 2.5 static bool _should_terminate; 2.6 static bool _terminated; 2.7 + static bool _gclog_reentry; 2.8 static Monitor * _terminate_lock; 2.9 static PerfCounter* _perf_accumulated_vm_operation_time; 2.10 2.11 @@ -115,6 +116,8 @@ 2.12 static void wait_for_vm_thread_exit(); 2.13 static bool should_terminate() { return _should_terminate; } 2.14 static bool is_terminated() { return _terminated == true; } 2.15 + static bool is_gclog_reentry() { return _gclog_reentry; } 2.16 + static void set_gclog_reentry(bool reentry) { _gclog_reentry = reentry; } 2.17 2.18 // Execution of vm operation 2.19 static void execute(VM_Operation* op);
3.1 --- a/src/share/vm/utilities/ostream.cpp Mon Nov 18 23:41:06 2019 -0500 3.2 +++ b/src/share/vm/utilities/ostream.cpp Thu Apr 09 13:07:11 2020 +0000 3.3 @@ -27,6 +27,7 @@ 3.4 #include "gc_implementation/shared/gcId.hpp" 3.5 #include "oops/oop.inline.hpp" 3.6 #include "runtime/arguments.hpp" 3.7 +#include "runtime/mutexLocker.hpp" 3.8 #include "runtime/os.hpp" 3.9 #include "utilities/defaultStream.hpp" 3.10 #include "utilities/ostream.hpp" 3.11 @@ -794,9 +795,11 @@ 3.12 FREE_C_HEAP_ARRAY(char, _file_name, mtInternal); 3.13 _file_name = NULL; 3.14 } 3.15 + 3.16 + delete _file_lock; 3.17 } 3.18 3.19 -gcLogFileStream::gcLogFileStream(const char* file_name) { 3.20 +gcLogFileStream::gcLogFileStream(const char* file_name) : _file_lock(NULL) { 3.21 _cur_file_num = 0; 3.22 _bytes_written = 0L; 3.23 _file_name = make_log_name(file_name, NULL); 3.24 @@ -819,6 +822,10 @@ 3.25 if (_file != NULL) { 3.26 _need_close = true; 3.27 dump_loggc_header(); 3.28 + 3.29 + if (UseGCLogFileRotation) { 3.30 + _file_lock = new Mutex(Mutex::leaf, "GCLogFile"); 3.31 + } 3.32 } else { 3.33 warning("Cannot open file %s due to %s\n", _file_name, strerror(errno)); 3.34 _need_close = false; 3.35 @@ -827,21 +834,54 @@ 3.36 3.37 void gcLogFileStream::write(const char* s, size_t len) { 3.38 if (_file != NULL) { 3.39 - size_t count = fwrite(s, 1, len, _file); 3.40 - _bytes_written += count; 3.41 + // we can't use Thread::current() here because thread may be NULL 3.42 + // in early stage(ostream_init_log) 3.43 + Thread* thread = ThreadLocalStorage::thread(); 3.44 + 3.45 + // avoid the mutex in the following cases 3.46 + // 1) ThreadLocalStorage::thread() hasn't been initialized 3.47 + // 2) _file_lock is not in use. 3.48 + // 3) current() is VMThread and its reentry flag is set 3.49 + if (!thread || !_file_lock || (thread->is_VM_thread() 3.50 + && ((VMThread* )thread)->is_gclog_reentry())) { 3.51 + size_t count = fwrite(s, 1, len, _file); 3.52 + _bytes_written += count; 3.53 + } 3.54 + else { 3.55 + MutexLockerEx ml(_file_lock, Mutex::_no_safepoint_check_flag); 3.56 + size_t count = fwrite(s, 1, len, _file); 3.57 + _bytes_written += count; 3.58 + } 3.59 } 3.60 update_position(s, len); 3.61 } 3.62 3.63 -// rotate_log must be called from VMThread at safepoint. In case need change parameters 3.64 +// rotate_log must be called from VMThread at a safepoint. In case need change parameters 3.65 // for gc log rotation from thread other than VMThread, a sub type of VM_Operation 3.66 // should be created and be submitted to VMThread's operation queue. DO NOT call this 3.67 -// function directly. Currently, it is safe to rotate log at safepoint through VMThread. 3.68 -// That is, no mutator threads and concurrent GC threads run parallel with VMThread to 3.69 -// write to gc log file at safepoint. If in future, changes made for mutator threads or 3.70 -// concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log 3.71 -// must be synchronized. 3.72 +// function directly. It is safe to rotate log through VMThread because 3.73 +// no mutator threads run concurrently with the VMThread, and GC threads that run 3.74 +// concurrently with the VMThread are synchronized in write and rotate_log via _file_lock. 3.75 +// rotate_log can write log entries, so write supports reentry for it. 3.76 void gcLogFileStream::rotate_log(bool force, outputStream* out) { 3.77 + #ifdef ASSERT 3.78 + Thread *thread = Thread::current(); 3.79 + assert(thread == NULL || 3.80 + (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()), 3.81 + "Must be VMThread at safepoint"); 3.82 + #endif 3.83 + 3.84 + VMThread* vmthread = VMThread::vm_thread(); 3.85 + { 3.86 + // nop if _file_lock is NULL. 3.87 + MutexLockerEx ml(_file_lock, Mutex::_no_safepoint_check_flag); 3.88 + vmthread->set_gclog_reentry(true); 3.89 + rotate_log_impl(force, out); 3.90 + vmthread->set_gclog_reentry(false); 3.91 + } 3.92 +} 3.93 + 3.94 +void gcLogFileStream::rotate_log_impl(bool force, outputStream* out) { 3.95 char time_msg[O_BUFLEN]; 3.96 char time_str[EXTRACHARLEN]; 3.97 char current_file_name[JVM_MAXPATHLEN]; 3.98 @@ -851,12 +891,6 @@ 3.99 return; 3.100 } 3.101 3.102 -#ifdef ASSERT 3.103 - Thread *thread = Thread::current(); 3.104 - assert(thread == NULL || 3.105 - (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()), 3.106 - "Must be VMThread at safepoint"); 3.107 -#endif 3.108 if (NumberOfGCLogFiles == 1) { 3.109 // rotate in same file 3.110 rewind();
4.1 --- a/src/share/vm/utilities/ostream.hpp Mon Nov 18 23:41:06 2019 -0500 4.2 +++ b/src/share/vm/utilities/ostream.hpp Thu Apr 09 13:07:11 2020 +0000 4.3 @@ -235,11 +235,15 @@ 4.4 void flush() {}; 4.5 }; 4.6 4.7 +class Mutex; 4.8 class gcLogFileStream : public fileStream { 4.9 protected: 4.10 const char* _file_name; 4.11 jlong _bytes_written; 4.12 uintx _cur_file_num; // current logfile rotation number, from 0 to NumberOfGCLogFiles-1 4.13 + private: 4.14 + Mutex* _file_lock; 4.15 + void rotate_log_impl(bool force, outputStream* out); 4.16 public: 4.17 gcLogFileStream(const char* file_name); 4.18 ~gcLogFileStream();