< prev index next >

src/hotspot/share/runtime/synchronizer.cpp

Print this page
rev 54108 : Add logging to ObjectSynchronizer::omFlush(), add global count logging at Info level to ObjectSynchronizer::finish_deflate_idle_monitors(); for monitorinflation logging, switch from cumulative "deflating per-thread idle monitors" mesgs to per-thread "deflating per-thread idle monitors" mesgs; fix timer bug in deflate_thread_local_monitors() where time to acquire gListLock wasn't counted; fix misc typos.

*** 1268,1277 **** --- 1268,1292 ---- gOmInUseList = inUseList; gOmInUseCount += inUseTally; } Thread::muxRelease(&gListLock); + + LogStreamHandle(Debug, monitorinflation) lsh_debug; + LogStreamHandle(Info, monitorinflation) lsh_info; + LogStream * ls = NULL; + if (log_is_enabled(Debug, monitorinflation)) { + ls = &lsh_debug; + } else if ((tally != 0 || inUseTally != 0) && + log_is_enabled(Info, monitorinflation)) { + ls = &lsh_info; + } + if (ls != NULL) { + ls->print_cr("omFlush: jt=" INTPTR_FORMAT ", free_monitor_tally=%d" + ", in_use_monitor_tally=%d" ", omFreeProvision=%d", + p2i(Self), tally, inUseTally, Self->omFreeProvision); + } } static void post_monitor_inflate_event(EventJavaMonitorInflate* event, const oop obj, ObjectSynchronizer::InflateCause cause) {
*** 1663,1690 **** // monitors. Note: if the work is split among more than one // worker thread, then the reported time will likely be more // than a beginning to end measurement of the phase. log_info(safepoint, cleanup)("deflating per-thread idle monitors, %3.7f secs, monitors=%d", counters->perThreadTimes, counters->perThreadScavenged); - LogStreamHandle(Debug, monitorinflation) lsh_debug; - LogStreamHandle(Info, monitorinflation) lsh_info; - LogStream * ls = NULL; - if (log_is_enabled(Debug, monitorinflation)) { - ls = &lsh_debug; - } else if (counters->perThreadScavenged != 0 && log_is_enabled(Info, monitorinflation)) { - ls = &lsh_info; - } - if (ls != NULL) { - ls->print_cr("deflating per-thread idle monitors, %3.7f secs, %d monitors", counters->perThreadTimes, counters->perThreadScavenged); - } - gMonitorFreeCount += counters->nScavenged; if (log_is_enabled(Debug, monitorinflation)) { // exit_globals()'s call to audit_and_print_stats() is done // at the Info level. ObjectSynchronizer::audit_and_print_stats(false /* on_exit */); } ForceMonitorScavenge = 0; // Reset OM_PERFDATA_OP(Deflations, inc(counters->nScavenged)); --- 1678,1699 ---- // monitors. Note: if the work is split among more than one // worker thread, then the reported time will likely be more // than a beginning to end measurement of the phase. log_info(safepoint, cleanup)("deflating per-thread idle monitors, %3.7f secs, monitors=%d", counters->perThreadTimes, counters->perThreadScavenged); gMonitorFreeCount += counters->nScavenged; if (log_is_enabled(Debug, monitorinflation)) { // exit_globals()'s call to audit_and_print_stats() is done // at the Info level. ObjectSynchronizer::audit_and_print_stats(false /* on_exit */); + } else if (log_is_enabled(Info, monitorinflation)) { + Thread::muxAcquire(&gListLock, "finish_deflate_idle_monitors"); + log_info(monitorinflation)("gMonitorPopulation=%d, gOmInUseCount=%d, " + "gMonitorFreeCount=%d", gMonitorPopulation, + gOmInUseCount, gMonitorFreeCount); + Thread::muxRelease(&gListLock); } ForceMonitorScavenge = 0; // Reset OM_PERFDATA_OP(Deflations, inc(counters->nScavenged));
*** 1706,1727 **** timer.start(); } int deflated_count = deflate_monitor_list(thread->omInUseList_addr(), &freeHeadp, &freeTailp); ! timer.stop(); ! ! Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors"); // Adjust counters counters->nInCirculation += thread->omInUseCount; thread->omInUseCount -= deflated_count; counters->nScavenged += deflated_count; counters->nInuse += thread->omInUseCount; counters->perThreadScavenged += deflated_count; - // For now, we only care about cumulative per-thread deflation time. - counters->perThreadTimes += timer.seconds(); // Move the scavenged monitors back to the global free list. if (freeHeadp != NULL) { guarantee(freeTailp != NULL && deflated_count > 0, "invariant"); assert(freeTailp->FreeNext == NULL, "invariant"); --- 1715,1732 ---- timer.start(); } int deflated_count = deflate_monitor_list(thread->omInUseList_addr(), &freeHeadp, &freeTailp); ! Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors(1)"); // Adjust counters counters->nInCirculation += thread->omInUseCount; thread->omInUseCount -= deflated_count; counters->nScavenged += deflated_count; counters->nInuse += thread->omInUseCount; counters->perThreadScavenged += deflated_count; // Move the scavenged monitors back to the global free list. if (freeHeadp != NULL) { guarantee(freeTailp != NULL && deflated_count > 0, "invariant"); assert(freeTailp->FreeNext == NULL, "invariant");
*** 1729,1738 **** --- 1734,1765 ---- // constant-time list splice - prepend scavenged segment to gFreeList freeTailp->FreeNext = gFreeList; gFreeList = freeHeadp; } Thread::muxRelease(&gListLock); + + timer.stop(); + if (log_is_enabled(Info, safepoint, cleanup)) { + // Only safepoint logging cares about cumulative perThreadTimes + // and we don't count this muxAcquire() that we have to do in + // order to safely update perThreadTimes. + Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors(2)"); + counters->perThreadTimes += timer.seconds(); + Thread::muxRelease(&gListLock); + } + + LogStreamHandle(Debug, monitorinflation) lsh_debug; + LogStreamHandle(Info, monitorinflation) lsh_info; + LogStream * ls = NULL; + if (log_is_enabled(Debug, monitorinflation)) { + ls = &lsh_debug; + } else if (deflated_count != 0 && log_is_enabled(Info, monitorinflation)) { + ls = &lsh_info; + } + if (ls != NULL) { + ls->print_cr("jt=" INTPTR_FORMAT ": deflating per-thread idle monitors, %3.7f secs, %d monitors", p2i(thread), timer.seconds(), deflated_count); + } } // Monitor cleanup on JavaThread::exit // Iterate through monitor cache and attempt to release thread's monitors
< prev index next >