Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[master] DeadLock detection diagnostic - WriteLockManager.acquireLocksForClonemessage change #2373

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

rfelcman
Copy link
Contributor

Fixes #2173
There is incorrect log output in case if deadlock is detected and dump triggered in WriteLockManager.acquireLocksForClonemessage(). Mentioned method acquire read lock instead of write lock -> logged output was incorrect.
See log output before

...
Concurrency manager - Page 01 end - thread dump about all threads at time of event
Concurrency manager - Page 02 start - information about threads waiting to acquire (write/deferred) cache keys 
Total number of threads waiting to acquire lock: 1

[currentThreadNumber: 1] [ThreadName: main]: Waiting to acquire (write/deferred): --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1680621693) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 452415295) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 89) (concurrencyManagerCreationDate: 2025-02-27 10:37:09.693)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) ---
[methodNameThatGotStuckWaitingToAcquire: org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(...)] 
Concurrency manager - Page 02 end - information about threads waiting to acquire (write/deferred) cache keys
Concurrency manager - Page 03 start - information about threads waiting to acquire read cache keys 
Total number of threads waiting to acquire read locks: 0 

Concurrency manager - Page 03 end - information about threads waiting to acquire read cache keys
Concurrency manager - Page 04 start - information about threads waiting on release deferred locks (waiting for other thread to finish building the objects deferred) 
Total number of threads waiting to acquire lock: 0 

Concurrency manager - Page 04 end - information about threads waiting on release deferred locks (waiting for other thread to finish building the objects deferred)
Concurrency manager - Page 05 start (currentThreadNumber: 1 of totalNumberOfThreads: 1)  - detailed information about specific thread 
Thread: main
ThreadWaitingToReleaseDeferredLocks: false
 waitingOnAcquireWritingCacheKey: true  waiting to acquire writing: --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1680621693) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 452415295) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 89) (concurrencyManagerCreationDate: 2025-02-27 10:37:09.693)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) ---
 waitingOnAcquireReadCacheKey: false
 writeManagerThreadPrimaryKeysWithChangesToBeMerged: false
Summary of active locks owned by thread main Listing of all ACTIVE Locks.
Thread Name: main 
0 Active locks. The lockManager for this thread is null. 

Summary of deferred locks (could not be acquired and cause thread to wait for object building to complete) of thread main Listing of all DEFERRED Locks.
Thread Name: main 
0 deferred locks. The lockManager for this thread is null. 

 waitingToReleaseDeferredLocksJustification: information not available. 
Summary of read locks acquired by thread main Listing of all READ Locks. Step 001 - sparse summary loop over all read locks acquired:
Thread Name: main 
0 read locks. The lockManager for this thread is null. 

Concurrency manager - Page 05 end (currentThreadNumber: 1 of totalNumberOfThreads: 1)  - detailed information about specific thread
Concurrency manager - Page 06 start - information about cache keys and threads needing them 
Total number of cacheKeys to describe: 1 

-------------- [currentCacheKeyNumber: 1 of 1]--------------
[currentCacheKeyNumber: 1] [CacheKey: --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1680621693) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 452415295) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 89) (concurrencyManagerCreationDate: 2025-02-27 10:37:09.693)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) --- ]:
[currentCacheKeyNumber: 1] threadsThatAcquiredActiveLock: []
[currentCacheKeyNumber: 1] threadsThatAcquiredDeferredLock: []
[currentCacheKeyNumber: 1] threadsThatAcquiredReadLock:  []
[currentCacheKeyNumber: 1] threadsKnownToBeStuckTryingToAcquireLock:  [main]
[currentCacheKeyNumber: 1] threadsKnownToBeStuckTryingToAcquireLockForReading:  []
[currentCacheKeyNumber: 1] threads doing object building with root on this cache key (not yet supported)...

Concurrency manager - Page 06 end - information about cache keys and threads needing them
Concurrency manager - Page 07 start - dead lock explanation
We were not able to determine to determine a set of threads that went into dead lock.deadlock algorithm took 1 ms to try to find deadlock.
Concurrency manager - Page 07 end - dead lock explanation
Concurrency manager - Page 08 start - Threads in MergeManager Acquiring Cache Keys for Clones to be merged into eclipselink server session cache of originals
 This section provides information about threads within the MergeManager that require cache keys for merging clones with changes.
 Specifically, it focuses on the threads working in the context of an ObjectChangeSet where the server session CacheKey is found to still have CacheKy.object null,
 and the CacheKey is acquired by a competing thread (typically an ObjectBuilder thread).
Total number of threads waiting to see lock being released: 0

Concurrency manager - Page 08 end - Threads in MergeManager Acquiring Cache Keys for Clones to be merged into eclipselink server session cache of originals
End full concurrency manager state (massive) dump No: 1
...

and after change

...
Concurrency manager - Page 01 end - thread dump about all threads at time of event
Concurrency manager - Page 02 start - information about threads waiting to acquire (write/deferred) cache keys 
Total number of threads waiting to acquire lock: 0

