< prev index next >

src/hotspot/share/runtime/sharedRuntime.cpp

Print this page
@@ -64,19 +64,20 @@
  #include "runtime/init.hpp"
  #include "runtime/interfaceSupport.inline.hpp"
  #include "runtime/java.hpp"
  #include "runtime/javaCalls.hpp"
  #include "runtime/jniHandles.inline.hpp"
- #include "runtime/perfData.hpp"
+ #include "runtime/perfData.inline.hpp"
  #include "runtime/sharedRuntime.hpp"
  #include "runtime/stackWatermarkSet.hpp"
  #include "runtime/stubRoutines.hpp"
  #include "runtime/synchronizer.inline.hpp"
  #include "runtime/timerTrace.hpp"
  #include "runtime/vframe.inline.hpp"
  #include "runtime/vframeArray.hpp"
  #include "runtime/vm_version.hpp"
+ #include "services/management.hpp"
  #include "utilities/copy.hpp"
  #include "utilities/dtrace.hpp"
  #include "utilities/events.hpp"
  #include "utilities/globalDefinitions.hpp"
  #include "utilities/resourceHash.hpp"

@@ -98,10 +99,16 @@
    SHARED_STUBS_DO(SHARED_STUB_FIELD_DEFINE)
  #undef SHARED_STUB_FIELD_DEFINE
  
  nmethod*            SharedRuntime::_cont_doYield_stub;
  
+ PerfTickCounters* SharedRuntime::_perf_resolve_opt_virtual_total_time = nullptr;
+ PerfTickCounters* SharedRuntime::_perf_resolve_virtual_total_time     = nullptr;
+ PerfTickCounters* SharedRuntime::_perf_resolve_static_total_time      = nullptr;
+ PerfTickCounters* SharedRuntime::_perf_handle_wrong_method_total_time = nullptr;
+ PerfTickCounters* SharedRuntime::_perf_ic_miss_total_time             = nullptr;
+ 
  #define SHARED_STUB_NAME_DECLARE(name, type) "Shared Runtime " # name "_blob",
  const char *SharedRuntime::_stub_names[] = {
    SHARED_STUBS_DO(SHARED_STUB_NAME_DECLARE)
  };
  

@@ -166,10 +173,61 @@
    _polling_page_return_handler_blob =
      generate_handler_blob(SharedStubId::polling_page_return_handler_id,
                            CAST_FROM_FN_PTR(address, SafepointSynchronize::handle_polling_page_exception));
  
    generate_deopt_blob();
