8157240: GC task trace logging is incomprehensible
authorjmasa
Thu, 19 May 2016 13:59:50 -0700
changeset 39704 157f39705057
parent 39703 66722c5bc87a
child 39705 55baa0ddef24
8157240: GC task trace logging is incomprehensible Reviewed-by: tschatzl, redestad
hotspot/src/share/vm/gc/parallel/gcTaskManager.cpp
hotspot/src/share/vm/gc/parallel/gcTaskManager.hpp
hotspot/src/share/vm/gc/parallel/gcTaskThread.cpp
hotspot/src/share/vm/gc/parallel/gcTaskThread.hpp
hotspot/src/share/vm/gc/shared/workerManager.hpp
hotspot/src/share/vm/gc/shared/workgroup.cpp
hotspot/src/share/vm/gc/shared/workgroup.hpp
hotspot/test/gc/ergonomics/TestInitialGCThreadLogging.java
--- a/hotspot/src/share/vm/gc/parallel/gcTaskManager.cpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/parallel/gcTaskManager.cpp	Thu May 19 13:59:50 2016 -0700
@@ -386,13 +386,21 @@
 
 void GCTaskManager::add_workers(bool initializing) {
   os::ThreadType worker_type = os::pgc_thread;
+  uint previous_created_workers = _created_workers;
+
   _created_workers = WorkerManager::add_workers(this,
                                                 _active_workers,
-                                                (uint) _workers,
+                                                _workers,
                                                 _created_workers,
                                                 worker_type,
                                                 initializing);
   _active_workers = MIN2(_created_workers, _active_workers);
+
+  WorkerManager::log_worker_creation(this, previous_created_workers, _active_workers, _created_workers, initializing);
+}
+
+const char* GCTaskManager::group_name() {
+  return "ParGC Thread";
 }
 
 void GCTaskManager::initialize() {
--- a/hotspot/src/share/vm/gc/parallel/gcTaskManager.hpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/parallel/gcTaskManager.hpp	Thu May 19 13:59:50 2016 -0700
@@ -556,6 +556,8 @@
   GCTaskThread* install_worker(uint worker_id);
   // Add GC workers as needed.
   void add_workers(bool initializing);
+  // Base name (without worker id #) of threads.
+  const char* group_name();
 };
 
 //
--- a/hotspot/src/share/vm/gc/parallel/gcTaskThread.cpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/parallel/gcTaskThread.cpp	Thu May 19 13:59:50 2016 -0700
@@ -45,7 +45,7 @@
   _time_stamp_index(0)
 {
   set_id(which);
-  set_name("ParGC Thread#%d", which);
+  set_name("%s#%d", manager->group_name(), which);
 }
 
 GCTaskThread::~GCTaskThread() {
--- a/hotspot/src/share/vm/gc/parallel/gcTaskThread.hpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/parallel/gcTaskThread.hpp	Thu May 19 13:59:50 2016 -0700
@@ -55,6 +55,7 @@
     return new GCTaskThread(manager, which, processor_id);
   }
  public:
