From 9ec46968fbfddf99a8349cb6903d24b1c2fdaf1d Mon Sep 17 00:00:00 2001 From: Xiaolong Peng Date: Wed, 26 Feb 2025 17:29:12 +0000 Subject: [PATCH] 8350313: Include timings for leaving safepoint in safepoint logging Reviewed-by: shade, dholmes --- src/hotspot/share/runtime/safepoint.cpp | 15 ++++++++++++--- src/hotspot/share/runtime/safepoint.hpp | 2 ++ 2 files changed, 14 insertions(+), 3 deletions(-) diff --git a/src/hotspot/share/runtime/safepoint.cpp b/src/hotspot/share/runtime/safepoint.cpp index e6f3b84945b..6f86aa09d95 100644 --- a/src/hotspot/share/runtime/safepoint.cpp +++ b/src/hotspot/share/runtime/safepoint.cpp @@ -468,6 +468,8 @@ void SafepointSynchronize::disarm_safepoint() { // operation has been carried out void SafepointSynchronize::end() { assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); + SafepointTracing::leave(); + EventSafepointEnd event; assert(Thread::current()->is_VM_thread(), "Only VM thread can execute a safepoint"); @@ -862,6 +864,7 @@ void ThreadSafepointState::handle_polling_page_exception() { jlong SafepointTracing::_last_safepoint_begin_time_ns = 0; jlong SafepointTracing::_last_safepoint_sync_time_ns = 0; +jlong SafepointTracing::_last_safepoint_leave_time_ns = 0; jlong SafepointTracing::_last_safepoint_end_time_ns = 0; jlong SafepointTracing::_last_app_time_ns = 0; int SafepointTracing::_nof_threads = 0; @@ -963,6 +966,10 @@ void SafepointTracing::synchronized(int nof_threads, int nof_running, int traps) RuntimeService::record_safepoint_synchronized(_last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns); } +void SafepointTracing::leave() { + _last_safepoint_leave_time_ns = os::javaTimeNanos(); +} + void SafepointTracing::end() { _last_safepoint_end_time_ns = os::javaTimeNanos(); @@ -981,12 +988,14 @@ void SafepointTracing::end() { "Time since last: " JLONG_FORMAT " ns, " "Reaching safepoint: " JLONG_FORMAT " ns, " "At safepoint: " JLONG_FORMAT " ns, " + "Leaving safepoint: " JLONG_FORMAT " ns, " "Total: " JLONG_FORMAT " ns", VM_Operation::name(_current_type), _last_app_time_ns, - _last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns, - _last_safepoint_end_time_ns - _last_safepoint_sync_time_ns, - _last_safepoint_end_time_ns - _last_safepoint_begin_time_ns + _last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns, + _last_safepoint_leave_time_ns - _last_safepoint_sync_time_ns, + _last_safepoint_end_time_ns - _last_safepoint_leave_time_ns, + _last_safepoint_end_time_ns - _last_safepoint_begin_time_ns ); RuntimeService::record_safepoint_end(_last_safepoint_end_time_ns - _last_safepoint_sync_time_ns); diff --git a/src/hotspot/share/runtime/safepoint.hpp b/src/hotspot/share/runtime/safepoint.hpp index 93ede70c6ac..190095ec30b 100644 --- a/src/hotspot/share/runtime/safepoint.hpp +++ b/src/hotspot/share/runtime/safepoint.hpp @@ -230,6 +230,7 @@ private: // Absolute static jlong _last_safepoint_begin_time_ns; static jlong _last_safepoint_sync_time_ns; + static jlong _last_safepoint_leave_time_ns; static jlong _last_safepoint_end_time_ns; // Relative @@ -251,6 +252,7 @@ public: static void begin(VM_Operation::VMOp_Type type); static void synchronized(int nof_threads, int nof_running, int traps); + static void leave(); static void end(); static void statistics_exit_log();