8364638: Refactor and make accumulated GC CPU time code generic

Reviewed-by: ayang, sjohanss

Author: JonasNorlinder

src/hotspot/share/gc/shared/collectedHeap.cpp

@@ -201,34 +201,6 @@ void CollectedHeap::print_relative_to_gc(GCWhen::Type when) const {
   }
 }
 
-class CPUTimeThreadClosure : public ThreadClosure {
-private:
-  jlong _cpu_time = 0;
-
-public:
-  virtual void do_thread(Thread* thread) {
-    jlong cpu_time = os::thread_cpu_time(thread);
-    if (cpu_time != -1) {
-      _cpu_time += cpu_time;
-    }
-  }
-  jlong cpu_time() { return _cpu_time; };
-};
-
-double CollectedHeap::elapsed_gc_cpu_time() const {
-  double string_dedup_cpu_time = UseStringDeduplication ?
-    os::thread_cpu_time((Thread*)StringDedup::_processor->_thread) : 0;
-
-  if (string_dedup_cpu_time == -1) {
-    string_dedup_cpu_time = 0;
-  }
-
-  CPUTimeThreadClosure cl;
-  gc_threads_do(&cl);
-
-  return (double)(cl.cpu_time() + _vmthread_cpu_time + string_dedup_cpu_time) / NANOSECS_PER_SEC;
-}
-
 void CollectedHeap::print_before_gc() const {
   print_relative_to_gc(GCWhen::BeforeGC);
 }
@@ -633,36 +605,9 @@ void CollectedHeap::post_initialize() {
   initialize_serviceability();
 }
 
-void CollectedHeap::log_gc_cpu_time() const {
-  LogTarget(Info, gc, cpu) out;
-  if (os::is_thread_cpu_time_supported() && out.is_enabled()) {
-    double process_cpu_time = os::elapsed_process_cpu_time();
-    double gc_cpu_time = elapsed_gc_cpu_time();
-
-    if (process_cpu_time == -1 || gc_cpu_time == -1) {
-      log_warning(gc, cpu)("Could not sample CPU time");
-      return;
-    }
-
-    double usage;
-    if (gc_cpu_time > process_cpu_time ||
-        process_cpu_time == 0 || gc_cpu_time == 0) {
-      // This can happen e.g. for short running processes with
-      // low CPU utilization
-      usage = 0;
-    } else {
-      usage = 100 * gc_cpu_time / process_cpu_time;
-    }
-    out.print("GC CPU usage: %.2f%% (Process: %.4fs GC: %.4fs)", usage, process_cpu_time, gc_cpu_time);
-  }
-}
-
 void CollectedHeap::before_exit() {
   print_tracing_info();
 
-  // Log GC CPU usage.
-  log_gc_cpu_time();
-
   // Stop any on-going concurrent work and prepare for exit.
   stop();
 }

src/hotspot/share/gc/shared/collectedHeap.hpp

@@ -36,6 +36,7 @@
 #include "runtime/handles.hpp"
 #include "runtime/perfDataTypes.hpp"
 #include "runtime/safepoint.hpp"
+#include "services/cpuTimeUsage.hpp"
 #include "services/memoryUsage.hpp"
 #include "utilities/debug.hpp"
 #include "utilities/formatBuffer.hpp"
