RFR: 8334904: Add some perf counters to monitor the usage of VM locks [v2]

[Calvin Cheung]

On Wed, 3 Jul 2024 03:52:40 GMT, David Holmes <dholmes at openjdk.org> wrote:

> This isn't monitoring all VM locks only those used via `MutexLocker` - why?
 
For now, this only monitors the locks used via 'MutexLocker'.
Should I change the bug title to `Add some perf counters to monitor the usage of MutexLocker`?

> src/hotspot/share/logging/logTag.hpp line 216:
> 
>> 214:   LOG_TAG(verify) \
>> 215:   LOG_TAG(vmlocks) \
>> 216:   LOG_TAG(vmmutex) \
> 
> Why not just use the existing `vmmutex` tag?

Fixed. Now the logging is enabled via `-Xlog:perf+vmmutex`.

> src/hotspot/share/runtime/mutex.hpp line 101:
> 
>> 99:   PlatformMonitor _lock;                 // Native monitor implementation
>> 100:   const char* _name;                     // Name of mutex/monitor
>> 101:   int _id;                               // ID for named mutexes
> 
> It would be clearer if this were described in terms of how it is used - IIUC it is an index into the name array. `_id` is somewhat vague.

Yes, it is an index into the `_name` array. I've added some comments.

> src/hotspot/share/runtime/mutexLocker.cpp line 192:
> 
>> 190:   int id = _num_mutex++;
>> 191:   _mutex_array[id] = var;
>> 192:   var->set_id(id);
> 
> It is not obvious how the setting of the `_id` by the constructor interacts with this code. So IIUC the `_id` of each Mutex in the array is the Mutex's index into the array. So what does `_id` mean for mutexes that are not in the array?

This change is actually incorrect and unnecessary. The `name2Id()` function will set the Mutex's `_id` which will be used as an index into the `_names` and `_is_unique` array.

> src/hotspot/share/runtime/mutexLocker.cpp line 380:
> 
>> 378: static const int MAX_NAMES = 200;
>> 379: static const char* _names[MAX_NAMES] = { nullptr };
>> 380: static bool _is_unique[MAX_NAMES] = { false };
> 
> Some explanatory comments would be useful. Why do we need to duplicate all the names? What does the `is_unique` array signify? The way it is used in `name2Id` doesn't make sense to me.

The names in the `_names` array are not the same order as the named mutexes created from the `mutex_init()` function. There are mutexes created prior to the `mutex_init()` function. The `_is_unique` is to indicate whether a mutex is a singleton instance (e.g. the ones created from the `mutex_init()` function) or not (e.g. the startThread_lock).
I've added some comment in the above declarations.

> src/hotspot/share/runtime/mutexLocker.cpp line 387:
> 
>> 385: PerfCounter** MutexLockerImpl::_perf_lock_hold_time = nullptr;
>> 386: 
>> 387: void MutexLockerImpl::init_counters() {
> 
> It looks very odd to put an externally callable function in the Impl class. Impl classes are supposed to be private internal details.

I've converted `MutexLockerImpl::init_counters()` to a protected function and added a `MutexLocker::init_counters()` which calls `MutexLockerImpl::init_counters()`. In threads.cpp, it can just call `MutexLocker::init_counters()`.

> src/hotspot/share/runtime/mutexLocker.cpp line 410:
> 
>> 408:       NEWPERFEVENTCOUNTER(_perf_lock_hold_time[i + 1], SUN_RT, PerfDataManager::counter_name(counter_name, "AfterTime"));
>> 409:     }
>> 410:     if (HAS_PENDING_EXCEPTION) {
> 
> What code above could raise a Java exception??? I'm not sure the VM is initialized enough to throw an exception when this is called.

`NEWPERFEVENTCOUNTER` calls into the following which may throw an exception


PerfLongCounter* PerfDataManager::create_long_counter(CounterNS ns,
                                                      const char* name,
                                                      PerfData::Units u,
                                                      jlong ival, TRAPS) {

  PerfLongCounter* p = new PerfLongCounter(ns, name, u, ival);

  if (!p->is_valid()) {
    // allocation of native resources failed.
    delete p;
    THROW_0(vmSymbols::java_lang_OutOfMemoryError());
  }

> src/hotspot/share/runtime/mutexLocker.hpp line 196:
> 
>> 194:   bool _prof;
>> 195:   elapsedTimer _before;
>> 196:   elapsedTimer _after;
> 
> It would be a lot clearer if these were also called `_wait_time` and `_hold_time`! And add a descriptive comment.

I've changed them to `_wait_time` and `_hold_time` and added some comments.

> src/hotspot/share/runtime/thread.hpp line 643:
> 
>> 641:   VMErrorCallback* _vm_error_callbacks;
>> 642: 
>> 643:   bool  _profile_vm_locks;
> 
> It is not clear what role this plays - why do we only profile certain threads?

For now, we only profile the main thread.
It is used for determining whether to start and stop the "wait time" and "hold time" timers. (Please refer to changes in mutexLocker.hpp)

-------------

PR Comment: https://git.openjdk.org/jdk/pull/19954#issuecomment-2224210139
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674888165
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674888355
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674888673
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674888899
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674887565
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674887797
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674888015
PR Review Comment: https://git.openjdk.org/jdk/pull/19954#discussion_r1674889190