8145294: TestLogRotation.java triggers a race in the UL framework

Reviewed-by: sla, mgronlun

hotspot/src/share/vm/logging/logConfiguration.cpp

@@ -39,7 +39,6 @@
 
 LogOutput** LogConfiguration::_outputs = NULL;
 size_t      LogConfiguration::_n_outputs = 0;
-bool        LogConfiguration::_post_initialized = false;
 
 // Stack object to take the lock for configuring the logging.
 // Should only be held during the critical parts of the configuration
@@ -79,8 +78,6 @@ void LogConfiguration::post_initialize() {
     ResourceMark rm;
     describe(log.trace_stream());
   }
-
-  _post_initialized = true;
 }
 
 void LogConfiguration::initialize(jlong vm_start_time) {
@@ -469,10 +466,9 @@ void LogConfiguration::print_command_line_help(FILE* out) {
 }
 
 void LogConfiguration::rotate_all_outputs() {
-  for (size_t idx = 0; idx < _n_outputs; idx++) {
-    if (_outputs[idx]->is_rotatable()) {
-      _outputs[idx]->rotate(true);
-    }
+  // Start from index 2 since neither stdout nor stderr can be rotated.
+  for (size_t idx = 2; idx < _n_outputs; idx++) {
+    _outputs[idx]->force_rotate();
   }
 }
 

hotspot/src/share/vm/logging/logConfiguration.hpp

@@ -40,7 +40,6 @@ class LogConfiguration : public AllStatic {
  private:
   static LogOutput**  _outputs;
   static size_t       _n_outputs;
-  static bool         _post_initialized;
 
   // Create a new output. Returns NULL if failed.
   static LogOutput* new_output(char* name, const char* options, outputStream* errstream);
@@ -96,10 +95,6 @@ class LogConfiguration : public AllStatic {
   // Prints usage help for command line log configuration.
   static void print_command_line_help(FILE* out);
 
-  static bool is_post_initialized() {
-    return _post_initialized;
-  }
-
   // Rotates all LogOutput
   static void rotate_all_outputs();
 };

hotspot/src/share/vm/logging/logFileOutput.cpp

@@ -26,7 +26,6 @@
 #include "logging/logConfiguration.hpp"
 #include "logging/logFileOutput.hpp"
 #include "memory/allocation.inline.hpp"
-#include "runtime/mutexLocker.hpp"
 #include "runtime/os.inline.hpp"
 #include "utilities/globalDefinitions.hpp"
 #include "utilities/defaultStream.hpp"
@@ -43,8 +42,7 @@ char        LogFileOutput::_vm_start_time_str[StartTimeBufferSize];
 LogFileOutput::LogFileOutput(const char* name)
     : LogFileStreamOutput(NULL), _name(os::strdup_check_oom(name, mtLogging)),
       _file_name(NULL), _archive_name(NULL), _archive_name_len(0), _current_size(0),
-      _rotate_size(0), _current_file(1), _file_count(0),
-      _rotation_lock(Mutex::leaf, "LogFileOutput rotation lock", true, Mutex::_safepoint_check_sometimes) {
+      _rotate_size(0), _current_file(1), _file_count(0), _rotation_semaphore(1) {
   _file_name = make_file_name(name, _pid_str, _vm_start_time_str);
 }
 
@@ -152,10 +150,15 @@ int LogFileOutput::write(const LogDecorations& decorations, const char* msg) {
     // An error has occurred with this output, avoid writing to it.
     return 0;
   }
+
+  _rotation_semaphore.wait();
   int written = LogFileStreamOutput::write(decorations, msg);
   _current_size += written;
 
-  rotate(false);
+  if (should_rotate()) {
+    rotate();
+  }
+  _rotation_semaphore.signal();
 
   return written;
 }
@@ -177,19 +180,28 @@ void LogFileOutput::archive() {
   }
 }
 
-void LogFileOutput::rotate(bool force) {
-
-  if (!should_rotate(force)) {
+void LogFileOutput::force_rotate() {
+  if (_file_count == 0) {
+    // Rotation not possible
     return;
   }
+  _rotation_semaphore.wait();
+  rotate();
+  _rotation_semaphore.signal();
+}
 
-  MutexLockerEx ml(&_rotation_lock, true /* no safepoint check */);
+void LogFileOutput::rotate() {
+
+  if (fclose(_stream)) {
+    jio_fprintf(defaultStream::error_stream(), "Error closing file '%s' during log rotation (%s).\n",
+                _file_name, strerror(errno));
+  }
 
   // Archive the current log file
   archive();
 
   // Open the active log file using the same stream as before
-  _stream = freopen(_file_name, FileOpenMode, _stream);
+  _stream = fopen(_file_name, FileOpenMode);
   if (_stream == NULL) {
     jio_fprintf(defaultStream::error_stream(), "Could not reopen file '%s' during log rotation (%s).\n",
                 _file_name, strerror(errno));

hotspot/src/share/vm/logging/logFileOutput.hpp

@@ -25,7 +25,7 @@
 #define SHARE_VM_LOGGING_LOGFILEOUTPUT_HPP
 
 #include "logging/logFileStreamOutput.hpp"
-#include "runtime/mutex.hpp"
+#include "runtime/semaphore.hpp"
 #include "utilities/globalDefinitions.hpp"
 
 class LogDecorations;
@@ -44,7 +44,6 @@ class LogFileOutput : public LogFileStreamOutput {
   static char         _pid_str[PidBufferSize];
   static char         _vm_start_time_str[StartTimeBufferSize];
 
-  Mutex _rotation_lock;
   const char* _name;
   char* _file_name;
   char* _archive_name;
@@ -57,14 +56,17 @@ class LogFileOutput : public LogFileStreamOutput {
   size_t  _rotate_size;
   size_t  _current_size;
 
+  // Semaphore used for synchronizing file rotations and writes
+  Semaphore _rotation_semaphore;
+
   void archive();
+  void rotate();
   bool configure_rotation(const char* options);
   char *make_file_name(const char* file_name, const char* pid_string, const char* timestamp_string);
   static size_t parse_value(const char* value_str);
 
-  bool should_rotate(bool force) {
-    return is_rotatable() &&
-             (force || (_rotate_size > 0 && _current_size >= _rotate_size));
+  bool should_rotate() {
+    return _file_count > 0 && _rotate_size > 0 && _current_size >= _rotate_size;
   }
 
  public:
@@ -72,12 +74,7 @@ class LogFileOutput : public LogFileStreamOutput {
   virtual ~LogFileOutput();
   virtual bool initialize(const char* options);
   virtual int write(const LogDecorations& decorations, const char* msg);
-
-  virtual bool is_rotatable() {
-    return LogConfiguration::is_post_initialized() && (_file_count > 0);
-  }
-
-  virtual void rotate(bool force);
+  virtual void force_rotate();
 
   virtual const char* name() const {
     return _name;

hotspot/src/share/vm/logging/logOutput.hpp

@@ -75,17 +75,15 @@ class LogOutput : public CHeapObj<mtLogging> {
 
   virtual ~LogOutput();
 
+  // If the output can be rotated, trigger a forced rotation, otherwise do nothing.
+  // Log outputs with rotation capabilities should override this.
+  virtual void force_rotate() {
+    // Do nothing by default.
+  }
+
   virtual const char* name() const = 0;
   virtual bool initialize(const char* options) = 0;
   virtual int write(const LogDecorations &decorations, const char* msg) = 0;
-
-  virtual bool is_rotatable() {
-    return false;
-  }
-
-  virtual void rotate(bool force) {
-    // Do nothing by default.
-  }
 };
 
 #endif // SHARE_VM_LOGGING_LOGOUTPUT_HPP