comparison src/share/vm/runtime/sweeper.cpp @ 14199:49a31fd8b93d

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
author anoll
date Thu, 19 Dec 2013 14:08:02 +0100
parents d49557091d18
children abec000618bf
comparison
equal deleted inserted replaced
14198:b8b5791fa045 14199:49a31fd8b93d
127 #define SWEEP(nm) 127 #define SWEEP(nm)
128 #endif 128 #endif
129 129
130 nmethod* NMethodSweeper::_current = NULL; // Current nmethod 130 nmethod* NMethodSweeper::_current = NULL; // Current nmethod
131 long NMethodSweeper::_traversals = 0; // Stack scan count, also sweep ID. 131 long NMethodSweeper::_traversals = 0; // Stack scan count, also sweep ID.
132 long NMethodSweeper::_total_nof_code_cache_sweeps = 0; // Total number of full sweeps of the code cache
132 long NMethodSweeper::_time_counter = 0; // Virtual time used to periodically invoke sweeper 133 long NMethodSweeper::_time_counter = 0; // Virtual time used to periodically invoke sweeper
133 long NMethodSweeper::_last_sweep = 0; // Value of _time_counter when the last sweep happened 134 long NMethodSweeper::_last_sweep = 0; // Value of _time_counter when the last sweep happened
134 int NMethodSweeper::_seen = 0; // Nof. nmethod we have currently processed in current pass of CodeCache 135 int NMethodSweeper::_seen = 0; // Nof. nmethod we have currently processed in current pass of CodeCache
135 int NMethodSweeper::_flushed_count = 0; // Nof. nmethods flushed in current sweep 136 int NMethodSweeper::_flushed_count = 0; // Nof. nmethods flushed in current sweep
136 int NMethodSweeper::_zombified_count = 0; // Nof. nmethods made zombie in current sweep 137 int NMethodSweeper::_zombified_count = 0; // Nof. nmethods made zombie in current sweep
141 volatile int NMethodSweeper::_sweep_started = 0; // Flag to control conc sweeper 142 volatile int NMethodSweeper::_sweep_started = 0; // Flag to control conc sweeper
142 volatile int NMethodSweeper::_bytes_changed = 0; // Counts the total nmethod size if the nmethod changed from: 143 volatile int NMethodSweeper::_bytes_changed = 0; // Counts the total nmethod size if the nmethod changed from:
143 // 1) alive -> not_entrant 144 // 1) alive -> not_entrant
144 // 2) not_entrant -> zombie 145 // 2) not_entrant -> zombie
145 // 3) zombie -> marked_for_reclamation 146 // 3) zombie -> marked_for_reclamation
146 147 int NMethodSweeper::_hotness_counter_reset_val = 0;
147 int NMethodSweeper::_total_nof_methods_reclaimed = 0; // Accumulated nof methods flushed 148
148 Tickspan NMethodSweeper::_total_time_sweeping; // Accumulated time sweeping 149 long NMethodSweeper::_total_nof_methods_reclaimed = 0; // Accumulated nof methods flushed
149 Tickspan NMethodSweeper::_total_time_this_sweep; // Total time this sweep 150 long NMethodSweeper::_total_nof_c2_methods_reclaimed = 0; // Accumulated nof methods flushed
150 Tickspan NMethodSweeper::_peak_sweep_time; // Peak time for a full sweep 151 size_t NMethodSweeper::_total_flushed_size = 0; // Total number of bytes flushed from the code cache
151 Tickspan NMethodSweeper::_peak_sweep_fraction_time; // Peak time sweeping one fraction 152 Tickspan NMethodSweeper::_total_time_sweeping; // Accumulated time sweeping
152 int NMethodSweeper::_hotness_counter_reset_val = 0; 153 Tickspan NMethodSweeper::_total_time_this_sweep; // Total time this sweep
154 Tickspan NMethodSweeper::_peak_sweep_time; // Peak time for a full sweep
155 Tickspan NMethodSweeper::_peak_sweep_fraction_time; // Peak time sweeping one fraction
156
153 157
154 158
155 class MarkActivationClosure: public CodeBlobClosure { 159 class MarkActivationClosure: public CodeBlobClosure {
156 public: 160 public:
157 virtual void do_code_blob(CodeBlob* cb) { 161 virtual void do_code_blob(CodeBlob* cb) {
290 _sweep_fractions_left--; 294 _sweep_fractions_left--;
291 } 295 }
292 296
293 // We are done with sweeping the code cache once. 297 // We are done with sweeping the code cache once.
294 if (_sweep_fractions_left == 0) { 298 if (_sweep_fractions_left == 0) {
299 _total_nof_code_cache_sweeps++;
295 _last_sweep = _time_counter; 300 _last_sweep = _time_counter;
296 // Reset flag; temporarily disables sweeper 301 // Reset flag; temporarily disables sweeper
297 _should_sweep = false; 302 _should_sweep = false;
298 // If there was enough state change, 'possibly_enable_sweeper()' 303 // If there was enough state change, 'possibly_enable_sweeper()'
299 // sets '_should_sweep' to true 304 // sets '_should_sweep' to true
376 const Ticks sweep_end_counter = Ticks::now(); 381 const Ticks sweep_end_counter = Ticks::now();
377 const Tickspan sweep_time = sweep_end_counter - sweep_start_counter; 382 const Tickspan sweep_time = sweep_end_counter - sweep_start_counter;
378 _total_time_sweeping += sweep_time; 383 _total_time_sweeping += sweep_time;
379 _total_time_this_sweep += sweep_time; 384 _total_time_this_sweep += sweep_time;
380 _peak_sweep_fraction_time = MAX2(sweep_time, _peak_sweep_fraction_time); 385 _peak_sweep_fraction_time = MAX2(sweep_time, _peak_sweep_fraction_time);
386 _total_flushed_size += freed_memory;
381 _total_nof_methods_reclaimed += _flushed_count; 387 _total_nof_methods_reclaimed += _flushed_count;
382 388
383 EventSweepCodeCache event(UNTIMED); 389 EventSweepCodeCache event(UNTIMED);
384 if (event.should_commit()) { 390 if (event.should_commit()) {
385 event.set_starttime(sweep_start_counter); 391 event.set_starttime(sweep_start_counter);
507 assert(!nm->is_locked_by_vm(), "must not flush locked nmethods"); 513 assert(!nm->is_locked_by_vm(), "must not flush locked nmethods");
508 if (PrintMethodFlushing && Verbose) { 514 if (PrintMethodFlushing && Verbose) {
509 tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (marked for reclamation) being flushed", nm->compile_id(), nm); 515 tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (marked for reclamation) being flushed", nm->compile_id(), nm);
510 } 516 }
511 freed_memory = nm->total_size(); 517 freed_memory = nm->total_size();
518 if (nm->is_compiled_by_c2()) {
519 _total_nof_c2_methods_reclaimed++;
520 }
512 release_nmethod(nm); 521 release_nmethod(nm);
513 _flushed_count++; 522 _flushed_count++;
514 } else { 523 } else {
515 if (PrintMethodFlushing && Verbose) { 524 if (PrintMethodFlushing && Verbose) {
516 tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (zombie) being marked for reclamation", nm->compile_id(), nm); 525 tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (zombie) being marked for reclamation", nm->compile_id(), nm);
545 } 554 }
546 if (nm->is_osr_method()) { 555 if (nm->is_osr_method()) {
547 SWEEP(nm); 556 SWEEP(nm);
548 // No inline caches will ever point to osr methods, so we can just remove it 557 // No inline caches will ever point to osr methods, so we can just remove it
549 freed_memory = nm->total_size(); 558 freed_memory = nm->total_size();
559 if (nm->is_compiled_by_c2()) {
560 _total_nof_c2_methods_reclaimed++;
561 }
550 release_nmethod(nm); 562 release_nmethod(nm);
551 _flushed_count++; 563 _flushed_count++;
552 } else { 564 } else {
553 // Code cache state change is tracked in make_zombie() 565 // Code cache state change is tracked in make_zombie()
554 nm->make_zombie(); 566 nm->make_zombie();
632 xtty->print(s.as_string()); 644 xtty->print(s.as_string());
633 xtty->stamp(); 645 xtty->stamp();
634 xtty->end_elem(); 646 xtty->end_elem();
635 } 647 }
636 } 648 }
649
650 void NMethodSweeper::print() {
651 ttyLocker ttyl;
652 tty->print_cr("Code cache sweeper statistics:");
653 tty->print_cr(" Total sweep time: %1.0lfms", (double)_total_time_sweeping.value()/1000000);
654 tty->print_cr(" Total number of full sweeps: %ld", _total_nof_code_cache_sweeps);
655 tty->print_cr(" Total number of flushed methods: %ld(%ld C2 methods)", _total_nof_methods_reclaimed,
656 _total_nof_c2_methods_reclaimed);
657 tty->print_cr(" Total size of flushed methods: " SIZE_FORMAT "kB", _total_flushed_size/K);
658 }