+ 
+   if (UsePerfData) {
+     EXCEPTION_MARK;
+     NEWPERFTICKCOUNTERS(_perf_resolve_opt_virtual_total_time, SUN_CI, "resovle_opt_virtual_call");
+     NEWPERFTICKCOUNTERS(_perf_resolve_virtual_total_time,     SUN_CI, "resovle_virtual_call");
+     NEWPERFTICKCOUNTERS(_perf_resolve_static_total_time,      SUN_CI, "resovle_static_call");
+     NEWPERFTICKCOUNTERS(_perf_handle_wrong_method_total_time, SUN_CI, "handle_wrong_method");
+     NEWPERFTICKCOUNTERS(_perf_ic_miss_total_time ,            SUN_CI, "ic_miss");
+     if (HAS_PENDING_EXCEPTION) {
+       vm_exit_during_initialization("SharedRuntime::generate_stubs() failed unexpectedly");
+     }
+   }
+ }
+ 
+ static void print_counter_on(outputStream* st, const char* name, PerfTickCounters* counter, uint cnt) {
+   st->print("  %-28s " JLONG_FORMAT_W(6) "us", name, counter->elapsed_counter_value_us());
+   if (TraceThreadTime) {
+     st->print(" (elapsed) " JLONG_FORMAT_W(6) "us (thread)", counter->thread_counter_value_us());
+   }
+   st->print(" / %5d events", cnt);
+   st->cr();
+ }
+ 
+ void SharedRuntime::print_counters_on(outputStream* st) {
+   st->print_cr("SharedRuntime:");
+   if (UsePerfData) {
+     print_counter_on(st, "resolve_opt_virtual_call:", _perf_resolve_opt_virtual_total_time, _resolve_opt_virtual_ctr);
+     print_counter_on(st, "resolve_virtual_call:",     _perf_resolve_virtual_total_time,     _resolve_virtual_ctr);
+     print_counter_on(st, "resolve_static_call:",      _perf_resolve_static_total_time,      _resolve_static_ctr);
+     print_counter_on(st, "handle_wrong_method:",      _perf_handle_wrong_method_total_time, _wrong_method_ctr);
+     print_counter_on(st, "ic_miss:",                  _perf_ic_miss_total_time,             _ic_miss_ctr);
+ 
+     jlong total_elapsed_time_us = Management::ticks_to_us(_perf_resolve_opt_virtual_total_time->elapsed_counter_value() +
+                                                           _perf_resolve_virtual_total_time->elapsed_counter_value() +
+                                                           _perf_resolve_static_total_time->elapsed_counter_value() +
+                                                           _perf_handle_wrong_method_total_time->elapsed_counter_value() +
+                                                           _perf_ic_miss_total_time->elapsed_counter_value());
+     st->print("Total:                      " JLONG_FORMAT_W(5) "us", total_elapsed_time_us);
+     if (TraceThreadTime) {
+       jlong total_thread_time_us = Management::ticks_to_us(_perf_resolve_opt_virtual_total_time->thread_counter_value() +
+                                                            _perf_resolve_virtual_total_time->thread_counter_value() +
+                                                            _perf_resolve_static_total_time->thread_counter_value() +
+                                                            _perf_handle_wrong_method_total_time->thread_counter_value() +
+                                                            _perf_ic_miss_total_time->thread_counter_value());
+       st->print(" (elapsed) " JLONG_FORMAT_W(5) "us (thread)", total_thread_time_us);
+ 
+     }
+     st->cr();
+   } else {
+     st->print_cr("  no data (UsePerfData is turned off)");
+   }
  }
  
  #if INCLUDE_JFR
  //------------------------------generate jfr runtime stubs ------
  void SharedRuntime::generate_jfr_stubs() {

@@ -185,17 +243,18 @@
  
  #include <math.h>
  
  // Implementation of SharedRuntime
  
- #ifndef PRODUCT
  // For statistics
  uint SharedRuntime::_ic_miss_ctr = 0;
  uint SharedRuntime::_wrong_method_ctr = 0;
  uint SharedRuntime::_resolve_static_ctr = 0;
  uint SharedRuntime::_resolve_virtual_ctr = 0;
  uint SharedRuntime::_resolve_opt_virtual_ctr = 0;
+ 
+ #ifndef PRODUCT
  uint SharedRuntime::_implicit_null_throws = 0;
  uint SharedRuntime::_implicit_div0_throws = 0;
  
  int64_t SharedRuntime::_nof_normal_calls = 0;
  int64_t SharedRuntime::_nof_inlined_calls = 0;

@@ -245,22 +304,22 @@
    if (_ICmiss_index >= maxICmiss_count) _ICmiss_index = maxICmiss_count - 1;
    _ICmiss_at[index] = at;
    _ICmiss_count[index] = 1;
  }
  
- void SharedRuntime::print_ic_miss_histogram() {
+ void SharedRuntime::print_ic_miss_histogram_on(outputStream* st) {
    if (ICMissHistogram) {
-     tty->print_cr("IC Miss Histogram:");
+     st->print_cr("IC Miss Histogram:");
      int tot_misses = 0;
      for (int i = 0; i < _ICmiss_index; i++) {
-       tty->print_cr("  at: " INTPTR_FORMAT "  nof: %d", p2i(_ICmiss_at[i]), _ICmiss_count[i]);
+       st->print_cr("  at: " INTPTR_FORMAT "  nof: %d", p2i(_ICmiss_at[i]), _ICmiss_count[i]);
        tot_misses += _ICmiss_count[i];
      }
-     tty->print_cr("Total IC misses: %7d", tot_misses);
+     st->print_cr("Total IC misses: %7d", tot_misses);
    }
  }
- #endif // PRODUCT
+ #endif // !PRODUCT
  
  
  JRT_LEAF(jlong, SharedRuntime::lmul(jlong y, jlong x))
    return x * y;
  JRT_END

@@ -723,10 +782,22 @@
      // an error. Our method could have been redefined just after we
      // fetched the Method* from the constant pool.
      ResourceMark rm;
      log_trace(redefine, class, obsolete)("calling obsolete method '%s'", method->name_and_sig_as_C_string());
    }