Concurrency manager - Page 02 end - information about threads waiting to acquire (write/deferred) cache keys
Concurrency manager - Page 03 start - information about threads waiting to acquire read cache keys 
Total number of threads waiting to acquire read locks: 1 

[currentThreadNumber: 1] [ThreadName: main ]: Waiting to acquire (read lock): --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1224595497) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 1147061049) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 66) (concurrencyManagerCreationDate: 2025-02-27 11:28:07.714)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) ---
[methodNameThatGotStuckWaitingToAcquire: org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(...)]  
Concurrency manager - Page 03 end - information about threads waiting to acquire read cache keys
Concurrency manager - Page 04 start - information about threads waiting on release deferred locks (waiting for other thread to finish building the objects deferred) 
Total number of threads waiting to acquire lock: 0 

Concurrency manager - Page 04 end - information about threads waiting on release deferred locks (waiting for other thread to finish building the objects deferred)
Concurrency manager - Page 05 start (currentThreadNumber: 1 of totalNumberOfThreads: 1)  - detailed information about specific thread 
Thread: main
ThreadWaitingToReleaseDeferredLocks: false
 waitingOnAcquireWritingCacheKey: false
 waitingOnAcquireReadCacheKey: true   waiting to acquire reading: --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1224595497) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 1147061049) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 66) (concurrencyManagerCreationDate: 2025-02-27 11:28:07.714)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) ---
 writeManagerThreadPrimaryKeysWithChangesToBeMerged: false
Summary of active locks owned by thread main Listing of all ACTIVE Locks.
Thread Name: main 
0 Active locks. The lockManager for this thread is null. 

Summary of deferred locks (could not be acquired and cause thread to wait for object building to complete) of thread main Listing of all DEFERRED Locks.
Thread Name: main 
0 deferred locks. The lockManager for this thread is null. 

 waitingToReleaseDeferredLocksJustification: information not available. 
Summary of read locks acquired by thread main Listing of all READ Locks. Step 001 - sparse summary loop over all read locks acquired:
Thread Name: main 
0 read locks. The lockManager for this thread is null. 

Concurrency manager - Page 05 end (currentThreadNumber: 1 of totalNumberOfThreads: 1)  - detailed information about specific thread
Concurrency manager - Page 06 start - information about cache keys and threads needing them 
Total number of cacheKeys to describe: 1 

-------------- [currentCacheKeyNumber: 1 of 1]--------------
[currentCacheKeyNumber: 1] [CacheKey: --- CacheKey  (org.eclipse.persistence.testing.models.jpa.deadlock.diagnostic.CacheDeadLockDetectionMaster):  (primaryKey: 1) (object hash code: 1224595497) (cacheKeyClass: org.eclipse.persistence.internal.identitymaps.HardCacheWeakIdentityMap.ReferenceCacheKey) (cacheKey hash code: 1147061049) (current cache key owner/activeThread: main) (getNumberOfReaders: 0)  (concurrencyManagerId: 66) (concurrencyManagerCreationDate: 2025-02-27 11:28:07.714)  (totalNumberOfTimeCacheKeyAcquiredForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReading:  3)  (totalNumberOfTimeCacheKeyReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero:  0)  (depth: 1) --- ]:
[currentCacheKeyNumber: 1] threadsThatAcquiredActiveLock: []
[currentCacheKeyNumber: 1] threadsThatAcquiredDeferredLock: []
[currentCacheKeyNumber: 1] threadsThatAcquiredReadLock:  []
[currentCacheKeyNumber: 1] threadsKnownToBeStuckTryingToAcquireLock:  []
[currentCacheKeyNumber: 1] threadsKnownToBeStuckTryingToAcquireLockForReading:  [main]
[currentCacheKeyNumber: 1] threads doing object building with root on this cache key (not yet supported)...

Concurrency manager - Page 06 end - information about cache keys and threads needing them
Concurrency manager - Page 07 start - dead lock explanation
We were not able to determine to determine a set of threads that went into dead lock.deadlock algorithm took 1 ms to try to find deadlock.
Concurrency manager - Page 07 end - dead lock explanation
Concurrency manager - Page 08 start - Threads in MergeManager Acquiring Cache Keys for Clones to be merged into eclipselink server session cache of originals
 This section provides information about threads within the MergeManager that require cache keys for merging clones with changes.
 Specifically, it focuses on the threads working in the context of an ObjectChangeSet where the server session CacheKey is found to still have CacheKy.object null,
 and the CacheKey is acquired by a competing thread (typically an ObjectBuilder thread).
Total number of threads waiting to see lock being released: 0

Concurrency manager - Page 08 end - Threads in MergeManager Acquiring Cache Keys for Clones to be merged into eclipselink server session cache of originals
End full concurrency manager state (massive) dump No: 1
...

This change is also covered by org.eclipse.persistence.testing.tests.jpa.deadlock.diagnostic.CacheDeadLockManagersTest#testWriteLockManagerAcquireLocksForClone test.

@rfelcman
Copy link
Contributor Author

Complete log output is there.
logOutput.tar.gz

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
1 participant