+
   static void destroy(GCTaskThread* manager) {
     if (manager != NULL) {
       delete manager;
--- a/hotspot/src/share/vm/gc/shared/workerManager.hpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/shared/workerManager.hpp	Thu May 19 13:59:50 2016 -0700
@@ -47,18 +47,18 @@
   // threads and a failure would not be optimal but should not be fatal.
   template <class WorkerType>
   static uint add_workers (WorkerType* holder,
-                   uint active_workers,
-                   uint total_workers,
-                   uint created_workers,
-                   os::ThreadType worker_type,
-                   bool initializing) {
+                           uint active_workers,
+                           uint total_workers,
+                           uint created_workers,
+                           os::ThreadType worker_type,
+                           bool initializing) {
     uint start = created_workers;
     uint end = MIN2(active_workers, total_workers);
     for (uint worker_id = start; worker_id < end; worker_id += 1) {
       WorkerThread* new_worker = holder->install_worker(worker_id);
       assert(new_worker != NULL, "Failed to allocate GangWorker");
       if (new_worker == NULL || !os::create_thread(new_worker, worker_type)) {
-        if(initializing) {
+        if (initializing) {
           vm_exit_out_of_memory(0, OOM_MALLOC_ERROR,
                   "Cannot create worker GC thread. Out of system resources.");
         }
@@ -67,11 +67,21 @@
       os::start_thread(new_worker);
     }
 
-    log_trace(gc, task)("AdaptiveSizePolicy::add_workers() : "
-       "active_workers: %u created_workers: %u",
-       active_workers, created_workers);
+    return created_workers;
+  }
 
-    return created_workers;
+  // Log (at trace level) a change in the number of created workers.
+  template <class WorkerType>
+  static void log_worker_creation(WorkerType* holder,
+                                  uint previous_created_workers,
+                                  uint active_workers,
+                                  uint created_workers,
+                                  bool initializing) {
+    if (previous_created_workers < created_workers) {
+      const char* initializing_msg =  initializing ? "Adding initial" : "Creating additional";
+      log_trace(gc, task)("%s %s(s) previously created workers %u active workers %u total created workers %u",
+                          initializing_msg, holder->group_name(), previous_created_workers, active_workers, created_workers);
+    }
   }
 };
 #endif // SHARE_VM_GC_SHARED_WORKERMANAGER_HPP
--- a/hotspot/src/share/vm/gc/shared/workgroup.cpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/shared/workgroup.cpp	Thu May 19 13:59:50 2016 -0700
@@ -66,6 +66,7 @@
   } else {
     worker_type = os::pgc_thread;
   }
+  uint previous_created_workers = _created_workers;
 
   _created_workers = WorkerManager::add_workers(this,
                                                 active_workers,
@@ -74,6 +75,8 @@
                                                 worker_type,
                                                 initializing);
   _active_workers = MIN2(_created_workers, _active_workers);
+
+  WorkerManager::log_worker_creation(this, previous_created_workers, _active_workers, _created_workers, initializing);
 }
 
 AbstractGangWorker* AbstractWorkGang::worker(uint i) const {
--- a/hotspot/src/share/vm/gc/shared/workgroup.hpp	Tue Jun 21 14:00:18 2016 +0200
+++ b/hotspot/src/share/vm/gc/shared/workgroup.hpp	Thu May 19 13:59:50 2016 -0700
@@ -176,6 +176,9 @@
   // Return the Ith worker.
   AbstractGangWorker* worker(uint i) const;
 
+  // Base name (without worker id #) of threads.
+  const char* group_name() { return name(); }
+
   void threads_do(ThreadClosure* tc) const;
 
   // Create a GC worker and install it into the work gang.
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/gc/ergonomics/TestInitialGCThreadLogging.java	Thu May 19 13:59:50 2016 -0700
@@ -0,0 +1,60 @@
+/*
+ * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+/*
+ * @test TestInitialGCThreadLogging
+ * @bug 8157240
+ * @summary Check trace logging of initial GC threads.
+ * @requires vm.gc=="null"
+ * @key gc
+ * @modules java.base/jdk.internal.misc
+ * @library /testlibrary
+ */
+
+import jdk.test.lib.ProcessTools;
+import jdk.test.lib.OutputAnalyzer;
+
+public class TestInitialGCThreadLogging {
+  public static void main(String[] args) throws Exception {
+
+    testInitialGCThreadLogging("UseConcMarkSweepGC", "GC Thread");
+
+    testInitialGCThreadLogging("UseG1GC", "GC Thread");
+
+    testInitialGCThreadLogging("UseParallelGC", "ParGC Thread");
+  }
+
+  private static void verifyDynamicNumberOfGCThreads(OutputAnalyzer output, String threadName) {
+    output.shouldHaveExitValue(0); // test should run succesfully
+    output.shouldContain(threadName);
+  }
+
+  private static void testInitialGCThreadLogging(String gcFlag, String threadName) throws Exception {
+    // UseDynamicNumberOfGCThreads and TraceDynamicGCThreads enabled
+    String[] baseArgs = {"-XX:+" + gcFlag, "-Xmx10M", "-XX:+UseDynamicNumberOfGCThreads", "-Xlog:gc+task=trace", "-version"};
+
+    // Base test with gc and +UseDynamicNumberOfGCThreads:
+    ProcessBuilder pb_enabled = ProcessTools.createJavaProcessBuilder(baseArgs);
+    verifyDynamicNumberOfGCThreads(new OutputAnalyzer(pb_enabled.start()), threadName);
+  }
+}