1.1 --- a/src/share/vm/runtime/safepoint.cpp Thu Aug 01 03:44:03 2019 +0100 1.2 +++ b/src/share/vm/runtime/safepoint.cpp Mon Aug 12 18:30:40 2019 +0300 1.3 @@ -32,6 +32,7 @@ 1.4 #include "code/scopeDesc.hpp" 1.5 #include "gc_interface/collectedHeap.hpp" 1.6 #include "interpreter/interpreter.hpp" 1.7 +#include "jfr/jfrEvents.hpp" 1.8 #include "memory/resourceArea.hpp" 1.9 #include "memory/universe.inline.hpp" 1.10 #include "oops/oop.inline.hpp" 1.11 @@ -83,6 +84,73 @@ 1.12 1.13 PRAGMA_FORMAT_MUTE_WARNINGS_FOR_GCC 1.14 1.15 +template <typename E> 1.16 +static void set_current_safepoint_id(E* event, int adjustment = 0) { 1.17 + assert(event != NULL, "invariant"); 1.18 + event->set_safepointId(SafepointSynchronize::safepoint_counter() + adjustment); 1.19 +} 1.20 + 1.21 +static void post_safepoint_begin_event(EventSafepointBegin* event, 1.22 + int thread_count, 1.23 + int critical_thread_count) { 1.24 + assert(event != NULL, "invariant"); 1.25 + assert(event->should_commit(), "invariant"); 1.26 + set_current_safepoint_id(event); 1.27 + event->set_totalThreadCount(thread_count); 1.28 + event->set_jniCriticalThreadCount(critical_thread_count); 1.29 + event->commit(); 1.30 +} 1.31 + 1.32 +static void post_safepoint_cleanup_event(EventSafepointCleanup* event) { 1.33 + assert(event != NULL, "invariant"); 1.34 + assert(event->should_commit(), "invariant"); 1.35 + set_current_safepoint_id(event); 1.36 + event->commit(); 1.37 +} 1.38 + 1.39 +static void post_safepoint_synchronize_event(EventSafepointStateSynchronization* event, 1.40 + int initial_number_of_threads, 1.41 + int threads_waiting_to_block, 1.42 + unsigned int iterations) { 1.43 + assert(event != NULL, "invariant"); 1.44 + if (event->should_commit()) { 1.45 + // Group this event together with the ones committed after the counter is increased 1.46 + set_current_safepoint_id(event, 1); 1.47 + event->set_initialThreadCount(initial_number_of_threads); 1.48 + event->set_runningThreadCount(threads_waiting_to_block); 1.49 + event->set_iterations(iterations); 1.50 + event->commit(); 1.51 + } 1.52 +} 1.53 + 1.54 +static void post_safepoint_wait_blocked_event(EventSafepointWaitBlocked* event, 1.55 + int initial_threads_waiting_to_block) { 1.56 + assert(event != NULL, "invariant"); 1.57 + assert(event->should_commit(), "invariant"); 1.58 + set_current_safepoint_id(event); 1.59 + event->set_runningThreadCount(initial_threads_waiting_to_block); 1.60 + event->commit(); 1.61 +} 1.62 + 1.63 +static void post_safepoint_cleanup_task_event(EventSafepointCleanupTask* event, 1.64 + const char* name) { 1.65 + assert(event != NULL, "invariant"); 1.66 + if (event->should_commit()) { 1.67 + set_current_safepoint_id(event); 1.68 + event->set_name(name); 1.69 + event->commit(); 1.70 + } 1.71 +} 1.72 + 1.73 +static void post_safepoint_end_event(EventSafepointEnd* event) { 1.74 + assert(event != NULL, "invariant"); 1.75 + if (event->should_commit()) { 1.76 + // Group this event together with the ones committed before the counter increased 1.77 + set_current_safepoint_id(event, -1); 1.78 + event->commit(); 1.79 + } 1.80 +} 1.81 + 1.82 // -------------------------------------------------------------------------------------------------- 1.83 // Implementation of Safepoint begin/end 1.84 1.85 @@ -97,7 +165,7 @@ 1.86 1.87 // Roll all threads forward to a safepoint and suspend them all 1.88 void SafepointSynchronize::begin() { 1.89 - 1.90 + EventSafepointBegin begin_event; 1.91 Thread* myThread = Thread::current(); 1.92 assert(myThread->is_VM_thread(), "Only VM thread may execute a safepoint"); 1.93 1.94 @@ -189,6 +257,9 @@ 1.95 // between states, the safepointing code will wait for the thread to 1.96 // block itself when it attempts transitions to a new state. 1.97 // 1.98 + EventSafepointStateSynchronization sync_event; 1.99 + int initial_running = 0; 1.100 + 1.101 _state = _synchronizing; 1.102 OrderAccess::fence(); 1.103 1.104 @@ -243,8 +314,11 @@ 1.105 } 1.106 } 1.107 1.108 - if (PrintSafepointStatistics && iterations == 0) { 1.109 - begin_statistics(nof_threads, still_running); 1.110 + if (iterations == 0) { 1.111 + initial_running = still_running; 1.112 + if (PrintSafepointStatistics) { 1.113 + begin_statistics(nof_threads, still_running); 1.114 + } 1.115 } 1.116 1.117 if (still_running > 0) { 1.118 @@ -336,43 +410,56 @@ 1.119 update_statistics_on_spin_end(); 1.120 } 1.121 1.122 + if (sync_event.should_commit()) { 1.123 + post_safepoint_synchronize_event(&sync_event, initial_running, _waiting_to_block, iterations); 1.124 + } 1.125 + 1.126 // wait until all threads are stopped 1.127 - while (_waiting_to_block > 0) { 1.128 - if (TraceSafepoint) tty->print_cr("Waiting for %d thread(s) to block", _waiting_to_block); 1.129 - if (!SafepointTimeout || timeout_error_printed) { 1.130 - Safepoint_lock->wait(true); // true, means with no safepoint checks 1.131 - } else { 1.132 - // Compute remaining time 1.133 - jlong remaining_time = safepoint_limit_time - os::javaTimeNanos(); 1.134 + { 1.135 + EventSafepointWaitBlocked wait_blocked_event; 1.136 + int initial_waiting_to_block = _waiting_to_block; 1.137 1.138 - // If there is no remaining time, then there is an error 1.139 - if (remaining_time < 0 || Safepoint_lock->wait(true, remaining_time / MICROUNITS)) { 1.140 - print_safepoint_timeout(_blocking_timeout); 1.141 + while (_waiting_to_block > 0) { 1.142 + if (TraceSafepoint) tty->print_cr("Waiting for %d thread(s) to block", _waiting_to_block); 1.143 + if (!SafepointTimeout || timeout_error_printed) { 1.144 + Safepoint_lock->wait(true); // true, means with no safepoint checks 1.145 + } else { 1.146 + // Compute remaining time 1.147 + jlong remaining_time = safepoint_limit_time - os::javaTimeNanos(); 1.148 + 1.149 + // If there is no remaining time, then there is an error 1.150 + if (remaining_time < 0 || Safepoint_lock->wait(true, remaining_time / MICROUNITS)) { 1.151 + print_safepoint_timeout(_blocking_timeout); 1.152 + } 1.153 } 1.154 } 1.155 - } 1.156 - assert(_waiting_to_block == 0, "sanity check"); 1.157 + assert(_waiting_to_block == 0, "sanity check"); 1.158 1.159 #ifndef PRODUCT 1.160 - if (SafepointTimeout) { 1.161 - jlong current_time = os::javaTimeNanos(); 1.162 - if (safepoint_limit_time < current_time) { 1.163 - tty->print_cr("# SafepointSynchronize: Finished after " 1.164 - INT64_FORMAT_W(6) " ms", 1.165 - ((current_time - safepoint_limit_time) / MICROUNITS + 1.166 - SafepointTimeoutDelay)); 1.167 + if (SafepointTimeout) { 1.168 + jlong current_time = os::javaTimeNanos(); 1.169 + if (safepoint_limit_time < current_time) { 1.170 + tty->print_cr("# SafepointSynchronize: Finished after " 1.171 + INT64_FORMAT_W(6) " ms", 1.172 + ((current_time - safepoint_limit_time) / MICROUNITS + 1.173 + SafepointTimeoutDelay)); 1.174 + } 1.175 + } 1.176 +#endif 1.177 + 1.178 + assert((_safepoint_counter & 0x1) == 0, "must be even"); 1.179 + assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); 1.180 + _safepoint_counter ++; 1.181 + 1.182 + // Record state 1.183 + _state = _synchronized; 1.184 + 1.185 + OrderAccess::fence(); 1.186 + 1.187 + if (wait_blocked_event.should_commit()) { 1.188 + post_safepoint_wait_blocked_event(&wait_blocked_event, initial_waiting_to_block); 1.189 } 1.190 } 1.191 -#endif 1.192 - 1.193 - assert((_safepoint_counter & 0x1) == 0, "must be even"); 1.194 - assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); 1.195 - _safepoint_counter ++; 1.196 - 1.197 - // Record state 1.198 - _state = _synchronized; 1.199 - 1.200 - OrderAccess::fence(); 1.201 1.202 #ifdef ASSERT 1.203 for (JavaThread *cur = Threads::first(); cur != NULL; cur = cur->next()) { 1.204 @@ -395,12 +482,22 @@ 1.205 } 1.206 1.207 // Call stuff that needs to be run when a safepoint is just about to be completed 1.208 - do_cleanup_tasks(); 1.209 + { 1.210 + EventSafepointCleanup cleanup_event; 1.211 + do_cleanup_tasks(); 1.212 + if (cleanup_event.should_commit()) { 1.213 + post_safepoint_cleanup_event(&cleanup_event); 1.214 + } 1.215 + } 1.216 1.217 if (PrintSafepointStatistics) { 1.218 // Record how much time spend on the above cleanup tasks 1.219 update_statistics_on_cleanup_end(os::javaTimeNanos()); 1.220 } 1.221 + 1.222 + if (begin_event.should_commit()) { 1.223 + post_safepoint_begin_event(&begin_event, nof_threads, _current_jni_active_count); 1.224 + } 1.225 } 1.226 1.227 // Wake up all threads, so they are ready to resume execution after the safepoint 1.228 @@ -409,6 +506,7 @@ 1.229 1.230 assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); 1.231 assert((_safepoint_counter & 0x1) == 1, "must be odd"); 1.232 + EventSafepointEnd event; 1.233 _safepoint_counter ++; 1.234 // memory fence isn't required here since an odd _safepoint_counter 1.235 // value can do no harm and a fence is issued below anyway. 1.236 @@ -494,6 +592,9 @@ 1.237 // record this time so VMThread can keep track how much time has elasped 1.238 // since last safepoint. 1.239 _end_of_last_safepoint = os::javaTimeMillis(); 1.240 + if (event.should_commit()) { 1.241 + post_safepoint_end_event(&event); 1.242 + } 1.243 } 1.244 1.245 bool SafepointSynchronize::is_cleanup_needed() { 1.246 @@ -507,32 +608,62 @@ 1.247 // Various cleaning tasks that should be done periodically at safepoints 1.248 void SafepointSynchronize::do_cleanup_tasks() { 1.249 { 1.250 - TraceTime t1("deflating idle monitors", TraceSafepointCleanupTime); 1.251 + const char* name = "deflating idle monitors"; 1.252 + EventSafepointCleanupTask event; 1.253 + TraceTime t1(name, TraceSafepointCleanupTime); 1.254 ObjectSynchronizer::deflate_idle_monitors(); 1.255 + if (event.should_commit()) { 1.256 + post_safepoint_cleanup_task_event(&event, name); 1.257 + } 1.258 } 1.259 1.260 { 1.261 - TraceTime t2("updating inline caches", TraceSafepointCleanupTime); 1.262 + const char* name = "updating inline caches"; 1.263 + EventSafepointCleanupTask event; 1.264 + TraceTime t2(name, TraceSafepointCleanupTime); 1.265 InlineCacheBuffer::update_inline_caches(); 1.266 + if (event.should_commit()) { 1.267 + post_safepoint_cleanup_task_event(&event, name); 1.268 + } 1.269 } 1.270 { 1.271 - TraceTime t3("compilation policy safepoint handler", TraceSafepointCleanupTime); 1.272 + const char* name = "compilation policy safepoint handler"; 1.273 + EventSafepointCleanupTask event; 1.274 + TraceTime t3(name, TraceSafepointCleanupTime); 1.275 CompilationPolicy::policy()->do_safepoint_work(); 1.276 + if (event.should_commit()) { 1.277 + post_safepoint_cleanup_task_event(&event, name); 1.278 + } 1.279 } 1.280 1.281 { 1.282 - TraceTime t4("mark nmethods", TraceSafepointCleanupTime); 1.283 + const char* name = "mark nmethods"; 1.284 + EventSafepointCleanupTask event; 1.285 + TraceTime t4(name, TraceSafepointCleanupTime); 1.286 NMethodSweeper::mark_active_nmethods(); 1.287 + if (event.should_commit()) { 1.288 + post_safepoint_cleanup_task_event(&event, name); 1.289 + } 1.290 } 1.291 1.292 if (SymbolTable::needs_rehashing()) { 1.293 - TraceTime t5("rehashing symbol table", TraceSafepointCleanupTime); 1.294 + const char* name = "rehashing symbol table"; 1.295 + EventSafepointCleanupTask event; 1.296 + TraceTime t5(name, TraceSafepointCleanupTime); 1.297 SymbolTable::rehash_table(); 1.298 + if (event.should_commit()) { 1.299 + post_safepoint_cleanup_task_event(&event, name); 1.300 + } 1.301 } 1.302 1.303 if (StringTable::needs_rehashing()) { 1.304 - TraceTime t6("rehashing string table", TraceSafepointCleanupTime); 1.305 + const char* name = "rehashing string table"; 1.306 + EventSafepointCleanupTask event; 1.307 + TraceTime t6(name, TraceSafepointCleanupTime); 1.308 StringTable::rehash_table(); 1.309 + if (event.should_commit()) { 1.310 + post_safepoint_cleanup_task_event(&event, name); 1.311 + } 1.312 } 1.313 1.314 // rotate log files?