8145083: Use semaphore instead of mutex for synchronization of Unified Logging configuration
authormlarsson
Mon, 04 Jan 2016 11:37:18 +0100
changeset 35228 e7bbfb90fd31
parent 35227 176e593eb364
child 35229 b8d78ee728b2
8145083: Use semaphore instead of mutex for synchronization of Unified Logging configuration Reviewed-by: dholmes, kbarrett, mgronlun
hotspot/src/share/vm/logging/log.cpp
hotspot/src/share/vm/logging/logConfiguration.cpp
hotspot/src/share/vm/logging/logDiagnosticCommand.cpp
hotspot/src/share/vm/logging/logOutput.cpp
hotspot/src/share/vm/logging/logOutput.hpp
hotspot/src/share/vm/prims/jvmtiEnv.cpp
hotspot/src/share/vm/runtime/mutexLocker.cpp
hotspot/src/share/vm/runtime/mutexLocker.hpp
hotspot/src/share/vm/services/memoryService.cpp
--- a/hotspot/src/share/vm/logging/log.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/logging/log.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -36,7 +36,6 @@
   remove("loglengthoutput.txt");
 
   // Write long message to output file
-  MutexLocker ml(LogConfiguration_lock);
   LogConfiguration::parse_log_arguments("loglengthoutput.txt", "logging=trace",
     NULL, NULL, NULL);
   ResourceMark rm;
--- a/hotspot/src/share/vm/logging/logConfiguration.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/logging/logConfiguration.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -33,23 +33,50 @@
 #include "logging/logTagSet.hpp"
 #include "memory/allocation.inline.hpp"
 #include "memory/resourceArea.hpp"
-#include "runtime/mutexLocker.hpp"
 #include "runtime/os.inline.hpp"
+#include "runtime/semaphore.hpp"
 #include "utilities/globalDefinitions.hpp"
 
 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
+// (when calling configure_output or reading/modifying the outputs array).
+// Thread must never block when holding this lock.
+class ConfigurationLock : public StackObj {
+ private:
+  // Semaphore used as lock
+  static Semaphore _semaphore;
+  debug_only(static intx _locking_thread_id;)
+ public:
+  ConfigurationLock() {
+    _semaphore.wait();
+    debug_only(_locking_thread_id = os::current_thread_id());
+  }
+  ~ConfigurationLock() {
+    debug_only(_locking_thread_id = -1);
+    _semaphore.signal();
+  }
+  debug_only(static bool current_thread_has_lock();)
+};
+
+Semaphore ConfigurationLock::_semaphore(1);
+#ifdef ASSERT
+intx ConfigurationLock::_locking_thread_id = -1;
+bool ConfigurationLock::current_thread_has_lock() {
+  return _locking_thread_id == os::current_thread_id();
+}
+#endif
+
 void LogConfiguration::post_initialize() {
-  assert(LogConfiguration_lock != NULL, "Lock must be initialized before post-initialization");
   LogDiagnosticCommand::registerCommand();
   LogHandle(logging) log;
   log.info("Log configuration fully initialized.");
   log_develop_info(logging)("Develop logging is available.");
   if (log.is_trace()) {
     ResourceMark rm;
-    MutexLocker ml(LogConfiguration_lock);
     describe(log.trace_stream());
   }
 
@@ -129,6 +156,7 @@
 }
 
 void LogConfiguration::configure_output(size_t idx, const LogTagLevelExpression& tag_level_expression, const LogDecorators& decorators) {
+  assert(ConfigurationLock::current_thread_has_lock(), "Must hold configuration lock to call this function.");
   assert(idx < _n_outputs, "Invalid index, idx = " SIZE_FORMAT " and _n_outputs = " SIZE_FORMAT, idx, _n_outputs);
   LogOutput* output = _outputs[idx];
 
@@ -208,17 +236,13 @@
 }
 
 void LogConfiguration::disable_logging() {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "LogConfiguration lock must be held when calling this function");
+  ConfigurationLock cl;
   for (size_t i = 0; i < _n_outputs; i++) {
     disable_output(i);
   }
 }
 
 void LogConfiguration::configure_stdout(LogLevelType level, bool exact_match, ...) {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "LogConfiguration lock must be held when calling this function");
-
   size_t i;
   va_list ap;
   LogTagLevelExpression expr;
@@ -242,6 +266,7 @@
   expr.new_combination();
 
   // Apply configuration to stdout (output #0), with the same decorators as before.
+  ConfigurationLock cl;
   configure_output(0, expr, LogOutput::Stdout->decorators());
 }
 
