--- old/src/share/vm/runtime/globals.hpp 2013-09-27 16:07:10.862196093 +0200 +++ new/src/share/vm/runtime/globals.hpp 2013-09-27 16:07:10.818195874 +0200 @@ -2511,6 +2511,9 @@ develop(bool, PrintMethodFlushing, false, \ "print the nmethods being flushed") \ \ + diagnostic(bool, PrintMethodFlushingStatistics, false, \ + "print statistics about method flushing") \ + \ develop(bool, UseRelocIndex, false, \ "use an index to speed random access to relocations") \ \ --- old/src/share/vm/runtime/java.cpp 2013-09-27 16:07:11.174197657 +0200 +++ new/src/share/vm/runtime/java.cpp 2013-09-27 16:07:11.126197417 +0200 @@ -52,6 +52,7 @@ #include "runtime/memprofiler.hpp" #include "runtime/sharedRuntime.hpp" #include "runtime/statSampler.hpp" +#include "runtime/sweeper.hpp" #include "runtime/task.hpp" #include "runtime/thread.inline.hpp" #include "runtime/timer.hpp" @@ -208,9 +209,7 @@ // General statistics printing (profiling ...) - void print_statistics() { - #ifdef ASSERT if (CountRuntimeCalls) { @@ -306,6 +305,10 @@ CodeCache::print(); } + if (PrintMethodFlushingStatistics) { + NMethodSweeper::print(); + } + if (PrintCodeCache2) { MutexLockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag); CodeCache::print_internals(); @@ -373,6 +376,10 @@ CodeCache::print(); } + if (PrintMethodFlushingStatistics) { + NMethodSweeper::print(); + } + #ifdef COMPILER2 if (PrintPreciseBiasedLockingStatistics) { OptoRuntime::print_named_counters(); --- old/src/share/vm/runtime/sweeper.cpp 2013-09-27 16:07:11.414198838 +0200 +++ new/src/share/vm/runtime/sweeper.cpp 2013-09-27 16:07:11.370198616 +0200 @@ -132,6 +132,7 @@ nmethod* NMethodSweeper::_current = NULL; // Current nmethod int NMethodSweeper::_seen = 0 ; // No. of nmethods we have currently processed in current pass of CodeCache int NMethodSweeper::_flushed_count = 0; // Nof. nmethods flushed in current sweep +size_t NMethodSweeper::_flushed_size = 0; // Total size of nmethods flushed in current sweep int NMethodSweeper::_zombified_count = 0; // Nof. nmethods made zombie in current sweep int NMethodSweeper::_marked_count = 0; // Nof. nmethods marked for reclaim in current sweep @@ -149,6 +150,7 @@ int NMethodSweeper::_number_of_flushes = 0; // Total of full traversals caused by full cache int NMethodSweeper::_total_nof_methods_reclaimed = 0; +size_t NMethodSweeper::_total_flushed_size = 0; jlong NMethodSweeper::_total_time_sweeping = 0; jlong NMethodSweeper::_total_time_this_sweep = 0; jlong NMethodSweeper::_peak_sweep_time = 0; @@ -248,6 +250,7 @@ jlong sweep_start_counter = os::elapsed_counter(); _flushed_count = 0; + _flushed_size = 0; _zombified_count = 0; _marked_count = 0; @@ -325,6 +328,7 @@ _total_time_sweeping += sweep_time; _total_time_this_sweep += sweep_time; _peak_sweep_fraction_time = MAX2(sweep_time, _peak_sweep_fraction_time); + _total_flushed_size += _flushed_size; _total_nof_methods_reclaimed += _flushed_count; EventSweepCodeCache event(UNTIMED); @@ -425,6 +429,7 @@ if (PrintMethodFlushing && Verbose) { tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (marked for reclamation) being flushed", nm->compile_id(), nm); } + _flushed_size += nm->size(); release_nmethod(nm); _flushed_count++; } else { @@ -465,6 +470,7 @@ if (nm->is_osr_method()) { SWEEP(nm); // No inline caches will ever point to osr methods, so we can just remove it + _flushed_size += nm->size(); release_nmethod(nm); _flushed_count++; } else { @@ -651,3 +657,14 @@ xtty->end_elem(); } } + +void NMethodSweeper::print() { + ttyLocker ttyl; + tty->print_cr("Method flushing statistics:"); + tty->print_cr(" Total sweep time: %1.3lfms", (double)_total_time_sweeping/1000); + tty->print_cr(" Peak sweep time: %1.3lfms", (double)_peak_sweep_time/1000); + tty->print_cr(" Peak sweep fraction time: %1.3lfms", (double)_peak_sweep_fraction_time/1000); + tty->print_cr(" Total number of stack traversals: %d", _traversals); + tty->print_cr(" Total number of flushed methods: %d", _total_nof_methods_reclaimed); + tty->print_cr(" Total size of flushed methods: " SIZE_FORMAT "Kb", _total_flushed_size/K); +} --- old/src/share/vm/runtime/sweeper.hpp 2013-09-27 16:07:11.690200203 +0200 +++ new/src/share/vm/runtime/sweeper.hpp 2013-09-27 16:07:11.638199967 +0200 @@ -35,6 +35,7 @@ static nmethod* _current; // Current nmethod static int _seen; // Nof. nmethod we have currently processed in current pass of CodeCache static int _flushed_count; // Nof. nmethods flushed in current sweep + static size_t _flushed_size; // Total size of nmethods flushed in current sweep static int _zombified_count; // Nof. nmethods made zombie in current sweep static int _marked_count; // Nof. nmethods marked for reclaim in current sweep @@ -59,6 +60,7 @@ // Stat counters static int _number_of_flushes; // Total of full traversals caused by full cache static int _total_nof_methods_reclaimed; // Accumulated nof methods flushed + static size_t _total_flushed_size; // Total size of flushed methods static jlong _total_time_sweeping; // Accumulated time sweeping static jlong _total_time_this_sweep; // Total time this sweep static jlong _peak_sweep_time; // Peak time for a full sweep @@ -103,6 +105,9 @@ static void handle_full_code_cache(bool is_full); // Called by compilers who fail to allocate static void speculative_disconnect_nmethods(bool was_full); // Called by vm op to deal with alloc failure + + // Printing/debugging + static void print(); }; #endif // SHARE_VM_RUNTIME_SWEEPER_HPP