1 /*
   2  * Copyright (c) 1997, 2012, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  *
  23  */
  24 
  25 #include "precompiled.hpp"
  26 #include "code/codeCache.hpp"
  27 #include "code/nmethod.hpp"
  28 #include "compiler/compileBroker.hpp"
  29 #include "memory/resourceArea.hpp"
  30 #include "oops/methodOop.hpp"
  31 #include "runtime/atomic.hpp"
  32 #include "runtime/compilationPolicy.hpp"
  33 #include "runtime/mutexLocker.hpp"
  34 #include "runtime/os.hpp"
  35 #include "runtime/sweeper.hpp"
  36 #include "runtime/vm_operations.hpp"
  37 #include "utilities/events.hpp"
  38 #include "utilities/xmlstream.hpp"
  39 
  40 #ifdef ASSERT
  41 
  42 #define SWEEP(nm) record_sweep(nm, __LINE__)
  43 // Sweeper logging code
  44 class SweeperRecord {
  45  public:
  46   int traversal;
  47   int invocation;
  48   int compile_id;
  49   long traversal_mark;
  50   int state;
  51   const char* kind;
  52   address vep;
  53   address uep;
  54   int line;
  55 
  56   void print() {
  57       tty->print_cr("traversal = %d invocation = %d compile_id = %d %s uep = " PTR_FORMAT " vep = "
  58                     PTR_FORMAT " state = %d traversal_mark %d line = %d",
  59                     traversal,
  60                     invocation,
  61                     compile_id,
  62                     kind == NULL ? "" : kind,
  63                     uep,
  64                     vep,
  65                     state,
  66                     traversal_mark,
  67                     line);
  68   }
  69 };
  70 
  71 static int _sweep_index = 0;
  72 static SweeperRecord* _records = NULL;
  73 
  74 void NMethodSweeper::report_events(int id, address entry) {
  75   if (_records != NULL) {
  76     for (int i = _sweep_index; i < SweeperLogEntries; i++) {
  77       if (_records[i].uep == entry ||
  78           _records[i].vep == entry ||
  79           _records[i].compile_id == id) {
  80         _records[i].print();
  81       }
  82     }
  83     for (int i = 0; i < _sweep_index; i++) {
  84       if (_records[i].uep == entry ||
  85           _records[i].vep == entry ||
  86           _records[i].compile_id == id) {
  87         _records[i].print();
  88       }
  89     }
  90   }
  91 }
  92 
  93 void NMethodSweeper::report_events() {
  94   if (_records != NULL) {
  95     for (int i = _sweep_index; i < SweeperLogEntries; i++) {
  96       // skip empty records
  97       if (_records[i].vep == NULL) continue;
  98       _records[i].print();
  99     }
 100     for (int i = 0; i < _sweep_index; i++) {
 101       // skip empty records
 102       if (_records[i].vep == NULL) continue;
 103       _records[i].print();
 104     }
 105   }
 106 }
 107 
 108 void NMethodSweeper::record_sweep(nmethod* nm, int line) {
 109   if (_records != NULL) {
 110     _records[_sweep_index].traversal = _traversals;
 111     _records[_sweep_index].traversal_mark = nm->_stack_traversal_mark;
 112     _records[_sweep_index].invocation = _invocations;
 113     _records[_sweep_index].compile_id = nm->compile_id();
 114     _records[_sweep_index].kind = nm->compile_kind();
 115     _records[_sweep_index].state = nm->_state;
 116     _records[_sweep_index].vep = nm->verified_entry_point();
 117     _records[_sweep_index].uep = nm->entry_point();
 118     _records[_sweep_index].line = line;
 119 
 120     _sweep_index = (_sweep_index + 1) % SweeperLogEntries;
 121   }
 122 }
 123 #else
 124 #define SWEEP(nm)
 125 #endif
 126 
 127 
 128 long      NMethodSweeper::_traversals = 0;   // No. of stack traversals performed
 129 nmethod*  NMethodSweeper::_current = NULL;   // Current nmethod
 130 int       NMethodSweeper::_seen = 0 ;        // No. of nmethods we have currently processed in current pass of CodeCache
 131 
 132 volatile int NMethodSweeper::_invocations = 0;   // No. of invocations left until we are completed with this pass
 133 volatile int NMethodSweeper::_sweep_started = 0; // Whether a sweep is in progress.
 134 
 135 jint      NMethodSweeper::_locked_seen = 0;
 136 jint      NMethodSweeper::_not_entrant_seen_on_stack = 0;
 137 bool      NMethodSweeper::_rescan = false;
 138 bool      NMethodSweeper::_do_sweep = false;
 139 bool      NMethodSweeper::_was_full = false;
 140 jint      NMethodSweeper::_advise_to_sweep = 0;
 141 jlong     NMethodSweeper::_last_was_full = 0;
 142 uint      NMethodSweeper::_highest_marked = 0;
 143 long      NMethodSweeper::_was_full_traversal = 0;
 144 
 145 class MarkActivationClosure: public CodeBlobClosure {
 146 public:
 147   virtual void do_code_blob(CodeBlob* cb) {
 148     // If we see an activation belonging to a non_entrant nmethod, we mark it.
 149     if (cb->is_nmethod() && ((nmethod*)cb)->is_not_entrant()) {
 150       ((nmethod*)cb)->mark_as_seen_on_stack();
 151     }
 152   }
 153 };
 154 static MarkActivationClosure mark_activation_closure;
 155 
 156 void NMethodSweeper::scan_stacks() {
 157   assert(SafepointSynchronize::is_at_safepoint(), "must be executed at a safepoint");
 158   if (!MethodFlushing) return;
 159   _do_sweep = true;
 160 
 161   // No need to synchronize access, since this is always executed at a
 162   // safepoint.  If we aren't in the middle of scan and a rescan
 163   // hasn't been requested then just return. If UseCodeCacheFlushing is on and
 164   // code cache flushing is in progress, don't skip sweeping to help make progress
 165   // clearing space in the code cache.
 166   if ((_current == NULL && !_rescan) && !(UseCodeCacheFlushing && !CompileBroker::should_compile_new_jobs())) {
 167     _do_sweep = false;
 168     return;
 169   }
 170 
 171   // Make sure CompiledIC_lock in unlocked, since we might update some
 172   // inline caches. If it is, we just bail-out and try later.
 173   if (CompiledIC_lock->is_locked() || Patching_lock->is_locked()) return;
 174 
 175   // Check for restart
 176   assert(CodeCache::find_blob_unsafe(_current) == _current, "Sweeper nmethod cached state invalid");
 177   if (_current == NULL) {
 178     _seen        = 0;
 179     _invocations = NmethodSweepFraction;
 180     _current     = CodeCache::first_nmethod();
 181     _traversals  += 1;
 182     if (PrintMethodFlushing) {
 183       tty->print_cr("### Sweep: stack traversal %d", _traversals);
 184     }
 185     Threads::nmethods_do(&mark_activation_closure);
 186 
 187     // reset the flags since we started a scan from the beginning.
 188     _rescan = false;
 189     _locked_seen = 0;
 190     _not_entrant_seen_on_stack = 0;
 191   }
 192 
 193   if (UseCodeCacheFlushing) {
 194     if (!CodeCache::needs_flushing()) {
 195       // scan_stacks() runs during a safepoint, no race with setters
 196       _advise_to_sweep = 0;
 197     }
 198 
 199     if (was_full()) {
 200       // There was some progress so attempt to restart the compiler
 201       jlong now           = os::javaTimeMillis();
 202       jlong max_interval  = (jlong)MinCodeCacheFlushingInterval * (jlong)1000;
 203       jlong curr_interval = now - _last_was_full;
 204       if ((!CodeCache::needs_flushing()) && (curr_interval > max_interval)) {
 205         CompileBroker::set_should_compile_new_jobs(CompileBroker::run_compilation);
 206         set_was_full(false);
 207 
 208         // Update the _last_was_full time so we can tell how fast the
 209         // code cache is filling up
 210         _last_was_full = os::javaTimeMillis();
 211 
 212         log_sweep("restart_compiler");
 213       }
 214     }
 215   }
 216 }
 217 
 218 void NMethodSweeper::possibly_sweep() {
 219   assert(JavaThread::current()->thread_state() == _thread_in_vm, "must run in vm mode");
 220   if ((!MethodFlushing) || (!_do_sweep)) return;
 221 
 222   if (_invocations > 0) {
 223     // Only one thread at a time will sweep
 224     jint old = Atomic::cmpxchg( 1, &_sweep_started, 0 );
 225     if (old != 0) {
 226       return;
 227     }
 228 #ifdef ASSERT
 229     if (LogSweeper && _records == NULL) {
 230       // Create the ring buffer for the logging code
 231       _records = NEW_C_HEAP_ARRAY(SweeperRecord, SweeperLogEntries);
 232       memset(_records, 0, sizeof(SweeperRecord) * SweeperLogEntries);
 233     }
 234 #endif
 235     if (_invocations > 0) {
 236       sweep_code_cache();
 237       _invocations--;
 238     }
 239     _sweep_started = 0;
 240   }
 241 }
 242 
 243 void NMethodSweeper::sweep_code_cache() {
 244 #ifdef ASSERT
 245   jlong sweep_start;
 246   if (PrintMethodFlushing) {
 247     sweep_start = os::javaTimeMillis();
 248   }
 249 #endif
 250   if (PrintMethodFlushing && Verbose) {
 251     tty->print_cr("### Sweep at %d out of %d. Invocations left: %d", _seen, CodeCache::nof_nmethods(), _invocations);
 252   }
 253 
 254   // We want to visit all nmethods after NmethodSweepFraction
 255   // invocations so divide the remaining number of nmethods by the
 256   // remaining number of invocations.  This is only an estimate since
 257   // the number of nmethods changes during the sweep so the final
 258   // stage must iterate until it there are no more nmethods.
 259   int todo = (CodeCache::nof_nmethods() - _seen) / _invocations;
 260 
 261   assert(!SafepointSynchronize::is_at_safepoint(), "should not be in safepoint when we get here");
 262   assert(!CodeCache_lock->owned_by_self(), "just checking");
 263 
 264   {
 265     MutexLockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag);
 266 
 267     // The last invocation iterates until there are no more nmethods
 268     for (int i = 0; (i < todo || _invocations == 1) && _current != NULL; i++) {
 269       if (SafepointSynchronize::is_synchronizing()) { // Safepoint request
 270         if (PrintMethodFlushing && Verbose) {
 271           tty->print_cr("### Sweep at %d out of %d, aborting due to safepoint request", CodeCache::nof_nmethods(), _invocations);
 272         }
 273         _invocations++;                    // Restart this iteration later
 274         break;                             // Bail out
 275       }
 276       // Since we will give up the CodeCache_lock, always skip ahead
 277       // to the next nmethod.  Other blobs can be deleted by other
 278       // threads but nmethods are only reclaimed by the sweeper.
 279       nmethod* next = CodeCache::next_nmethod(_current);
 280 
 281       // Now ready to process nmethod and give up CodeCache_lock
 282       {
 283         MutexUnlockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag);
 284         process_nmethod(_current);
 285       }
 286       _seen++;
 287       _current = next;
 288     }
 289   }
 290 
 291   assert(_invocations > 1 || _current == NULL, "must have scanned the whole cache");
 292 
 293   if (_current == NULL && !_rescan && (_locked_seen || _not_entrant_seen_on_stack)) {
 294     // we've completed a scan without making progress but there were
 295     // nmethods we were unable to process either because they were
 296     // locked or were still on stack.  We don't have to aggresively
 297     // clean them up so just stop scanning.  We could scan once more
 298     // but that complicates the control logic and it's unlikely to
 299     // matter much.
 300     if (PrintMethodFlushing) {
 301       tty->print_cr("### Couldn't make progress on some nmethods so stopping sweep");
 302     }
 303   }
 304 
 305 #ifdef ASSERT
 306   if(PrintMethodFlushing) {
 307     jlong sweep_end             = os::javaTimeMillis();
 308     tty->print_cr("### sweeper:      sweep time(%d): " INT64_FORMAT, _invocations, sweep_end - sweep_start);
 309   }
 310 #endif
 311 
 312   if (_invocations == 1) {
 313     log_sweep("finished");
 314   }
 315 }
 316 
 317 class NMethodMarker: public StackObj {
 318  private:
 319   CompilerThread* _thread;
 320  public:
 321   NMethodMarker(nmethod* nm) {
 322     _thread = CompilerThread::current();
 323     _thread->set_scanned_nmethod(nm);
 324   }
 325   ~NMethodMarker() {
 326     _thread->set_scanned_nmethod(NULL);
 327   }
 328 };
 329 
 330 
 331 void NMethodSweeper::process_nmethod(nmethod *nm) {
 332   assert(!CodeCache_lock->owned_by_self(), "just checking");
 333 
 334   // Make sure this nmethod doesn't get unloaded during the scan,
 335   // since the locks acquired below might safepoint.
 336   NMethodMarker nmm(nm);
 337 
 338   SWEEP(nm);
 339 
 340   // Skip methods that are currently referenced by the VM
 341   if (nm->is_locked_by_vm()) {
 342     // But still remember to clean-up inline caches for alive nmethods
 343     if (nm->is_alive()) {
 344       // Clean-up all inline caches that points to zombie/non-reentrant methods
 345       MutexLocker cl(CompiledIC_lock);
 346       nm->cleanup_inline_caches();
 347       SWEEP(nm);
 348     } else {
 349       _locked_seen++;
 350       SWEEP(nm);
 351     }
 352     return;
 353   }
 354 
 355   if (nm->is_zombie()) {
 356     // If it is first time, we see nmethod then we mark it. Otherwise,
 357     // we reclame it. When we have seen a zombie method twice, we know that
 358     // there are no inline caches that refer to it.
 359     if (nm->is_marked_for_reclamation()) {
 360       assert(!nm->is_locked_by_vm(), "must not flush locked nmethods");
 361       if (PrintMethodFlushing && Verbose) {
 362         tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (marked for reclamation) being flushed", nm->compile_id(), nm);
 363       }
 364       MutexLockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag);
 365       nm->flush();
 366     } else {
 367       if (PrintMethodFlushing && Verbose) {
 368         tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (zombie) being marked for reclamation", nm->compile_id(), nm);
 369       }
 370       nm->mark_for_reclamation();
 371       _rescan = true;
 372       SWEEP(nm);
 373     }
 374   } else if (nm->is_not_entrant()) {
 375     // If there is no current activations of this method on the
 376     // stack we can safely convert it to a zombie method
 377     if (nm->can_not_entrant_be_converted()) {
 378       if (PrintMethodFlushing && Verbose) {
 379         tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (not entrant) being made zombie", nm->compile_id(), nm);
 380       }
 381       nm->make_zombie();
 382       _rescan = true;
 383       SWEEP(nm);
 384     } else {
 385       // Still alive, clean up its inline caches
 386       MutexLocker cl(CompiledIC_lock);
 387       nm->cleanup_inline_caches();
 388       // we coudn't transition this nmethod so don't immediately
 389       // request a rescan.  If this method stays on the stack for a
 390       // long time we don't want to keep rescanning the code cache.
 391       _not_entrant_seen_on_stack++;
 392       SWEEP(nm);
 393     }
 394   } else if (nm->is_unloaded()) {
 395     // Unloaded code, just make it a zombie
 396     if (PrintMethodFlushing && Verbose)
 397       tty->print_cr("### Nmethod %3d/" PTR_FORMAT " (unloaded) being made zombie", nm->compile_id(), nm);
 398     if (nm->is_osr_method()) {
 399       // No inline caches will ever point to osr methods, so we can just remove it
 400       MutexLockerEx mu(CodeCache_lock, Mutex::_no_safepoint_check_flag);
 401       SWEEP(nm);
 402       nm->flush();
 403     } else {
 404       nm->make_zombie();
 405       _rescan = true;
 406       SWEEP(nm);
 407     }
 408   } else {
 409     assert(nm->is_alive(), "should be alive");
 410 
 411     if (UseCodeCacheFlushing) {
 412       if ((nm->method()->code() != nm) && !(nm->is_locked_by_vm()) && !(nm->is_osr_method()) &&
 413           (_traversals > _was_full_traversal+2) && (((uint)nm->compile_id()) < _highest_marked) &&
 414           CodeCache::needs_flushing()) {
 415         // This method has not been called since the forced cleanup happened
 416         nm->make_not_entrant();
 417       }
 418     }
 419 
 420     // Clean-up all inline caches that points to zombie/non-reentrant methods
 421     MutexLocker cl(CompiledIC_lock);
 422     nm->cleanup_inline_caches();
 423     SWEEP(nm);
 424   }
 425 }
 426 
 427 // Code cache unloading: when compilers notice the code cache is getting full,
 428 // they will call a vm op that comes here. This code attempts to speculatively
 429 // unload the oldest half of the nmethods (based on the compile job id) by
 430 // saving the old code in a list in the CodeCache. Then
 431 // execution resumes. If a method so marked is not called by the second sweeper
 432 // stack traversal after the current one, the nmethod will be marked non-entrant and
 433 // got rid of by normal sweeping. If the method is called, the methodOop's
 434 // _code field is restored and the methodOop/nmethod
 435 // go back to their normal state.
 436 void NMethodSweeper::handle_full_code_cache(bool is_full) {
 437   // Only the first one to notice can advise us to start early cleaning
 438   if (!is_full){
 439     jint old = Atomic::cmpxchg( 1, &_advise_to_sweep, 0 );
 440     if (old != 0) {
 441       return;
 442     }
 443   }
 444 
 445   if (is_full) {
 446     // Since code cache is full, immediately stop new compiles
 447     bool did_set = CompileBroker::set_should_compile_new_jobs(CompileBroker::stop_compilation);
 448     if (!did_set) {
 449       // only the first to notice can start the cleaning,
 450       // others will go back and block
 451       return;
 452     }
 453     set_was_full(true);
 454 
 455     // If we run out within MinCodeCacheFlushingInterval of the last unload time, give up
 456     jlong now = os::javaTimeMillis();
 457     jlong max_interval = (jlong)MinCodeCacheFlushingInterval * (jlong)1000;
 458     jlong curr_interval = now - _last_was_full;
 459     if (curr_interval < max_interval) {
 460       _rescan = true;
 461       log_sweep("disable_compiler", "flushing_interval='" UINT64_FORMAT "'",
 462                            curr_interval/1000);
 463       return;
 464     }
 465   }
 466 
 467   VM_HandleFullCodeCache op(is_full);
 468   VMThread::execute(&op);
 469 
 470   // rescan again as soon as possible
 471   _rescan = true;
 472 }
 473 
 474 void NMethodSweeper::speculative_disconnect_nmethods(bool is_full) {
 475   // If there was a race in detecting full code cache, only run
 476   // one vm op for it or keep the compiler shut off
 477 
 478   debug_only(jlong start = os::javaTimeMillis();)
 479 
 480   if ((!was_full()) && (is_full)) {
 481     if (!CodeCache::needs_flushing()) {
 482       log_sweep("restart_compiler");
 483       CompileBroker::set_should_compile_new_jobs(CompileBroker::run_compilation);
 484       return;
 485     }
 486   }
 487 
 488   // Traverse the code cache trying to dump the oldest nmethods
 489   uint curr_max_comp_id = CompileBroker::get_compilation_id();
 490   uint flush_target = ((curr_max_comp_id - _highest_marked) >> 1) + _highest_marked;
 491   log_sweep("start_cleaning");
 492 
 493   nmethod* nm = CodeCache::alive_nmethod(CodeCache::first());
 494   jint disconnected = 0;
 495   jint made_not_entrant  = 0;
 496   while ((nm != NULL)){
 497     uint curr_comp_id = nm->compile_id();
 498 
 499     // OSR methods cannot be flushed like this. Also, don't flush native methods
 500     // since they are part of the JDK in most cases
 501     if (nm->is_in_use() && (!nm->is_osr_method()) && (!nm->is_locked_by_vm()) &&
 502         (!nm->is_native_method()) && ((curr_comp_id < flush_target))) {
 503 
 504       if ((nm->method()->code() == nm)) {
 505         // This method has not been previously considered for
 506         // unloading or it was restored already
 507         CodeCache::speculatively_disconnect(nm);
 508         disconnected++;
 509       } else if (nm->is_speculatively_disconnected()) {
 510         // This method was previously considered for preemptive unloading and was not called since then
 511         CompilationPolicy::policy()->delay_compilation(nm->method());
 512         nm->make_not_entrant();
 513         made_not_entrant++;
 514       }
 515 
 516       if (curr_comp_id > _highest_marked) {
 517         _highest_marked = curr_comp_id;
 518       }
 519     }
 520     nm = CodeCache::alive_nmethod(CodeCache::next(nm));
 521   }
 522 
 523   log_sweep("stop_cleaning",
 524                        "disconnected='" UINT32_FORMAT "' made_not_entrant='" UINT32_FORMAT "'",
 525                        disconnected, made_not_entrant);
 526 
 527   // Shut off compiler. Sweeper will start over with a new stack scan and
 528   // traversal cycle and turn it back on if it clears enough space.
 529   if (was_full()) {
 530     _last_was_full = os::javaTimeMillis();
 531     CompileBroker::set_should_compile_new_jobs(CompileBroker::stop_compilation);
 532   }
 533 
 534   // After two more traversals the sweeper will get rid of unrestored nmethods
 535   _was_full_traversal = _traversals;
 536 #ifdef ASSERT
 537   jlong end = os::javaTimeMillis();
 538   if(PrintMethodFlushing && Verbose) {
 539     tty->print_cr("### sweeper: unload time: " INT64_FORMAT, end-start);
 540   }
 541 #endif
 542 }
 543 
 544 
 545 // Print out some state information about the current sweep and the
 546 // state of the code cache if it's requested.
 547 void NMethodSweeper::log_sweep(const char* msg, const char* format, ...) {
 548   if (PrintMethodFlushing) {
 549     stringStream s;
 550     // Dump code cache state into a buffer before locking the tty,
 551     // because log_state() will use locks causing lock conflicts.
 552     CodeCache::log_state(&s);
 553 
 554     ttyLocker ttyl;
 555     tty->print("### sweeper: %s ", msg);
 556     if (format != NULL) {
 557       va_list ap;
 558       va_start(ap, format);
 559       tty->vprint(format, ap);
 560       va_end(ap);
 561     }
 562     tty->print_cr(s.as_string());
 563   }
 564 
 565   if (LogCompilation && (xtty != NULL)) {
 566     stringStream s;
 567     // Dump code cache state into a buffer before locking the tty,
 568     // because log_state() will use locks causing lock conflicts.
 569     CodeCache::log_state(&s);
 570 
 571     ttyLocker ttyl;
 572     xtty->begin_elem("sweeper state='%s' traversals='" INTX_FORMAT "' ", msg, (intx)traversal_count());
 573     if (format != NULL) {
 574       va_list ap;
 575       va_start(ap, format);
 576       xtty->vprint(format, ap);
 577       va_end(ap);
 578     }
 579     xtty->print(s.as_string());
 580     xtty->stamp();
 581     xtty->end_elem();
 582   }
 583 }