8200720: Print additional information in thread dump (times, allocated bytes etc.)
Reviewed-by: dholmes, clanger, cjplummer, sspitsyn
--- a/src/hotspot/share/classfile/klassFactory.cpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/classfile/klassFactory.cpp Mon Jun 25 16:00:56 2018 +0200
@@ -197,6 +197,9 @@
ClassFileStream* old_stream = stream;
+ // increment counter
+ THREAD->statistical_info().incr_define_class_count();
+
// Skip this processing for VM anonymous classes
if (host_klass == NULL) {
stream = check_class_file_load_hook(stream,
--- a/src/hotspot/share/runtime/globals.hpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/runtime/globals.hpp Mon Jun 25 16:00:56 2018 +0200
@@ -661,6 +661,9 @@
product(bool, PrintCompilation, false, \
"Print compilations") \
\
+ product(bool, PrintExtendedThreadInfo, false, \
+ "Print more information in thread dump") \
+ \
diagnostic(bool, TraceNMethodInstalls, false, \
"Trace nmethod installation") \
\
--- a/src/hotspot/share/runtime/thread.cpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/runtime/thread.cpp Mon Jun 25 16:00:56 2018 +0200
@@ -93,6 +93,7 @@
#include "runtime/thread.inline.hpp"
#include "runtime/threadCritical.hpp"
#include "runtime/threadSMR.inline.hpp"
+#include "runtime/threadStatisticalInfo.hpp"
#include "runtime/timer.hpp"
#include "runtime/timerTrace.hpp"
#include "runtime/vframe.inline.hpp"
@@ -869,13 +870,29 @@
}
}
-void Thread::print_on(outputStream* st) const {
+void Thread::print_on(outputStream* st, bool print_extended_info) const {
// get_priority assumes osthread initialized
if (osthread() != NULL) {
int os_prio;
if (os::get_native_priority(this, &os_prio) == OS_OK) {
st->print("os_prio=%d ", os_prio);
}
+
+ st->print("cpu=%.2fms ",
+ os::thread_cpu_time(const_cast<Thread*>(this), true) / 1000000.0
+ );
+ st->print("elapsed=%.2fs ",
+ _statistical_info.getElapsedTime() / 1000.0
+ );
+ if (is_Java_thread() && (PrintExtendedThreadInfo || print_extended_info)) {
+ size_t allocated_bytes = (size_t) const_cast<Thread*>(this)->cooked_allocated_bytes();
+ st->print("allocated=" SIZE_FORMAT "%s ",
+ byte_size_in_proper_unit(allocated_bytes),
+ proper_unit_for_byte_size(allocated_bytes)
+ );
+ st->print("defined_classes=" INT64_FORMAT " ", _statistical_info.getDefineClassCount());
+ }
+
st->print("tid=" INTPTR_FORMAT " ", p2i(this));
osthread()->print_on(st);
}
@@ -2871,7 +2888,7 @@
#endif // PRODUCT
// Called by Threads::print() for VM_PrintThreads operation
-void JavaThread::print_on(outputStream *st) const {
+void JavaThread::print_on(outputStream *st, bool print_extended_info) const {
st->print_raw("\"");
st->print_raw(get_thread_name());
st->print_raw("\" ");
@@ -2881,7 +2898,7 @@
if (java_lang_Thread::is_daemon(thread_oop)) st->print("daemon ");
st->print("prio=%d ", java_lang_Thread::priority(thread_oop));
}
- Thread::print_on(st);
+ Thread::print_on(st, print_extended_info);
// print guess for valid stack memory region (assume 4K pages); helps lock debugging
st->print_cr("[" INTPTR_FORMAT "]", (intptr_t)last_Java_sp() & ~right_n_bits(12));
if (thread_oop != NULL) {
@@ -4531,7 +4548,8 @@
// Threads::print_on() is called at safepoint by VM_PrintThreads operation.
void Threads::print_on(outputStream* st, bool print_stacks,
- bool internal_format, bool print_concurrent_locks) {
+ bool internal_format, bool print_concurrent_locks,
+ bool print_extended_info) {
char buf[32];
st->print_raw_cr(os::local_time_string(buf, sizeof(buf)));
@@ -4554,7 +4572,7 @@
ALL_JAVA_THREADS(p) {
ResourceMark rm;
- p->print_on(st);
+ p->print_on(st, print_extended_info);
if (print_stacks) {
if (internal_format) {
p->trace_stack();
--- a/src/hotspot/share/runtime/thread.hpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/runtime/thread.hpp Mon Jun 25 16:00:56 2018 +0200
@@ -44,6 +44,7 @@
#include "runtime/stubRoutines.hpp"
#include "runtime/threadHeapSampler.hpp"
#include "runtime/threadLocalStorage.hpp"
+#include "runtime/threadStatisticalInfo.hpp"
#include "runtime/unhandledOops.hpp"
#include "utilities/align.hpp"
#include "utilities/exceptions.hpp"
@@ -341,6 +342,8 @@
// the Java heap
ThreadHeapSampler _heap_sampler; // For use when sampling the memory.
+ ThreadStatisticalInfo _statistical_info; // Statistics about the thread
+
JFR_ONLY(DEFINE_THREAD_LOCAL_FIELD_JFR;) // Thread-local data for jfr
int _vm_operation_started_count; // VM_Operation support
@@ -521,6 +524,8 @@
ThreadHeapSampler& heap_sampler() { return _heap_sampler; }
+ ThreadStatisticalInfo& statistical_info() { return _statistical_info; }
+
JFR_ONLY(DEFINE_THREAD_LOCAL_ACCESSOR_JFR;)
bool is_trace_suspend() { return (_suspend_flags & _trace_flag) != 0; }
@@ -638,7 +643,8 @@
void set_lgrp_id(int value) { _lgrp_id = value; }
// Printing
- virtual void print_on(outputStream* st) const;
+ void print_on(outputStream* st, bool print_extended_info) const;
+ virtual void print_on(outputStream* st) const { print_on(st, false); }
void print() const { print_on(tty); }
virtual void print_on_error(outputStream* st, char* buf, int buflen) const;
void print_value_on(outputStream* st) const;
@@ -1759,7 +1765,8 @@
// Misc. operations
char* name() const { return (char*)get_thread_name(); }
- void print_on(outputStream* st) const;
+ void print_on(outputStream* st, bool print_extended_info) const;
+ void print_on(outputStream* st) const { print_on(st, false); }
void print_value();
void print_thread_state_on(outputStream*) const PRODUCT_RETURN;
void print_thread_state() const PRODUCT_RETURN;
@@ -2173,10 +2180,10 @@
// Verification
static void verify();
- static void print_on(outputStream* st, bool print_stacks, bool internal_format, bool print_concurrent_locks);
+ static void print_on(outputStream* st, bool print_stacks, bool internal_format, bool print_concurrent_locks, bool print_extended_info);
static void print(bool print_stacks, bool internal_format) {
// this function is only used by debug.cpp
- print_on(tty, print_stacks, internal_format, false /* no concurrent lock printed */);
+ print_on(tty, print_stacks, internal_format, false /* no concurrent lock printed */, false /* simple format */);
}
static void print_on_error(outputStream* st, Thread* current, char* buf, int buflen);
static void print_on_error(Thread* this_thread, outputStream* st, Thread* current, char* buf,
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/src/hotspot/share/runtime/threadStatisticalInfo.hpp Mon Jun 25 16:00:56 2018 +0200
@@ -0,0 +1,48 @@
+/*
+ * Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2018 SAP SE. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ *
+ */
+
+#ifndef SHARE_VM_RUNTIME_THREADSTATISTICS_HPP
+#define SHARE_VM_RUNTIME_THREADSTATISTICS_HPP
+
+#include "jni.h"
+#include "runtime/os.hpp"
+#include "utilities/globalDefinitions.hpp"
+
+
+class ThreadStatisticalInfo {
+ // The time stamp the thread was started.
+ const uint64_t _start_time_stamp;
+ uint64_t _define_class_count;
+
+public:
+ ThreadStatisticalInfo() : _start_time_stamp(os::javaTimeMillis()), _define_class_count(0) {}
+ uint64_t getStartTime() const { return _start_time_stamp; }
+ uint64_t getDefineClassCount() const { return _define_class_count; }
+ void setDefineClassCount(uint64_t defineClassCount) { _define_class_count = defineClassCount; }
+ void incr_define_class_count() { _define_class_count += 1; }
+ uint64_t getElapsedTime() const { return os::javaTimeMillis() - getStartTime(); }
+};
+
+#endif // SHARE_VM_RUNTIME_THREADSTATISTICS_HPP
--- a/src/hotspot/share/runtime/vm_operations.cpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/runtime/vm_operations.cpp Mon Jun 25 16:00:56 2018 +0200
@@ -212,7 +212,7 @@
}
void VM_PrintThreads::doit() {
- Threads::print_on(_out, true, false, _print_concurrent_locks);
+ Threads::print_on(_out, true, false, _print_concurrent_locks, _print_extended_info);
}
void VM_PrintThreads::doit_epilogue() {
--- a/src/hotspot/share/runtime/vm_operations.hpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/runtime/vm_operations.hpp Mon Jun 25 16:00:56 2018 +0200
@@ -372,10 +372,17 @@
private:
outputStream* _out;
bool _print_concurrent_locks;
+ bool _print_extended_info;
public:
- VM_PrintThreads() { _out = tty; _print_concurrent_locks = PrintConcurrentLocks; }
- VM_PrintThreads(outputStream* out, bool print_concurrent_locks) { _out = out; _print_concurrent_locks = print_concurrent_locks; }
- VMOp_Type type() const { return VMOp_PrintThreads; }
+ VM_PrintThreads()
+ : _out(tty), _print_concurrent_locks(PrintConcurrentLocks), _print_extended_info(false)
+ {}
+ VM_PrintThreads(outputStream* out, bool print_concurrent_locks, bool print_extended_info)
+ : _out(out), _print_concurrent_locks(print_concurrent_locks), _print_extended_info(print_extended_info)
+ {}
+ VMOp_Type type() const {
+ return VMOp_PrintThreads;
+ }
void doit();
bool doit_prologue();
void doit_epilogue();
--- a/src/hotspot/share/services/attachListener.cpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/services/attachListener.cpp Mon Jun 25 16:00:56 2018 +0200
@@ -168,12 +168,20 @@
//
static jint thread_dump(AttachOperation* op, outputStream* out) {
bool print_concurrent_locks = false;
- if (op->arg(0) != NULL && strcmp(op->arg(0), "-l") == 0) {
- print_concurrent_locks = true;
+ bool print_extended_info = false;
+ if (op->arg(0) != NULL) {
+ for (int i = 0; op->arg(0)[i] != 0; ++i) {
+ if (op->arg(0)[i] == 'l') {
+ print_concurrent_locks = true;
+ }
+ if (op->arg(0)[i] == 'e') {
+ print_extended_info = true;
+ }
+ }
}
// thread stacks
- VM_PrintThreads op1(out, print_concurrent_locks);
+ VM_PrintThreads op1(out, print_concurrent_locks, print_extended_info);
VMThread::execute(&op1);
// JNI global handles
--- a/src/hotspot/share/services/diagnosticCommand.cpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/services/diagnosticCommand.cpp Mon Jun 25 16:00:56 2018 +0200
@@ -612,13 +612,15 @@
ThreadDumpDCmd::ThreadDumpDCmd(outputStream* output, bool heap) :
DCmdWithParser(output, heap),
- _locks("-l", "print java.util.concurrent locks", "BOOLEAN", false, "false") {
+ _locks("-l", "print java.util.concurrent locks", "BOOLEAN", false, "false"),
+ _extended("-e", "print extended thread information", "BOOLEAN", false, "false") {
_dcmdparser.add_dcmd_option(&_locks);
+ _dcmdparser.add_dcmd_option(&_extended);
}
void ThreadDumpDCmd::execute(DCmdSource source, TRAPS) {
// thread stacks
- VM_PrintThreads op1(output(), _locks.value());
+ VM_PrintThreads op1(output(), _locks.value(), _extended.value());
VMThread::execute(&op1);
// JNI global handles
--- a/src/hotspot/share/services/diagnosticCommand.hpp Tue Jun 26 08:13:02 2018 +0100
+++ b/src/hotspot/share/services/diagnosticCommand.hpp Mon Jun 25 16:00:56 2018 +0200
@@ -446,6 +446,7 @@
class ThreadDumpDCmd : public DCmdWithParser {
protected:
DCmdArgument<bool> _locks;
+ DCmdArgument<bool> _extended;
public:
ThreadDumpDCmd(outputStream* output, bool heap);
static const char* name() { return "Thread.print"; }
--- a/src/jdk.jcmd/share/classes/sun/tools/jstack/JStack.java Tue Jun 26 08:13:02 2018 +0100
+++ b/src/jdk.jcmd/share/classes/sun/tools/jstack/JStack.java Mon Jun 25 16:00:56 2018 +0200
@@ -48,6 +48,7 @@
checkForUnsupportedOptions(args);
boolean locks = false;
+ boolean extended = false;
// Parse the options (arguments starting with "-" )
int optionCount = 0;
@@ -67,7 +68,11 @@
if (arg.equals("-l")) {
locks = true;
} else {
- usage(1);
+ if (arg.equals("-e")) {
+ extended = true;
+ } else {
+ usage(1);
+ }
}
}
optionCount++;
@@ -81,12 +86,14 @@
// pass -l to thread dump operation to get extra lock info
String pidArg = args[optionCount];
- String params[];
+ String params[]= new String[] { "" };
+ if (extended) {
+ params[0] += "-e ";
+ }
if (locks) {
- params = new String[] { "-l" };
- } else {
- params = new String[0];
+ params[0] += "-l";
}
+
ProcessArgumentMatcher ap = new ProcessArgumentMatcher(pidArg);
Collection<String> pids = ap.getVirtualMachinePids(JStack.class);
@@ -170,11 +177,12 @@
// print usage message
private static void usage(int exit) {
System.err.println("Usage:");
- System.err.println(" jstack [-l] <pid>");
+ System.err.println(" jstack [-l][-e] <pid>");
System.err.println(" (to connect to running process)");
System.err.println("");
System.err.println("Options:");
System.err.println(" -l long listing. Prints additional information about locks");
+ System.err.println(" -e extended listing. Prints additional information about threads");
System.err.println(" -? -h --help -help to print this help message");
System.exit(exit);
}