8237499: JFR: Include stack trace in the ThreadStart event

Reviewed-by: egahlin
This commit is contained in:
Denghui Dong 2020-02-24 23:24:14 +01:00
parent 8493812702
commit 52d7a61e8d
8 changed files with 54 additions and 8 deletions

View file

@ -26,8 +26,9 @@
<Metadata> <Metadata>
<Event name="ThreadStart" category="Java Application" label="Java Thread Start" thread="true" startTime="false"> <Event name="ThreadStart" category="Java Application" label="Java Thread Start" thread="true" startTime="false" stackTrace="true">
<Field type="Thread" name="thread" label="Java Thread" /> <Field type="Thread" name="thread" label="New Java Thread" />
<Field type="Thread" name="parentThread" label="Parent Java Thread" />
</Event> </Event>
<Event name="ThreadEnd" category="Java Application" label="Java Thread End" thread="true" startTime="false"> <Event name="ThreadEnd" category="Java Application" label="Java Thread End" thread="true" startTime="false">

View file

@ -56,7 +56,11 @@ JfrThreadLocal::JfrThreadLocal() :
_stackdepth(0), _stackdepth(0),
_entering_suspend_flag(0), _entering_suspend_flag(0),
_excluded(false), _excluded(false),
_dead(false) {} _dead(false) {
Thread* thread = Thread::current_or_null();
_parent_trace_id = thread != NULL ? thread->jfr_thread_local()->trace_id() : (traceid)0;
}
u8 JfrThreadLocal::add_data_lost(u8 value) { u8 JfrThreadLocal::add_data_lost(u8 value) {
_data_lost += value; _data_lost += value;
@ -79,6 +83,7 @@ const JfrBlobHandle& JfrThreadLocal::thread_blob() const {
static void send_java_thread_start_event(JavaThread* jt) { static void send_java_thread_start_event(JavaThread* jt) {
EventThreadStart event; EventThreadStart event;
event.set_thread(jt->jfr_thread_local()->thread_id()); event.set_thread(jt->jfr_thread_local()->thread_id());
event.set_parentThread(jt->jfr_thread_local()->parent_thread_id());
event.commit(); event.commit();
} }
@ -94,6 +99,9 @@ void JfrThreadLocal::on_start(Thread* t) {
} }
} }
} }
if (t->jfr_thread_local()->has_cached_stack_trace()) {
t->jfr_thread_local()->clear_cached_stack_trace();
}
} }
static void send_java_thread_end_events(traceid id, JavaThread* jt) { static void send_java_thread_end_events(traceid id, JavaThread* jt) {

View file

@ -52,6 +52,7 @@ class JfrThreadLocal {
volatile jint _entering_suspend_flag; volatile jint _entering_suspend_flag;
bool _excluded; bool _excluded;
bool _dead; bool _dead;
traceid _parent_trace_id;
JfrBuffer* install_native_buffer() const; JfrBuffer* install_native_buffer() const;
JfrBuffer* install_java_buffer() const; JfrBuffer* install_java_buffer() const;
@ -128,6 +129,10 @@ class JfrThreadLocal {
_trace_id = thread_id; _trace_id = thread_id;
} }
traceid parent_thread_id() const {
return _parent_trace_id;
}
void set_cached_stack_trace_id(traceid id, unsigned int hash = 0) { void set_cached_stack_trace_id(traceid id, unsigned int hash = 0) {
_stack_trace_id = id; _stack_trace_id = id;
_stack_trace_hash = hash; _stack_trace_hash = hash;

View file

@ -3659,7 +3659,14 @@ static void post_thread_start_event(const JavaThread* jt) {
EventThreadStart event; EventThreadStart event;
if (event.should_commit()) { if (event.should_commit()) {
event.set_thread(JFR_THREAD_ID(jt)); event.set_thread(JFR_THREAD_ID(jt));
event.set_parentThread((traceid)0);
if (EventThreadStart::is_stacktrace_enabled()) {
jt->jfr_thread_local()->set_cached_stack_trace_id((traceid)0);
event.commit(); event.commit();
jt->jfr_thread_local()->clear_cached_stack_trace();
} else {
event.commit();
}
} }
} }

View file

@ -94,6 +94,7 @@
#endif #endif
#include <errno.h> #include <errno.h>
#include <jfr/recorder/jfrRecorder.hpp>
/* /*
NOTE about use of any ctor or function call that can trigger a safepoint/GC: NOTE about use of any ctor or function call that can trigger a safepoint/GC:
@ -2882,6 +2883,15 @@ JVM_ENTRY(void, JVM_StartThread(JNIEnv* env, jobject jthread))
os::native_thread_creation_failed_msg()); os::native_thread_creation_failed_msg());
} }
#if INCLUDE_JFR
if (JfrRecorder::is_recording() && EventThreadStart::is_enabled() &&
EventThreadStart::is_stacktrace_enabled()) {
JfrThreadLocal* tl = native_thread->jfr_thread_local();
// skip Thread.start() and Thread.start0()
tl->set_cached_stack_trace_id(JfrStackTraceRepository::record(thread, 2));
}
#endif
Thread::start(native_thread); Thread::start(native_thread);
JVM_END JVM_END

View file

@ -54,6 +54,7 @@
<event name="jdk.ThreadStart"> <event name="jdk.ThreadStart">
<setting name="enabled">true</setting> <setting name="enabled">true</setting>
<setting name="stackTrace">true</setting>
</event> </event>
<event name="jdk.ThreadEnd"> <event name="jdk.ThreadEnd">

View file

@ -54,6 +54,7 @@
<event name="jdk.ThreadStart"> <event name="jdk.ThreadStart">
<setting name="enabled">true</setting> <setting name="enabled">true</setting>
<setting name="stackTrace">true</setting>
</event> </event>
<event name="jdk.ThreadEnd"> <event name="jdk.ThreadEnd">

View file

@ -25,12 +25,17 @@
package jdk.jfr.event.runtime; package jdk.jfr.event.runtime;
import static jdk.test.lib.Asserts.assertEQ;
import static jdk.test.lib.Asserts.assertNotNull;
import java.time.Duration; import java.time.Duration;
import java.util.List; import java.util.List;
import java.util.concurrent.CountDownLatch; import java.util.concurrent.CountDownLatch;
import jdk.jfr.Recording; import jdk.jfr.Recording;
import jdk.jfr.consumer.RecordedEvent; import jdk.jfr.consumer.RecordedEvent;
import jdk.jfr.consumer.RecordedMethod;
import jdk.jfr.consumer.RecordedStackTrace;
import jdk.test.lib.jfr.EventNames; import jdk.test.lib.jfr.EventNames;
import jdk.test.lib.jfr.Events; import jdk.test.lib.jfr.Events;
@ -62,19 +67,27 @@ public class TestThreadStartEndEvents {
recording.stop(); recording.stop();
int currThreadIndex = 0; int currThreadIndex = 0;
long currentThreadId = Thread.currentThread().getId();
List<RecordedEvent> events = Events.fromRecording(recording); List<RecordedEvent> events = Events.fromRecording(recording);
events.sort((e1, e2) -> e1.getStartTime().compareTo(e2.getStartTime()));
Events.hasEvents(events); Events.hasEvents(events);
for (RecordedEvent event : events) { for (RecordedEvent event : events) {
System.out.println("Event:" + event); if (!event.getThread().getJavaName().startsWith(THREAD_NAME_PREFIX)) {
if (event.getThread().getJavaThreadId() != currentThreadId) {
continue; continue;
} }
System.out.println("Event:" + event);
// Threads should be started and stopped in the correct order. // Threads should be started and stopped in the correct order.
Events.assertEventThread(event, threads[currThreadIndex % threads.length]); Events.assertEventThread(event, threads[currThreadIndex % threads.length]);
String eventName = currThreadIndex < threads.length ? EVENT_NAME_THREAD_START : EVENT_NAME_THREAD_END; String eventName = currThreadIndex < threads.length ? EVENT_NAME_THREAD_START : EVENT_NAME_THREAD_END;
if (!eventName.equals(event.getEventType().getName())) { if (!eventName.equals(event.getEventType().getName())) {
throw new Exception("Expected event of tyoe " + eventName + " but got " + event.getEventType().getName()); throw new Exception("Expected event of type " + eventName + " but got " + event.getEventType().getName());
}
if (eventName == EVENT_NAME_THREAD_START) {
Events.assertEventThread(event, "parentThread", Thread.currentThread());
RecordedStackTrace stackTrace = event.getValue("stackTrace");
assertNotNull(stackTrace);
RecordedMethod topMethod = stackTrace.getFrames().get(0).getMethod();
assertEQ(topMethod.getName(), "startThread");
} }
currThreadIndex++; currThreadIndex++;
} }