@@ -89,6 +90,7 @@ class ParallelObjectIterator : public StackObj {
 //   ZCollectedHeap
 //
 class CollectedHeap : public CHeapObj<mtGC> {
+  friend class CPUTimeUsage::GC;
   friend class VMStructs;
   friend class JVMCIVMStructs;
   friend class IsSTWGCActiveMark; // Block structured external access to _is_stw_gc_active
@@ -429,8 +431,6 @@ class CollectedHeap : public CHeapObj<mtGC> {
 
   void print_relative_to_gc(GCWhen::Type when) const;
 
-  void log_gc_cpu_time() const;
-
  public:
   void pre_full_gc_dump(GCTimer* timer);
   void post_full_gc_dump(GCTimer* timer);
@@ -463,8 +463,6 @@ class CollectedHeap : public CHeapObj<mtGC> {
   // Iterator for all GC threads (other than VM thread)
   virtual void gc_threads_do(ThreadClosure* tc) const = 0;
 
-  double elapsed_gc_cpu_time() const;
-
   void print_before_gc() const;
   void print_after_gc() const;
 

src/hotspot/share/gc/shared/stringdedup/stringDedup.hpp

@@ -103,9 +103,9 @@
 #include "memory/allocation.hpp"
 #include "memory/allStatic.hpp"
 #include "oops/oopsHierarchy.hpp"
+#include "services/cpuTimeUsage.hpp"
 #include "utilities/globalDefinitions.hpp"
 
-class CollectedHeap;
 class Klass;
 class StringDedupThread;
 class ThreadClosure;
@@ -116,7 +116,7 @@ class ThreadClosure;
 // feature.  Other functions in the StringDedup class are called where
 // needed, without requiring GC-specific code.
 class StringDedup : public AllStatic {
-  friend class CollectedHeap;
+  friend class CPUTimeUsage::GC;
   friend class StringDedupThread;
 
   class Config;

src/hotspot/share/gc/shared/stringdedup/stringDedupProcessor.hpp

@@ -27,9 +27,9 @@
 
 #include "gc/shared/stringdedup/stringDedup.hpp"
 #include "memory/allocation.hpp"
+#include "services/cpuTimeUsage.hpp"
 #include "utilities/macros.hpp"
 
-class CollectedHeap;
 class JavaThread;
 class OopStorage;
 
@@ -43,7 +43,7 @@ class OopStorage;
 // incremental operations for resizing and for removing dead entries, so
 // safepoint checks can be performed between steps in those operations.
 class StringDedup::Processor : public CHeapObj<mtGC> {
-  friend class CollectedHeap;
+  friend class CPUTimeUsage::GC;
 
   Processor();
   ~Processor() = default;

src/hotspot/share/memory/universe.cpp

@@ -81,11 +81,13 @@
 #include "runtime/threads.hpp"
 #include "runtime/timerTrace.hpp"
 #include "sanitizers/leak.hpp"
+#include "services/cpuTimeUsage.hpp"
 #include "services/memoryService.hpp"
 #include "utilities/align.hpp"
 #include "utilities/autoRestore.hpp"
 #include "utilities/debug.hpp"
 #include "utilities/formatBuffer.hpp"
+#include "utilities/globalDefinitions.hpp"
 #include "utilities/macros.hpp"
 #include "utilities/ostream.hpp"
 #include "utilities/preserveException.hpp"
@@ -1300,6 +1302,63 @@ void Universe::verify(VerifyOption option, const char* prefix) {
   }
 }
 
+static void log_cpu_time() {
+  LogTarget(Info, cpu) cpuLog;
+  if (!cpuLog.is_enabled()) {
+    return;
+  }
+
+  const double process_cpu_time = os::elapsed_process_cpu_time();
+  if (process_cpu_time == 0 || process_cpu_time == -1) {
+    // 0 can happen e.g. for short running processes with
+    // low CPU utilization
+    return;
+  }
+
+  const double gc_threads_cpu_time = (double) CPUTimeUsage::GC::gc_threads() / NANOSECS_PER_SEC;
+  const double gc_vm_thread_cpu_time = (double) CPUTimeUsage::GC::vm_thread() / NANOSECS_PER_SEC;
+  const double gc_string_dedup_cpu_time = (double) CPUTimeUsage::GC::stringdedup() / NANOSECS_PER_SEC;
+  const double gc_cpu_time = (double) gc_threads_cpu_time + gc_vm_thread_cpu_time + gc_string_dedup_cpu_time;
+
+  const double elasped_time = os::elapsedTime();
+  const bool has_error = CPUTimeUsage::Error::has_error();
+
+  if (gc_cpu_time < process_cpu_time) {
+    cpuLog.print("=== CPU time Statistics =============================================================");
+    if (has_error) {
+      cpuLog.print("WARNING: CPU time sampling reported errors, numbers may be unreliable");
+    }
+    cpuLog.print("                                                                            CPUs");
+    cpuLog.print("                                                               s       %%  utilized");
+    cpuLog.print("   Process");
+    cpuLog.print("     Total                        %30.4f  %6.2f  %8.1f", process_cpu_time, 100.0, process_cpu_time / elasped_time);
+    cpuLog.print("     Garbage Collection           %30.4f  %6.2f  %8.1f", gc_cpu_time, percent_of(gc_cpu_time, process_cpu_time), gc_cpu_time / elasped_time);
+    cpuLog.print("       GC Threads                 %30.4f  %6.2f  %8.1f", gc_threads_cpu_time, percent_of(gc_threads_cpu_time, process_cpu_time), gc_threads_cpu_time / elasped_time);
+    cpuLog.print("       VM Thread                  %30.4f  %6.2f  %8.1f", gc_vm_thread_cpu_time, percent_of(gc_vm_thread_cpu_time, process_cpu_time), gc_vm_thread_cpu_time / elasped_time);
+
+    if (UseStringDeduplication) {
+      cpuLog.print("       String Deduplication       %30.4f  %6.2f  %8.1f", gc_string_dedup_cpu_time, percent_of(gc_string_dedup_cpu_time, process_cpu_time), gc_string_dedup_cpu_time / elasped_time);
+    }
+    cpuLog.print("=====================================================================================");
+  }
+}
+
+void Universe::before_exit() {
+  log_cpu_time();
+  heap()->before_exit();
+
+  // Print GC/heap related information.
+  Log(gc, exit) log;
+  if (log.is_info()) {
+    LogStream ls_info(log.info());
+    Universe::print_on(&ls_info);
+    if (log.is_trace()) {
+      LogStream ls_trace(log.trace());
+      MutexLocker mcld(ClassLoaderDataGraph_lock);
+      ClassLoaderDataGraph::print_on(&ls_trace);
+    }
+  }
+}
 
 #ifndef PRODUCT
 void Universe::calculate_verify_data(HeapWord* low_boundary, HeapWord* high_boundary) {

src/hotspot/share/memory/universe.hpp

@@ -305,6 +305,8 @@ class Universe: AllStatic {
   // The particular choice of collected heap.
   static CollectedHeap* heap() { return _collectedHeap; }
 
+  static void before_exit();
+
   DEBUG_ONLY(static bool is_stw_gc_active();)
   DEBUG_ONLY(static bool is_in_heap(const void* p);)
   DEBUG_ONLY(static bool is_in_heap_or_null(const void* p) { return p == nullptr || is_in_heap(p); })

src/hotspot/share/runtime/java.cpp

@@ -475,19 +475,7 @@ void before_exit(JavaThread* thread, bool halt) {
   NativeHeapTrimmer::cleanup();
 
   // Run before exit and then stop concurrent GC threads
-  Universe::heap()->before_exit();
-
-  // Print GC/heap related information.
-  Log(gc, exit) log;
-  if (log.is_info()) {
-    LogStream ls_info(log.info());
-    Universe::print_on(&ls_info);
-    if (log.is_trace()) {
-      LogStream ls_trace(log.trace());
-      MutexLocker mcld(ClassLoaderDataGraph_lock);
-      ClassLoaderDataGraph::print_on(&ls_trace);
-    }
-  }
+  Universe::before_exit();
 
   if (PrintBytecodeHistogram) {
     BytecodeHistogram::print();

src/hotspot/share/runtime/vmThread.cpp

@@ -28,8 +28,8 @@
 #include "jfr/jfrEvents.hpp"
 #include "jfr/support/jfrThreadId.hpp"
 #include "logging/log.hpp"
-#include "logging/logStream.hpp"
 #include "logging/logConfiguration.hpp"
+#include "logging/logStream.hpp"
 #include "memory/resourceArea.hpp"
 #include "memory/universe.hpp"
 #include "oops/oop.inline.hpp"
@@ -46,8 +46,8 @@
 #include "runtime/safepoint.hpp"
 #include "runtime/synchronizer.hpp"
 #include "runtime/timerTrace.hpp"
-#include "runtime/vmThread.hpp"
 #include "runtime/vmOperations.hpp"
+#include "runtime/vmThread.hpp"
 #include "utilities/dtrace.hpp"
 #include "utilities/events.hpp"
 #include "utilities/vmError.hpp"

src/hotspot/share/runtime/vmThread.hpp

@@ -27,8 +27,8 @@
 
 #include "runtime/atomic.hpp"
 #include "runtime/javaThread.hpp"
-#include "runtime/perfDataTypes.hpp"
 #include "runtime/nonJavaThread.hpp"
+#include "runtime/perfDataTypes.hpp"
 #include "runtime/task.hpp"
 #include "runtime/vmOperation.hpp"
 

src/hotspot/share/services/cpuTimeUsage.cpp

@@ -0,0 +1,84 @@
+/*
+ * Copyright (c) 2025, 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.
+ *
+ */
+
+#include "gc/shared/collectedHeap.hpp"
+#include "gc/shared/stringdedup/stringDedup.hpp"
+#include "gc/shared/stringdedup/stringDedupProcessor.hpp"
+#include "memory/universe.hpp"
+#include "runtime/globals.hpp"
+#include "runtime/os.hpp"
+#include "runtime/perfData.hpp"
+#include "runtime/vmThread.hpp"
+#include "services/cpuTimeUsage.hpp"
+
+volatile bool CPUTimeUsage::Error::_has_error = false;
+
+static inline jlong thread_cpu_time_or_zero(Thread* thread) {
+  jlong cpu_time = os::thread_cpu_time(thread);
+  if (cpu_time == -1) {
+    CPUTimeUsage::Error::mark_error();
+    return 0;
+  }
+  return cpu_time;
+}
+
+class CPUTimeThreadClosure : public ThreadClosure {
+private:
+  jlong _cpu_time = 0;
+
+public:
+  virtual void do_thread(Thread* thread) {
+    _cpu_time += thread_cpu_time_or_zero(thread);
+  }
+  jlong cpu_time() { return _cpu_time; };
+};
+
+jlong CPUTimeUsage::GC::vm_thread() {
+  return Universe::heap()->_vmthread_cpu_time;
+}
+
+jlong CPUTimeUsage::GC::gc_threads() {
+  CPUTimeThreadClosure cl;
+  Universe::heap()->gc_threads_do(&cl);
+  return cl.cpu_time();
+}
+
+jlong CPUTimeUsage::GC::total() {
+  return gc_threads() + vm_thread() + stringdedup();
+}
+
+jlong CPUTimeUsage::GC::stringdedup() {
+  if (UseStringDeduplication) {
+    return thread_cpu_time_or_zero((Thread*)StringDedup::_processor->_thread);
+  }
+  return 0;
+}
+
+bool CPUTimeUsage::Error::has_error() {
+  return Atomic::load(&_has_error);
+}
+
+void CPUTimeUsage::Error::mark_error() {
+  Atomic::store(&_has_error, true);
+}