@@ -289,12 +314,21 @@
                                            const char* decoratorstr,
                                            const char* output_options,
                                            outputStream* errstream) {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "LogConfiguration lock must be held when calling this function");
   if (outputstr == NULL || strlen(outputstr) == 0) {
     outputstr = "stdout";
   }
 
+  LogTagLevelExpression expr;
+  if (!expr.parse(what, errstream)) {
+    return false;
+  }
+
+  LogDecorators decorators;
+  if (!decorators.parse(decoratorstr, errstream)) {
+    return false;
+  }
+
+  ConfigurationLock cl;
   size_t idx;
   if (outputstr[0] == '#') {
     int ret = sscanf(outputstr+1, SIZE_FORMAT, &idx);
@@ -321,25 +355,11 @@
       errstream->print_cr("Output options for existing outputs are ignored.");
     }
   }
-
-  LogTagLevelExpression expr;
-  if (!expr.parse(what, errstream)) {
-    return false;
-  }
-
-  LogDecorators decorators;
-  if (!decorators.parse(decoratorstr, errstream)) {
-    return false;
-  }
-
   configure_output(idx, expr, decorators);
   return true;
 }
 
 void LogConfiguration::describe(outputStream* out) {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "LogConfiguration lock must be held when calling this function");
-
   out->print("Available log levels:");
   for (size_t i = 0; i < LogLevel::Count; i++) {
     out->print("%s %s", (i == 0 ? "" : ","), LogLevel::name(static_cast<LogLevelType>(i)));
@@ -359,6 +379,7 @@
   }
   out->cr();
 
