# HG changeset patch # User anoll # Date 1387458482 -3600 # Node ID 6aa49042b101d9d2a3c17225346844ab6f83521a # Parent d6e7180abab55b80c2fc2064b325a3294dbd6fc7 8025277: Add -XX: flag to print code cache sweeper statistics Summary: New diagnostic flag prints statistics about the code cache sweeper Reviewed-by: kvn Contributed-by: tobi.hartmann@gmail.com diff -r d6e7180abab5 -r 6aa49042b101 src/share/vm/runtime/globals.hpp --- a/src/share/vm/runtime/globals.hpp Thu Dec 19 06:09:16 2013 +0100 +++ b/src/share/vm/runtime/globals.hpp Thu Dec 19 14:08:02 2013 +0100 @@ -2531,6 +2531,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") \ \ diff -r d6e7180abab5 -r 6aa49042b101 src/share/vm/runtime/java.cpp --- a/src/share/vm/runtime/java.cpp Thu Dec 19 06:09:16 2013 +0100 +++ b/src/share/vm/runtime/java.cpp Thu Dec 19 14:08:02 2013 +0100 @@ -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" @@ -217,9 +218,7 @@ // General statistics printing (profiling ...) - void print_statistics() { - #ifdef ASSERT if (CountRuntimeCalls) { @@ -315,6 +314,10 @@ CodeCache::print(); } + if (PrintMethodFlushingStatistics) { + NMethodSweeper::print(); + } + if (PrintCodeCache2) { MutexLockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag); CodeCache::print_internals(); @@ -382,6 +385,10 @@ CodeCache::print(); } + if (PrintMethodFlushingStatistics) { + NMethodSweeper::print(); + } + #ifdef COMPILER2 if (PrintPreciseBiasedLockingStatistics) { OptoRuntime::print_named_counters(); diff -r d6e7180abab5 -r 6aa49042b101 src/share/vm/runtime/sweeper.cpp --- a/src/share/vm/runtime/sweeper.cpp Thu Dec 19 06:09:16 2013 +0100 +++ b/src/share/vm/runtime/sweeper.cpp Thu Dec 19 14:08:02 2013 +0100 @@ -129,6 +129,7 @@ nmethod* NMethodSweeper::_current = NULL; // Current nmethod long NMethodSweeper::_traversals = 0; // Stack scan count, also sweep ID. +long NMethodSweeper::_total_nof_code_cache_sweeps = 0; // Total number of full sweeps of the code cache long NMethodSweeper::_time_counter = 0; // Virtual time used to periodically invoke sweeper long NMethodSweeper::_last_sweep = 0; // Value of _time_counter when the last sweep happened int NMethodSweeper::_seen = 0; // Nof. nmethod we have currently processed in current pass of CodeCache @@ -143,13 +144,16 @@ // 1) alive -> not_entrant // 2) not_entrant -> zombie // 3) zombie -> marked_for_reclamation +int NMethodSweeper::_hotness_counter_reset_val = 0; -int NMethodSweeper::_total_nof_methods_reclaimed = 0; // Accumulated nof methods flushed -Tickspan NMethodSweeper::_total_time_sweeping; // Accumulated time sweeping -Tickspan NMethodSweeper::_total_time_this_sweep; // Total time this sweep -Tickspan NMethodSweeper::_peak_sweep_time; // Peak time for a full sweep -Tickspan NMethodSweeper::_peak_sweep_fraction_time; // Peak time sweeping one fraction -int NMethodSweeper::_hotness_counter_reset_val = 0; +long NMethodSweeper::_total_nof_methods_reclaimed = 0; // Accumulated nof methods flushed +long NMethodSweeper::_total_nof_c2_methods_reclaimed = 0; // Accumulated nof methods flushed +size_t NMethodSweeper::_total_flushed_size = 0; // Total number of bytes flushed from the code cache +Tickspan NMethodSweeper::_total_time_sweeping; // Accumulated time sweeping +Tickspan NMethodSweeper::_total_time_this_sweep; // Total time this sweep +Tickspan NMethodSweeper::_peak_sweep_time; // Peak time for a full sweep +Tickspan NMethodSweeper::_peak_sweep_fraction_time; // Peak time sweeping one fraction + class MarkActivationClosure: public CodeBlobClosure { @@ -292,6 +296,7 @@ // We are done with sweeping the code cache once. if (_sweep_fractions_left == 0) { + _total_nof_code_cache_sweeps++; _last_sweep = _time_counter; // Reset flag; temporarily disables sweeper _should_sweep = false; @@ -378,6 +383,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 += freed_memory; _total_nof_methods_reclaimed += _flushed_count; EventSweepCodeCache event(UNTIMED); @@ -509,6 +515,9 @@ tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (marked for reclamation) being flushed", nm->compile_id(), nm); } freed_memory = nm->total_size(); + if (nm->is_compiled_by_c2()) { + _total_nof_c2_methods_reclaimed++; + } release_nmethod(nm); _flushed_count++; } else { @@ -547,6 +556,9 @@ SWEEP(nm); // No inline caches will ever point to osr methods, so we can just remove it freed_memory = nm->total_size(); + if (nm->is_compiled_by_c2()) { + _total_nof_c2_methods_reclaimed++; + } release_nmethod(nm); _flushed_count++; } else { @@ -634,3 +646,13 @@ xtty->end_elem(); } } + +void NMethodSweeper::print() { + ttyLocker ttyl; + tty->print_cr("Code cache sweeper statistics:"); + tty->print_cr(" Total sweep time: %1.0lfms", (double)_total_time_sweeping.value()/1000000); + tty->print_cr(" Total number of full sweeps: %ld", _total_nof_code_cache_sweeps); + tty->print_cr(" Total number of flushed methods: %ld(%ld C2 methods)", _total_nof_methods_reclaimed, + _total_nof_c2_methods_reclaimed); + tty->print_cr(" Total size of flushed methods: " SIZE_FORMAT "kB", _total_flushed_size/K); +} diff -r d6e7180abab5 -r 6aa49042b101 src/share/vm/runtime/sweeper.hpp --- a/src/share/vm/runtime/sweeper.hpp Thu Dec 19 06:09:16 2013 +0100 +++ b/src/share/vm/runtime/sweeper.hpp Thu Dec 19 14:08:02 2013 +0100 @@ -54,28 +54,33 @@ // is full. class NMethodSweeper : public AllStatic { - static long _traversals; // Stack scan count, also sweep ID. - static long _time_counter; // Virtual time used to periodically invoke sweeper - static long _last_sweep; // Value of _time_counter when the last sweep happened - 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 int _zombified_count; // Nof. nmethods made zombie in current sweep - static int _marked_for_reclamation_count; // Nof. nmethods marked for reclaim in current sweep + static long _traversals; // Stack scan count, also sweep ID. + static long _total_nof_code_cache_sweeps; // Total number of full sweeps of the code cache + static long _time_counter; // Virtual time used to periodically invoke sweeper + static long _last_sweep; // Value of _time_counter when the last sweep happened + 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 int _zombified_count; // Nof. nmethods made zombie in current sweep + static int _marked_for_reclamation_count; // Nof. nmethods marked for reclaim in current sweep - static volatile int _sweep_fractions_left; // Nof. invocations left until we are completed with this pass - static volatile int _sweep_started; // Flag to control conc sweeper - static volatile bool _should_sweep; // Indicates if we should invoke the sweeper - static volatile int _bytes_changed; // Counts the total nmethod size if the nmethod changed from: - // 1) alive -> not_entrant - // 2) not_entrant -> zombie - // 3) zombie -> marked_for_reclamation + static volatile int _sweep_fractions_left; // Nof. invocations left until we are completed with this pass + static volatile int _sweep_started; // Flag to control conc sweeper + static volatile bool _should_sweep; // Indicates if we should invoke the sweeper + static volatile int _bytes_changed; // Counts the total nmethod size if the nmethod changed from: + // 1) alive -> not_entrant + // 2) not_entrant -> zombie + // 3) zombie -> marked_for_reclamation // Stat counters - static int _total_nof_methods_reclaimed; // Accumulated nof methods flushed - static Tickspan _total_time_sweeping; // Accumulated time sweeping - static Tickspan _total_time_this_sweep; // Total time this sweep - static Tickspan _peak_sweep_time; // Peak time for a full sweep - static Tickspan _peak_sweep_fraction_time; // Peak time sweeping one fraction + static long _total_nof_methods_reclaimed; // Accumulated nof methods flushed + static long _total_nof_c2_methods_reclaimed; // Accumulated nof C2-compiled methods flushed + static size_t _total_flushed_size; // Total size of flushed methods + static int _hotness_counter_reset_val; + + static Tickspan _total_time_sweeping; // Accumulated time sweeping + static Tickspan _total_time_this_sweep; // Total time this sweep + static Tickspan _peak_sweep_time; // Peak time for a full sweep + static Tickspan _peak_sweep_fraction_time; // Peak time sweeping one fraction static int process_nmethod(nmethod *nm); static void release_nmethod(nmethod* nm); @@ -83,8 +88,6 @@ static bool sweep_in_progress(); static void sweep_code_cache(); - static int _hotness_counter_reset_val; - public: static long traversal_count() { return _traversals; } static int total_nof_methods_reclaimed() { return _total_nof_methods_reclaimed; } @@ -105,10 +108,10 @@ static void mark_active_nmethods(); // Invoked at the end of each safepoint static void possibly_sweep(); // Compiler threads call this to sweep - static int sort_nmethods_by_hotness(nmethod** nm1, nmethod** nm2); static int hotness_counter_reset_val(); static void report_state_change(nmethod* nm); static void possibly_enable_sweeper(); + static void print(); // Printing/debugging }; #endif // SHARE_VM_RUNTIME_SWEEPER_HPP