--- /dev/null 2017-11-09 09:38:01.297999907 +0100 +++ new/src/hotspot/share/jfr/periodic/sampling/jfrThreadSampler.cpp 2018-04-09 14:52:59.222729300 +0200 @@ -0,0 +1,565 @@ +/* + * Copyright (c) 2012, 2018, Oracle and/or its affiliates. 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. + * + */ + +#include "precompiled.hpp" +#include "jfr/recorder/jfrRecorder.hpp" +#include "jfr/periodic/sampling/jfrCallTrace.hpp" +#include "jfr/periodic/sampling/jfrThreadSampler.hpp" +#include "jfr/recorder/stacktrace/jfrStackTraceRepository.hpp" +#include "jfr/recorder/access/jfrOptionSet.hpp" +#include "jfr/utilities/jfrTraceTime.hpp" +#include "logging/log.hpp" +#include "runtime/frame.inline.hpp" +#include "runtime/os.hpp" +#include "runtime/thread.inline.hpp" +#include "runtime/threadSMR.hpp" +#include "trace/tracing.hpp" +#include "tracefiles/traceEventIds.hpp" + +static bool in_java_sample(JavaThread* thread) { + switch (thread->thread_state()) { + case _thread_new: + case _thread_uninitialized: + case _thread_new_trans: + case _thread_in_vm_trans: + case _thread_blocked_trans: + case _thread_in_native_trans: + case _thread_blocked: + case _thread_in_vm: + case _thread_in_native: + case _thread_in_Java_trans: + break; + case _thread_in_Java: + return true; + default: + ShouldNotReachHere(); + break; + } + return false; +} + +static bool in_native_sample(JavaThread* thread) { + switch (thread->thread_state()) { + case _thread_new: + case _thread_uninitialized: + case _thread_new_trans: + case _thread_blocked_trans: + case _thread_blocked: + case _thread_in_vm: + case _thread_in_vm_trans: + case _thread_in_Java_trans: + case _thread_in_Java: + case _thread_in_native_trans: + break; + case _thread_in_native: + return true; + default: + ShouldNotReachHere(); + break; + } + return false; +} + +class JfrThreadSampleClosure { + public: + JfrThreadSampleClosure(EventExecutionSample* events, EventNativeMethodSample* events_native); + ~JfrThreadSampleClosure() {} + EventExecutionSample* next_event() { return &_events[_added_java++]; } + EventNativeMethodSample* next_event_native() { return &_events_native[_added_native++]; } + void commit_events(); + int added() const { return _added_java; } + JfrSampleType do_sample_thread(JavaThread* thread, JfrStackFrame* frames, u4 max_frames, bool java_sample, bool native_sample); + int java_entries() { return _added_java; } + int native_entries() { return _added_native; } + + private: + bool sample_thread_in_java(JavaThread* thread, JfrStackFrame* frames, u4 max_frames); + bool sample_thread_in_native(JavaThread* thread, JfrStackFrame* frames, u4 max_frames); + EventExecutionSample* _events; + EventNativeMethodSample* _events_native; + Thread* _self; + int _added_java; + int _added_native; +}; + +class OSThreadSampler : public os::SuspendedThreadTask { + public: + OSThreadSampler(JavaThread* thread, + JfrThreadSampleClosure& closure, + JfrStackFrame *frames, + u4 max_frames) : os::SuspendedThreadTask((Thread*)thread), + _success(false), + _stacktrace(frames, max_frames), + _closure(closure), + _suspend_time(0) {} + + void take_sample(); + void do_task(const os::SuspendedThreadTaskContext& context); + void protected_task(const os::SuspendedThreadTaskContext& context); + bool success() const { return _success; } + const JfrStackTrace& stacktrace() const { return _stacktrace; } + + private: + bool _success; + JfrStackTrace _stacktrace; + JfrThreadSampleClosure& _closure; + JfrTraceTime _suspend_time; +}; + +class OSThreadSamplerCallback : public os::CrashProtectionCallback { + public: + OSThreadSamplerCallback(OSThreadSampler& sampler, const os::SuspendedThreadTaskContext &context) : + _sampler(sampler), _context(context) { + } + virtual void call() { + _sampler.protected_task(_context); + } + private: + OSThreadSampler& _sampler; + const os::SuspendedThreadTaskContext& _context; +}; + +void OSThreadSampler::do_task(const os::SuspendedThreadTaskContext& context) { +#ifndef ASSERT + guarantee(JfrOptionSet::sample_protection(), "Sample Protection should be on in product builds"); +#endif + assert(0 == _suspend_time, "already timestamped!"); + _suspend_time = JfrTraceTime::now(); + + if (JfrOptionSet::sample_protection()) { + OSThreadSamplerCallback cb(*this, context); + os::ThreadCrashProtection crash_protection; + if (!crash_protection.call(cb)) { + log_error(jfr)("Thread method sampler crashed"); + } + } else { + protected_task(context); + } +} + +/* +* From this method and down the call tree we attempt to protect against crashes +* using a signal handler / __try block. Don't take locks, rely on destructors or +* leave memory (in case of signal / exception) in an inconsistent state. */ +void OSThreadSampler::protected_task(const os::SuspendedThreadTaskContext& context) { + JavaThread* jth = (JavaThread*)context.thread(); + // Skip sample if we signaled a thread that moved to other state + if (!in_java_sample(jth)) { + return; + } + JfrGetCallTrace trace(true, jth); + frame topframe; + if (trace.get_topframe(context.ucontext(), topframe)) { + if (_stacktrace.record_thread(*jth, topframe)) { + /* If we managed to get a topframe and a stacktrace, create an event + * and put it into our array. We can't call Jfr::_stacktraces.add() + * here since it would allocate memory using malloc. Doing so while + * the stopped thread is inside malloc would deadlock. */ + _success = true; + EventExecutionSample *ev = _closure.next_event(); + ev->set_starttime(_suspend_time); + ev->set_endtime(JfrTraceTime(1)); // fake to not take an end time + ev->set_sampledThread(THREAD_TRACE_ID(jth)); + ev->set_state(java_lang_Thread::get_thread_status(jth->threadObj())); + } + } +} + +void OSThreadSampler::take_sample() { + run(); +} + +class JfrNativeSamplerCallback : public os::CrashProtectionCallback { + public: + JfrNativeSamplerCallback(JfrThreadSampleClosure& closure, JavaThread* jt, JfrStackFrame* frames, u4 max_frames) : + _closure(closure), _jt(jt), _stacktrace(frames, max_frames), _success(false) { + } + virtual void call(); + bool success() { return _success; } + JfrStackTrace& stacktrace() { return _stacktrace; } + + private: + JfrThreadSampleClosure& _closure; + JavaThread* _jt; + JfrStackTrace _stacktrace; + bool _success; +}; + +static void write_native_event(JfrThreadSampleClosure& closure, JavaThread* jt) { + EventNativeMethodSample *ev = closure.next_event_native(); + ev->set_starttime(JfrTraceTime(0)); + ev->set_sampledThread(THREAD_TRACE_ID(jt)); + ev->set_state(java_lang_Thread::get_thread_status(jt->threadObj())); +} + +void JfrNativeSamplerCallback::call() { + // When a thread is only attach it will be native without a last java frame + if (!_jt->has_last_Java_frame()) { + return; + } + + frame topframe = _jt->last_frame(); + frame first_java_frame; + Method* method = NULL; + JfrGetCallTrace gct(false, _jt); + if (!gct.find_top_frame(topframe, &method, first_java_frame)) { + return; + } + if (method == NULL) { + return; + } + topframe = first_java_frame; + _success = _stacktrace.record_thread(*_jt, topframe); + if (_success) { + write_native_event(_closure, _jt); + } +} + +bool JfrThreadSampleClosure::sample_thread_in_java(JavaThread* thread, JfrStackFrame* frames, u4 max_frames) { + OSThreadSampler sampler(thread, *this, frames, max_frames); + sampler.take_sample(); + /* We don't want to allocate any memory using malloc/etc while the thread + * is stopped, so everything is stored in stack allocated memory until this + * point where the thread has been resumed again, if the sampling was a success + * we need to store the stacktrace in the stacktrace repository and update + * the event with the id that was returned. */ + if (!sampler.success()) { + return false; + } + EventExecutionSample *event = &_events[_added_java - 1]; + traceid id = JfrStackTraceRepository::add(sampler.stacktrace()); + assert(id != 0, "Stacktrace id should not be 0"); + event->set_stackTrace(id); + return true; +} + +bool JfrThreadSampleClosure::sample_thread_in_native(JavaThread* thread, JfrStackFrame* frames, u4 max_frames) { + JfrNativeSamplerCallback cb(*this, thread, frames, max_frames); + if (JfrOptionSet::sample_protection()) { + os::ThreadCrashProtection crash_protection; + if (!crash_protection.call(cb)) { + log_error(jfr)("Thread method sampler crashed for native"); + } + } else { + cb.call(); + } + if (!cb.success()) { + return false; + } + EventNativeMethodSample *event = &_events_native[_added_native - 1]; + traceid id = JfrStackTraceRepository::add(cb.stacktrace()); + assert(id != 0, "Stacktrace id should not be 0"); + event->set_stackTrace(id); + return true; +} + +void JfrThreadSampleClosure::commit_events() { + for (int i = 0; i < _added_java; ++i) { + _events[i].commit(); + } + for (int i = 0; i < _added_native; ++i) { + _events_native[i].commit(); + } +} + +JfrThreadSampleClosure::JfrThreadSampleClosure(EventExecutionSample* events, EventNativeMethodSample* events_native) : + _events(events), + _events_native(events_native), + _self(Thread::current()), + _added_java(0), + _added_native(0) { +} + +static void clear_transition_block(JavaThread* jt) { + jt->clear_trace_flag(); + JfrThreadData* jtd = jt->trace_data(); + if (jtd->is_trace_block()) { + MutexLockerEx ml(JfrThreadSampler::transition_block(), Mutex::_no_safepoint_check_flag); + JfrThreadSampler::transition_block()->notify_all(); + } +} + +JfrSampleType JfrThreadSampleClosure::do_sample_thread(JavaThread* thread, JfrStackFrame* frames, u4 max_frames, bool java_sample, bool native_sample) { + assert(Threads_lock->owned_by_self(), "Holding the thread table lock."); + if (thread->is_hidden_from_external_view()) { + return NO_SAMPLE; + } + if (thread->in_deopt_handler()) { + return NO_SAMPLE; + } + JfrSampleType ret = NO_SAMPLE; + thread->set_trace_flag(); + if (!UseMembar) { + os::serialize_thread_states(); + } + if (in_java_sample(thread) && java_sample) { + ret = sample_thread_in_java(thread, frames, max_frames) ? JAVA_SAMPLE : NO_SAMPLE; + } else if (in_native_sample(thread) && native_sample) { + ret = sample_thread_in_native(thread, frames, max_frames) ? NATIVE_SAMPLE : NO_SAMPLE; + } + clear_transition_block(thread); + return ret; +} + +Monitor* JfrThreadSampler::_transition_block_lock = new Monitor(Mutex::leaf, "Trace block", true, Monitor::_safepoint_check_never); + +JfrThreadSampler::JfrThreadSampler(size_t interval_java, size_t interval_native, u4 max_frames) : + _frames(JfrCHeapObj::new_array(max_frames)), + _last_thread_java(NULL), + _last_thread_native(NULL), + _interval_java(interval_java), + _interval_native(interval_native), + _cur_index(-1), + _max_frames(max_frames), + _should_terminate(false) { +} + +JfrThreadSampler::~JfrThreadSampler() { + JfrCHeapObj::free(_frames, sizeof(JfrStackFrame) * _max_frames); +} + +void JfrThreadSampler::on_javathread_suspend(JavaThread* thread) { + JfrThreadData* jtd = thread->trace_data(); + jtd->set_trace_block(); + { + MutexLockerEx ml(transition_block(), Mutex::_no_safepoint_check_flag); + while (thread->is_trace_suspend()) { + transition_block()->wait(true); + } + jtd->clear_trace_block(); + } +} + +JavaThread* JfrThreadSampler::next_thread(ThreadsList* t_list, JavaThread* first_sampled, JavaThread* current) { + assert(Threads_lock->owned_by_self(), "Holding the thread table lock."); + if (current == NULL) { + _cur_index = 0; + return t_list->thread_at(_cur_index); + } + + if (_cur_index == -1 || t_list->thread_at(_cur_index) != current) { + // 'current' is not at '_cur_index' so find it: + _cur_index = t_list->find_index_of_JavaThread(current); + assert(_cur_index != -1, "current JavaThread should be findable."); + } + _cur_index++; + + JavaThread* next = NULL; + // wrap + if ((uint)_cur_index >= t_list->length()) { + _cur_index = 0; + } + next = t_list->thread_at(_cur_index); + + // sample wrap + if (next == first_sampled) { + return NULL; + } + return next; +} + +void JfrThreadSampler::enroll() { + if (os::create_thread(this, os::os_thread)) { + os::start_thread(this); + } else { + log_error(jfr)("Failed to create thread for thread sampling"); + } +} + +void JfrThreadSampler::disenroll() { + _should_terminate = true; +} + +static jlong get_monotonic_ms() { + return os::javaTimeNanos() / 1000000; +} + +void JfrThreadSampler::run() { + jlong last_java_ms = get_monotonic_ms(); + jlong last_native_ms = last_java_ms; + while (!_should_terminate) { + jlong java_interval = _interval_java == 0 ? max_jlong : MAX2(_interval_java, 10); + jlong native_interval = _interval_native == 0 ? max_jlong : MAX2(_interval_native, 10); + + jlong now_ms = get_monotonic_ms(); + + jlong next_j = java_interval + last_java_ms - now_ms; + jlong next_n = native_interval + last_native_ms - now_ms; + + jlong sleep_to_next = MIN2(next_j, next_n); + + if (sleep_to_next > 0) { + os::naked_short_sleep(sleep_to_next); + } + + if ((next_j - sleep_to_next) <= 0) { + task_stacktrace(JAVA_SAMPLE, &_last_thread_java); + last_java_ms = get_monotonic_ms(); + } + if ((next_n - sleep_to_next) <= 0) { + task_stacktrace(NATIVE_SAMPLE, &_last_thread_native); + last_native_ms = get_monotonic_ms(); + } + } + delete this; +} + +static const int MAX_NR_OF_SAMPLES = 5; + +void JfrThreadSampler::task_stacktrace(JfrSampleType type, JavaThread** last_thread) { + ResourceMark rm; + EventExecutionSample samples[MAX_NR_OF_SAMPLES]; + EventNativeMethodSample samples_native[MAX_NR_OF_SAMPLES]; + JfrThreadSampleClosure sample_task(samples, samples_native); + + int num_samples = 0; + { + elapsedTimer sample_time; + sample_time.start(); + + { + MonitorLockerEx tlock(Threads_lock, Mutex::_allow_vm_block_flag); + ThreadsListHandle tlh; + JavaThread* current = tlh.includes(*last_thread) ? *last_thread : NULL; + JavaThread* start = NULL; + + while (num_samples < MAX_NR_OF_SAMPLES) { + current = next_thread(tlh.list(), start, current); + if (current == NULL) { + break; + } + if (start == NULL) { + start = current; // remember thread where we started sampling + } + if (current->is_Compiler_thread()) { + continue; + } + *last_thread = current; // remember thread we last sampled + JfrSampleType ret = sample_task.do_sample_thread(current, _frames, _max_frames, type == JAVA_SAMPLE, type == NATIVE_SAMPLE); + switch (type) { + case JAVA_SAMPLE: + case NATIVE_SAMPLE: + ++num_samples; + break; + default: + break; + } + } + } + sample_time.stop(); + log_trace(jfr)("JFR thread sampling done in %3.7f secs with %d java %d native samples", + sample_time.seconds(), sample_task.java_entries(), sample_task.native_entries()); + } + if (num_samples>0) { + sample_task.commit_events(); + } +} + +static JfrThreadSampling* _instance = NULL; + +JfrThreadSampling& JfrThreadSampling::instance() { + return *_instance; +} + +JfrThreadSampling* JfrThreadSampling::create() { + assert(_instance == NULL, "invariant"); + _instance = new JfrThreadSampling(); + return _instance; +} + +void JfrThreadSampling::destroy() { + if (_instance != NULL) { + delete _instance; + _instance = NULL; + } +} + +JfrThreadSampling::JfrThreadSampling() : _sampler(NULL) {} + +JfrThreadSampling::~JfrThreadSampling() { + log_info(jfr)("Disrolling thread sampler"); + stop_sampler(); +} + +static void log(size_t interval_java, size_t interval_native) { + log_info(jfr)("Updated thread sampler for java: " SIZE_FORMAT" ms, native " SIZE_FORMAT " ms", interval_java, interval_native); +} + +void JfrThreadSampling::start_sampler(size_t interval_java, size_t interval_native) { + assert(_sampler == NULL, "invariant"); + log_info(jfr)("Enrolling thread sampler"); + _sampler = new JfrThreadSampler(interval_java, interval_native, JfrOptionSet::stackdepth()); + _sampler->enroll(); +} + +void JfrThreadSampling::stop_sampler() { + if (_sampler != NULL) { + _sampler->disenroll(); + _sampler = NULL; + } +} + +void JfrThreadSampling::set_sampling_interval(bool java_interval, size_t period) { + size_t interval_java = 0; + size_t interval_native = 0; + if (_sampler != NULL) { + interval_java = _sampler->get_java_interval(); + interval_native = _sampler->get_native_interval(); + } + + if (java_interval) { + interval_java = period; + } else { + interval_native = period; + } + + if (interval_java > 0 || interval_native > 0) { + if (_sampler == NULL) { + start_sampler(interval_java, interval_native); + } else { + _sampler->set_java_interval(interval_java); + _sampler->set_native_interval(interval_native); + } + assert(_sampler != NULL, "invariant"); + log(interval_java, interval_native); + } else if (_sampler != NULL) { + log_info(jfr)("Disrolling thread sampler"); + stop_sampler(); + } +} + +void JfrThreadSampling::set_java_sample_interval(size_t period) { + if (_instance == NULL && 0 == period) { + return; + } + instance().set_sampling_interval(true, period); +} + +void JfrThreadSampling::set_native_sample_interval(size_t period) { + if (_instance == NULL && 0 == period) { + return; + } + instance().set_sampling_interval(false, period); +} +