< prev index next >

src/hotspot/share/runtime/handshake.cpp

Print this page
rev 57079 : [mq]: handshake-logs

*** 30,80 **** #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); 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; ! VM_Handshake(HandshakeThreadsOperation* op) : _handshake_timeout(TimeHelper::millis_to_counter(HandshakeTimeout)), _op(op) {} void set_handshake(JavaThread* target) { target->set_handshake_operation(_op); } --- 30,57 ---- #include "runtime/interfaceSupport.inline.hpp" #include "runtime/orderAccess.hpp" #include "runtime/osThread.hpp" #include "runtime/semaphore.inline.hpp" #include "runtime/task.hpp" #include "runtime/thread.hpp" #include "runtime/vmThread.hpp" #include "utilities/formatBuffer.hpp" #include "utilities/preserveException.hpp" ! 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: ! HandshakeOperation* const _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,177 **** } log_stream.flush(); fatal("Handshake operation timed out"); } class VM_HandshakeOneThread: public VM_Handshake { JavaThread* _target; public: ! VM_HandshakeOneThread(HandshakeThreadsOperation* 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)); ThreadsListHandle tlh; if (tlh.includes(_target)) { set_handshake(_target); } else { ! log_trace(handshake)("JavaThread " INTPTR_FORMAT " is not alive", p2i(_target)); return; } log_trace(handshake)("JavaThread " INTPTR_FORMAT " signaled, begin attempt to process by VMThtread", p2i(_target)); ! jlong start_time = os::elapsed_counter(); do { ! if (handshake_has_timed_out(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(); } } while (!poll_for_completed_thread()); DEBUG_ONLY(_op->check_state();) } 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) {} void doit() { DEBUG_ONLY(_op->check_state();) ! TraceTime timer("Finished executing multi-target operation (VM_HandshakeAllThreads::doit)", TRACETIME_LOG(Info, handshake)); 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."); return; } ! log_debug(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)) { --- 83,173 ---- } 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(HandshakeOperation* op, JavaThread* target) : VM_Handshake(op), _target(target) {} void doit() { DEBUG_ONLY(_op->check_state();) ! ! 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_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 timeout_start_time = os::elapsed_counter(); ! bool by_vm_thread = false; do { ! 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); ! 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(HandshakeOperation* op) : VM_Handshake(op) {} void doit() { DEBUG_ONLY(_op->check_state();) ! ! 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_trace(handshake)("No threads to handshake."); return; } ! 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,198 **** 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(); } } while (poll_for_completed_thread()) { // Includes canceled operations by exiting threads. --- 184,196 ---- 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. ! if (thr->handshake_process_by_vmthread()) { ! handshake_executed_by_vm_thread++; ! } } } while (poll_for_completed_thread()) { // Includes canceled operations by exiting threads.
*** 200,276 **** } } 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();) } VMOp_Type type() const { return VMOp_HandshakeAllThreads; } }; class VM_HandshakeFallbackOperation : public VM_Operation { ! ThreadClosure* _thread_cl; 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) {} void doit() { ! log_trace(handshake)("VMThread executing VM_HandshakeFallbackOperation"); for (JavaThreadIteratorWithHandle jtiwh; JavaThread *t = jtiwh.next(); ) { if (_all_threads || t == _target_thread) { if (t == _target_thread) { _executed = true; } ! _thread_cl->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)); // Only actually execute the operation for non terminated threads. if (!thread->is_terminated()) { ! _thread_cl->do_thread(thread); _executed = true; } // Use the semaphore to inform the VM thread that we have completed the operation _done.signal(); } ! void Handshake::execute(ThreadClosure* thread_cl) { if (ThreadLocalHandshakes) { ! HandshakeThreadsOperation cto(thread_cl); ! VM_HandshakeAllThreads handshake(&cto); VMThread::execute(&handshake); } else { ! VM_HandshakeFallbackOperation op(thread_cl); VMThread::execute(&op); } } ! bool Handshake::execute(ThreadClosure* thread_cl, JavaThread* target) { if (ThreadLocalHandshakes) { ! HandshakeThreadsOperation cto(thread_cl); ! VM_HandshakeOneThread handshake(&cto, target); VMThread::execute(&handshake); return handshake.executed(); } else { ! VM_HandshakeFallbackOperation op(thread_cl, target); VMThread::execute(&op); return op.executed(); } } --- 198,280 ---- } } 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 { ! HandshakeOperation* _hs_op; Thread* _target_thread; bool _all_threads; bool _executed; public: ! 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, operation: %s", name()); for (JavaThreadIteratorWithHandle jtiwh; JavaThread *t = jtiwh.next(); ) { if (_all_threads || t == _target_thread) { if (t == _target_thread) { _executed = true; } ! _hs_op->do_thread(t); } } } VMOp_Type type() const { return VMOp_HandshakeFallback; } bool executed() const { return _executed; } }; ! 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()) { ! 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(HandshakeOperation* hs_op) { if (ThreadLocalHandshakes) { ! VM_HandshakeAllThreads handshake(hs_op); VMThread::execute(&handshake); } else { ! VM_HandshakeFallbackOperation op(hs_op); VMThread::execute(&op); } } ! bool Handshake::execute(HandshakeOperation* hs_op, JavaThread* target) { if (ThreadLocalHandshakes) { ! VM_HandshakeOneThread handshake(hs_op, target); VMThread::execute(&handshake); return handshake.executed(); } else { ! VM_HandshakeFallbackOperation op(hs_op, target); VMThread::execute(&op); return op.executed(); } }
*** 344,382 **** } _semaphore.signal(); return false; } ! void 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; } if (!possibly_vmthread_can_process_handshake(target)) { // JT is observed in an unsafe state, it must notice the handshake itself ! return; } // Claim the semaphore if there still an operation to be executed. if (!claim_handshake_for_vmthread()) { ! return; } // 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. 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 } _semaphore.signal(); } --- 348,390 ---- } _semaphore.signal(); return false; } ! 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 false; } if (!possibly_vmthread_can_process_handshake(target)) { // JT is observed in an unsafe state, it must notice the handshake itself ! return false; } // Claim the semaphore if there still an operation to be executed. if (!claim_handshake_for_vmthread()) { ! 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); ! executed = true; } + // Release the thread _semaphore.signal(); + + return executed; }
< prev index next >