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