< 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.


1253     guarantee(inUseTail != NULL, "invariant");
1254     assert(Self->omInUseCount == inUseTally, "in-use count off");
1255     Self->omInUseList = NULL;
1256     Self->omInUseCount = 0;
1257   }
1258 
1259   Thread::muxAcquire(&gListLock, "omFlush");
1260   if (tail != NULL) {
1261     tail->FreeNext = gFreeList;
1262     gFreeList = list;
1263     gMonitorFreeCount += tally;
1264   }
1265 
1266   if (inUseTail != NULL) {
1267     inUseTail->FreeNext = gOmInUseList;
1268     gOmInUseList = inUseList;
1269     gOmInUseCount += inUseTally;
1270   }
1271 
1272   Thread::muxRelease(&gListLock);















1273 }
1274 
1275 static void post_monitor_inflate_event(EventJavaMonitorInflate* event,
1276                                        const oop obj,
1277                                        ObjectSynchronizer::InflateCause cause) {
1278   assert(event != NULL, "invariant");
1279   assert(event->should_commit(), "invariant");
1280   event->set_monitorClass(obj->klass());
1281   event->set_address((uintptr_t)(void*)obj);
1282   event->set_cause((u1)cause);
1283   event->commit();
1284 }
1285 
1286 // Fast path code shared by multiple functions
1287 void ObjectSynchronizer::inflate_helper(oop obj) {
1288   markOop mark = obj->mark();
1289   if (mark->has_monitor()) {
1290     assert(ObjectSynchronizer::verify_objmon_isinpool(mark->monitor()), "monitor is invalid");
1291     assert(mark->monitor()->header()->is_neutral(), "monitor must record a good object header");
1292     return;


1648   LogStreamHandle(Debug, monitorinflation) lsh_debug;
1649   LogStreamHandle(Info, monitorinflation) lsh_info;
1650   LogStream * ls = NULL;
1651   if (log_is_enabled(Debug, monitorinflation)) {
1652     ls = &lsh_debug;
1653   } else if (deflated_count != 0 && log_is_enabled(Info, monitorinflation)) {
1654     ls = &lsh_info;
1655   }
1656   if (ls != NULL) {
1657     ls->print_cr("deflating global idle monitors, %3.7f secs, %d monitors", timer.seconds(), deflated_count);
1658   }
1659 }
1660 
1661 void ObjectSynchronizer::finish_deflate_idle_monitors(DeflateMonitorCounters* counters) {
1662   // Report the cumulative time for deflating each thread's idle
1663   // monitors. Note: if the work is split among more than one
1664   // worker thread, then the reported time will likely be more
1665   // than a beginning to end measurement of the phase.
1666   log_info(safepoint, cleanup)("deflating per-thread idle monitors, %3.7f secs, monitors=%d", counters->perThreadTimes, counters->perThreadScavenged);
1667 
1668   LogStreamHandle(Debug, monitorinflation) lsh_debug;
1669   LogStreamHandle(Info, monitorinflation) lsh_info;
1670   LogStream * ls = NULL;
1671   if (log_is_enabled(Debug, monitorinflation)) {
1672     ls = &lsh_debug;
1673   } else if (counters->perThreadScavenged != 0 && log_is_enabled(Info, monitorinflation)) {
1674     ls = &lsh_info;
1675   }
1676   if (ls != NULL) {
1677     ls->print_cr("deflating per-thread idle monitors, %3.7f secs, %d monitors", counters->perThreadTimes, counters->perThreadScavenged);
1678   }
1679 
1680   gMonitorFreeCount += counters->nScavenged;
1681 
1682   if (log_is_enabled(Debug, monitorinflation)) {
1683     // exit_globals()'s call to audit_and_print_stats() is done
1684     // at the Info level.
1685     ObjectSynchronizer::audit_and_print_stats(false /* on_exit */);






1686   }
1687 
1688   ForceMonitorScavenge = 0;    // Reset
1689 
1690   OM_PERFDATA_OP(Deflations, inc(counters->nScavenged));
1691   OM_PERFDATA_OP(MonExtant, set_value(counters->nInCirculation));
1692 
1693   GVars.stwRandom = os::random();
1694   GVars.stwCycle++;
1695 }
1696 
1697 void ObjectSynchronizer::deflate_thread_local_monitors(Thread* thread, DeflateMonitorCounters* counters) {
1698   assert(SafepointSynchronize::is_at_safepoint(), "must be at safepoint");
1699 
1700   ObjectMonitor * freeHeadp = NULL;  // Local SLL of scavenged monitors
1701   ObjectMonitor * freeTailp = NULL;
1702   elapsedTimer timer;
1703 
1704   if (log_is_enabled(Info, safepoint, cleanup) ||
1705       log_is_enabled(Info, monitorinflation)) {
1706     timer.start();
1707   }
1708 
1709   int deflated_count = deflate_monitor_list(thread->omInUseList_addr(), &freeHeadp, &freeTailp);
1710 
1711   timer.stop();
1712 
1713   Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors");
1714 
1715   // Adjust counters
1716   counters->nInCirculation += thread->omInUseCount;
1717   thread->omInUseCount -= deflated_count;
1718   counters->nScavenged += deflated_count;
1719   counters->nInuse += thread->omInUseCount;
1720   counters->perThreadScavenged += deflated_count;
1721   // For now, we only care about cumulative per-thread deflation time.
1722   counters->perThreadTimes += timer.seconds();
1723 
1724   // Move the scavenged monitors back to the global free list.
1725   if (freeHeadp != NULL) {
1726     guarantee(freeTailp != NULL && deflated_count > 0, "invariant");
1727     assert(freeTailp->FreeNext == NULL, "invariant");
1728 
1729     // constant-time list splice - prepend scavenged segment to gFreeList
1730     freeTailp->FreeNext = gFreeList;
1731     gFreeList = freeHeadp;
1732   }
1733   Thread::muxRelease(&gListLock);






















1734 }
1735 
1736 // Monitor cleanup on JavaThread::exit
1737 
1738 // Iterate through monitor cache and attempt to release thread's monitors
1739 // Gives up on a particular monitor if an exception occurs, but continues
1740 // the overall iteration, swallowing the exception.
1741 class ReleaseJavaMonitorsClosure: public MonitorClosure {
1742  private:
1743   TRAPS;
1744 
1745  public:
1746   ReleaseJavaMonitorsClosure(Thread* thread) : THREAD(thread) {}
1747   void do_monitor(ObjectMonitor* mid) {
1748     if (mid->owner() == THREAD) {
1749       (void)mid->complete_exit(CHECK);
1750     }
1751   }
1752 };
1753 




1253     guarantee(inUseTail != NULL, "invariant");
1254     assert(Self->omInUseCount == inUseTally, "in-use count off");
1255     Self->omInUseList = NULL;
1256     Self->omInUseCount = 0;
1257   }
1258 
1259   Thread::muxAcquire(&gListLock, "omFlush");
1260   if (tail != NULL) {
1261     tail->FreeNext = gFreeList;
1262     gFreeList = list;
1263     gMonitorFreeCount += tally;
1264   }
1265 
1266   if (inUseTail != NULL) {
1267     inUseTail->FreeNext = gOmInUseList;
1268     gOmInUseList = inUseList;
1269     gOmInUseCount += inUseTally;
1270   }
1271 
1272   Thread::muxRelease(&gListLock);
1273 
1274   LogStreamHandle(Debug, monitorinflation) lsh_debug;
1275   LogStreamHandle(Info, monitorinflation) lsh_info;
1276   LogStream * ls = NULL;
1277   if (log_is_enabled(Debug, monitorinflation)) {
1278     ls = &lsh_debug;
1279   } else if ((tally != 0 || inUseTally != 0) &&
1280              log_is_enabled(Info, monitorinflation)) {
1281     ls = &lsh_info;
1282   }
1283   if (ls != NULL) {
1284     ls->print_cr("omFlush: jt=" INTPTR_FORMAT ", free_monitor_tally=%d"
1285                  ", in_use_monitor_tally=%d" ", omFreeProvision=%d",
1286                  p2i(Self), tally, inUseTally, Self->omFreeProvision);
1287   }
1288 }
1289 
1290 static void post_monitor_inflate_event(EventJavaMonitorInflate* event,
1291                                        const oop obj,
1292                                        ObjectSynchronizer::InflateCause cause) {
1293   assert(event != NULL, "invariant");
1294   assert(event->should_commit(), "invariant");
1295   event->set_monitorClass(obj->klass());
1296   event->set_address((uintptr_t)(void*)obj);
1297   event->set_cause((u1)cause);
1298   event->commit();
1299 }
1300 
1301 // Fast path code shared by multiple functions
1302 void ObjectSynchronizer::inflate_helper(oop obj) {
1303   markOop mark = obj->mark();
1304   if (mark->has_monitor()) {
1305     assert(ObjectSynchronizer::verify_objmon_isinpool(mark->monitor()), "monitor is invalid");
1306     assert(mark->monitor()->header()->is_neutral(), "monitor must record a good object header");
1307     return;


1663   LogStreamHandle(Debug, monitorinflation) lsh_debug;
1664   LogStreamHandle(Info, monitorinflation) lsh_info;
1665   LogStream * ls = NULL;
1666   if (log_is_enabled(Debug, monitorinflation)) {
1667     ls = &lsh_debug;
1668   } else if (deflated_count != 0 && log_is_enabled(Info, monitorinflation)) {
1669     ls = &lsh_info;
1670   }
1671   if (ls != NULL) {
1672     ls->print_cr("deflating global idle monitors, %3.7f secs, %d monitors", timer.seconds(), deflated_count);
1673   }
1674 }
1675 
1676 void ObjectSynchronizer::finish_deflate_idle_monitors(DeflateMonitorCounters* counters) {
1677   // Report the cumulative time for deflating each thread's idle
1678   // monitors. Note: if the work is split among more than one
1679   // worker thread, then the reported time will likely be more
1680   // than a beginning to end measurement of the phase.
1681   log_info(safepoint, cleanup)("deflating per-thread idle monitors, %3.7f secs, monitors=%d", counters->perThreadTimes, counters->perThreadScavenged);
1682 












1683   gMonitorFreeCount += counters->nScavenged;
1684 
1685   if (log_is_enabled(Debug, monitorinflation)) {
1686     // exit_globals()'s call to audit_and_print_stats() is done
1687     // at the Info level.
1688     ObjectSynchronizer::audit_and_print_stats(false /* on_exit */);
1689   } else if (log_is_enabled(Info, monitorinflation)) {
1690     Thread::muxAcquire(&gListLock, "finish_deflate_idle_monitors");
1691     log_info(monitorinflation)("gMonitorPopulation=%d, gOmInUseCount=%d, "
1692                                "gMonitorFreeCount=%d", gMonitorPopulation,
1693                                gOmInUseCount, gMonitorFreeCount);
1694     Thread::muxRelease(&gListLock);
1695   }
1696 
1697   ForceMonitorScavenge = 0;    // Reset
1698 
1699   OM_PERFDATA_OP(Deflations, inc(counters->nScavenged));
1700   OM_PERFDATA_OP(MonExtant, set_value(counters->nInCirculation));
1701 
1702   GVars.stwRandom = os::random();
1703   GVars.stwCycle++;
1704 }
1705 
1706 void ObjectSynchronizer::deflate_thread_local_monitors(Thread* thread, DeflateMonitorCounters* counters) {
1707   assert(SafepointSynchronize::is_at_safepoint(), "must be at safepoint");
1708 
1709   ObjectMonitor * freeHeadp = NULL;  // Local SLL of scavenged monitors
1710   ObjectMonitor * freeTailp = NULL;
1711   elapsedTimer timer;
1712 
1713   if (log_is_enabled(Info, safepoint, cleanup) ||
1714       log_is_enabled(Info, monitorinflation)) {
1715     timer.start();
1716   }
1717 
1718   int deflated_count = deflate_monitor_list(thread->omInUseList_addr(), &freeHeadp, &freeTailp);
1719 
1720   Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors(1)");


1721 
1722   // Adjust counters
1723   counters->nInCirculation += thread->omInUseCount;
1724   thread->omInUseCount -= deflated_count;
1725   counters->nScavenged += deflated_count;
1726   counters->nInuse += thread->omInUseCount;
1727   counters->perThreadScavenged += deflated_count;


1728 
1729   // Move the scavenged monitors back to the global free list.
1730   if (freeHeadp != NULL) {
1731     guarantee(freeTailp != NULL && deflated_count > 0, "invariant");
1732     assert(freeTailp->FreeNext == NULL, "invariant");
1733 
1734     // constant-time list splice - prepend scavenged segment to gFreeList
1735     freeTailp->FreeNext = gFreeList;
1736     gFreeList = freeHeadp;
1737   }
1738   Thread::muxRelease(&gListLock);
1739 
1740   timer.stop();
1741   if (log_is_enabled(Info, safepoint, cleanup)) {
1742     // Only safepoint logging cares about cumulative perThreadTimes
1743     // and we don't count this muxAcquire() that we have to do in
1744     // order to safely update perThreadTimes.
1745     Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors(2)");
1746     counters->perThreadTimes += timer.seconds();
1747     Thread::muxRelease(&gListLock);
1748   }
1749 
1750   LogStreamHandle(Debug, monitorinflation) lsh_debug;
1751   LogStreamHandle(Info, monitorinflation) lsh_info;
1752   LogStream * ls = NULL;
1753   if (log_is_enabled(Debug, monitorinflation)) {
1754     ls = &lsh_debug;
1755   } else if (deflated_count != 0 && log_is_enabled(Info, monitorinflation)) {
1756     ls = &lsh_info;
1757   }
1758   if (ls != NULL) {
1759     ls->print_cr("jt=" INTPTR_FORMAT ": deflating per-thread idle monitors, %3.7f secs, %d monitors", p2i(thread), timer.seconds(), deflated_count);
1760   }
1761 }
1762 
1763 // Monitor cleanup on JavaThread::exit
1764 
1765 // Iterate through monitor cache and attempt to release thread's monitors
1766 // Gives up on a particular monitor if an exception occurs, but continues
1767 // the overall iteration, swallowing the exception.
1768 class ReleaseJavaMonitorsClosure: public MonitorClosure {
1769  private:
1770   TRAPS;
1771 
1772  public:
1773   ReleaseJavaMonitorsClosure(Thread* thread) : THREAD(thread) {}
1774   void do_monitor(ObjectMonitor* mid) {
1775     if (mid->owner() == THREAD) {
1776       (void)mid->complete_exit(CHECK);
1777     }
1778   }
1779 };
1780 


< prev index next >