Skip to content
This repository has been archived by the owner. It is now read-only.

8273107: RunThese24H times out with "java.lang.management.ThreadInfo.getLockName()" is null #25

Closed
wants to merge 4 commits into from
Closed
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
@@ -63,6 +63,6 @@ void MonitorDeflationThread::monitor_deflation_thread_entry(JavaThread* jt, TRAP
}
}

(void)ObjectSynchronizer::deflate_idle_monitors();
(void)ObjectSynchronizer::deflate_idle_monitors(/* ObjectMonitorsHashtable is not needed here */ nullptr);
}
}
@@ -57,6 +57,44 @@
#include "utilities/events.hpp"
#include "utilities/preserveException.hpp"

class CleanupObjectMonitorsHashtable: StackObj {
public:
bool do_entry(JavaThread*& key, ObjectMonitorsHashtable::PtrList*& list) {
Copy link
Member

@dholmes-ora dholmes-ora Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't see this being called by anything ???

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See L71 below: _ptrs->unlink(&cleanup); // cleanup the LinkedLists
That passes the cleanup object to ResourceHashtable::unlink()
function which calls the do_entry() function in the cleanup object.

Copy link
Member

@dholmes-ora dholmes-ora Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah I see (well I don't really see as this is very obscure). I would have expected CleanupObjectMonitorsHashtable to be a subtype of something that I could then see is used by the ResourceHashtable. I'm going to guess that there is some template usage here that ensures the passed in object has the right API even if there is no subtyping relationship. Hard to see these connections at a distance.

To be clear not a review as I don't understand our Hashtable's enough to make much sense of what is actually happening here.

Copy link
Contributor

@coleenp coleenp Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be a nice place for a lambda (on the list of future RFEs). You could also put this class in scope of the function that calls it which might help. (optional)

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ResourceHashtable::unlink() is definitely one of those template
things that I don't really like, but I have to use it... All that stuff
is in src/hotspot/share/utilities/resourceHash.hpp, but I don't
see any precedent for putting the CleanupObjectMonitorsHashtable
definition in there. I think I'll leave it where it is.

list->clear(); // clear the LinkListNodes
delete list; // then delete the LinkedList
return true;
}
};

ObjectMonitorsHashtable::~ObjectMonitorsHashtable() {
CleanupObjectMonitorsHashtable cleanup;
_ptrs->unlink(&cleanup); // cleanup the LinkedLists
delete _ptrs; // then delete the hash table
}

void ObjectMonitorsHashtable::add_entry(JavaThread* jt, ObjectMonitor* om) {
ObjectMonitorsHashtable::PtrList* list = get_entry(jt);
if (list != nullptr) {
// Add to existing list from the hash table:
list->add(om);
Copy link

@fisk fisk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These two lines are executed in both the if and else clause. Consider putting it after instead.

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll take a look at doing that. Thanks for the suggestion.

_om_count++;
} else {
// Create new list, add the ObjectMonitor* to it, and add the list to the hash table:
list = new (ResourceObj::C_HEAP, mtThread) ObjectMonitorsHashtable::PtrList();
list->add(om);
_om_count++;
add_entry(jt, list);
}
}

bool ObjectMonitorsHashtable::has_entry(JavaThread* jt, ObjectMonitor* om) {
ObjectMonitorsHashtable::PtrList* list = get_entry(jt);
if (list == nullptr || list->find(om) == nullptr) {
return false;
}
return true;
}

void MonitorList::add(ObjectMonitor* m) {
ObjectMonitor* head;
do {
@@ -992,6 +1030,8 @@ JavaThread* ObjectSynchronizer::get_lock_owner(ThreadsList * t_list, Handle h_ob

// Visitors ...

// This version of monitors_iterate() works with the in-use monitor list.
//
void ObjectSynchronizer::monitors_iterate(MonitorClosure* closure, JavaThread* thread) {
MonitorList::Iterator iter = _in_use_list.iterator();
while (iter.has_next()) {
@@ -1013,6 +1053,30 @@ void ObjectSynchronizer::monitors_iterate(MonitorClosure* closure, JavaThread* t
}
}

// This version of monitors_iterate() works with the specified linked list.
//
void ObjectSynchronizer::monitors_iterate(MonitorClosure* closure,
ObjectMonitorsHashtable::PtrList* list,
JavaThread* thread) {
typedef LinkedListIterator<ObjectMonitor*> ObjectMonitorIterator;
ObjectMonitorIterator iter = ObjectMonitorIterator(list->head());
Copy link

@fisk fisk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seems to create an object and then copy it to iter. I think the more obvious syntax is ObjectMonitorIterator iter(list->head());

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice catch. I'll fix that.

while (!iter.is_empty()) {
ObjectMonitor* mid = *iter.next();
assert(mid->owner() == thread, "must be");
if (!mid->is_being_async_deflated() && mid->object_peek() != NULL) {
// Only process with closure if the object is set.

// monitors_iterate() is only called at a safepoint or when the
// target thread is suspended or when the target thread is
// operating on itself. The current closures in use today are
// only interested in an owned ObjectMonitor and ownership
// cannot be dropped under the calling contexts so the
// ObjectMonitor cannot be async deflated.
closure->do_monitor(mid);
}
}
}

static bool monitors_used_above_threshold(MonitorList* list) {
if (MonitorUsedDeflationThreshold == 0) { // disabled case is easy
return false;
@@ -1339,7 +1403,8 @@ void ObjectSynchronizer::chk_for_block_req(JavaThread* current, const char* op_n
// Walk the in-use list and deflate (at most MonitorDeflationMax) idle
// ObjectMonitors. Returns the number of deflated ObjectMonitors.
size_t ObjectSynchronizer::deflate_monitor_list(Thread* current, LogStream* ls,
elapsedTimer* timer_p) {
elapsedTimer* timer_p,
ObjectMonitorsHashtable* table) {
MonitorList::Iterator iter = _in_use_list.iterator();
size_t deflated_count = 0;

@@ -1350,6 +1415,15 @@ size_t ObjectSynchronizer::deflate_monitor_list(Thread* current, LogStream* ls,
ObjectMonitor* mid = iter.next();
if (mid->deflate_monitor()) {
deflated_count++;
} else if (table != nullptr) {
// The caller is interested in the owned ObjectMonitors. This does not capture
// unowned ObjectMonitors that cannot be deflated because of a waiter. Since
// deflate_idle_monitors() and deflate_monitor_list() can be called more than
// once, we have to make sure the entry has not already been added.
JavaThread* jt = (JavaThread*)mid->owner();
Copy link

@fisk fisk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmmmm. I'm not sure this is correct. The owned of an ObjectMonitor is a JavaThread most of the time, but not always. I think that if the owner started off with a stack lock, and another thread inflated the lock due to contention, then the ObjectMonitor will get the stack lock as the owner, as the random other thread is too lazy to look up which thread stack the stack lock belongs to.

Because of that, I think we might miss locks that really are owned by a thread, as the thread key now will not map to such locks. Some kind of ownership lookup probably needs to happen here.

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice catch on an oddity of ObjectMonitor ownership!

The baseline code has the same "issue":

void ObjectSynchronizer::monitors_iterate(MonitorClosure* closure, JavaThread* thread) {

<snip>

    ObjectMonitor* mid = iter.next();
    if (mid->owner() != thread) {
      continue;
    }

Please notice that I said "issue" and not "bug". This isn't a bug and you really
won't like the reason that it's not a bug. I know that I don't like it...

Because of this ownership check monitors_iterate() won't apply the closure
(InflatedMonitorsClosure in this case) to an ObjectMonitor that is marked as
owned by a stack lock address because it will never match the target JavaThread*.

Here's the closure:

// Iterate through monitor cache to find JNI locked monitors
class InflatedMonitorsClosure: public MonitorClosure {
private:
  ThreadStackTrace* _stack_trace;
public:
  InflatedMonitorsClosure(ThreadStackTrace* st) {
    _stack_trace = st;
  }
  void do_monitor(ObjectMonitor* mid) {
    oop object = mid->object();
    if (!_stack_trace->is_owned_monitor_on_stack(object)) {
      _stack_trace->add_jni_locked_monitor(object);
    }
  }
};

This particular monitors_iterate() call uses InflatedMonitorsClosure to
gather just the JNI locked monitors owned by the target JavaThread*.
A JNI locked monitor will never have a stack lock address as its owner
marking. It will always have a JavaThread*. So the baseline code isn't
"broken" because it will find the JNI locked monitors just fine. Similarly
the new code isn't "broken" because it will also find the JNI locked
monitors just fine.

I definitely need to clarify the baseline comments and the new code
comments to make this subtlety much more clear.

if (jt != nullptr && !table->has_entry(jt, mid)) {
table->add_entry(jt, mid);
}
}

if (current->is_Java_thread()) {
@@ -1374,8 +1448,8 @@ class HandshakeForDeflation : public HandshakeClosure {

// This function is called by the MonitorDeflationThread to deflate
// ObjectMonitors. It is also called via do_final_audit_and_print_stats()
// by the VMThread.
size_t ObjectSynchronizer::deflate_idle_monitors() {
// and VM_ThreadDump::doit() by the VMThread.
size_t ObjectSynchronizer::deflate_idle_monitors(ObjectMonitorsHashtable* table) {
Thread* current = Thread::current();
if (current->is_Java_thread()) {
// The async deflation request has been processed.
@@ -1400,7 +1474,7 @@ size_t ObjectSynchronizer::deflate_idle_monitors() {
}

// Deflate some idle ObjectMonitors.
size_t deflated_count = deflate_monitor_list(current, ls, &timer);
size_t deflated_count = deflate_monitor_list(current, ls, &timer, table);
if (deflated_count > 0 || is_final_audit()) {
// There are ObjectMonitors that have been deflated or this is the
// final audit and all the remaining ObjectMonitors have been
@@ -1458,6 +1532,10 @@ size_t ObjectSynchronizer::deflate_idle_monitors() {
}
ls->print_cr("end deflating: in_use_list stats: ceiling=" SIZE_FORMAT ", count=" SIZE_FORMAT ", max=" SIZE_FORMAT,
in_use_list_ceiling(), _in_use_list.count(), _in_use_list.max());
if (table != nullptr) {
ls->print_cr("ObjectMonitorsHashtable: jt_count=" SIZE_FORMAT ", om_count=" SIZE_FORMAT,
table->jt_count(), table->om_count());
}
}

OM_PERFDATA_OP(MonExtant, set_value(_in_use_list.count()));
@@ -1560,7 +1638,7 @@ void ObjectSynchronizer::do_final_audit_and_print_stats() {
// Do a deflation in order to reduce the in-use monitor population
// that is reported by ObjectSynchronizer::log_in_use_monitor_details()
// which is called by ObjectSynchronizer::audit_and_print_stats().
while (ObjectSynchronizer::deflate_idle_monitors() != 0) {
while (ObjectSynchronizer::deflate_idle_monitors(/* ObjectMonitorsHashtable is not needed here */ nullptr) >= (size_t)MonitorDeflationMax) {
; // empty
}
// The other audit_and_print_stats() call is done at the Debug
@@ -30,11 +30,68 @@
#include "runtime/basicLock.hpp"
#include "runtime/handles.hpp"
#include "utilities/growableArray.hpp"
#include "utilities/linkedlist.hpp"
#include "utilities/resourceHash.hpp"

class LogStream;
class ObjectMonitor;
class ThreadsList;

// Hash table of JavaThread* to a list of ObjectMonitor* owned by the JavaThread*.
//
class ObjectMonitorsHashtable {
private:
static unsigned int ptr_hash(JavaThread* const& s1) {
// 2654435761 = 2^32 * Phi (golden ratio)
return (unsigned int)(((uint32_t)(uintptr_t)s1) * 2654435761u);
}

public:
typedef LinkedListImpl<ObjectMonitor*,
ResourceObj::C_HEAP, mtThread,
AllocFailStrategy::RETURN_NULL> PtrList;

// ResourceHashtable SIZE is specified at compile time so we
// use 1031 which is the first prime after 1024.
typedef ResourceHashtable<JavaThread*, PtrList*, 1031,
ResourceObj::C_HEAP, mtThread,
&ObjectMonitorsHashtable::ptr_hash> PtrTable;
private:
PtrTable* _ptrs;
size_t _jt_count;
size_t _om_count;

public:
// ResourceHashtable is passed to various functions and populated in
// different places so we allocate it using C_HEAP to make it immune
// from any ResourceMarks that happen to be in the code paths.
ObjectMonitorsHashtable() : _ptrs(new (ResourceObj::C_HEAP, mtThread) PtrTable()), _jt_count(0), _om_count(0) {}

~ObjectMonitorsHashtable();

void add_entry(JavaThread* jt, ObjectMonitor* om);

void add_entry(JavaThread* jt, PtrList* list) {
_ptrs->put(jt, list);
_jt_count++;
}

PtrList* get_entry(JavaThread* jt) {
PtrList** listpp = _ptrs->get(jt);
return (listpp == nullptr) ? nullptr : *listpp;
}

bool has_entry(JavaThread* jt) {
PtrList** listpp = _ptrs->get(jt);
return listpp != nullptr && *listpp != nullptr;
}

bool has_entry(JavaThread* jt, ObjectMonitor* om);

size_t jt_count() { return _jt_count; }
size_t om_count() { return _om_count; }
};

class MonitorList {
friend class VMStructs;

@@ -133,21 +190,26 @@ class ObjectSynchronizer : AllStatic {

// JNI detach support
static void release_monitors_owned_by_thread(JavaThread* current);
// This version of monitors_iterate() works with the in-use monitor list.
static void monitors_iterate(MonitorClosure* m, JavaThread* thread);
// This version of monitors_iterate() works with the specified linked list.
static void monitors_iterate(MonitorClosure* closure,
ObjectMonitorsHashtable::PtrList* list,
JavaThread* thread);

// Initialize the gInflationLocks
static void initialize();

// GC: we current use aggressive monitor deflation policy
// GC: we currently use aggressive monitor deflation policy
// Basically we try to deflate all monitors that are not busy.
static size_t deflate_idle_monitors();
static size_t deflate_idle_monitors(ObjectMonitorsHashtable* table);

// Deflate idle monitors:
static void chk_for_block_req(JavaThread* current, const char* op_name,
const char* cnt_name, size_t cnt, LogStream* ls,
elapsedTimer* timer_p);
static size_t deflate_monitor_list(Thread* current, LogStream* ls,
elapsedTimer* timer_p);
static size_t deflate_monitor_list(Thread* current, LogStream* ls, elapsedTimer* timer_p,
ObjectMonitorsHashtable* table);
static size_t in_use_list_ceiling();
static void dec_in_use_list_ceiling();
static void inc_in_use_list_ceiling();
@@ -279,6 +279,18 @@ void VM_ThreadDump::doit() {
concurrent_locks.dump_at_safepoint();
}

ObjectMonitorsHashtable table;
ObjectMonitorsHashtable* tablep = nullptr;
Copy link

@robehn robehn Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like you can remove this pointer.
ThreadStackTrace::dump_stack_at_safepoint also looks at "with_locked_monitors", if false it ignores the table.
So there should not be any need to pass in null.

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Right now ThreadStackTrace::dump_stack_at_safepoint() is flexible in
that it does not require ObjectMonitorsHashtable* table to be non-null
when _with_locked_monitors is true.

From this call site, when _with_locked_monitors is true we always pass
a non-nullptr ObjectMonitorsHashtable* table and we do that because
we're at a safepoint and likely have to deal with a lot of threads if not all
the threads in the system.

For other ThreadStackTrace::dump_stack_at_safepoint() call sites,
I want things to be more flexible. Mostly because I haven't done
detailed analysis of them to justify changing their behavior.

if (_with_locked_monitors) {
// The caller wants locked monitor information and that's expensive to gather
// when there are a lot of inflated monitors. So we deflate idle monitors and
// gather information about owned monitors at the same time.
tablep = &table;
while (ObjectSynchronizer::deflate_idle_monitors(tablep) >= (size_t)MonitorDeflationMax) {
; /* empty */
}
}

if (_num_threads == 0) {
// Snapshot all live threads

@@ -293,7 +305,7 @@ void VM_ThreadDump::doit() {
if (_with_locked_synchronizers) {
tcl = concurrent_locks.thread_concurrent_locks(jt);
}
snapshot_thread(jt, tcl);
snapshot_thread(jt, tcl, tablep);
}
} else {
// Snapshot threads in the given _threads array
@@ -328,14 +340,15 @@ void VM_ThreadDump::doit() {
if (_with_locked_synchronizers) {
tcl = concurrent_locks.thread_concurrent_locks(jt);
}
snapshot_thread(jt, tcl);
snapshot_thread(jt, tcl, tablep);
}
}
}

void VM_ThreadDump::snapshot_thread(JavaThread* java_thread, ThreadConcurrentLocks* tcl) {
void VM_ThreadDump::snapshot_thread(JavaThread* java_thread, ThreadConcurrentLocks* tcl,
ObjectMonitorsHashtable* table) {
ThreadSnapshot* snapshot = _result->add_thread_snapshot(java_thread);
snapshot->dump_stack_at_safepoint(_max_depth, _with_locked_monitors);
snapshot->dump_stack_at_safepoint(_max_depth, _with_locked_monitors, table);
snapshot->set_concurrent_locks(tcl);
}

@@ -207,7 +207,8 @@ class VM_ThreadDump : public VM_Operation {
bool _with_locked_monitors;
bool _with_locked_synchronizers;

void snapshot_thread(JavaThread* java_thread, ThreadConcurrentLocks* tcl);
void snapshot_thread(JavaThread* java_thread, ThreadConcurrentLocks* tcl,
ObjectMonitorsHashtable* table);

public:
VM_ThreadDump(ThreadDumpResult* result,
@@ -2388,7 +2388,7 @@ void VM_HeapDumper::dump_stack_traces() {
HandleMark hm(current_thread);

ThreadStackTrace* stack_trace = new ThreadStackTrace(thread, false);
stack_trace->dump_stack_at_safepoint(-1);
stack_trace->dump_stack_at_safepoint(-1, /* ObjectMonitorsHashtable is not needed here */ nullptr);
_stack_traces[_num_threads++] = stack_trace;

// write HPROF_FRAME records for this thread's stack trace
@@ -659,7 +659,7 @@ ThreadStackTrace::~ThreadStackTrace() {
}
}

void ThreadStackTrace::dump_stack_at_safepoint(int maxDepth) {
void ThreadStackTrace::dump_stack_at_safepoint(int maxDepth, ObjectMonitorsHashtable* table) {
assert(SafepointSynchronize::is_at_safepoint(), "all threads are stopped");

if (_thread->has_last_Java_frame()) {
@@ -683,9 +683,17 @@ void ThreadStackTrace::dump_stack_at_safepoint(int maxDepth) {

if (_with_locked_monitors) {
// Iterate inflated monitors and find monitors locked by this thread
// not found in the stack
// and not found in the stack:
InflatedMonitorsClosure imc(this);
ObjectSynchronizer::monitors_iterate(&imc, _thread);
if (table != nullptr) {
// Get the ObjectMonitors locked by this thread (if any):
ObjectMonitorsHashtable::PtrList* list = table->get_entry(_thread);
if (list != nullptr) {
ObjectSynchronizer::monitors_iterate(&imc, list, _thread);
Copy link

@robehn robehn Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The InflatedMonitorsClosure walks the stack until object is found with this method:
ThreadStackTrace::is_owned_monitor_on_stack(oop object)
for every object...

If you instead just collect all locks on stack with one pass you don't have to walk the stack over and over, which should be major speedup.

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sounds like an interesting RFE, but I'd prefer that be investigated
separately from this bug.

Copy link
Member Author

@dcubed-ojdk dcubed-ojdk Dec 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Clarification: ThreadStackTrace::is_owned_monitor_on_stack() is not actually
walking the (JavaThread's) stack, but it is walking the collection of
StackFrameInfo objects that was gathered earlier in
ThreadStackTrace::dump_stack_at_safepoint(). Adding a gather-locked-monitor
helper object to the "add_stack_frame()" call would provide an easy hook and
then InflatedMonitorsClosure could use the new helper object. Something like
that anyway...

Copy link

@robehn robehn Dec 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, sorry, we loop the stack frame info for every object. I.e. a loop in a loop which is bad for time-complexity.
If the we created a sorted list from the frame info, we can binary search it instead.
Since a thread often only have at max a few locks, but could have hundreds of frames, just to be able skip looping over all frames without locks would be very beneficial.

}
} else {
ObjectSynchronizer::monitors_iterate(&imc, _thread);
}
}
}

@@ -936,9 +944,10 @@ ThreadSnapshot::~ThreadSnapshot() {
delete _concurrent_locks;
}

void ThreadSnapshot::dump_stack_at_safepoint(int max_depth, bool with_locked_monitors) {
void ThreadSnapshot::dump_stack_at_safepoint(int max_depth, bool with_locked_monitors,
ObjectMonitorsHashtable* table) {
_stack_trace = new ThreadStackTrace(_thread, with_locked_monitors);
_stack_trace->dump_stack_at_safepoint(max_depth);
_stack_trace->dump_stack_at_safepoint(max_depth, table);
}


@@ -247,7 +247,8 @@ class ThreadSnapshot : public CHeapObj<mtInternal> {
ThreadStackTrace* get_stack_trace() { return _stack_trace; }
ThreadConcurrentLocks* get_concurrent_locks() { return _concurrent_locks; }

void dump_stack_at_safepoint(int max_depth, bool with_locked_monitors);
void dump_stack_at_safepoint(int max_depth, bool with_locked_monitors,
ObjectMonitorsHashtable* table);
void set_concurrent_locks(ThreadConcurrentLocks* l) { _concurrent_locks = l; }
void metadata_do(void f(Metadata*));
};
@@ -270,7 +271,7 @@ class ThreadStackTrace : public CHeapObj<mtInternal> {
int get_stack_depth() { return _depth; }

void add_stack_frame(javaVFrame* jvf);
void dump_stack_at_safepoint(int max_depth);
void dump_stack_at_safepoint(int max_depth, ObjectMonitorsHashtable* table);
Handle allocate_fill_stack_trace_element_array(TRAPS);
void metadata_do(void f(Metadata*));
GrowableArray<OopHandle>* jni_locked_monitors() { return _jni_locked_monitors; }