+ 
+   LogStreamHandle(Trace, interpreter, bytecode) log;
+   if (log.is_enabled()) {
+     ResourceMark rm;
+     log.print("method entry: " INTPTR_FORMAT " %s %s%s%s%s",
+               p2i(thread),
+               (method->is_static() ? "static" : "virtual"),
+               method->name_and_sig_as_C_string(),
+               (method->is_native() ? " native" : ""),
+               (thread->class_being_initialized() != nullptr ? " clinit" : ""),
+               (method->method_holder()->is_initialized() ? "" : " being_initialized"));
+   }
    return 0;
  JRT_END
  
  // ret_pc points into caller; we are returning caller's exception handler
  // for given exception

@@ -1362,17 +1433,17 @@
           (!is_virtual && invoke_code == Bytecodes::_invokedynamic) ||
           ( is_virtual && invoke_code != Bytecodes::_invokestatic ), "inconsistent bytecode");
  
    assert(!caller_nm->is_unloading(), "It should not be unloading");
  
- #ifndef PRODUCT
    // tracing/debugging/statistics
    uint *addr = (is_optimized) ? (&_resolve_opt_virtual_ctr) :
                   (is_virtual) ? (&_resolve_virtual_ctr) :
                                  (&_resolve_static_ctr);
    Atomic::inc(addr);
  
+ #ifndef PRODUCT
    if (TraceCallFixup) {
      ResourceMark rm(current);
      tty->print("resolving %s%s (%s) call to",
                 (is_optimized) ? "optimized " : "", (is_virtual) ? "virtual" : "static",
                 Bytecodes::name(invoke_code));

@@ -1424,10 +1495,12 @@
    return callee_method;
  }
  
  // Inline caches exist only in compiled code
  JRT_BLOCK_ENTRY(address, SharedRuntime::handle_wrong_method_ic_miss(JavaThread* current))
+   PerfTraceTime timer(_perf_ic_miss_total_time);
+ 
  #ifdef ASSERT
    RegisterMap reg_map(current,
                        RegisterMap::UpdateMap::skip,
                        RegisterMap::ProcessFrames::include,
                        RegisterMap::WalkContinuation::skip);

@@ -1448,10 +1521,12 @@
  JRT_END
  
  
  // Handle call site that has been made non-entrant
  JRT_BLOCK_ENTRY(address, SharedRuntime::handle_wrong_method(JavaThread* current))
+   PerfTraceTime timer(_perf_handle_wrong_method_total_time);
+ 
    // 6243940 We might end up in here if the callee is deoptimized
    // as we race to call it.  We don't want to take a safepoint if
    // the caller was interpreted because the caller frame will look
    // interpreted to the stack walkers and arguments are now
    // "compiled" so it is much better to make this transition

@@ -1500,10 +1575,12 @@
    return get_resolved_entry(current, callee_method);
  JRT_END
  
  // Handle abstract method call
  JRT_BLOCK_ENTRY(address, SharedRuntime::handle_wrong_method_abstract(JavaThread* current))
+   PerfTraceTime timer(_perf_handle_wrong_method_total_time);
+ 
    // Verbose error message for AbstractMethodError.
    // Get the called method from the invoke bytecode.
    vframeStream vfst(current, true);
    assert(!vfst.at_end(), "Java frame must exist");
    methodHandle caller(current, vfst.method());

@@ -1546,10 +1623,12 @@
    return callee_method->verified_code_entry();
  }
  
  // resolve a static call and patch code
  JRT_BLOCK_ENTRY(address, SharedRuntime::resolve_static_call_C(JavaThread* current ))
+   PerfTraceTime timer(_perf_resolve_static_total_time);
+ 
    methodHandle callee_method;
    bool enter_special = false;
    JRT_BLOCK
      callee_method = SharedRuntime::resolve_helper(false, false, CHECK_NULL);
      current->set_vm_result_2(callee_method());

@@ -1558,10 +1637,12 @@
    return get_resolved_entry(current, callee_method);
  JRT_END
  
  // resolve virtual call and update inline cache to monomorphic
  JRT_BLOCK_ENTRY(address, SharedRuntime::resolve_virtual_call_C(JavaThread* current))
