8261447: MethodInvocationCounters frequently run into overflow

Reviewed-by: thartmann, mdoerr, kvn, iveresov
This commit is contained in:
Lutz Schmidt 2021-03-03 20:04:31 +00:00
parent 75aa15467e
commit 268d9b7982
11 changed files with 160 additions and 113 deletions

View file

@ -97,9 +97,11 @@
GrowableArray<Method*>* collected_profiled_methods;
int compare_methods(Method** a, Method** b) {
// %%% there can be 32-bit overflow here
return ((*b)->invocation_count() + (*b)->compiled_invocation_count())
- ((*a)->invocation_count() + (*a)->compiled_invocation_count());
// compiled_invocation_count() returns int64_t, forcing the entire expression
// to be evaluated as int64_t. Overflow is not an issue.
int64_t diff = (((*b)->invocation_count() + (*b)->compiled_invocation_count())
- ((*a)->invocation_count() + (*a)->compiled_invocation_count()));
return (diff < 0) ? -1 : (diff > 0) ? 1 : 0;
}
void collect_profiled_methods(Method* m) {
@ -151,14 +153,15 @@ void print_method_profiling_data() {
GrowableArray<Method*>* collected_invoked_methods;
void collect_invoked_methods(Method* m) {
if (m->invocation_count() + m->compiled_invocation_count() >= 1 ) {
if (m->invocation_count() + m->compiled_invocation_count() >= 1) {
collected_invoked_methods->push(m);
}
}
// Invocation count accumulators should be unsigned long to shift the
// overflow border. Longer-running workloads tend to create invocation
// counts which already overflow 32-bit counters for individual methods.
void print_method_invocation_histogram() {
ResourceMark rm;
collected_invoked_methods = new GrowableArray<Method*>(1024);
@ -169,31 +172,45 @@ void print_method_invocation_histogram() {
tty->print_cr("Histogram Over Method Invocation Counters (cutoff = " INTX_FORMAT "):", MethodHistogramCutoff);
tty->cr();
tty->print_cr("____Count_(I+C)____Method________________________Module_________________");
unsigned total = 0, int_total = 0, comp_total = 0, static_total = 0, final_total = 0,
synch_total = 0, nativ_total = 0, acces_total = 0;
uint64_t total = 0,
int_total = 0,
comp_total = 0,
special_total= 0,
static_total = 0,
final_total = 0,
synch_total = 0,
native_total = 0,
access_total = 0;
for (int index = 0; index < collected_invoked_methods->length(); index++) {
// Counter values returned from getter methods are signed int.
// To shift the overflow border by a factor of two, we interpret
// them here as unsigned long. A counter can't be negative anyway.
Method* m = collected_invoked_methods->at(index);
int c = m->invocation_count() + m->compiled_invocation_count();
if (c >= MethodHistogramCutoff) m->print_invocation_count();
int_total += m->invocation_count();
comp_total += m->compiled_invocation_count();
if (m->is_final()) final_total += c;
if (m->is_static()) static_total += c;
if (m->is_synchronized()) synch_total += c;
if (m->is_native()) nativ_total += c;
if (m->is_accessor()) acces_total += c;
uint64_t iic = (uint64_t)m->invocation_count();
uint64_t cic = (uint64_t)m->compiled_invocation_count();
if ((iic + cic) >= (uint64_t)MethodHistogramCutoff) m->print_invocation_count();
int_total += iic;
comp_total += cic;
if (m->is_final()) final_total += iic + cic;
if (m->is_static()) static_total += iic + cic;
if (m->is_synchronized()) synch_total += iic + cic;
if (m->is_native()) native_total += iic + cic;
if (m->is_accessor()) access_total += iic + cic;
}
tty->cr();
total = int_total + comp_total;
tty->print_cr("Invocations summary:");
tty->print_cr("\t%9d (%4.1f%%) interpreted", int_total, 100.0 * int_total / total);
tty->print_cr("\t%9d (%4.1f%%) compiled", comp_total, 100.0 * comp_total / total);
tty->print_cr("\t%9d (100%%) total", total);
tty->print_cr("\t%9d (%4.1f%%) synchronized", synch_total, 100.0 * synch_total / total);
tty->print_cr("\t%9d (%4.1f%%) final", final_total, 100.0 * final_total / total);
tty->print_cr("\t%9d (%4.1f%%) static", static_total, 100.0 * static_total / total);
tty->print_cr("\t%9d (%4.1f%%) native", nativ_total, 100.0 * nativ_total / total);
tty->print_cr("\t%9d (%4.1f%%) accessor", acces_total, 100.0 * acces_total / total);
special_total = final_total + static_total +synch_total + native_total + access_total;
tty->print_cr("Invocations summary for %d methods:", collected_invoked_methods->length());
tty->print_cr("\t" UINT64_FORMAT_W(12) " (100%%) total", total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- interpreted", int_total, 100.0 * int_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- compiled", comp_total, 100.0 * comp_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- special methods (interpreted and compiled)",
special_total, 100.0 * special_total/ total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- synchronized",synch_total, 100.0 * synch_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- final", final_total, 100.0 * final_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- static", static_total, 100.0 * static_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- native", native_total, 100.0 * native_total / total);
tty->print_cr("\t" UINT64_FORMAT_W(12) " (%4.1f%%) |- accessor", access_total, 100.0 * access_total / total);
tty->cr();
SharedRuntime::print_call_statistics(comp_total);
}