+  ConfigurationLock cl;
   out->print_cr("Log output configuration:");
   for (size_t i = 0; i < _n_outputs; i++) {
     out->print("#" SIZE_FORMAT ": %s %s ", i, _outputs[i]->name(), _outputs[i]->config_string());
--- a/hotspot/src/share/vm/logging/logDiagnosticCommand.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/logging/logDiagnosticCommand.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -25,7 +25,6 @@
 #include "logging/logConfiguration.hpp"
 #include "logging/logDiagnosticCommand.hpp"
 #include "memory/resourceArea.hpp"
-#include "runtime/mutexLocker.hpp"
 #include "utilities/globalDefinitions.hpp"
 
 LogDiagnosticCommand::LogDiagnosticCommand(outputStream* output, bool heap_allocated)
@@ -65,13 +64,11 @@
 void LogDiagnosticCommand::execute(DCmdSource source, TRAPS) {
   bool any_command = false;
   if (_disable.has_value()) {
-    MutexLocker ml(LogConfiguration_lock);
     LogConfiguration::disable_logging();
     any_command = true;
   }
 
   if (_output.has_value() || _what.has_value() || _decorators.has_value()) {
-    MutexLocker ml(LogConfiguration_lock);
     if (!LogConfiguration::parse_log_arguments(_output.value(),
                                                _what.value(),
                                                _decorators.value(),
@@ -83,7 +80,6 @@
   }
 
   if (_list.has_value()) {
-    MutexLocker ml(LogConfiguration_lock);
     LogConfiguration::describe(output());
     any_command = true;
   }
--- a/hotspot/src/share/vm/logging/logOutput.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/logging/logOutput.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -37,9 +37,6 @@
 }
 
 void LogOutput::clear_config_string() {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "Must hold configuration lock to modify config string");
-
   os::free(_config_string);
   _config_string_buffer_size = InitialConfigBufferSize;
   _config_string = NEW_C_HEAP_ARRAY(char, _config_string_buffer_size, mtLogging);
@@ -47,18 +44,12 @@
 }
 
 void LogOutput::set_config_string(const char* string) {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "Must hold configuration lock to modify config string");
-
   os::free(_config_string);
   _config_string = os::strdup(string, mtLogging);
   _config_string_buffer_size = strlen(_config_string) + 1;
 }
 
 void LogOutput::add_to_config_string(const LogTagSet* ts, LogLevelType level) {
-  assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
-         "Must hold configuration lock to modify config string");
-
   if (_config_string_buffer_size < InitialConfigBufferSize) {
     _config_string_buffer_size = InitialConfigBufferSize;
     _config_string = REALLOC_C_HEAP_ARRAY(char, _config_string, _config_string_buffer_size, mtLogging);
--- a/hotspot/src/share/vm/logging/logOutput.hpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/logging/logOutput.hpp	Mon Jan 04 11:37:18 2016 +0100
@@ -36,6 +36,9 @@
 // Keeps track of the latest configuration string,
 // and its selected decorators.
 class LogOutput : public CHeapObj<mtLogging> {
+  // Make LogConfiguration a friend to allow it to modify the configuration string.
+  friend class LogConfiguration;
+
  private:
   static const size_t InitialConfigBufferSize = 256;
   char* _config_string;
@@ -44,6 +47,13 @@
  protected:
   LogDecorators _decorators;
 
+  // Clears any previous config description in preparation of reconfiguration.
+  void clear_config_string();
+  // Adds the tagset on the given level to the config description (e.g. "tag1+tag2=level").
+  void add_to_config_string(const LogTagSet* ts, LogLevelType level);
+  // Replaces the current config description with the given string.
+  void set_config_string(const char* string);
+
  public:
   static LogOutput* const Stdout;
   static LogOutput* const Stderr;
@@ -65,13 +75,6 @@
 
   virtual ~LogOutput();
 
-  // Clears any previous config description in preparation of reconfiguration.
-  void clear_config_string();
-  // Adds the tagset on the given level to the config description (e.g. "tag1+tag2=level").
-  void add_to_config_string(const LogTagSet* ts, LogLevelType level);
-  // Replaces the current config description with the given string.
-  void set_config_string(const char* string);
-
   virtual const char* name() const = 0;
   virtual bool initialize(const char* options) = 0;
   virtual int write(const LogDecorations &decorations, const char* msg) = 0;
--- a/hotspot/src/share/vm/prims/jvmtiEnv.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/prims/jvmtiEnv.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -629,21 +629,10 @@
     TraceClassUnloading = value != 0;
     break;
   case JVMTI_VERBOSE_GC:
-    {
-      // This is a temporary solution to work around initialization issues.
-      // JDK-8145083 will fix this.
-      Mutex* conf_mutex = LogConfiguration_lock;
-      if (Threads::number_of_threads() == 0) {
-        // We're too early in the initialization to use mutexes
-        LogConfiguration_lock = NULL;
-      }
-      MutexLockerEx ml(LogConfiguration_lock);
-      if (value == 0) {
-        LogConfiguration::parse_log_arguments("stdout", "gc=off", NULL, NULL, NULL);
-      } else {
-        LogConfiguration::parse_log_arguments("stdout", "gc", NULL, NULL, NULL);
-      }
-      LogConfiguration_lock = conf_mutex;
+    if (value == 0) {
+      LogConfiguration::parse_log_arguments("stdout", "gc=off", NULL, NULL, NULL);
+    } else {
+      LogConfiguration::parse_log_arguments("stdout", "gc", NULL, NULL, NULL);
     }
     break;
   case JVMTI_VERBOSE_JNI:
--- a/hotspot/src/share/vm/runtime/mutexLocker.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/runtime/mutexLocker.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -127,7 +127,6 @@
 Mutex*   Management_lock              = NULL;
 Monitor* Service_lock                 = NULL;
 Monitor* PeriodicTask_lock            = NULL;
-Mutex*   LogConfiguration_lock        = NULL;
 
 #ifdef INCLUDE_TRACE
 Mutex*   JfrStacktrace_lock           = NULL;
@@ -284,7 +283,6 @@
   if (WhiteBoxAPI) {
     def(Compilation_lock           , Monitor, leaf,        false, Monitor::_safepoint_check_never);
   }
-  def(LogConfiguration_lock        , Mutex,   nonleaf,     false, Monitor::_safepoint_check_always);
 
 #ifdef INCLUDE_TRACE
   def(JfrMsg_lock                  , Monitor, leaf,        true,  Monitor::_safepoint_check_always);
--- a/hotspot/src/share/vm/runtime/mutexLocker.hpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/runtime/mutexLocker.hpp	Mon Jan 04 11:37:18 2016 +0100
@@ -127,7 +127,6 @@
 extern Mutex*   Management_lock;                 // a lock used to serialize JVM management
 extern Monitor* Service_lock;                    // a lock used for service thread operation
 extern Monitor* PeriodicTask_lock;               // protects the periodic task structure
-extern Mutex*   LogConfiguration_lock;           // protects configuration of logging
 
 #ifdef INCLUDE_TRACE
 extern Mutex*   JfrStacktrace_lock;              // used to guard access to the JFR stacktrace table
--- a/hotspot/src/share/vm/services/memoryService.cpp	Mon Jan 04 11:27:02 2016 +0100
+++ b/hotspot/src/share/vm/services/memoryService.cpp	Mon Jan 04 11:37:18 2016 +0100
@@ -518,7 +518,6 @@
 bool MemoryService::set_verbose(bool verbose) {
   MutexLocker m(Management_lock);
   // verbose will be set to the previous value
-  MutexLocker ml(LogConfiguration_lock);
   if (verbose) {
     LogConfiguration::parse_log_arguments("stdout", "gc", NULL, NULL, NULL);
   } else {