1 /* 2 * Copyright (c) 1997, 2019, Oracle and/or its affiliates. All rights reserved. 3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. 4 * 5 * This code is free software; you can redistribute it and/or modify it 6 * under the terms of the GNU General Public License version 2 only, as 7 * published by the Free Software Foundation. 8 * 9 * This code is distributed in the hope that it will be useful, but WITHOUT 10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License 12 * version 2 for more details (a copy is included in the LICENSE file that 13 * accompanied this code). 14 * 15 * You should have received a copy of the GNU General Public License version 16 * 2 along with this work; if not, write to the Free Software Foundation, 17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. 18 * 19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA 20 * or visit www.oracle.com if you need additional information or have any 21 * questions. 22 * 23 */ 24 25 #include "precompiled.hpp" 26 #include "classfile/classLoaderDataGraph.inline.hpp" 27 #include "classfile/stringTable.hpp" 28 #include "classfile/symbolTable.hpp" 29 #include "classfile/systemDictionary.hpp" 30 #include "code/codeCache.hpp" 31 #include "code/icBuffer.hpp" 32 #include "code/nmethod.hpp" 33 #include "code/pcDesc.hpp" 34 #include "code/scopeDesc.hpp" 35 #include "gc/shared/collectedHeap.hpp" 36 #include "gc/shared/gcLocker.hpp" 37 #include "gc/shared/strongRootsScope.hpp" 38 #include "gc/shared/workgroup.hpp" 39 #include "interpreter/interpreter.hpp" 40 #include "jfr/jfrEvents.hpp" 41 #include "logging/log.hpp" 42 #include "logging/logStream.hpp" 43 #include "memory/resourceArea.hpp" 44 #include "memory/universe.hpp" 45 #include "oops/oop.inline.hpp" 46 #include "oops/symbol.hpp" 47 #include "runtime/atomic.hpp" 48 #include "runtime/compilationPolicy.hpp" 49 #include "runtime/deoptimization.hpp" 50 #include "runtime/frame.inline.hpp" 51 #include "runtime/handles.inline.hpp" 52 #include "runtime/interfaceSupport.inline.hpp" 53 #include "runtime/mutexLocker.hpp" 54 #include "runtime/orderAccess.hpp" 55 #include "runtime/osThread.hpp" 56 #include "runtime/safepoint.hpp" 57 #include "runtime/safepointMechanism.inline.hpp" 58 #include "runtime/signature.hpp" 59 #include "runtime/stubCodeGenerator.hpp" 60 #include "runtime/stubRoutines.hpp" 61 #include "runtime/sweeper.hpp" 62 #include "runtime/synchronizer.hpp" 63 #include "runtime/thread.inline.hpp" 64 #include "runtime/threadSMR.hpp" 65 #include "runtime/timerTrace.hpp" 66 #include "services/runtimeService.hpp" 67 #include "utilities/events.hpp" 68 #include "utilities/macros.hpp" 69 #ifdef COMPILER1 70 #include "c1/c1_globals.hpp" 71 #endif 72 73 static void post_safepoint_begin_event(EventSafepointBegin& event, 74 uint64_t safepoint_id, 75 int thread_count, 76 int critical_thread_count) { 77 if (event.should_commit()) { 78 event.set_safepointId(safepoint_id); 79 event.set_totalThreadCount(thread_count); 80 event.set_jniCriticalThreadCount(critical_thread_count); 81 event.commit(); 82 } 83 } 84 85 static void post_safepoint_cleanup_event(EventSafepointCleanup& event, uint64_t safepoint_id) { 86 if (event.should_commit()) { 87 event.set_safepointId(safepoint_id); 88 event.commit(); 89 } 90 } 91 92 static void post_safepoint_synchronize_event(EventSafepointStateSynchronization& event, 93 uint64_t safepoint_id, 94 int initial_number_of_threads, 95 int threads_waiting_to_block, 96 uint64_t iterations) { 97 if (event.should_commit()) { 98 event.set_safepointId(safepoint_id); 99 event.set_initialThreadCount(initial_number_of_threads); 100 event.set_runningThreadCount(threads_waiting_to_block); 101 event.set_iterations(iterations); 102 event.commit(); 103 } 104 } 105 106 static void post_safepoint_cleanup_task_event(EventSafepointCleanupTask& event, 107 uint64_t safepoint_id, 108 const char* name) { 109 if (event.should_commit()) { 110 event.set_safepointId(safepoint_id); 111 event.set_name(name); 112 event.commit(); 113 } 114 } 115 116 static void post_safepoint_end_event(EventSafepointEnd& event, uint64_t safepoint_id) { 117 if (event.should_commit()) { 118 event.set_safepointId(safepoint_id); 119 event.commit(); 120 } 121 } 122 123 // -------------------------------------------------------------------------------------------------- 124 // Implementation of Safepoint begin/end 125 126 SafepointSynchronize::SynchronizeState volatile SafepointSynchronize::_state = SafepointSynchronize::_not_synchronized; 127 int SafepointSynchronize::_waiting_to_block = 0; 128 volatile uint64_t SafepointSynchronize::_safepoint_counter = 0; 129 const uint64_t SafepointSynchronize::InactiveSafepointCounter = 0; 130 int SafepointSynchronize::_current_jni_active_count = 0; 131 132 WaitBarrier* SafepointSynchronize::_wait_barrier; 133 134 static volatile bool PageArmed = false; // safepoint polling page is RO|RW vs PROT_NONE 135 static bool timeout_error_printed = false; 136 137 // Statistic related 138 static jlong _safepoint_begin_time = 0; 139 static volatile int _nof_threads_hit_polling_page = 0; 140 141 void SafepointSynchronize::init(Thread* vmthread) { 142 // WaitBarrier should never be destroyed since we will have 143 // threads waiting on it while exiting. 144 _wait_barrier = new WaitBarrier(vmthread); 145 SafepointTracing::init(); 146 } 147 148 void SafepointSynchronize::increment_jni_active_count() { 149 assert(Thread::current()->is_VM_thread(), "Only VM thread may increment"); 150 ++_current_jni_active_count; 151 } 152 153 void SafepointSynchronize::decrement_waiting_to_block() { 154 assert(_waiting_to_block > 0, "sanity check"); 155 assert(Thread::current()->is_VM_thread(), "Only VM thread may decrement"); 156 --_waiting_to_block; 157 } 158 159 static bool thread_not_running(ThreadSafepointState *cur_state) { 160 if (!cur_state->is_running()) { 161 return true; 162 } 163 cur_state->examine_state_of_thread(SafepointSynchronize::safepoint_counter()); 164 if (!cur_state->is_running()) { 165 return true; 166 } 167 LogTarget(Trace, safepoint) lt; 168 if (lt.is_enabled()) { 169 ResourceMark rm; 170 LogStream ls(lt); 171 cur_state->print_on(&ls); 172 } 173 return false; 174 } 175 176 #ifdef ASSERT 177 static void assert_list_is_valid(const ThreadSafepointState* tss_head, int still_running) { 178 int a = 0; 179 const ThreadSafepointState *tmp_tss = tss_head; 180 while (tmp_tss != NULL) { 181 ++a; 182 assert(tmp_tss->is_running(), "Illegal initial state"); 183 tmp_tss = tmp_tss->get_next(); 184 } 185 assert(a == still_running, "Must be the same"); 186 } 187 #endif // ASSERT 188 189 static void back_off(int iteration) { 190 // iteration will be 1 the first time we enter this spin back-off. 191 // naked_short_nanosleep takes tenths of micros which means that 192 // number of nanoseconds is irrelevant if it's below that. We do 193 // 20 1 ns sleeps with a total cost of ~1 ms, then we do 1 ms sleeps. 194 jlong sleep_ns = 1; 195 if (iteration > 20) { 196 sleep_ns = NANOUNITS / MILLIUNITS; // 1 ms 197 } 198 os::naked_short_nanosleep(sleep_ns); 199 } 200 201 int SafepointSynchronize::synchronize_threads(jlong safepoint_limit_time, int nof_threads, int* initial_running) 202 { 203 JavaThreadIteratorWithHandle jtiwh; 204 205 #ifdef ASSERT 206 for (; JavaThread *cur = jtiwh.next(); ) { 207 assert(cur->safepoint_state()->is_running(), "Illegal initial state"); 208 } 209 jtiwh.rewind(); 210 #endif // ASSERT 211 212 // Iterate through all threads until it has been determined how to stop them all at a safepoint. 213 int still_running = nof_threads; 214 ThreadSafepointState *tss_head = NULL; 215 ThreadSafepointState **p_prev = &tss_head; 216 for (; JavaThread *cur = jtiwh.next(); ) { 217 ThreadSafepointState *cur_tss = cur->safepoint_state(); 218 assert(cur_tss->get_next() == NULL, "Must be NULL"); 219 if (thread_not_running(cur_tss)) { 220 --still_running; 221 } else { 222 *p_prev = cur_tss; 223 p_prev = cur_tss->next_ptr(); 224 } 225 } 226 *p_prev = NULL; 227 228 DEBUG_ONLY(assert_list_is_valid(tss_head, still_running);) 229 230 *initial_running = still_running; 231 232 int iterations = 1; // The first iteration is above. 233 234 while (still_running > 0) { 235 // Check if this has taken too long: 236 if (SafepointTimeout && safepoint_limit_time < os::javaTimeNanos()) { 237 print_safepoint_timeout(); 238 } 239 if (int(iterations) == -1) { // overflow - something is wrong. 240 // We can only overflow here when we are using global 241 // polling pages. We keep this guarantee in its original 242 // form so that searches of the bug database for this 243 // failure mode find the right bugs. 244 guarantee (!PageArmed, "invariant"); 245 } 246 247 p_prev = &tss_head; 248 ThreadSafepointState *cur_tss = tss_head; 249 while (cur_tss != NULL) { 250 assert(cur_tss->is_running(), "Illegal initial state"); 251 if (thread_not_running(cur_tss)) { 252 --still_running; 253 *p_prev = NULL; 254 ThreadSafepointState *tmp = cur_tss; 255 cur_tss = cur_tss->get_next(); 256 tmp->set_next(NULL); 257 } else { 258 *p_prev = cur_tss; 259 p_prev = cur_tss->next_ptr(); 260 cur_tss = cur_tss->get_next(); 261 } 262 } 263 264 DEBUG_ONLY(assert_list_is_valid(tss_head, still_running);) 265 266 if (still_running > 0) { 267 back_off(iterations); 268 } 269 270 iterations++; 271 } 272 273 assert(tss_head == NULL, "Must be empty"); 274 275 return iterations; 276 } 277 278 void SafepointSynchronize::arm_safepoint() { 279 // Begin the process of bringing the system to a safepoint. 280 // Java threads can be in several different states and are 281 // stopped by different mechanisms: 282 // 283 // 1. Running interpreted 284 // When executing branching/returning byte codes interpreter 285 // checks if the poll is armed, if so blocks in SS::block(). 286 // When using global polling the interpreter dispatch table 287 // is changed to force it to check for a safepoint condition 288 // between bytecodes. 289 // 2. Running in native code 290 // When returning from the native code, a Java thread must check 291 // the safepoint _state to see if we must block. If the 292 // VM thread sees a Java thread in native, it does 293 // not wait for this thread to block. The order of the memory 294 // writes and reads of both the safepoint state and the Java 295 // threads state is critical. In order to guarantee that the 296 // memory writes are serialized with respect to each other, 297 // the VM thread issues a memory barrier instruction. 298 // 3. Running compiled Code 299 // Compiled code reads the local polling page that 300 // is set to fault if we are trying to get to a safepoint. 301 // 4. Blocked 302 // A thread which is blocked will not be allowed to return from the 303 // block condition until the safepoint operation is complete. 304 // 5. In VM or Transitioning between states 305 // If a Java thread is currently running in the VM or transitioning 306 // between states, the safepointing code will poll the thread state 307 // until the thread blocks itself when it attempts transitions to a 308 // new state or locking a safepoint checked monitor. 309 310 // We must never miss a thread with correct safepoint id, so we must make sure we arm 311 // the wait barrier for the next safepoint id/counter. 312 // Arming must be done after resetting _current_jni_active_count, _waiting_to_block. 313 _wait_barrier->arm(static_cast<int>(_safepoint_counter + 1)); 314 315 assert((_safepoint_counter & 0x1) == 0, "must be even"); 316 // The store to _safepoint_counter must happen after any stores in arming. 317 OrderAccess::release_store(&_safepoint_counter, _safepoint_counter + 1); 318 319 // We are synchronizing 320 OrderAccess::storestore(); // Ordered with _safepoint_counter 321 _state = _synchronizing; 322 323 if (SafepointMechanism::uses_thread_local_poll()) { 324 // Arming the per thread poll while having _state != _not_synchronized means safepointing 325 log_trace(safepoint)("Setting thread local yield flag for threads"); 326 OrderAccess::storestore(); // storestore, global state -> local state 327 for (JavaThreadIteratorWithHandle jtiwh; JavaThread *cur = jtiwh.next(); ) { 328 // Make sure the threads start polling, it is time to yield. 329 SafepointMechanism::arm_local_poll(cur); 330 } 331 } 332 OrderAccess::fence(); // storestore|storeload, global state -> local state 333 334 if (SafepointMechanism::uses_global_page_poll()) { 335 // Make interpreter safepoint aware 336 Interpreter::notice_safepoints(); 337 338 // Make polling safepoint aware 339 guarantee (!PageArmed, "invariant") ; 340 PageArmed = true; 341 os::make_polling_page_unreadable(); 342 } 343 } 344 345 // Roll all threads forward to a safepoint and suspend them all 346 void SafepointSynchronize::begin() { 347 assert(Thread::current()->is_VM_thread(), "Only VM thread may execute a safepoint"); 348 349 EventSafepointBegin begin_event; 350 SafepointTracing::begin(VMThread::vm_op_type()); 351 352 Universe::heap()->safepoint_synchronize_begin(); 353 354 // By getting the Threads_lock, we assure that no threads are about to start or 355 // exit. It is released again in SafepointSynchronize::end(). 356 Threads_lock->lock(); 357 358 assert( _state == _not_synchronized, "trying to safepoint synchronize with wrong state"); 359 360 int nof_threads = Threads::number_of_threads(); 361 362 _nof_threads_hit_polling_page = 0; 363 364 log_debug(safepoint)("Safepoint synchronization initiated using %s wait barrier. (%d threads)", _wait_barrier->description(), nof_threads); 365 366 // Reset the count of active JNI critical threads 367 _current_jni_active_count = 0; 368 369 // Set number of threads to wait for 370 _waiting_to_block = nof_threads; 371 372 jlong safepoint_limit_time = 0; 373 if (SafepointTimeout) { 374 // Set the limit time, so that it can be compared to see if this has taken 375 // too long to complete. 376 safepoint_limit_time = SafepointTracing::start_of_safepoint() + (jlong)SafepointTimeoutDelay * (NANOUNITS / MILLIUNITS); 377 timeout_error_printed = false; 378 } 379 380 EventSafepointStateSynchronization sync_event; 381 int initial_running = 0; 382 383 // Arms the safepoint, _current_jni_active_count and _waiting_to_block must be set before. 384 arm_safepoint(); 385 386 // Will spin until all threads are safe. 387 int iterations = synchronize_threads(safepoint_limit_time, nof_threads, &initial_running); 388 assert(_waiting_to_block == 0, "No thread should be running"); 389 390 #ifndef PRODUCT 391 if (safepoint_limit_time != 0) { 392 jlong current_time = os::javaTimeNanos(); 393 if (safepoint_limit_time < current_time) { 394 log_warning(safepoint)("# SafepointSynchronize: Finished after " 395 INT64_FORMAT_W(6) " ms", 396 (int64_t)(current_time - SafepointTracing::start_of_safepoint()) / (NANOUNITS / MILLIUNITS)); 397 } 398 } 399 #endif 400 401 assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); 402 403 // Record state 404 _state = _synchronized; 405 406 OrderAccess::fence(); 407 408 #ifdef ASSERT 409 // Make sure all the threads were visited. 410 for (JavaThreadIteratorWithHandle jtiwh; JavaThread *cur = jtiwh.next(); ) { 411 assert(cur->was_visited_for_critical_count(_safepoint_counter), "missed a thread"); 412 } 413 #endif // ASSERT 414 415 // Update the count of active JNI critical regions 416 GCLocker::set_jni_lock_count(_current_jni_active_count); 417 418 post_safepoint_synchronize_event(sync_event, 419 _safepoint_counter, 420 initial_running, 421 _waiting_to_block, iterations); 422 423 SafepointTracing::synchronized(nof_threads, initial_running, _nof_threads_hit_polling_page); 424 425 // We do the safepoint cleanup first since a GC related safepoint 426 // needs cleanup to be completed before running the GC op. 427 EventSafepointCleanup cleanup_event; 428 do_cleanup_tasks(); 429 post_safepoint_cleanup_event(cleanup_event, _safepoint_counter); 430 431 post_safepoint_begin_event(begin_event, _safepoint_counter, nof_threads, _current_jni_active_count); 432 SafepointTracing::cleanup(); 433 } 434 435 void SafepointSynchronize::disarm_safepoint() { 436 uint64_t safepoint_id = _safepoint_counter; 437 { 438 JavaThreadIteratorWithHandle jtiwh; 439 #ifdef ASSERT 440 // A pending_exception cannot be installed during a safepoint. The threads 441 // may install an async exception after they come back from a safepoint into 442 // pending_exception after they unblock. But that should happen later. 443 for (; JavaThread *cur = jtiwh.next(); ) { 444 assert (!(cur->has_pending_exception() && 445 cur->safepoint_state()->is_at_poll_safepoint()), 446 "safepoint installed a pending exception"); 447 } 448 #endif // ASSERT 449 450 if (SafepointMechanism::uses_global_page_poll()) { 451 guarantee (PageArmed, "invariant"); 452 // Make polling safepoint aware 453 os::make_polling_page_readable(); 454 PageArmed = false; 455 // Remove safepoint check from interpreter 456 Interpreter::ignore_safepoints(); 457 } 458 459 OrderAccess::fence(); // keep read and write of _state from floating up 460 assert(_state == _synchronized, "must be synchronized before ending safepoint synchronization"); 461 462 // Change state first to _not_synchronized. 463 // No threads should see _synchronized when running. 464 _state = _not_synchronized; 465 466 // Set the next dormant (even) safepoint id. 467 assert((_safepoint_counter & 0x1) == 1, "must be odd"); 468 OrderAccess::release_store(&_safepoint_counter, _safepoint_counter + 1); 469 470 OrderAccess::fence(); // Keep the local state from floating up. 471 472 jtiwh.rewind(); 473 for (; JavaThread *current = jtiwh.next(); ) { 474 // Clear the visited flag to ensure that the critical counts are collected properly. 475 DEBUG_ONLY(current->reset_visited_for_critical_count(safepoint_id);) 476 ThreadSafepointState* cur_state = current->safepoint_state(); 477 assert(!cur_state->is_running(), "Thread not suspended at safepoint"); 478 cur_state->restart(); // TSS _running 479 assert(cur_state->is_running(), "safepoint state has not been reset"); 480 481 SafepointMechanism::disarm_if_needed(current, false /* NO release */); 482 } 483 } // ~JavaThreadIteratorWithHandle 484 485 // Release threads lock, so threads can be created/destroyed again. 486 Threads_lock->unlock(); 487 488 // Wake threads after local state is correctly set. 489 _wait_barrier->disarm(); 490 } 491 492 // Wake up all threads, so they are ready to resume execution after the safepoint 493 // operation has been carried out 494 void SafepointSynchronize::end() { 495 assert(Threads_lock->owned_by_self(), "must hold Threads_lock"); 496 EventSafepointEnd event; 497 uint64_t safepoint_id = _safepoint_counter; 498 assert(Thread::current()->is_VM_thread(), "Only VM thread can execute a safepoint"); 499 500 disarm_safepoint(); 501 502 Universe::heap()->safepoint_synchronize_end(); 503 504 SafepointTracing::end(); 505 506 post_safepoint_end_event(event, safepoint_id); 507 } 508 509 bool SafepointSynchronize::is_cleanup_needed() { 510 // Need a safepoint if there are many monitors to deflate. 511 if (ObjectSynchronizer::is_cleanup_needed()) return true; 512 // Need a safepoint if some inline cache buffers is non-empty 513 if (!InlineCacheBuffer::is_empty()) return true; 514 return false; 515 } 516 517 class ParallelSPCleanupThreadClosure : public ThreadClosure { 518 private: 519 CodeBlobClosure* _nmethod_cl; 520 DeflateMonitorCounters* _counters; 521 522 public: 523 ParallelSPCleanupThreadClosure(DeflateMonitorCounters* counters) : 524 _nmethod_cl(UseCodeAging ? NMethodSweeper::prepare_reset_hotness_counters() : NULL), 525 _counters(counters) {} 526 527 void do_thread(Thread* thread) { 528 ObjectSynchronizer::deflate_thread_local_monitors(thread, _counters); 529 if (_nmethod_cl != NULL && thread->is_Java_thread() && 530 ! thread->is_Code_cache_sweeper_thread()) { 531 JavaThread* jt = (JavaThread*) thread; 532 jt->nmethods_do(_nmethod_cl); 533 } 534 } 535 }; 536 537 class ParallelSPCleanupTask : public AbstractGangTask { 538 private: 539 SubTasksDone _subtasks; 540 ParallelSPCleanupThreadClosure _cleanup_threads_cl; 541 uint _num_workers; 542 DeflateMonitorCounters* _counters; 543 public: 544 ParallelSPCleanupTask(uint num_workers, DeflateMonitorCounters* counters) : 545 AbstractGangTask("Parallel Safepoint Cleanup"), 546 _subtasks(SubTasksDone(SafepointSynchronize::SAFEPOINT_CLEANUP_NUM_TASKS)), 547 _cleanup_threads_cl(ParallelSPCleanupThreadClosure(counters)), 548 _num_workers(num_workers), 549 _counters(counters) {} 550 551 void work(uint worker_id) { 552 uint64_t safepoint_id = SafepointSynchronize::safepoint_counter(); 553 // All threads deflate monitors and mark nmethods (if necessary). 554 Threads::possibly_parallel_threads_do(true, &_cleanup_threads_cl); 555 556 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_DEFLATE_MONITORS)) { 557 const char* name = "deflating global idle monitors"; 558 EventSafepointCleanupTask event; 559 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 560 // AsyncDeflateIdleMonitors only uses DeflateMonitorCounters 561 // when a special cleanup has been requested. 562 // Note: This logging output will include global idle monitor 563 // elapsed times, but not global idle monitor deflation count. 564 ObjectSynchronizer::do_safepoint_work(!AsyncDeflateIdleMonitors ? _counters : NULL); 565 566 post_safepoint_cleanup_task_event(event, safepoint_id, name); 567 } 568 569 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_UPDATE_INLINE_CACHES)) { 570 const char* name = "updating inline caches"; 571 EventSafepointCleanupTask event; 572 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 573 InlineCacheBuffer::update_inline_caches(); 574 575 post_safepoint_cleanup_task_event(event, safepoint_id, name); 576 } 577 578 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_COMPILATION_POLICY)) { 579 const char* name = "compilation policy safepoint handler"; 580 EventSafepointCleanupTask event; 581 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 582 CompilationPolicy::policy()->do_safepoint_work(); 583 584 post_safepoint_cleanup_task_event(event, safepoint_id, name); 585 } 586 587 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_SYMBOL_TABLE_REHASH)) { 588 if (SymbolTable::needs_rehashing()) { 589 const char* name = "rehashing symbol table"; 590 EventSafepointCleanupTask event; 591 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 592 SymbolTable::rehash_table(); 593 594 post_safepoint_cleanup_task_event(event, safepoint_id, name); 595 } 596 } 597 598 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_STRING_TABLE_REHASH)) { 599 if (StringTable::needs_rehashing()) { 600 const char* name = "rehashing string table"; 601 EventSafepointCleanupTask event; 602 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 603 StringTable::rehash_table(); 604 605 post_safepoint_cleanup_task_event(event, safepoint_id, name); 606 } 607 } 608 609 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_CLD_PURGE)) { 610 // CMS delays purging the CLDG until the beginning of the next safepoint and to 611 // make sure concurrent sweep is done 612 const char* name = "purging class loader data graph"; 613 EventSafepointCleanupTask event; 614 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 615 ClassLoaderDataGraph::purge_if_needed(); 616 617 post_safepoint_cleanup_task_event(event, safepoint_id, name); 618 } 619 620 if (_subtasks.try_claim_task(SafepointSynchronize::SAFEPOINT_CLEANUP_SYSTEM_DICTIONARY_RESIZE)) { 621 const char* name = "resizing system dictionaries"; 622 EventSafepointCleanupTask event; 623 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 624 ClassLoaderDataGraph::resize_if_needed(); 625 626 post_safepoint_cleanup_task_event(event, safepoint_id, name); 627 } 628 629 _subtasks.all_tasks_completed(_num_workers); 630 } 631 }; 632 633 // Various cleaning tasks that should be done periodically at safepoints. 634 void SafepointSynchronize::do_cleanup_tasks() { 635 636 TraceTime timer("safepoint cleanup tasks", TRACETIME_LOG(Info, safepoint, cleanup)); 637 638 // Prepare for monitor deflation. 639 DeflateMonitorCounters deflate_counters; 640 ObjectSynchronizer::prepare_deflate_idle_monitors(&deflate_counters); 641 642 CollectedHeap* heap = Universe::heap(); 643 assert(heap != NULL, "heap not initialized yet?"); 644 WorkGang* cleanup_workers = heap->get_safepoint_workers(); 645 if (cleanup_workers != NULL) { 646 // Parallel cleanup using GC provided thread pool. 647 uint num_cleanup_workers = cleanup_workers->active_workers(); 648 ParallelSPCleanupTask cleanup(num_cleanup_workers, &deflate_counters); 649 StrongRootsScope srs(num_cleanup_workers); 650 cleanup_workers->run_task(&cleanup); 651 } else { 652 // Serial cleanup using VMThread. 653 ParallelSPCleanupTask cleanup(1, &deflate_counters); 654 StrongRootsScope srs(1); 655 cleanup.work(0); 656 } 657 658 // Needs to be done single threaded by the VMThread. This walks 659 // the thread stacks looking for references to metadata before 660 // deciding to remove it from the metaspaces. 661 if (ClassLoaderDataGraph::should_clean_metaspaces_and_reset()) { 662 const char* name = "cleanup live ClassLoaderData metaspaces"; 663 TraceTime timer(name, TRACETIME_LOG(Info, safepoint, cleanup)); 664 ClassLoaderDataGraph::walk_metadata_and_clean_metaspaces(); 665 } 666 667 // Finish monitor deflation. 668 ObjectSynchronizer::finish_deflate_idle_monitors(&deflate_counters); 669 670 assert(InlineCacheBuffer::is_empty(), "should have cleaned up ICBuffer"); 671 } 672 673 // Methods for determining if a JavaThread is safepoint safe. 674 675 // False means unsafe with undetermined state. 676 // True means a determined state, but it may be an unsafe state. 677 // If called from a non-safepoint context safepoint_count MUST be InactiveSafepointCounter. 678 bool SafepointSynchronize::try_stable_load_state(JavaThreadState *state, JavaThread *thread, uint64_t safepoint_count) { 679 assert((safepoint_count != InactiveSafepointCounter && 680 Thread::current() == (Thread*)VMThread::vm_thread() && 681 SafepointSynchronize::_state != _not_synchronized) 682 || safepoint_count == InactiveSafepointCounter, "Invalid check"); 683 684 // To handle the thread_blocked state on the backedge of the WaitBarrier from 685 // previous safepoint and reading the reset value (0/InactiveSafepointCounter) we 686 // re-read state after we read thread safepoint id. The JavaThread changes its 687 // thread state from thread_blocked before resetting safepoint id to 0. 688 // This guarantees the second read will be from an updated thread state. It can 689 // either be different state making this an unsafe state or it can see blocked 690 // again. When we see blocked twice with a 0 safepoint id, either: 691 // - It is normally blocked, e.g. on Mutex, TBIVM. 692 // - It was in SS:block(), looped around to SS:block() and is blocked on the WaitBarrier. 693 // - It was in SS:block() but now on a Mutex. 694 // All of these cases are safe. 695 696 *state = thread->thread_state(); 697 OrderAccess::loadload(); 698 uint64_t sid = thread->safepoint_state()->get_safepoint_id(); // Load acquire 699 if (sid != InactiveSafepointCounter && sid != safepoint_count) { 700 // In an old safepoint, state not relevant. 701 return false; 702 } 703 return *state == thread->thread_state(); 704 } 705 706 static bool safepoint_safe_with(JavaThread *thread, JavaThreadState state) { 707 switch(state) { 708 case _thread_in_native: 709 // native threads are safe if they have no java stack or have walkable stack 710 return !thread->has_last_Java_frame() || thread->frame_anchor()->walkable(); 711 712 case _thread_blocked: 713 // On wait_barrier or blocked. 714 // Blocked threads should already have walkable stack. 715 assert(!thread->has_last_Java_frame() || thread->frame_anchor()->walkable(), "blocked and not walkable"); 716 return true; 717 718 default: 719 return false; 720 } 721 } 722 723 bool SafepointSynchronize::handshake_safe(JavaThread *thread) { 724 // This function must be called with the Threads_lock held so an externally 725 // suspended thread cannot be resumed thus it is safe. 726 assert(Threads_lock->owned_by_self() && Thread::current()->is_VM_thread(), 727 "Must hold Threads_lock and be VMThread"); 728 if (thread->is_ext_suspended() || thread->is_terminated()) { 729 return true; 730 } 731 JavaThreadState stable_state; 732 if (try_stable_load_state(&stable_state, thread, InactiveSafepointCounter)) { 733 return safepoint_safe_with(thread, stable_state); 734 } 735 return false; 736 } 737 738 // See if the thread is running inside a lazy critical native and 739 // update the thread critical count if so. Also set a suspend flag to 740 // cause the native wrapper to return into the JVM to do the unlock 741 // once the native finishes. 742 static void check_for_lazy_critical_native(JavaThread *thread, JavaThreadState state) { 743 if (state == _thread_in_native && 744 thread->has_last_Java_frame() && 745 thread->frame_anchor()->walkable()) { 746 // This thread might be in a critical native nmethod so look at 747 // the top of the stack and increment the critical count if it 748 // is. 749 frame wrapper_frame = thread->last_frame(); 750 CodeBlob* stub_cb = wrapper_frame.cb(); 751 if (stub_cb != NULL && 752 stub_cb->is_nmethod() && 753 stub_cb->as_nmethod_or_null()->is_lazy_critical_native()) { 754 // A thread could potentially be in a critical native across 755 // more than one safepoint, so only update the critical state on 756 // the first one. When it returns it will perform the unlock. 757 if (!thread->do_critical_native_unlock()) { 758 #ifdef ASSERT 759 if (!thread->in_critical()) { 760 GCLocker::increment_debug_jni_lock_count(); 761 } 762 #endif 763 thread->enter_critical(); 764 // Make sure the native wrapper calls back on return to 765 // perform the needed critical unlock. 766 thread->set_critical_native_unlock(); 767 } 768 } 769 } 770 } 771 772 // ------------------------------------------------------------------------------------------------------- 773 // Implementation of Safepoint blocking point 774 775 void SafepointSynchronize::block(JavaThread *thread) { 776 assert(thread != NULL, "thread must be set"); 777 assert(thread->is_Java_thread(), "not a Java thread"); 778 779 // Threads shouldn't block if they are in the middle of printing, but... 780 ttyLocker::break_tty_lock_for_safepoint(os::current_thread_id()); 781 782 // Only bail from the block() call if the thread is gone from the 783 // thread list; starting to exit should still block. 784 if (thread->is_terminated()) { 785 // block current thread if we come here from native code when VM is gone 786 thread->block_if_vm_exited(); 787 788 // otherwise do nothing 789 return; 790 } 791 792 JavaThreadState state = thread->thread_state(); 793 thread->frame_anchor()->make_walkable(thread); 794 795 uint64_t safepoint_id = SafepointSynchronize::safepoint_counter(); 796 // Check that we have a valid thread_state at this point 797 switch(state) { 798 case _thread_in_vm_trans: 799 case _thread_in_Java: // From compiled code 800 case _thread_in_native_trans: 801 case _thread_blocked_trans: 802 case _thread_new_trans: 803 804 // We have no idea where the VMThread is, it might even be at next safepoint. 805 // So we can miss this poll, but stop at next. 806 807 // Load dependent store, it must not pass loading of safepoint_id. 808 thread->safepoint_state()->set_safepoint_id(safepoint_id); // Release store 809 810 // This part we can skip if we notice we miss or are in a future safepoint. 811 OrderAccess::storestore(); 812 thread->set_thread_state(_thread_blocked); 813 814 OrderAccess::fence(); // Load in wait barrier should not float up 815 _wait_barrier->wait(static_cast<int>(safepoint_id)); 816 assert(_state != _synchronized, "Can't be"); 817 818 // If barrier is disarmed stop store from floating above loads in barrier. 819 OrderAccess::loadstore(); 820 thread->set_thread_state(state); 821 822 // Then we reset the safepoint id to inactive. 823 thread->safepoint_state()->reset_safepoint_id(); // Release store 824 825 OrderAccess::fence(); 826 827 break; 828 829 default: 830 fatal("Illegal threadstate encountered: %d", state); 831 } 832 guarantee(thread->safepoint_state()->get_safepoint_id() == InactiveSafepointCounter, 833 "The safepoint id should be set only in block path"); 834 835 // Check for pending. async. exceptions or suspends - except if the 836 // thread was blocked inside the VM. has_special_runtime_exit_condition() 837 // is called last since it grabs a lock and we only want to do that when 838 // we must. 839 // 840 // Note: we never deliver an async exception at a polling point as the 841 // compiler may not have an exception handler for it. The polling 842 // code will notice the async and deoptimize and the exception will 843 // be delivered. (Polling at a return point is ok though). Sure is 844 // a lot of bother for a deprecated feature... 845 // 846 // We don't deliver an async exception if the thread state is 847 // _thread_in_native_trans so JNI functions won't be called with 848 // a surprising pending exception. If the thread state is going back to java, 849 // async exception is checked in check_special_condition_for_native_trans(). 850 851 if (state != _thread_blocked_trans && 852 state != _thread_in_vm_trans && 853 thread->has_special_runtime_exit_condition()) { 854 thread->handle_special_runtime_exit_condition( 855 !thread->is_at_poll_safepoint() && (state != _thread_in_native_trans)); 856 } 857 858 // cross_modify_fence is done by SafepointMechanism::block_if_requested_slow 859 // which is the only caller here. 860 } 861 862 // ------------------------------------------------------------------------------------------------------ 863 // Exception handlers 864 865 866 void SafepointSynchronize::handle_polling_page_exception(JavaThread *thread) { 867 assert(thread->is_Java_thread(), "polling reference encountered by VM thread"); 868 assert(thread->thread_state() == _thread_in_Java, "should come from Java code"); 869 if (!ThreadLocalHandshakes) { 870 assert(SafepointSynchronize::is_synchronizing(), "polling encountered outside safepoint synchronization"); 871 } 872 873 if (log_is_enabled(Info, safepoint, stats)) { 874 Atomic::inc(&_nof_threads_hit_polling_page); 875 } 876 877 ThreadSafepointState* state = thread->safepoint_state(); 878 879 state->handle_polling_page_exception(); 880 } 881 882 883 void SafepointSynchronize::print_safepoint_timeout() { 884 if (!timeout_error_printed) { 885 timeout_error_printed = true; 886 // Print out the thread info which didn't reach the safepoint for debugging 887 // purposes (useful when there are lots of threads in the debugger). 888 LogTarget(Warning, safepoint) lt; 889 if (lt.is_enabled()) { 890 ResourceMark rm; 891 LogStream ls(lt); 892 893 ls.cr(); 894 ls.print_cr("# SafepointSynchronize::begin: Timeout detected:"); 895 ls.print_cr("# SafepointSynchronize::begin: Timed out while spinning to reach a safepoint."); 896 ls.print_cr("# SafepointSynchronize::begin: Threads which did not reach the safepoint:"); 897 for (JavaThreadIteratorWithHandle jtiwh; JavaThread *cur_thread = jtiwh.next(); ) { 898 if (cur_thread->safepoint_state()->is_running()) { 899 ls.print("# "); 900 cur_thread->print_on(&ls); 901 ls.cr(); 902 } 903 } 904 ls.print_cr("# SafepointSynchronize::begin: (End of list)"); 905 } 906 } 907 908 // To debug the long safepoint, specify both AbortVMOnSafepointTimeout & 909 // ShowMessageBoxOnError. 910 if (AbortVMOnSafepointTimeout) { 911 // Send the blocking thread a signal to terminate and write an error file. 912 for (JavaThreadIteratorWithHandle jtiwh; JavaThread *cur_thread = jtiwh.next(); ) { 913 if (cur_thread->safepoint_state()->is_running()) { 914 if (!os::signal_thread(cur_thread, SIGILL, "blocking a safepoint")) { 915 break; // Could not send signal. Report fatal error. 916 } 917 // Give cur_thread a chance to report the error and terminate the VM. 918 os::sleep(Thread::current(), 3000, false); 919 } 920 } 921 fatal("Safepoint sync time longer than " INTX_FORMAT "ms detected when executing %s.", 922 SafepointTimeoutDelay, VMThread::vm_operation()->name()); 923 } 924 } 925 926 // ------------------------------------------------------------------------------------------------------- 927 // Implementation of ThreadSafepointState 928 929 ThreadSafepointState::ThreadSafepointState(JavaThread *thread) 930 : _at_poll_safepoint(false), _thread(thread), _safepoint_safe(false), 931 _safepoint_id(SafepointSynchronize::InactiveSafepointCounter), 932 _orig_thread_state(_thread_uninitialized), _next(NULL) { 933 } 934 935 void ThreadSafepointState::create(JavaThread *thread) { 936 ThreadSafepointState *state = new ThreadSafepointState(thread); 937 thread->set_safepoint_state(state); 938 } 939 940 void ThreadSafepointState::destroy(JavaThread *thread) { 941 if (thread->safepoint_state()) { 942 delete(thread->safepoint_state()); 943 thread->set_safepoint_state(NULL); 944 } 945 } 946 947 uint64_t ThreadSafepointState::get_safepoint_id() const { 948 return OrderAccess::load_acquire(&_safepoint_id); 949 } 950 951 void ThreadSafepointState::reset_safepoint_id() { 952 OrderAccess::release_store(&_safepoint_id, SafepointSynchronize::InactiveSafepointCounter); 953 } 954 955 void ThreadSafepointState::set_safepoint_id(uint64_t safepoint_id) { 956 OrderAccess::release_store(&_safepoint_id, safepoint_id); 957 } 958 959 void ThreadSafepointState::examine_state_of_thread(uint64_t safepoint_count) { 960 assert(is_running(), "better be running or just have hit safepoint poll"); 961 962 JavaThreadState stable_state; 963 if (!SafepointSynchronize::try_stable_load_state(&stable_state, _thread, safepoint_count)) { 964 // We could not get stable state of the JavaThread. 965 // Consider it running and just return. 966 return; 967 } 968 969 // Save the state at the start of safepoint processing. 970 _orig_thread_state = stable_state; 971 972 // Check for a thread that is suspended. Note that thread resume tries 973 // to grab the Threads_lock which we own here, so a thread cannot be 974 // resumed during safepoint synchronization. 975 976 // We check to see if this thread is suspended without locking to 977 // avoid deadlocking with a third thread that is waiting for this 978 // thread to be suspended. The third thread can notice the safepoint 979 // that we're trying to start at the beginning of its SR_lock->wait() 980 // call. If that happens, then the third thread will block on the 981 // safepoint while still holding the underlying SR_lock. We won't be 982 // able to get the SR_lock and we'll deadlock. 983 // 984 // We don't need to grab the SR_lock here for two reasons: 985 // 1) The suspend flags are both volatile and are set with an 986 // Atomic::cmpxchg() call so we should see the suspended 987 // state right away. 988 // 2) We're being called from the safepoint polling loop; if 989 // we don't see the suspended state on this iteration, then 990 // we'll come around again. 991 // 992 bool is_suspended = _thread->is_ext_suspended(); 993 if (is_suspended) { 994 account_safe_thread(); 995 return; 996 } 997 998 if (safepoint_safe_with(_thread, stable_state)) { 999 check_for_lazy_critical_native(_thread, stable_state); 1000 account_safe_thread(); 1001 return; 1002 } 1003 1004 // All other thread states will continue to run until they 1005 // transition and self-block in state _blocked 1006 // Safepoint polling in compiled code causes the Java threads to do the same. 1007 // Note: new threads may require a malloc so they must be allowed to finish 1008 1009 assert(is_running(), "examine_state_of_thread on non-running thread"); 1010 return; 1011 } 1012 1013 void ThreadSafepointState::account_safe_thread() { 1014 SafepointSynchronize::decrement_waiting_to_block(); 1015 if (_thread->in_critical()) { 1016 // Notice that this thread is in a critical section 1017 SafepointSynchronize::increment_jni_active_count(); 1018 } 1019 DEBUG_ONLY(_thread->set_visited_for_critical_count(SafepointSynchronize::safepoint_counter());) 1020 assert(!_safepoint_safe, "Must be unsafe before safe"); 1021 _safepoint_safe = true; 1022 } 1023 1024 void ThreadSafepointState::restart() { 1025 assert(_safepoint_safe, "Must be safe before unsafe"); 1026 _safepoint_safe = false; 1027 } 1028 1029 void ThreadSafepointState::print_on(outputStream *st) const { 1030 const char *s = _safepoint_safe ? "_at_safepoint" : "_running"; 1031 1032 st->print_cr("Thread: " INTPTR_FORMAT 1033 " [0x%2x] State: %s _at_poll_safepoint %d", 1034 p2i(_thread), _thread->osthread()->thread_id(), s, _at_poll_safepoint); 1035 1036 _thread->print_thread_state_on(st); 1037 } 1038 1039 // --------------------------------------------------------------------------------------------------------------------- 1040 1041 // Block the thread at poll or poll return for safepoint/handshake. 1042 void ThreadSafepointState::handle_polling_page_exception() { 1043 1044 // If we're using a global poll, then the thread should not be 1045 // marked as safepoint safe yet. 1046 assert(!SafepointMechanism::uses_global_page_poll() || !_safepoint_safe, 1047 "polling page exception on thread safepoint safe"); 1048 1049 // Step 1: Find the nmethod from the return address 1050 address real_return_addr = thread()->saved_exception_pc(); 1051 1052 CodeBlob *cb = CodeCache::find_blob(real_return_addr); 1053 assert(cb != NULL && cb->is_compiled(), "return address should be in nmethod"); 1054 CompiledMethod* nm = (CompiledMethod*)cb; 1055 1056 // Find frame of caller 1057 frame stub_fr = thread()->last_frame(); 1058 CodeBlob* stub_cb = stub_fr.cb(); 1059 assert(stub_cb->is_safepoint_stub(), "must be a safepoint stub"); 1060 RegisterMap map(thread(), true); 1061 frame caller_fr = stub_fr.sender(&map); 1062 1063 // Should only be poll_return or poll 1064 assert( nm->is_at_poll_or_poll_return(real_return_addr), "should not be at call" ); 1065 1066 // This is a poll immediately before a return. The exception handling code 1067 // has already had the effect of causing the return to occur, so the execution 1068 // will continue immediately after the call. In addition, the oopmap at the 1069 // return point does not mark the return value as an oop (if it is), so 1070 // it needs a handle here to be updated. 1071 if( nm->is_at_poll_return(real_return_addr) ) { 1072 // See if return type is an oop. 1073 bool return_oop = nm->method()->is_returning_oop(); 1074 Handle return_value; 1075 if (return_oop) { 1076 // The oop result has been saved on the stack together with all 1077 // the other registers. In order to preserve it over GCs we need 1078 // to keep it in a handle. 1079 oop result = caller_fr.saved_oop_result(&map); 1080 assert(oopDesc::is_oop_or_null(result), "must be oop"); 1081 return_value = Handle(thread(), result); 1082 assert(Universe::heap()->is_in_or_null(result), "must be heap pointer"); 1083 } 1084 1085 // Block the thread 1086 SafepointMechanism::block_if_requested(thread()); 1087 1088 // restore oop result, if any 1089 if (return_oop) { 1090 caller_fr.set_saved_oop_result(&map, return_value()); 1091 } 1092 } 1093 1094 // This is a safepoint poll. Verify the return address and block. 1095 else { 1096 set_at_poll_safepoint(true); 1097 1098 // verify the blob built the "return address" correctly 1099 assert(real_return_addr == caller_fr.pc(), "must match"); 1100 1101 // Block the thread 1102 SafepointMechanism::block_if_requested(thread()); 1103 set_at_poll_safepoint(false); 1104 1105 // If we have a pending async exception deoptimize the frame 1106 // as otherwise we may never deliver it. 1107 if (thread()->has_async_condition()) { 1108 ThreadInVMfromJavaNoAsyncException __tiv(thread()); 1109 Deoptimization::deoptimize_frame(thread(), caller_fr.id()); 1110 } 1111 1112 // If an exception has been installed we must check for a pending deoptimization 1113 // Deoptimize frame if exception has been thrown. 1114 1115 if (thread()->has_pending_exception() ) { 1116 RegisterMap map(thread(), true); 1117 frame caller_fr = stub_fr.sender(&map); 1118 if (caller_fr.is_deoptimized_frame()) { 1119 // The exception patch will destroy registers that are still 1120 // live and will be needed during deoptimization. Defer the 1121 // Async exception should have deferred the exception until the 1122 // next safepoint which will be detected when we get into 1123 // the interpreter so if we have an exception now things 1124 // are messed up. 1125 1126 fatal("Exception installed and deoptimization is pending"); 1127 } 1128 } 1129 } 1130 } 1131 1132 1133 // ------------------------------------------------------------------------------------------------------- 1134 // Implementation of SafepointTracing 1135 1136 jlong SafepointTracing::_last_safepoint_begin_time_ns = 0; 1137 jlong SafepointTracing::_last_safepoint_sync_time_ns = 0; 1138 jlong SafepointTracing::_last_safepoint_cleanup_time_ns = 0; 1139 jlong SafepointTracing::_last_safepoint_end_time_ns = 0; 1140 jlong SafepointTracing::_last_safepoint_end_time_epoch_ms = 0; 1141 jlong SafepointTracing::_last_app_time_ns = 0; 1142 int SafepointTracing::_nof_threads = 0; 1143 int SafepointTracing::_nof_running = 0; 1144 int SafepointTracing::_page_trap = 0; 1145 VM_Operation::VMOp_Type SafepointTracing::_current_type; 1146 jlong SafepointTracing::_max_sync_time = 0; 1147 jlong SafepointTracing::_max_vmop_time = 0; 1148 uint64_t SafepointTracing::_op_count[VM_Operation::VMOp_Terminating] = {0}; 1149 1150 void SafepointTracing::init() { 1151 // Application start 1152 _last_safepoint_end_time_ns = os::javaTimeNanos(); 1153 // amount of time since epoch 1154 _last_safepoint_end_time_epoch_ms = os::javaTimeMillis(); 1155 } 1156 1157 // Helper method to print the header. 1158 static void print_header(outputStream* st) { 1159 // The number of spaces is significant here, and should match the format 1160 // specifiers in print_statistics(). 1161 1162 st->print("VM Operation " 1163 "[ threads: total initial_running ]" 1164 "[ time: sync cleanup vmop total ]"); 1165 1166 st->print_cr(" page_trap_count"); 1167 } 1168 1169 // This prints a nice table. To get the statistics to not shift due to the logging uptime 1170 // decorator, use the option as: -Xlog:safepoint+stats:[outputfile]:none 1171 void SafepointTracing::statistics_log() { 1172 LogTarget(Info, safepoint, stats) lt; 1173 assert (lt.is_enabled(), "should only be called when printing statistics is enabled"); 1174 LogStream ls(lt); 1175 1176 static int _cur_stat_index = 0; 1177 1178 // Print header every 30 entries 1179 if ((_cur_stat_index % 30) == 0) { 1180 print_header(&ls); 1181 _cur_stat_index = 1; // wrap 1182 } else { 1183 _cur_stat_index++; 1184 } 1185 1186 ls.print("%-28s [ " 1187 INT32_FORMAT_W(8) " " INT32_FORMAT_W(8) " " 1188 "]", 1189 VM_Operation::name(_current_type), 1190 _nof_threads, 1191 _nof_running); 1192 ls.print("[ " 1193 INT64_FORMAT_W(10) " " INT64_FORMAT_W(10) " " 1194 INT64_FORMAT_W(10) " " INT64_FORMAT_W(10) " ]", 1195 (int64_t)(_last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns), 1196 (int64_t)(_last_safepoint_cleanup_time_ns - _last_safepoint_sync_time_ns), 1197 (int64_t)(_last_safepoint_end_time_ns - _last_safepoint_cleanup_time_ns), 1198 (int64_t)(_last_safepoint_end_time_ns - _last_safepoint_begin_time_ns)); 1199 1200 ls.print_cr(INT32_FORMAT_W(16), _page_trap); 1201 } 1202 1203 // This method will be called when VM exits. This tries to summarize the sampling. 1204 // Current thread may already be deleted, so don't use ResourceMark. 1205 void SafepointTracing::statistics_exit_log() { 1206 if (!log_is_enabled(Info, safepoint, stats)) { 1207 return; 1208 } 1209 for (int index = 0; index < VM_Operation::VMOp_Terminating; index++) { 1210 if (_op_count[index] != 0) { 1211 log_info(safepoint, stats)("%-28s" UINT64_FORMAT_W(10), VM_Operation::name(index), 1212 _op_count[index]); 1213 } 1214 } 1215 1216 log_info(safepoint, stats)("VM operations coalesced during safepoint " INT64_FORMAT, 1217 VMThread::get_coalesced_count()); 1218 log_info(safepoint, stats)("Maximum sync time " INT64_FORMAT" ns", 1219 (int64_t)(_max_sync_time)); 1220 log_info(safepoint, stats)("Maximum vm operation time (except for Exit VM operation) " 1221 INT64_FORMAT " ns", 1222 (int64_t)(_max_vmop_time)); 1223 } 1224 1225 void SafepointTracing::begin(VM_Operation::VMOp_Type type) { 1226 _op_count[type]++; 1227 _current_type = type; 1228 1229 // update the time stamp to begin recording safepoint time 1230 _last_safepoint_begin_time_ns = os::javaTimeNanos(); 1231 _last_safepoint_sync_time_ns = 0; 1232 _last_safepoint_cleanup_time_ns = 0; 1233 1234 _last_app_time_ns = _last_safepoint_begin_time_ns - _last_safepoint_end_time_ns; 1235 _last_safepoint_end_time_ns = 0; 1236 1237 RuntimeService::record_safepoint_begin(_last_app_time_ns); 1238 } 1239 1240 void SafepointTracing::synchronized(int nof_threads, int nof_running, int traps) { 1241 _last_safepoint_sync_time_ns = os::javaTimeNanos(); 1242 _nof_threads = nof_threads; 1243 _nof_running = nof_running; 1244 _page_trap = traps; 1245 RuntimeService::record_safepoint_synchronized(_last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns); 1246 } 1247 1248 void SafepointTracing::cleanup() { 1249 _last_safepoint_cleanup_time_ns = os::javaTimeNanos(); 1250 } 1251 1252 void SafepointTracing::end() { 1253 _last_safepoint_end_time_ns = os::javaTimeNanos(); 1254 // amount of time since epoch 1255 _last_safepoint_end_time_epoch_ms = os::javaTimeMillis(); 1256 1257 if (_max_sync_time < (_last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns)) { 1258 _max_sync_time = _last_safepoint_sync_time_ns - _last_safepoint_begin_time_ns; 1259 } 1260 if (_max_vmop_time < (_last_safepoint_end_time_ns - _last_safepoint_sync_time_ns)) { 1261 _max_vmop_time = _last_safepoint_end_time_ns - _last_safepoint_sync_time_ns; 1262 } 1263 if (log_is_enabled(Info, safepoint, stats)) { 1264 statistics_log(); 1265 } 1266 1267 log_info(safepoint)( 1268 "Safepoint \"%s\", " 1269 "Time since last: " JLONG_FORMAT " ns, " 1270 "Reaching safepoint: " JLONG_FORMAT " ns, " 1271 "At safepoint: " JLONG_FORMAT " ns, " 1272 "Total: " JLONG_FORMAT " ns", 1273 VM_Operation::name(_current_type), 1274 _last_app_time_ns, 1275 _last_safepoint_cleanup_time_ns - _last_safepoint_begin_time_ns, 1276 _last_safepoint_end_time_ns - _last_safepoint_cleanup_time_ns, 1277 _last_safepoint_end_time_ns - _last_safepoint_begin_time_ns 1278 ); 1279 1280 RuntimeService::record_safepoint_end(_last_safepoint_end_time_ns - _last_safepoint_cleanup_time_ns); 1281 }