< prev index next >
src/hotspot/share/runtime/handshake.cpp
Print this page
rev 57079 : [mq]: handshake-logs
@@ -30,51 +30,28 @@
#include "runtime/interfaceSupport.inline.hpp"
#include "runtime/orderAccess.hpp"
#include "runtime/osThread.hpp"
#include "runtime/semaphore.inline.hpp"
#include "runtime/task.hpp"
-#include "runtime/timerTrace.hpp"
#include "runtime/thread.hpp"
#include "runtime/vmThread.hpp"
#include "utilities/formatBuffer.hpp"
#include "utilities/preserveException.hpp"
-class HandshakeOperation: public StackObj {
-public:
- virtual void do_handshake(JavaThread* thread) = 0;
-};
-
-class HandshakeThreadsOperation: public HandshakeOperation {
- static Semaphore _done;
- ThreadClosure* _thread_cl;
- bool _executed;
-public:
- HandshakeThreadsOperation(ThreadClosure* cl) : _thread_cl(cl), _executed(false) {}
- void do_handshake(JavaThread* thread);
- bool thread_has_completed() { return _done.trywait(); }
- bool executed() const { return _executed; }
-
-#ifdef ASSERT
- void check_state() {
- assert(!_done.trywait(), "Must be zero");
- }
-#endif
-};
-
-Semaphore HandshakeThreadsOperation::_done(0);
+Semaphore HandshakeOperation::_done(0);
class VM_Handshake: public VM_Operation {
const jlong _handshake_timeout;
public:
bool evaluate_at_safepoint() const { return false; }
bool evaluate_concurrently() const { return false; }
protected:
- HandshakeThreadsOperation* const _op;
+ HandshakeOperation* const _op;
- VM_Handshake(HandshakeThreadsOperation* op) :
+ VM_Handshake(HandshakeOperation* op) :
_handshake_timeout(TimeHelper::millis_to_counter(HandshakeTimeout)), _op(op) {}
void set_handshake(JavaThread* target) {
target->set_handshake_operation(_op);
}
@@ -106,72 +83,91 @@
}
log_stream.flush();
fatal("Handshake operation timed out");
}
+static void log_handshake_info(jlong start_time_ns, const char* name, int targets, int vmt_executed, const char* extra) {
+ if (start_time_ns != 0) {
+ jlong completion_time = os::javaTimeNanos() - start_time_ns;
+ log_info(handshake)("Handshake \"%s\", Targeted threads: %d, Executed by targeted threads: %d, Total completion time: " JLONG_FORMAT " ns%s",
+ name, targets, targets - vmt_executed, completion_time, extra);
+ }
+}
+
class VM_HandshakeOneThread: public VM_Handshake {
JavaThread* _target;
public:
- VM_HandshakeOneThread(HandshakeThreadsOperation* op, JavaThread* target) :
+ VM_HandshakeOneThread(HandshakeOperation* op, JavaThread* target) :
VM_Handshake(op), _target(target) {}
void doit() {
DEBUG_ONLY(_op->check_state();)
- TraceTime timer("Finished executing single-target operation (VM_HandshakeOneThread::doit)", TRACETIME_LOG(Info, handshake));
+
+ jlong start_time_ns = 0;
+ if (log_is_enabled(Info, handshake)) {
+ start_time_ns = os::javaTimeNanos();
+ }
ThreadsListHandle tlh;
if (tlh.includes(_target)) {
set_handshake(_target);
} else {
- log_trace(handshake)("JavaThread " INTPTR_FORMAT " is not alive", p2i(_target));
+ log_handshake_info(start_time_ns, _op->name(), 0, 0, " (thread dead)");
return;
}
log_trace(handshake)("JavaThread " INTPTR_FORMAT " signaled, begin attempt to process by VMThtread", p2i(_target));
- jlong start_time = os::elapsed_counter();
+ jlong timeout_start_time = os::elapsed_counter();
+ bool by_vm_thread = false;
do {
- if (handshake_has_timed_out(start_time)) {
+ if (handshake_has_timed_out(timeout_start_time)) {
handle_timeout();
}
// We need to re-think this with SMR ThreadsList.
// There is an assumption in the code that the Threads_lock should be
// locked during certain phases.
{
MutexLocker ml(Threads_lock);
- _target->handshake_process_by_vmthread();
+ by_vm_thread = _target->handshake_process_by_vmthread();
}
} while (!poll_for_completed_thread());
DEBUG_ONLY(_op->check_state();)
+ log_handshake_info(start_time_ns, _op->name(), 1, by_vm_thread ? 1 : 0, "");
}
VMOp_Type type() const { return VMOp_HandshakeOneThread; }
bool executed() const { return _op->executed(); }
};
class VM_HandshakeAllThreads: public VM_Handshake {
public:
- VM_HandshakeAllThreads(HandshakeThreadsOperation* op) : VM_Handshake(op) {}
+ VM_HandshakeAllThreads(HandshakeOperation* op) : VM_Handshake(op) {}
void doit() {
DEBUG_ONLY(_op->check_state();)
- TraceTime timer("Finished executing multi-target operation (VM_HandshakeAllThreads::doit)", TRACETIME_LOG(Info, handshake));
+
+ jlong start_time_ns = 0;
+ if (log_is_enabled(Info, handshake)) {
+ start_time_ns = os::javaTimeNanos();
+ }
+ int handshake_executed_by_vm_thread = 0;
JavaThreadIteratorWithHandle jtiwh;
int number_of_threads_issued = 0;
for (JavaThread *thr = jtiwh.next(); thr != NULL; thr = jtiwh.next()) {
set_handshake(thr);
number_of_threads_issued++;
}
if (number_of_threads_issued < 1) {
- log_debug(handshake)("No threads to handshake.");
+ log_trace(handshake)("No threads to handshake.");
return;
}
- log_debug(handshake)("Threads signaled, begin processing blocked threads by VMThtread");
+ log_trace(handshake)("Threads signaled, begin processing blocked threads by VMThtread");
const jlong start_time = os::elapsed_counter();
int number_of_threads_completed = 0;
do {
// Check if handshake operation has timed out
if (handshake_has_timed_out(start_time)) {
@@ -188,11 +184,13 @@
jtiwh.rewind();
MutexLocker ml(Threads_lock);
for (JavaThread *thr = jtiwh.next(); thr != NULL; thr = jtiwh.next()) {
// A new thread on the ThreadsList will not have an operation,
// hence it is skipped in handshake_process_by_vmthread.
- thr->handshake_process_by_vmthread();
+ if (thr->handshake_process_by_vmthread()) {
+ handshake_executed_by_vm_thread++;
+ }
}
}
while (poll_for_completed_thread()) {
// Includes canceled operations by exiting threads.
@@ -200,77 +198,83 @@
}
} while (number_of_threads_issued > number_of_threads_completed);
assert(number_of_threads_issued == number_of_threads_completed, "Must be the same");
DEBUG_ONLY(_op->check_state();)
+
+ log_handshake_info(start_time_ns, _op->name(), number_of_threads_issued, handshake_executed_by_vm_thread, "");
}
VMOp_Type type() const { return VMOp_HandshakeAllThreads; }
};
class VM_HandshakeFallbackOperation : public VM_Operation {
- ThreadClosure* _thread_cl;
+ HandshakeOperation* _hs_op;
Thread* _target_thread;
bool _all_threads;
bool _executed;
public:
- VM_HandshakeFallbackOperation(ThreadClosure* cl) :
- _thread_cl(cl), _target_thread(NULL), _all_threads(true), _executed(false) {}
- VM_HandshakeFallbackOperation(ThreadClosure* cl, Thread* target) :
- _thread_cl(cl), _target_thread(target), _all_threads(false), _executed(false) {}
+ VM_HandshakeFallbackOperation(HandshakeOperation* hs_op) :
+ _hs_op(hs_op), _target_thread(NULL), _all_threads(true), _executed(false) {}
+ VM_HandshakeFallbackOperation(HandshakeOperation* hs_op, Thread* target) :
+ _hs_op(hs_op), _target_thread(target), _all_threads(false), _executed(false) {}
void doit() {
- log_trace(handshake)("VMThread executing VM_HandshakeFallbackOperation");
+ log_trace(handshake)("VMThread executing VM_HandshakeFallbackOperation, operation: %s", name());
for (JavaThreadIteratorWithHandle jtiwh; JavaThread *t = jtiwh.next(); ) {
if (_all_threads || t == _target_thread) {
if (t == _target_thread) {
_executed = true;
}
- _thread_cl->do_thread(t);
+ _hs_op->do_thread(t);
}
}
}
VMOp_Type type() const { return VMOp_HandshakeFallback; }
bool executed() const { return _executed; }
};
-void HandshakeThreadsOperation::do_handshake(JavaThread* thread) {
- ResourceMark rm;
- FormatBufferResource message("Operation for thread " PTR_FORMAT ", is_vm_thread: %s",
- p2i(thread), BOOL_TO_STR(Thread::current()->is_VM_thread()));
- TraceTime timer(message, TRACETIME_LOG(Debug, handshake, task));
+void HandshakeOperation::do_handshake(JavaThread* thread) {
+ jlong start_time_ns = 0;
+ if (log_is_enabled(Debug, handshake, task)) {
+ start_time_ns = os::javaTimeNanos();
+ }
// Only actually execute the operation for non terminated threads.
if (!thread->is_terminated()) {
- _thread_cl->do_thread(thread);
+ do_thread(thread);
_executed = true;
}
// Use the semaphore to inform the VM thread that we have completed the operation
_done.signal();
+
+ if (start_time_ns != 0) {
+ jlong completion_time = os::javaTimeNanos() - start_time_ns;
+ log_debug(handshake, task)("Operation: %s for thread " PTR_FORMAT ", is_vm_thread: %s, completed in " JLONG_FORMAT " ns",
+ name(), p2i(thread), BOOL_TO_STR(Thread::current()->is_VM_thread()), completion_time);
+ }
}
-void Handshake::execute(ThreadClosure* thread_cl) {
+void Handshake::execute(HandshakeOperation* hs_op) {
if (ThreadLocalHandshakes) {
- HandshakeThreadsOperation cto(thread_cl);
- VM_HandshakeAllThreads handshake(&cto);
+ VM_HandshakeAllThreads handshake(hs_op);
VMThread::execute(&handshake);
} else {
- VM_HandshakeFallbackOperation op(thread_cl);
+ VM_HandshakeFallbackOperation op(hs_op);
VMThread::execute(&op);
}
}
-bool Handshake::execute(ThreadClosure* thread_cl, JavaThread* target) {
+bool Handshake::execute(HandshakeOperation* hs_op, JavaThread* target) {
if (ThreadLocalHandshakes) {
- HandshakeThreadsOperation cto(thread_cl);
- VM_HandshakeOneThread handshake(&cto, target);
+ VM_HandshakeOneThread handshake(hs_op, target);
VMThread::execute(&handshake);
return handshake.executed();
} else {
- VM_HandshakeFallbackOperation op(thread_cl, target);
+ VM_HandshakeFallbackOperation op(hs_op, target);
VMThread::execute(&op);
return op.executed();
}
}
@@ -344,39 +348,43 @@
}
_semaphore.signal();
return false;
}
-void HandshakeState::process_by_vmthread(JavaThread* target) {
+bool HandshakeState::process_by_vmthread(JavaThread* target) {
assert(Thread::current()->is_VM_thread(), "should call from vm thread");
// Threads_lock must be held here, but that is assert()ed in
// possibly_vmthread_can_process_handshake().
if (!has_operation()) {
// JT has already cleared its handshake
- return;
+ return false;
}
if (!possibly_vmthread_can_process_handshake(target)) {
// JT is observed in an unsafe state, it must notice the handshake itself
- return;
+ return false;
}
// Claim the semaphore if there still an operation to be executed.
if (!claim_handshake_for_vmthread()) {
- return;
+ return false;
}
// If we own the semaphore at this point and while owning the semaphore
// can observe a safe state the thread cannot possibly continue without
// getting caught by the semaphore.
+ bool executed = false;
if (vmthread_can_process_handshake(target)) {
guarantee(!_semaphore.trywait(), "we should already own the semaphore");
log_trace(handshake)("Processing handshake by VMThtread");
_operation->do_handshake(target);
// Disarm after VM thread have executed the operation.
clear_handshake(target);
- // Release the thread
+ executed = true;
}
+ // Release the thread
_semaphore.signal();
+
+ return executed;
}
< prev index next >