From fb651fd6d246e69b42363e050eb8d96afb633eed Mon Sep 17 00:00:00 2001 From: Jonas Norlinder Date: Thu, 21 Aug 2025 14:05:36 +0000 Subject: [PATCH] 8364638: Refactor and make accumulated GC CPU time code generic Reviewed-by: ayang, sjohanss --- src/hotspot/share/gc/shared/collectedHeap.cpp | 55 ------------ src/hotspot/share/gc/shared/collectedHeap.hpp | 6 +- .../gc/shared/stringdedup/stringDedup.hpp | 4 +- .../stringdedup/stringDedupProcessor.hpp | 4 +- src/hotspot/share/memory/universe.cpp | 59 +++++++++++++ src/hotspot/share/memory/universe.hpp | 2 + src/hotspot/share/runtime/java.cpp | 14 +--- src/hotspot/share/runtime/vmThread.cpp | 4 +- src/hotspot/share/runtime/vmThread.hpp | 2 +- src/hotspot/share/services/cpuTimeUsage.cpp | 84 +++++++++++++++++++ src/hotspot/share/services/cpuTimeUsage.hpp | 50 +++++++++++ 11 files changed, 205 insertions(+), 79 deletions(-) create mode 100644 src/hotspot/share/services/cpuTimeUsage.cpp create mode 100644 src/hotspot/share/services/cpuTimeUsage.hpp diff --git a/src/hotspot/share/gc/shared/collectedHeap.cpp b/src/hotspot/share/gc/shared/collectedHeap.cpp index b636e3890d3..e82ec1439ea 100644 --- a/src/hotspot/share/gc/shared/collectedHeap.cpp +++ b/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(); } diff --git a/src/hotspot/share/gc/shared/collectedHeap.hpp b/src/hotspot/share/gc/shared/collectedHeap.hpp index 621f3a0bbc7..33d2fad8bba 100644 --- a/src/hotspot/share/gc/shared/collectedHeap.hpp +++ b/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 @@ public: // ZCollectedHeap // class CollectedHeap : public CHeapObj { + 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 @@ protected: 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 @@ protected: // 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; diff --git a/src/hotspot/share/gc/shared/stringdedup/stringDedup.hpp b/src/hotspot/share/gc/shared/stringdedup/stringDedup.hpp index 43cb513df33..24d17d7d45b 100644 --- a/src/hotspot/share/gc/shared/stringdedup/stringDedup.hpp +++ b/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; diff --git a/src/hotspot/share/gc/shared/stringdedup/stringDedupProcessor.hpp b/src/hotspot/share/gc/shared/stringdedup/stringDedupProcessor.hpp index 5d3929c5817..7e5e64df9b4 100644 --- a/src/hotspot/share/gc/shared/stringdedup/stringDedupProcessor.hpp +++ b/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 { - friend class CollectedHeap; + friend class CPUTimeUsage::GC; Processor(); ~Processor() = default; diff --git a/src/hotspot/share/memory/universe.cpp b/src/hotspot/share/memory/universe.cpp index bd47a054bc0..8afa17b0b3d 100644 --- a/src/hotspot/share/memory/universe.cpp +++ b/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) { diff --git a/src/hotspot/share/memory/universe.hpp b/src/hotspot/share/memory/universe.hpp index 5d481e889c4..ee4c05e1e06 100644 --- a/src/hotspot/share/memory/universe.hpp +++ b/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); }) diff --git a/src/hotspot/share/runtime/java.cpp b/src/hotspot/share/runtime/java.cpp index 3361ecf1558..2aaf020d6d6 100644 --- a/src/hotspot/share/runtime/java.cpp +++ b/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(); diff --git a/src/hotspot/share/runtime/vmThread.cpp b/src/hotspot/share/runtime/vmThread.cpp index 1f8265484f1..c93469c1362 100644 --- a/src/hotspot/share/runtime/vmThread.cpp +++ b/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" diff --git a/src/hotspot/share/runtime/vmThread.hpp b/src/hotspot/share/runtime/vmThread.hpp index 668ea4ce4e2..d2033f66ea5 100644 --- a/src/hotspot/share/runtime/vmThread.hpp +++ b/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" diff --git a/src/hotspot/share/services/cpuTimeUsage.cpp b/src/hotspot/share/services/cpuTimeUsage.cpp new file mode 100644 index 00000000000..aa658a67bad --- /dev/null +++ b/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); +} diff --git a/src/hotspot/share/services/cpuTimeUsage.hpp b/src/hotspot/share/services/cpuTimeUsage.hpp new file mode 100644 index 00000000000..ae4d04947a7 --- /dev/null +++ b/src/hotspot/share/services/cpuTimeUsage.hpp @@ -0,0 +1,50 @@ +/* + * 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. + * + */ + +#ifndef SHARE_SERVICES_CPUTIMEUSAGE_HPP +#define SHARE_SERVICES_CPUTIMEUSAGE_HPP + +#include "memory/allStatic.hpp" +#include "utilities/globalDefinitions.hpp" + +namespace CPUTimeUsage { + class GC : public AllStatic { + public: + static jlong total(); + static jlong gc_threads(); + static jlong vm_thread(); + static jlong stringdedup(); + }; + + class Error : public AllStatic { + private: + static volatile bool _has_error; + + public: + static bool has_error(); + static void mark_error(); + }; +} + +#endif // SHARE_SERVICES_CPUTIMEUSAGE_HPP