+   PerfTraceTime timer(_perf_resolve_virtual_total_time);
+ 
    methodHandle callee_method;
    JRT_BLOCK
      callee_method = SharedRuntime::resolve_helper(true, false, CHECK_NULL);
      current->set_vm_result_2(callee_method());
    JRT_BLOCK_END

@@ -1571,10 +1652,12 @@
  
  
  // Resolve a virtual call that can be statically bound (e.g., always
  // monomorphic, so it has no inline cache).  Patch code to resolved target.
  JRT_BLOCK_ENTRY(address, SharedRuntime::resolve_opt_virtual_call_C(JavaThread* current))
+   PerfTraceTime timer(_perf_resolve_opt_virtual_total_time);
+ 
    methodHandle callee_method;
    JRT_BLOCK
      callee_method = SharedRuntime::resolve_helper(true, true, CHECK_NULL);
      current->set_vm_result_2(callee_method());
    JRT_BLOCK_END

@@ -1592,13 +1675,13 @@
    // receivers for non-static calls
    Handle receiver = find_callee_info(bc, call_info, CHECK_(methodHandle()));
  
    methodHandle callee_method(current, call_info.selected_method());
  
- #ifndef PRODUCT
    Atomic::inc(&_ic_miss_ctr);
  
+ #ifndef PRODUCT
    // Statistics & Tracing
    if (TraceCallFixup) {
      ResourceMark rm(current);
      tty->print("IC miss (%s) call to", Bytecodes::name(bc));
      callee_method->print_short_name(tty);

@@ -1717,14 +1800,13 @@
      }
    }
  
    methodHandle callee_method = find_callee_method(CHECK_(methodHandle()));
  
- 
- #ifndef PRODUCT
    Atomic::inc(&_wrong_method_ctr);
  
+ #ifndef PRODUCT
    if (TraceCallFixup) {
      ResourceMark rm(current);
      tty->print("handle_wrong_method reresolving call to");
      callee_method->print_short_name(tty);
      tty->print_cr(" code: " INTPTR_FORMAT, p2i(callee_method->code()));

@@ -2018,49 +2100,51 @@
  
  void SharedRuntime::print_statistics() {
    ttyLocker ttyl;
    if (xtty != nullptr)  xtty->head("statistics type='SharedRuntime'");
  
-   SharedRuntime::print_ic_miss_histogram();
- 
-   // Dump the JRT_ENTRY counters
-   if (_new_instance_ctr) tty->print_cr("%5u new instance requires GC", _new_instance_ctr);
-   if (_new_array_ctr) tty->print_cr("%5u new array requires GC", _new_array_ctr);
-   if (_multi2_ctr) tty->print_cr("%5u multianewarray 2 dim", _multi2_ctr);
-   if (_multi3_ctr) tty->print_cr("%5u multianewarray 3 dim", _multi3_ctr);
-   if (_multi4_ctr) tty->print_cr("%5u multianewarray 4 dim", _multi4_ctr);
-   if (_multi5_ctr) tty->print_cr("%5u multianewarray 5 dim", _multi5_ctr);
- 
-   tty->print_cr("%5u inline cache miss in compiled", _ic_miss_ctr);
-   tty->print_cr("%5u wrong method", _wrong_method_ctr);
-   tty->print_cr("%5u unresolved static call site", _resolve_static_ctr);
-   tty->print_cr("%5u unresolved virtual call site", _resolve_virtual_ctr);
-   tty->print_cr("%5u unresolved opt virtual call site", _resolve_opt_virtual_ctr);
- 
-   if (_mon_enter_stub_ctr) tty->print_cr("%5u monitor enter stub", _mon_enter_stub_ctr);
-   if (_mon_exit_stub_ctr) tty->print_cr("%5u monitor exit stub", _mon_exit_stub_ctr);
-   if (_mon_enter_ctr) tty->print_cr("%5u monitor enter slow", _mon_enter_ctr);
-   if (_mon_exit_ctr) tty->print_cr("%5u monitor exit slow", _mon_exit_ctr);
-   if (_partial_subtype_ctr) tty->print_cr("%5u slow partial subtype", _partial_subtype_ctr);
-   if (_jbyte_array_copy_ctr) tty->print_cr("%5u byte array copies", _jbyte_array_copy_ctr);
-   if (_jshort_array_copy_ctr) tty->print_cr("%5u short array copies", _jshort_array_copy_ctr);
-   if (_jint_array_copy_ctr) tty->print_cr("%5u int array copies", _jint_array_copy_ctr);
-   if (_jlong_array_copy_ctr) tty->print_cr("%5u long array copies", _jlong_array_copy_ctr);
-   if (_oop_array_copy_ctr) tty->print_cr("%5u oop array copies", _oop_array_copy_ctr);
-   if (_checkcast_array_copy_ctr) tty->print_cr("%5u checkcast array copies", _checkcast_array_copy_ctr);
-   if (_unsafe_array_copy_ctr) tty->print_cr("%5u unsafe array copies", _unsafe_array_copy_ctr);
-   if (_generic_array_copy_ctr) tty->print_cr("%5u generic array copies", _generic_array_copy_ctr);
-   if (_slow_array_copy_ctr) tty->print_cr("%5u slow array copies", _slow_array_copy_ctr);
-   if (_find_handler_ctr) tty->print_cr("%5u find exception handler", _find_handler_ctr);
-   if (_rethrow_ctr) tty->print_cr("%5u rethrow handler", _rethrow_ctr);
-   if (_unsafe_set_memory_ctr) tty->print_cr("%5u unsafe set memorys", _unsafe_set_memory_ctr);
- 
-   AdapterHandlerLibrary::print_statistics();
+   SharedRuntime::print_ic_miss_histogram_on(tty);
+   SharedRuntime::print_counters_on(tty);
+   AdapterHandlerLibrary::print_statistics_on(tty);
  
    if (xtty != nullptr)  xtty->tail("statistics");
  }
  
+ //void SharedRuntime::print_counters_on(outputStream* st) {
+ //  // Dump the JRT_ENTRY counters
+ //  if (_new_instance_ctr) st->print_cr("%5u new instance requires GC", _new_instance_ctr);
+ //  if (_new_array_ctr)    st->print_cr("%5u new array requires GC", _new_array_ctr);
+ //  if (_multi2_ctr)       st->print_cr("%5u multianewarray 2 dim", _multi2_ctr);
+ //  if (_multi3_ctr)       st->print_cr("%5u multianewarray 3 dim", _multi3_ctr);
+ //  if (_multi4_ctr)       st->print_cr("%5u multianewarray 4 dim", _multi4_ctr);
+ //  if (_multi5_ctr)       st->print_cr("%5u multianewarray 5 dim", _multi5_ctr);
+ //
+ //  st->print_cr("%5u inline cache miss in compiled", _ic_miss_ctr);
+ //  st->print_cr("%5u wrong method", _wrong_method_ctr);
+ //  st->print_cr("%5u unresolved static call site", _resolve_static_ctr);
+ //  st->print_cr("%5u unresolved virtual call site", _resolve_virtual_ctr);
+ //  st->print_cr("%5u unresolved opt virtual call site", _resolve_opt_virtual_ctr);
+ //
+ //  if (_mon_enter_stub_ctr)       st->print_cr("%5u monitor enter stub", _mon_enter_stub_ctr);
+ //  if (_mon_exit_stub_ctr)        st->print_cr("%5u monitor exit stub", _mon_exit_stub_ctr);
+ //  if (_mon_enter_ctr)            st->print_cr("%5u monitor enter slow", _mon_enter_ctr);
+ //  if (_mon_exit_ctr)             st->print_cr("%5u monitor exit slow", _mon_exit_ctr);
+ //  if (_partial_subtype_ctr)      st->print_cr("%5u slow partial subtype", _partial_subtype_ctr);
+ //  if (_jbyte_array_copy_ctr)     st->print_cr("%5u byte array copies", _jbyte_array_copy_ctr);
+ //  if (_jshort_array_copy_ctr)    st->print_cr("%5u short array copies", _jshort_array_copy_ctr);
+ //  if (_jint_array_copy_ctr)      st->print_cr("%5u int array copies", _jint_array_copy_ctr);
+ //  if (_jlong_array_copy_ctr)     st->print_cr("%5u long array copies", _jlong_array_copy_ctr);
+ //  if (_oop_array_copy_ctr)       st->print_cr("%5u oop array copies", _oop_array_copy_ctr);
+ //  if (_checkcast_array_copy_ctr) st->print_cr("%5u checkcast array copies", _checkcast_array_copy_ctr);
+ //  if (_unsafe_array_copy_ctr)    st->print_cr("%5u unsafe array copies", _unsafe_array_copy_ctr);
+ //  if (_generic_array_copy_ctr)   st->print_cr("%5u generic array copies", _generic_array_copy_ctr);
+ //  if (_slow_array_copy_ctr)      st->print_cr("%5u slow array copies", _slow_array_copy_ctr);
+ //  if (_find_handler_ctr)         st->print_cr("%5u find exception handler", _find_handler_ctr);
+ //  if (_rethrow_ctr)              st->print_cr("%5u rethrow handler", _rethrow_ctr);
+ //  if (_unsafe_set_memory_ctr) tty->print_cr("%5u unsafe set memorys", _unsafe_set_memory_ctr);
+ //}
+ 
  inline double percent(int64_t x, int64_t y) {
    return 100.0 * (double)x / (double)MAX2(y, (int64_t)1);
  }
  
  class MethodArityHistogram {

@@ -2141,11 +2225,11 @@
  uint64_t MethodArityHistogram::_total_compiled_calls;
  uint64_t MethodArityHistogram::_max_compiled_calls_per_method;
  int MethodArityHistogram::_max_arity;
  int MethodArityHistogram::_max_size;
  
- void SharedRuntime::print_call_statistics(uint64_t comp_total) {
+ void SharedRuntime::print_call_statistics_on(outputStream* st) {
    tty->print_cr("Calls from compiled code:");
    int64_t total  = _nof_normal_calls + _nof_interface_calls + _nof_static_calls;
    int64_t mono_c = _nof_normal_calls - _nof_megamorphic_calls;
    int64_t mono_i = _nof_interface_calls;
    tty->print_cr("\t" INT64_FORMAT_W(12) " (100%%)  total non-inlined   ", total);

@@ -2394,22 +2478,22 @@
    }
    return nullptr;
  }
  
  #ifndef PRODUCT
- static void print_table_statistics() {
+ void AdapterHandlerLibrary::print_statistics_on(outputStream* st) {
    auto size = [&] (AdapterFingerPrint* key, AdapterHandlerEntry* a) {
      return sizeof(*key) + sizeof(*a);
    };
    TableStatistics ts = _adapter_handler_table->statistics_calculate(size);
-   ts.print(tty, "AdapterHandlerTable");
-   tty->print_cr("AdapterHandlerTable (table_size=%d, entries=%d)",
-                 _adapter_handler_table->table_size(), _adapter_handler_table->number_of_entries());
-   tty->print_cr("AdapterHandlerTable: lookups %d equals %d hits %d compact %d",
-                 _lookups, _equals, _hits, _compact);
+   ts.print(st, "AdapterHandlerTable");
+   st->print_cr("AdapterHandlerTable (table_size=%d, entries=%d)",
+                _adapter_handler_table->table_size(), _adapter_handler_table->number_of_entries());
+   st->print_cr("AdapterHandlerTable: lookups %d equals %d hits %d compact %d",
+                _lookups, _equals, _hits, _compact);
  }
- #endif
+ #endif // !PRODUCT
  
  // ---------------------------------------------------------------------------
  // Implementation of AdapterHandlerLibrary
  AdapterHandlerEntry* AdapterHandlerLibrary::_abstract_method_handler = nullptr;
  AdapterHandlerEntry* AdapterHandlerLibrary::_no_arg_handler = nullptr;

@@ -3093,18 +3177,10 @@
      st->print(" c2iNCI: " INTPTR_FORMAT, p2i(get_c2i_no_clinit_check_entry()));
    }
    st->cr();
  }
  
- #ifndef PRODUCT
- 
- void AdapterHandlerLibrary::print_statistics() {
-   print_table_statistics();
- }
- 
- #endif /* PRODUCT */
- 
  JRT_LEAF(void, SharedRuntime::enable_stack_reserved_zone(JavaThread* current))
    assert(current == JavaThread::current(), "pre-condition");
    StackOverflow* overflow_state = current->stack_overflow_state();
    overflow_state->enable_stack_reserved_zone(/*check_if_disabled*/true);
    overflow_state->set_reserved_stack_activation(current->stack_base());
< prev index next >