blob: 5ae4f25e7890cbca9620100c93773e35455ffa96 [file] [log] [blame]
/*
* Copyright (c) 2020, 2021 Oracle, IBM and/or its affiliates. All rights reserved.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License v. 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0,
* or the Eclipse Distribution License v. 1.0 which is available at
* http://www.eclipse.org/org/documents/edl-v10.php.
*
* SPDX-License-Identifier: EPL-2.0 OR BSD-3-Clause
*/
// Contributors:
// Oracle - initial API and implementation from Oracle TopLink
// IBM - ConcurrencyUtil call of ThreadMXBean.getThreadInfo() needs doPriv
package org.eclipse.persistence.internal.helper;
import org.eclipse.persistence.config.SystemProperties;
import org.eclipse.persistence.internal.helper.type.CacheKeyToThreadRelationships;
import org.eclipse.persistence.internal.helper.type.ConcurrencyManagerState;
import org.eclipse.persistence.internal.helper.type.DeadLockComponent;
import org.eclipse.persistence.internal.helper.type.ReadLockAcquisitionMetadata;
import org.eclipse.persistence.internal.identitymaps.CacheKey;
import org.eclipse.persistence.internal.localization.TraceLocalization;
import org.eclipse.persistence.internal.security.PrivilegedAccessHelper;
import org.eclipse.persistence.internal.security.PrivilegedGetSystemProperty;
import org.eclipse.persistence.internal.security.PrivilegedGetThreadInfo;
import org.eclipse.persistence.logging.AbstractSessionLog;
import org.eclipse.persistence.logging.SessionLog;
import java.io.StringWriter;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.security.AccessController;
import java.util.*;
import java.util.concurrent.atomic.AtomicLong;
public class ConcurrencyUtil {
public static final ConcurrencyUtil SINGLETON = new ConcurrencyUtil();
private static final long DEFAULT_ACQUIRE_WAIT_TIME = 0L;
private static final long DEFAULT_BUILD_OBJECT_COMPLETE_WAIT_TIME = 0L;
private static final long DEFAULT_MAX_ALLOWED_SLEEP_TIME_MS = 40000L;
private static final long DEFAULT_MAX_ALLOWED_FREQUENCY_TINY_DUMP_LOG_MESSAGE = 40000L;
private static final long DEFAULT_MAX_ALLOWED_FREQUENCY_MASSIVE_DUMP_LOG_MESSAGE = 60000L;
private static final boolean DEFAULT_INTERRUPTED_EXCEPTION_FIRED = true;
private static final boolean DEFAULT_CONCURRENCY_EXCEPTION_FIRED = true;
private static final boolean DEFAULT_TAKING_STACKTRACE_DURING_READ_LOCK_ACQUISITION = false;
public static final boolean DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING_CONCURRENCY = false;
public static final boolean DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS = false;
public static final int DEFAULT_CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS = 10;
public static final int DEFAULT_CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS = 2;
public static final long DEFAULT_CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT = 2000L;
public static final long DEFAULT_CONCURRENCY_SEMAPHORE_LOG_TIMEOUT = 10000L;
private long acquireWaitTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_ACQUIRE_WAIT_TIME, DEFAULT_ACQUIRE_WAIT_TIME);
private long buildObjectCompleteWaitTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_BUILD_OBJECT_COMPLETE_WAIT_TIME, DEFAULT_BUILD_OBJECT_COMPLETE_WAIT_TIME);
private long maxAllowedSleepTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_SLEEP_TIME, DEFAULT_MAX_ALLOWED_SLEEP_TIME_MS);
private long maxAllowedFrequencyToProduceTinyDumpLogMessage = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_FREQUENCY_DUMP_TINY_MESSAGE, DEFAULT_MAX_ALLOWED_FREQUENCY_TINY_DUMP_LOG_MESSAGE);
private long maxAllowedFrequencyToProduceMassiveDumpLogMessage = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_FREQUENCY_DUMP_MASSIVE_MESSAGE, DEFAULT_MAX_ALLOWED_FREQUENCY_MASSIVE_DUMP_LOG_MESSAGE);
private boolean allowInterruptedExceptionFired = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_INTERRUPTED_EXCEPTION, DEFAULT_INTERRUPTED_EXCEPTION_FIRED);
private boolean allowConcurrencyExceptionToBeFiredUp = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_CONCURRENCY_EXCEPTION, DEFAULT_CONCURRENCY_EXCEPTION_FIRED);
private boolean allowTakingStackTraceDuringReadLockAcquisition = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_STACK_TRACE_READ_LOCK, DEFAULT_TAKING_STACKTRACE_DURING_READ_LOCK_ACQUISITION);
private boolean useSemaphoreInObjectBuilder = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING, DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING_CONCURRENCY);
private boolean useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS, DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS);
private int noOfThreadsAllowedToObjectBuildInParallel = getIntProperty(SystemProperties.CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS, DEFAULT_CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS);
private int noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel = getIntProperty(SystemProperties.CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS, DEFAULT_CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS);
private long concurrencySemaphoreMaxTimePermit = getLongProperty(SystemProperties.CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT, DEFAULT_CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT);
private long concurrencySemaphoreLogTimeout = getLongProperty(SystemProperties.CONCURRENCY_SEMAPHORE_LOG_TIMEOUT, DEFAULT_CONCURRENCY_SEMAPHORE_LOG_TIMEOUT);
/**
* Thread local variable that allows the current thread to know when was the last time that this specific thread
* produced the "tiny dump" indicating that the thread is stuck.
*/
private final ThreadLocal<Date> threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock = new ThreadLocal<>();
/**
* Whenever we produce a tiny dump log message we will give it a unit identifier
*/
private final AtomicLong currentTinyMessageLogDumpNumber = new AtomicLong(0);
/**
* Whenever we produce a massive dump log message we will give it a unit identifier
*/
private final AtomicLong currentMassiveDumpMessageLogDumpNumber = new AtomicLong(0);
private final Object dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock = new Object();
/**
* Whenever we decide to log a massive dump of the state of the concurrency manager we need to make this date move forward.
* <P>
* This variable is telling any thread that might be considering the possibility of logging a massive dump log message,
* when a massive dump was last performed, thus allowing threads to avoid spamming too much.
*
* <P>
* NOTE: <br>
* Needs to be accessed in a synchronized method.
*/
private long dateWhenLastConcurrencyManagerStateFullDumpWasPerformed = 0L;
/**
* When we are explaining where read locks were acquired, the first time we see a new stack trace we create a stack
* trace id. Then for all other read locks we just say in the massive please go have a look at stack trace xxx.
*/
private final AtomicLong stackTraceIdAtomicLong = new AtomicLong(0);
private ConcurrencyUtil() {
}
/**
* Throw an interrupted exception if appears that eclipse link code is taking too long to release a deferred lock.
*
* @param whileStartTimeMillis
* the start date of the while tru loop for releasing a deferred lock
* @param callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary
* this flag is to allow the write lock manager to say that it is afraid of a concurrency exception being
* fire up because the thread in a dead lock might be trying to do a commit and blowing these threads up
* is most likely too dangerous and possibly the eclipselink code is not robust enough to code with such
* scenarios We do not care so much about blowing up exception during object building but during
* committing of transactions we are very afraid
* @throws InterruptedException
* we fire an interrupted exception to ensure that the code blows up and releases all of the locks it
* had.
*/
public void determineIfReleaseDeferredLockAppearsToBeDeadLocked(ConcurrencyManager concurrencyManager,
final long whileStartTimeMillis, DeferredLockManager lockManager, ReadLockManager readLockManager,
boolean callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary)
throws InterruptedException {
// (a) Determine if we believe to be dealing with a dead lock
final long maxAllowedSleepTimeMillis = ConcurrencyUtil.SINGLETON.getMaxAllowedSleepTime();
long whileCurrentTimeMillis = System.currentTimeMillis();
long elapsedTime = whileCurrentTimeMillis - whileStartTimeMillis;
boolean tooMuchTimeHasElapsed = tooMuchTimeHasElapsed(whileStartTimeMillis, maxAllowedSleepTimeMillis);
if (!tooMuchTimeHasElapsed) {
// this thread is not stuck for that long let us allow the code to continue waiting for the lock to be acquired
// or for the deferred locks to be considered as finished
return;
}
// (b) We believe this is a dead lock
// before we start spamming the server log lets make sure this thread has not spammed the server log too recently
if(threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.get() == null) {
// make sure the thread local variable never returns null
threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.set(new Date(0));
}
Date dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged = threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.get();
final long maxAllowedFrequencyToDumpTinyMessage = getMaxAllowedFrequencyToProduceTinyDumpLogMessage();
boolean tooMuchTimeHasElapsedSinceLastLoggingOfTinyMessage = tooMuchTimeHasElapsed(dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged.getTime(), maxAllowedFrequencyToDumpTinyMessage);
if(!tooMuchTimeHasElapsedSinceLastLoggingOfTinyMessage) {
// this thread has recently logged a small message about the fact that it is stuck
// no point in logging another message like that for some time
// let us allow for this thread to silently continue stuck without logging anything
return ;
}
// (c) This thread it is dead lock since the whileStartDate indicates a dead lock and
// this thread has been keeping silent about the problem for some time since the dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged
// indicates that quite some time has elapsed since we have last spammed the server log
// we now start by spamming into the server log a "tiny message" specific to the current thread
String tinyErrorMessage = currentThreadIsStuckForSomeTimeProduceTinyLogMessage(elapsedTime, concurrencyManager, lockManager, readLockManager);
// (d) next step is to log into the server log the massive dump log message where we try to explaing the concrrency mangaer state
// only one thread will suceed in doing the massive dump ever 1 minute or so
// we do not want that a massive dump is log all the time
dumpConcurrencyManagerInformationIfAppropriate();
// (e) Finaly we need to check what the user wants us to when we decide that we are in the middle of a dead lock
// and we have dumped whatever information we could dump
// does the user want us to blow up the thread to try release acquired locks and allow other threads to move forward
// or is the user afraid that we fire up a thread interrupted exception because if the dead lock does not resolve
// production will be serously affect by aborted business process that should normally have suceeded and after N rerties
// (e.g. 3 jms MDB message retries) the process is aborted as failed making live system recovery extermelly difficult?
// the project must decide how to forward here...
// a frozen system seems for the time being the safest course of action
// because the interrupted exception might be leaving the cocurrency manager corrupted in terms f the cache keys and the readers on the cache keys
// NOTE:
// This project has reported that our blowing up of the JTA transaction
// to release the dead lock is not being 100% effective the system can still freeze forever
// And if interrupting the thread and releasing its resources is not effective
// then we are worse off.
// Best is to leave the system frozen and simply spam into the log of the server
// the current state of cache
boolean allowConcurrencyExceptionToBeFiredUp = isAllowConcurrencyExceptionToBeFiredUp();
if (allowConcurrencyExceptionToBeFiredUp) {
// The first check if in general concurrency excpetions to resolve the dead locks can be fired is passed
// but we do one final check. The WriteLockManager is afraid of seing its thread being blown up
// so the write lock manager will be prohibiting this exception from being fired up
if (callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary) {
throw new InterruptedException(tinyErrorMessage);
}
} else {
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE,"concurrency_manager_allow_concurrency_exception_fired_up");
}
}
/**
* @return "eclipselink.concurrency.manager.waittime" persistence property value.
*/
public long getAcquireWaitTime() {
return this.acquireWaitTime;
}
public void setAcquireWaitTime(long acquireWaitTime) {
this.acquireWaitTime = acquireWaitTime;
}
/**
* @return "eclipselink.concurrency.manager.build.object.complete.waittime" persistence property value.
*/
public long getBuildObjectCompleteWaitTime() {
return buildObjectCompleteWaitTime;
}
public void setBuildObjectCompleteWaitTime(long buildObjectCompleteWaitTime) {
this.buildObjectCompleteWaitTime = buildObjectCompleteWaitTime;
}
/**
* @return property to control how long we are willing to wait before firing up an exception
*/
public long getMaxAllowedSleepTime() {
return this.maxAllowedSleepTime;
}
public void setMaxAllowedSleepTime(long maxAllowedSleepTime) {
this.maxAllowedSleepTime = maxAllowedSleepTime;
}
/**
* Just like we have a massive dump log message see {@link #getMaxAllowedFrequencyToProduceMassiveDumpLogMessage()}
* we also want threads to produce "tiny" dump about the fact that they rae stuck. We want to avoid these threads
* spaming too much the server log ... once the log message is out there not much point in continuously pumping the
* same log message out over and over again. Controlling how frequently the tiny dump is important especially when
* the user configures the hacked eclipselink to not fire up a blow up exception and instead to allow eclipselink to
* remain frozen forever.
*
* @return the frequency with which we are allowed to create a tiny dump log message
*/
public long getMaxAllowedFrequencyToProduceTinyDumpLogMessage() {
return this.maxAllowedFrequencyToProduceTinyDumpLogMessage;
}
public void setMaxAllowedFrequencyToProduceTinyDumpLogMessage(long maxAllowedFrequencyToProduceTinyDumpLogMessage) {
this.maxAllowedFrequencyToProduceTinyDumpLogMessage = maxAllowedFrequencyToProduceTinyDumpLogMessage;
}
/**
* If the system is perceived to be frozen and not evolving any longer, we will allow that every so often (e.g. once
* a minute) the logic complaining that the thread is stuck and going nowhere logs a very big dump message where the
* FULL concurrency manager state is explained. So that we can (manually) try to understand the dead lock based on
* the dumped information
*
* See also {@link #dateWhenLastConcurrencyManagerStateFullDumpWasPerformed}.
*/
public long getMaxAllowedFrequencyToProduceMassiveDumpLogMessage() {
return this.maxAllowedFrequencyToProduceMassiveDumpLogMessage;
}
public void setMaxAllowedFrequencyToProduceMassiveDumpLogMessage(long maxAllowedFrequencyToProduceMassiveDumpLogMessage) {
this.maxAllowedFrequencyToProduceMassiveDumpLogMessage = maxAllowedFrequencyToProduceMassiveDumpLogMessage;
}
public boolean isAllowInterruptedExceptionFired() {
return this.allowInterruptedExceptionFired;
}
public void setAllowInterruptedExceptionFired(boolean allowInterruptedExceptionFired) {
this.allowInterruptedExceptionFired = allowInterruptedExceptionFired;
}
/**
* @return true if we are supposed to be firing up exception to abort the thread in a dead lock, false we are afraid
* of trying to abort the transaction and not managing to resolve the dead lock and prefer to system frozen
* and be forced into restarting it.
*/
public boolean isAllowConcurrencyExceptionToBeFiredUp() {
return this.allowConcurrencyExceptionToBeFiredUp;
}
public void setAllowConcurrencyExceptionToBeFiredUp(boolean allowConcurrencyExceptionToBeFiredUp) {
this.allowConcurrencyExceptionToBeFiredUp = allowConcurrencyExceptionToBeFiredUp;
}
public boolean isAllowTakingStackTraceDuringReadLockAcquisition() {
return this.allowTakingStackTraceDuringReadLockAcquisition;
}
public void setAllowTakingStackTraceDuringReadLockAcquisition(boolean allowTakingStackTraceDuringReadLockAcquisition) {
this.allowTakingStackTraceDuringReadLockAcquisition = allowTakingStackTraceDuringReadLockAcquisition;
}
public boolean isUseSemaphoreInObjectBuilder() {
return useSemaphoreInObjectBuilder;
}
public void setUseSemaphoreInObjectBuilder(boolean useSemaphoreInObjectBuilder) {
this.useSemaphoreInObjectBuilder = useSemaphoreInObjectBuilder;
}
public boolean isUseSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks() {
return useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks;
}
public void setUseSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks(boolean useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks) {
this.useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks = useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks;
}
public int getNoOfThreadsAllowedToObjectBuildInParallel() {
return noOfThreadsAllowedToObjectBuildInParallel;
}
public void setNoOfThreadsAllowedToObjectBuildInParallel(int noOfThreadsAllowedToObjectBuildInParallel) {
this.noOfThreadsAllowedToObjectBuildInParallel = noOfThreadsAllowedToObjectBuildInParallel;
}
public int getNoOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel() {
return noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel;
}
public void setNoOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel(int noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel) {
this.noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel = noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel;
}
public long getConcurrencySemaphoreMaxTimePermit() {
return concurrencySemaphoreMaxTimePermit;
}
public void setConcurrencySemaphoreMaxTimePermit(long concurrencySemaphoreMaxTimePermit) {
this.concurrencySemaphoreMaxTimePermit = concurrencySemaphoreMaxTimePermit;
}
public long getConcurrencySemaphoreLogTimeout() {
return concurrencySemaphoreLogTimeout;
}
public void setConcurrencySemaphoreLogTimeout(long concurrencySemaphoreLogTimeout) {
this.concurrencySemaphoreLogTimeout = concurrencySemaphoreLogTimeout;
}
/**
*
* @return A to string of the cache key (e.g. that we are trying to lock
*/
public String createToStringExplainingOwnedCacheKey(ConcurrencyManager concurrencyManager) {
String cacheKeyClass = concurrencyManager.getClass().getCanonicalName();
Thread activeThreadObj = concurrencyManager.getActiveThread();
String activeThread = activeThreadObj != null ? activeThreadObj.getName() : "Null";
long concurrencyManagerId = concurrencyManager.getConcurrencyManagerId();
Date concurrencyManagerCreationDate = concurrencyManager.getConcurrencyManagerCreationDate();
if (concurrencyManager instanceof CacheKey) {
CacheKey cacheKey = (CacheKey) concurrencyManager;
Object primaryKey = cacheKey.getKey();
Object cacheKeyObject = cacheKey.getObject();
String canonicalName = cacheKeyObject != null ? cacheKeyObject.getClass().getCanonicalName()
: TraceLocalization.buildMessage("concurrency_util_owned_cache_key_null");
return TraceLocalization.buildMessage("concurrency_util_owned_cache_key_is_cache_key", new Object[] {canonicalName, primaryKey,
String.valueOf(System.identityHashCode(cacheKeyObject)),
cacheKeyClass, String.valueOf(System.identityHashCode(cacheKey)),
activeThread, concurrencyManager.getNumberOfReaders(), concurrencyManagerId,
ConversionManager.getDefaultManager().convertObject(concurrencyManagerCreationDate, String.class).toString()
// metadata of number of times the cache key suffered increases in number readers
, cacheKey.getTotalNumberOfKeysAcquiredForReading(),
cacheKey.getTotalNumberOfKeysReleasedForReading(),
cacheKey.getTotalNumberOfKeysReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero(),
concurrencyManager.getDepth()});
} else {
return TraceLocalization.buildMessage("concurrency_util_owned_cache_key_is_not_cache_key", new Object[] {cacheKeyClass, concurrencyManager, activeThread,
concurrencyManagerId, ConversionManager.getDefaultManager().convertObject(concurrencyManagerCreationDate, String.class).toString(),
concurrencyManager.getTotalNumberOfKeysAcquiredForReading(),
concurrencyManager.getTotalNumberOfKeysReleasedForReading(), concurrencyManager
.getTotalNumberOfKeysReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero(),
concurrencyManager.getDepth()});
}
}
/**
* We have a thread that is not evolving for quite some while. This is a fairy good indication of eclipselink being
* stuck in a dead lock. So we log some information about the thread that is stuck.
*
* @param elapsedTime
* how many ms have passed since the thread stopped moving
* @param concurrencyManager
* the current cache key that the thread is trying to acquire or the object where the thread is waiting
* for the release deferred locks .
* @param lockManager
* the lock manager
* @param readLockManager
* the read lock manager
* @return Return the string with the tiny message we logged on the server log. This message can be interesting if
* we decide to fire up an interrupted exception
*/
protected String currentThreadIsStuckForSomeTimeProduceTinyLogMessage(long elapsedTime, ConcurrencyManager concurrencyManager, DeferredLockManager lockManager, ReadLockManager readLockManager) {
// We believe this is a dead lock so now we will log some information
Thread currentThread = Thread.currentThread();
String threadName = currentThread.getName();
String currentCacheKeyContext = createToStringExplainingOwnedCacheKey(concurrencyManager);
StringWriter errorMessage = new StringWriter();
long messageNumber = currentTinyMessageLogDumpNumber.incrementAndGet();
// (i) Create a big head to explain the cache key we were in when we blow up
errorMessage.write(TraceLocalization.buildMessage("concurrency_util_header_current_cache_key", new Object[] {threadName}));
// explain the cache key itself where the problem is taking place
errorMessage.write(TraceLocalization.buildMessage("concurrency_util_stuck_thread_tiny_log_cache_key", new Object[] { messageNumber, threadName, currentCacheKeyContext, elapsedTime }));
// (ii) Add information about the cache keys where the current thread was set as actively owning
errorMessage.write(createStringWithSummaryOfActiveLocksOnThread(lockManager, threadName));
// (iii) Now very interesting as well are all of the objects that current thread could not acquire the
// deferred locks are essential
errorMessage.write(createStringWithSummaryOfDeferredLocksOnThread(lockManager, threadName));
// (iv) Add information about all cache keys te current thread acquired with READ permission
errorMessage.write(createStringWithSummaryOfReadLocksAcquiredByThread(readLockManager, threadName));
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, errorMessage.toString(), new Object[] {}, false);
threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.set(new Date());
return errorMessage.toString();
}
public boolean tooMuchTimeHasElapsed(final long whileStartTimeMillis, final long maxAllowedSleepTimeMs) {
if (maxAllowedSleepTimeMs == 0L) {
return false;
}
long elapsedTime = System.currentTimeMillis() - whileStartTimeMillis;
return elapsedTime > maxAllowedSleepTimeMs;
}
/**
* Invoke the {@link #dumpConcurrencyManagerInformationStep01(Map, Map, Map, Map, Map, Map, Map, Set, Map, Map)} if sufficient time has passed.
* This log message will potentially create a massive dump in the server log file. So we need to check when was the
* last time that the masive dump was produced and decide if we can log again the state of the concurrency manager.
*
* The access to dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock is synchronized, because we do not want
* two threads in parallel to star deciding to dump the complete state of the concurrency manager at the same time.
* Only one thread should succeed in producing the massive dump in a given time window.
*
*/
public void dumpConcurrencyManagerInformationIfAppropriate() {
// We do not want create a big synchronized method that would be dangerous
// but we want to make sure accessing the dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock is only
// done
// by cone thread at a time
synchronized (dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock) {
final long maxAllowedFrequencyToProduceMassiveDumpLogMessage = getMaxAllowedFrequencyToProduceMassiveDumpLogMessage();
boolean tooMuchTimeHasElapsedSinceLastLoggingOfMassiveMessage = tooMuchTimeHasElapsed(
dateWhenLastConcurrencyManagerStateFullDumpWasPerformed,
maxAllowedFrequencyToProduceMassiveDumpLogMessage);
if (!tooMuchTimeHasElapsedSinceLastLoggingOfMassiveMessage) {
// before we can fire to the serverlog such a gigantic message
// we need to allow for more time to pass (e.g. once a minute should be fine)
// it is not like production will be waiting for half an hour for a fozen system to magically
// start working if we do 30 dumps in a half an hour ... it is really irrelevant
return;
}
// we should proceed with making the big log dump - update the date of when the big dump was last done
dateWhenLastConcurrencyManagerStateFullDumpWasPerformed = System.currentTimeMillis();
}
// do the "MassiveDump" logging if enough time has passed since the previous massive dump logging
Map<Thread, DeferredLockManager> deferredLockManagers = ConcurrencyManager.getDeferredLockManagers();
Map<Thread, ReadLockManager> readLockManagersOriginal = ConcurrencyManager.getReadLockManagers();
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal = ConcurrencyManager.getThreadsToWaitOnAcquire();
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireMethodName();
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireReadLock();
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireReadLockMethodName();
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal = WriteLockManager.getThreadToFailToAcquireCacheKeys();
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal = ConcurrencyManager.getThreadsWaitingToReleaseDeferredLocks();
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone = ConcurrencyManager.getThreadsWaitingToReleaseDeferredLocksJustification();
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal = WriteLockManager.getMapWriteLockManagerThreadToObjectIdsWithChangeSet();
dumpConcurrencyManagerInformationStep01(
deferredLockManagers,
readLockManagersOriginal,
mapThreadToWaitOnAcquireOriginal,
mapThreadToWaitOnAcquireMethodNameOriginal,
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
mapThreadToWaitOnAcquireReadLockOriginal,
mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
setThreadWaitingToReleaseDeferredLocksOriginal,
mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
}
/**
* The current working thread is having problems. It seems to not go forward being stuck either trying to acquire a
* cache key for writing, as a deferred cache key or it is at the end of the process and it is waiting for some
* other thread to finish building some objects it needed to defer.
*
* Now that the system is frozen we want to start spamming into the server log file the state of the concurrency
* manager since this might help us understand the situation of the system.
*
*
* @param deferredLockManagers
* static map coming from the concurrency manager telling us all the threds and their defferred locks and
* active locks
* @param readLockManagersOriginal
* static map coming from the concurrency manager telling us all the threads and their read locks
* @param mapThreadToWaitOnAcquireOriginal
* static map of threads that have registered themselves as waiting for some cache key
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal
* this map relates to the fact that the write lock manager during transaction commits is very illusive.
* The write lock manger is not allowing itself to get stuck on acquiring any cache key. It uses waits
* with timings and therefore the locks needed to write and that cannot be obtained are not appearing
* inside our tracebility maps of the concurrency manager. We needed add the
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* but semantically this map is 100 percent the same thing as the mapThreadToWaitOnAcquireOriginal. It
* still represents a thread wanting to grab a write lock and not managing to get it. Being stuck in that
* step. Wo we will want to fuse together the (mapThreadToWaitOnAcquireOriginal and the
* mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal) to make our lives much easier.
*
*
* @param setThreadWaitingToReleaseDeferredLocksOriginal
* static map of threads that have stopped going deeped in the recursion of object building and are
* waiting for the confirmation that some of the objects they needed to build are finished building.
*
* @param mapThreadToObjectIdWithWriteLockManagerChangesOriginal
* The write lock manager has been tweaked to store information about objects ids that the current thread
* has in its hands and that will required for write locks to be acquired by a committing thread. This
* information is especially interesting if any thread participating in a dead lock is getting stuck in
* the acquisition of write locks as part of the commit process. This information might end up revealing
* a thread that has done too many changes and is creating a bigger risk fo dead lock. The more resources
* an individual thread tries to grab the worse it is for the concurrency layer. The size of the change
* set can be interesting.
*/
protected void dumpConcurrencyManagerInformationStep01(Map<Thread, DeferredLockManager> deferredLockManagers,
Map<Thread, ReadLockManager> readLockManagersOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal,
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal,
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
// (a) create object to represent our cache state.
ConcurrencyManagerState concurrencyManagerState = createConcurrencyManagerState(
deferredLockManagers,
readLockManagersOriginal,
mapThreadToWaitOnAcquireOriginal,
mapThreadToWaitOnAcquireMethodNameOriginal,
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
mapThreadToWaitOnAcquireReadLockOriginal,
mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
setThreadWaitingToReleaseDeferredLocksOriginal,
mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
dumpConcurrencyManagerInformationStep02(concurrencyManagerState);
}
/**
* Dump the server log all of the information that we managed to aggregate about the current state of the
* concurrency manager.
*
* @param concurrencyManagerState a snapshot of the current state of the concurrency manager and threads accessing locks.
*/
protected void dumpConcurrencyManagerInformationStep02(ConcurrencyManagerState concurrencyManagerState) {
StringWriter writer = new StringWriter();
long messageNumber = currentMassiveDumpMessageLogDumpNumber.incrementAndGet();
writer.write(TraceLocalization.buildMessage("concurrency_util_dump_concurrency_manager_information_step02_01", new Object[] {messageNumber}));
// (a) Log information about the current threads in the system and there stack traces
// PAGE 01 of logging information
writer.write(createInformationThreadDump());
// (b) log information about the threads that are waiting to acquire WRITE/DEFERRED locks
// PAGE 02 of logging information
writer.write(createInformationAboutAllThreadsWaitingToAcquireCacheKeys(concurrencyManagerState.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLock(),
concurrencyManagerState.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLockMethodName()));
// (c) log information about the threads that are waiting to acquire READ locks
// PAGE 03 of logging information
writer.write(createInformationAboutAllThreadsWaitingToAcquireReadCacheKeys(concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockClone(),
concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockCloneMethodName()));
// (c) An interesting summary of information as well is to tell the user about the threads
// that have finished their part of object building and now would like for othe threads to finish the object
// building of locks they had to defer
// PAGE 04 of logging information
writer.write(createInformationAboutAllThreadsWaitingToReleaseDeferredLocks(concurrencyManagerState.getSetThreadWaitingToReleaseDeferredLocksClone()));
// (d) Now we log information from the prespective of a THREAD to resources it has acquired and those
// it needed to defer
// PAGE 05 of logging information
writer.write(createInformationAboutAllResourcesAcquiredAndDeferredByAllThreads(concurrencyManagerState));
// (e) Dump information by going from cache key to the threads with some sort of relationship to the key
// PAGE 06 of logging information
writer.write(createInformationAboutCacheKeysAndThreadsMakingUseOfTheCacheKey(
concurrencyManagerState.getMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey()));
// (f) Try to explain the reason for the dead lock:
// PAGE 07: we try to find out the reason for the dead lock
// but based on what we have seen so far it is mostly due to cache key corruption
// with the number of readers increased
String deadLockExplanation = dumpDeadLockExplanationIfPossible(concurrencyManagerState);
writer.write(deadLockExplanation);
// (g) Final header
writer.write(TraceLocalization.buildMessage("concurrency_util_dump_concurrency_manager_information_step02_02", new Object[] {messageNumber}));
// there should be no risk that the string is simply to big. the max string size in java is 2pow31 chars
// which means 2 GB string... we can be fairly confident we are not logging 2 GB in a single message.
// not even in the largest of sites...
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
}
/**
* Log information focusing on the different cache keys where threads have hooks on the thread.
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* a map that we have constructed where the map keys are cache keys that are of some sort of interest to
* one or more threads (e.g. cache keys with a read lock, acquired or deferred)
*
*/
private String createInformationAboutCacheKeysAndThreadsMakingUseOfTheCacheKey(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
int numberOfCacheKeysGettingDescribed = mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.size();
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_01", new Object[] {numberOfCacheKeysGettingDescribed}));
int currentCacheKeyNumber = 0;
for(Map.Entry<ConcurrencyManager, CacheKeyToThreadRelationships> currentEntry : mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.entrySet()) {
currentCacheKeyNumber++;
// (b) put a clear separator from the line above
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_02", new Object[] {currentCacheKeyNumber, numberOfCacheKeysGettingDescribed}));
// (c) Describe the current cache key
ConcurrencyManager cacheKey = currentEntry.getKey();
String cacheKeyToString = createToStringExplainingOwnedCacheKey(cacheKey);
CacheKeyToThreadRelationships dto = currentEntry.getValue();
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_03", new Object[] {currentCacheKeyNumber, cacheKeyToString,
dto.getThreadNamesThatAcquiredActiveLock(), dto.getThreadNamesThatAcquiredDeferredLock(), dto.getThreadNamesThatAcquiredReadLock(),
dto.getThreadNamesKnownToBeStuckTryingToAcquireLock(), dto.getThreadNamesKnownToBeStuckTryingToAcquireLockForReading()}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_04"));
return writer.toString();
}
protected String dumpDeadLockExplanationIfPossible(ConcurrencyManagerState concurrencyManagerState) {
// (a) Step one - try to detect dead lock
final long startTimeMillis = System.currentTimeMillis();
List<DeadLockComponent> deadLockExplanation = Collections.emptyList();
long deadLockDetectionTotalExecutionTimeMs = 0l;
try {
deadLockExplanation = ExplainDeadLockUtil.SINGLETON.explainPossibleDeadLockStartRecursion(concurrencyManagerState);
} catch (Exception codeIsBuggyAndBlowingUp) {
// we are unsure if the code will actually work and help
// therefore we make sure we catch any blowup coming from here
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, new Exception(
TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_01"),
codeIsBuggyAndBlowingUp));
} finally {
final long endTimeMillis = System.currentTimeMillis();
deadLockDetectionTotalExecutionTimeMs = endTimeMillis - startTimeMillis;
}
// (b) explain what has happened
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_02"));
if (deadLockExplanation.isEmpty()) {
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_03"));
} else {
// (i) Write out a summary of how many threads are involved in the deadloc
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_04", new Object[] {deadLockExplanation.size()}));
// (ii) Print them all out
for (int currentThreadNumber = 0; currentThreadNumber < deadLockExplanation.size(); currentThreadNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_05", new Object[] {currentThreadNumber + 1, deadLockExplanation.get(currentThreadNumber).toString()}));
}
}
// (c) return the string that tries to explain the reason for the dead lock
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_06", new Object[] {deadLockDetectionTotalExecutionTimeMs}));
return writer.toString();
}
/**
* create a DTO that tries to represent the current snapshot of the concurrency manager and write lock manager cache
* state
*/
public ConcurrencyManagerState createConcurrencyManagerState(
Map<Thread, DeferredLockManager> deferredLockManagers,
Map<Thread, ReadLockManager> readLockManagersOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal,
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal,
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
// (a) As a first step we want to clone-copy the two maps
// once we start working with the maps and using them to do dead lock detection
// or simply print the state of the system we do not want the maps to continue changing as the threads referenced in the maps
// go forward with their work
Map<Thread, ReadLockManager> readLockManagerMapClone = cloneReadLockManagerMap(readLockManagersOriginal);
Map<Thread, DeferredLockManager> deferredLockManagerMapClone = cloneDeferredLockManagerMap(deferredLockManagers);
// NOTE: the wait on acquire write locks are tricky
// we want to fuse together the threads we are tracking waiting to acquire locks
// both the one we track in the hash map of the concurrency manager
// as well as the ones we need to track inside of the write lock manager
Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock = null;
// additional method data about the method that created the trace
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameClone = cloneMapThreadToMethodName(mapThreadToWaitOnAcquireMethodNameOriginal);
{
// information from the concurrency manager state
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireClone = cloneMapThreadToWaitOnAcquire(mapThreadToWaitOnAcquireOriginal);
// info from the the write lock manager state
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerClone = cloneMapThreadToWaitOnAcquireInsideWriteLockManagerOriginal(
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal);
// merge both maps together
enrichMapThreadToWaitOnAcquireInsideWriteLockManagerClone(mapThreadToWaitOnAcquireInsideWriteLockManagerClone, mapThreadToWaitOnAcquireClone);
// update the variable we want to be carrying forward to be the enriched map
unifiedMapOfThreadsStuckTryingToAcquireWriteLock = mapThreadToWaitOnAcquireInsideWriteLockManagerClone;
}
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone = cloneMapThreadToWaitOnAcquire(mapThreadToWaitOnAcquireReadLockOriginal);
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameClone = cloneMapThreadToMethodName(mapThreadToWaitOnAcquireReadLockMethodNameOriginal);
Set<Thread> setThreadWaitingToReleaseDeferredLocksClone = cloneSetThreadsThatAreCurrentlyWaitingToReleaseDeferredLocks(setThreadWaitingToReleaseDeferredLocksOriginal);
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesClone = cloneMapThreadToObjectIdWithWriteLockManagerChanges(
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
// (b) All of the above maps tell a story from the respective of the threads
// very interesting as well is to be able to go over the story of the cache keys and what threads have
// expectations for these cache keys
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey = new HashMap<>();
// (i) pump information about the read locks
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutReadLocks(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, readLockManagerMapClone);
// (ii) pump information about the active and deferred locks
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutActiveAndDeferredLocks(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, deferredLockManagerMapClone);
// (iii) Pump information into the map about the threads that are stuck because they cannot acquire a certain
// cache key (they want to acquire the cache key for WRITING either to become active thread or to defer)
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquire(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, unifiedMapOfThreadsStuckTryingToAcquireWriteLock);
// (iv) Pump information into the map about the threads that are stuck because they cannot acquire a certain
// cache key (they want to acquire the cache key for READING)
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquireLockForReading(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, mapThreadToWaitOnAcquireReadLockClone);
return new ConcurrencyManagerState(
readLockManagerMapClone, deferredLockManagerMapClone, unifiedMapOfThreadsStuckTryingToAcquireWriteLock,
mapThreadToWaitOnAcquireMethodNameClone, mapThreadToWaitOnAcquireReadLockClone, mapThreadToWaitOnAcquireReadLockMethodNameClone,
setThreadWaitingToReleaseDeferredLocksClone, mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, mapThreadToObjectIdWithWriteLockManagerChangesClone);
}
/**
* Create a print of the ACTIVE locks associated to the DeferredLockManager. Owning an active lock on a thread
* implies that the thread is allowed to do write operations in relation to the object.
*/
private String createStringWithSummaryOfActiveLocksOnThread(DeferredLockManager lockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_active_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_1", new Object[] {threadName}));
if (lockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the active locks on the thread
// Loop over all of the active locks and print them
List<ConcurrencyManager> activeLocks = new ArrayList<>(lockManager.getActiveLocks());
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_3", new Object[] {activeLocks.size()}));
for (int activeLockNumber = 0; activeLockNumber < activeLocks.size(); activeLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_4", new Object[] {activeLockNumber, createToStringExplainingOwnedCacheKey(activeLocks.get(activeLockNumber))}));
}
return writer.toString();
}
/**
* The {@link org.eclipse.persistence.internal.helper.DeferredLockManager} contains two baskat of locks being
* managed for a thread. One are active locks (granted write permission). The other deferred locks (write access or
* read access was being held by somebody else and the thread deferred).
*
* @param lockManager
* the deferred lock manager of the current thread
*/
private String createStringWithSummaryOfDeferredLocksOnThread(DeferredLockManager lockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_deferred_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_1", new Object[] {threadName}));
if (lockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the active locks on the thread
// Loop over all of the deferred locks and print them
@SuppressWarnings("unchecked")
List<ConcurrencyManager> deferredLocks = new ArrayList<>(lockManager.getDeferredLocks());
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_3", new Object[] {deferredLocks.size()}));
for (int deferredLockNumber = 0; deferredLockNumber < deferredLocks.size(); deferredLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_4", new Object[] {deferredLockNumber, createToStringExplainingOwnedCacheKey(deferredLocks.get(deferredLockNumber))}));
}
return writer.toString();
}
/**
* Relates to issue. We are convinced that a read lock manager is needed for two reasons: implementing a
* dead lock detection algorithm which are currently not doing. And also beause when the code does not go according
* to happy path and do encounter a dead lock and forced to interrupt the thread, we need to force the thread to
* release any acquired a read locks it may have.
*
* @param readLockManager
* this is hacky class we created to close a gap in eclipselink code whereby read access on cache keys is
* not tracked. The only thing that happens is incrementing the nuber of readers but that is not
* sufficient if we need to abort all read locks.
* @param threadName
* the thread for which we are logging the read locks acquired
* @return A big string summarizing all of the read locks the thread.
*/
private String createStringWithSummaryOfReadLocksAcquiredByThread(ReadLockManager readLockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_reader_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_1", new Object[] {threadName}));
if (readLockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the acitve locks on the thread
// Loop over al of the active locks and print them
@SuppressWarnings("unchecked")
List<ConcurrencyManager> readLocks = readLockManager.getReadLocks();
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_3", new Object[] {readLocks.size()}));
for (int readLockNumber = 0; readLockNumber < readLocks.size(); readLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_4", new Object[] {readLockNumber + 1, createToStringExplainingOwnedCacheKey(readLocks.get(readLockNumber))}));
}
// (c) This is the main point of candidate 007 - having a lot fatter information about when and where the read
// locks were acquired
// (i) If a thread has 48 read locks most likely it acquired all 48 read locks in the exact same code area
// so we want to avoid dumping 48 stack traces to the massive dump that would be completely out of control
// we create a map of strings in order to know if we can refer to any previously created stack trace
Map<String, Long> stackTraceStringToStackTraceExampleNumber = new HashMap<>();
// (ii) Let us start dumping a mini header to give indication we now will sow very fact information about the
// read locks acquired by a thread
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_1"));
// (iii) let us organize the iformation we are about to dump by the creation date of the records in the map
Map<Long, List<ReadLockAcquisitionMetadata>> mapThreadToReadLockAcquisitionMetadata = readLockManager.getMapThreadToReadLockAcquisitionMetadata();
List<Long> sortedThreadIds = new ArrayList<>(mapThreadToReadLockAcquisitionMetadata.keySet());
Collections.sort(sortedThreadIds);
// (iv) commence the loop of dumping trace data LOOP OVER EACH JPA TRANSACTION ID
for (Long currentThreadId : sortedThreadIds) {
List<ReadLockAcquisitionMetadata> readLocksAcquiredByThread = mapThreadToReadLockAcquisitionMetadata.get(currentThreadId);
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_2", new Object[] {threadName, currentThreadId, readLocksAcquiredByThread.size()}));
// LOOP OVER EACH CACHE KEY ACQUIRED FORE READING BUT NEVER RELEASED FOR CURRENT THREAD ID
int readLockNumber = 0;
for (ReadLockAcquisitionMetadata currentReadLockAcquiredAndNeverReleased : readLocksAcquiredByThread) {
readLockNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_3", new Object[] {readLockNumber,
SINGLETON.createToStringExplainingOwnedCacheKey(currentReadLockAcquiredAndNeverReleased.getCacheKeyWhoseNumberOfReadersThreadIsIncrementing()),
ConversionManager.getDefaultManager().convertObject(currentReadLockAcquiredAndNeverReleased.getDateOfReadLockAcquisition(), String.class).toString(),
currentReadLockAcquiredAndNeverReleased.getNumberOfReadersOnCacheKeyBeforeIncrementingByOne(),
currentReadLockAcquiredAndNeverReleased.getCurrentThreadStackTraceInformationCpuTimeCostMs()}));
String stackTraceInformation = currentReadLockAcquiredAndNeverReleased.getCurrentThreadStackTraceInformation();
if (stackTraceStringToStackTraceExampleNumber.containsKey(stackTraceInformation)) {
// we can spare the massive dump from being any fatter we have alreayd added a stack trace id that
// is identical to the stack trace were were about dump
// we just refer to the stack trace id.
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_4", new Object[] {readLockNumber, stackTraceStringToStackTraceExampleNumber.get(stackTraceInformation)}));
} else {
// Since we have not see this stack trace pattern for this thread yet we will dump the stack trace
// into the massive dump giving it a new global id
long stackTraceId = stackTraceIdAtomicLong.incrementAndGet();
stackTraceStringToStackTraceExampleNumber.put(stackTraceInformation, stackTraceId);
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_5", new Object[] {readLockNumber, stackTraceId, stackTraceInformation}));
}
writer.write("\n\n");
}
}
// (d) We have some more information to pump out namely errors we have traced each time the number of readers was decremented
writer.write("\n\n");
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_6", new Object[] {threadName, readLockManager.getRemoveReadLockProblemsDetected().size()}));
for (int releaseReadLockProblemNumber = 0; releaseReadLockProblemNumber < readLockManager.getRemoveReadLockProblemsDetected().size(); releaseReadLockProblemNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_7", new Object[] {releaseReadLockProblemNumber + 1, readLockManager.getRemoveReadLockProblemsDetected().get(releaseReadLockProblemNumber)}));
}
writer.write("\n\n");
return writer.toString();
}
/**
* This helper API is created due to the problem of the corruption of the eclipselink cache. The idea is to have a
* tool that allows us to know specifically where the current thread was located when it acquired a READ LOCK.
*
* <P>
* Cache corruption problem: <br>
* namely the fact that when dead locks are seen to be taking place some of the threads that seem to be primary
* culprits of the dead lock are actually idle doing nothing but they have have left the number of readers of the
* cache corrupted (e.g. typically forever incremnted).
*
* @return get the stack trace of the current thread.
*/
public String enrichGenerateThreadDumpForCurrentThread() {
final Thread currentThread = Thread.currentThread();
final long currentThreadId = currentThread.getId();
try {
// (a) search for the stack trace of the current
final StringWriter writer = new StringWriter();
ThreadInfo[] threadInfos = null;
if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
threadInfos = AccessController.doPrivileged(new PrivilegedGetThreadInfo(new long[] { currentThreadId }, 700));
} else {
final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
threadInfos = threadMXBean.getThreadInfo(new long[] { currentThreadId }, 700);
}
for (ThreadInfo threadInfo : threadInfos) {
enrichGenerateThreadDumpForThreadInfo(writer, threadInfo);
}
return writer.toString();
} catch (Exception failToAcquireThreadDumpProgrammatically) {
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, failToAcquireThreadDumpProgrammatically);
return TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump", new Object[] {failToAcquireThreadDumpProgrammatically.getMessage()});
}
}
/**
* We simply copy pasted this code from the net to have some helper tool to generate thread dumps programatically
* when the event takes place.
*
* <P>
* NOTE: This approach can be easily tested in a basic unit test.
*
*
* <a href="https://crunchify.com/how-to-generate-java-thread-dump-programmatically/">Original source of code</a>
*
*/
private String enrichGenerateThreadDump() {
try {
final StringWriter writer = new StringWriter();
ThreadInfo[] threadInfos = null;
if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
threadInfos = AccessController.doPrivileged(new PrivilegedGetThreadInfo(700));
} else {
final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
threadInfos = threadMXBean.getThreadInfo(threadMXBean.getAllThreadIds(), 700);
}
for (ThreadInfo threadInfo : threadInfos) {
enrichGenerateThreadDumpForThreadInfo(writer, threadInfo);
}
return writer.toString();
} catch (Exception failToAcquireThreadDumpProgrammatically) {
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, failToAcquireThreadDumpProgrammatically);
return TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump", new Object[] {failToAcquireThreadDumpProgrammatically.getMessage()});
}
}
/**
* Enrich a given string building with the the thread writer for a given thread info object.
*/
private void enrichGenerateThreadDumpForThreadInfo(StringWriter writer, ThreadInfo threadInfo) {
writer.write(TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump_thread_info_1", new Object[] {threadInfo.getThreadName(), threadInfo.getThreadState()}));
final StackTraceElement[] stackTraceElements = threadInfo.getStackTrace();
for (final StackTraceElement stackTraceElement : stackTraceElements) {
writer.write(TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump_thread_info_2", new Object[] {stackTraceElement}));
}
writer.write("\n\n");
}
/**
* Write a severe log message with the current thread dump.
*/
private String createInformationThreadDump() {
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_thread_dump", new Object[] {enrichGenerateThreadDump()}));
return writer.toString();
}
/**
* In this page of log dumping information we want to give a summary to the user of threads that appear to be stuck
* doing an acquire of the cache key.
*
* @param unifiedMapOfThreadsStuckTryingToAcquireWriteLock
* this a cloned map that has an association between thread and cache keys the thread would like to
* acquire but cannot because there are readers on the cache key. The thread might be stuck either on the
* concurrency manager or on the write lock manager.
* @param mapThreadToWaitOnAcquireMethodNameClone
* the name of the method that updated the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#THREADS_TO_WAIT_ON_ACQUIRE} If we
* do not know the method name that created the trace then it must have been the
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#addCacheKeyToMapWriteLockManagerToCacheKeysThatCouldNotBeAcquired(Thread, ConcurrencyManager, long)}
* . This is not obvious but essentially we trace the acquisition of write locks in to places. The first
* is the map already mentioned in the concurrency manager. The second is the map
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* for the purose of the massive dump we act as if there was a single unified map. However when the
* MAP_THREAD_TO_WAIT_ON_ACQUIRE we not only add to this map the cache key we cannot acquire but also the
* method name. When we work with the map the THREADS_TO_FAIL_TO_ACQUIRE_CACHE_KEYS
* we just keep trace of the cache key that could not be acquired. This
* THREADS_TO_FAIL_TO_ACQUIRE_CACHE_KEYS is currently only used in one spot so we
* can avoid the trouble of adding even more tracing for this.
*/
private String createInformationAboutAllThreadsWaitingToAcquireCacheKeys(Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_1", new Object[] {unifiedMapOfThreadsStuckTryingToAcquireWriteLock.size()}));
int currentThreadNumber = 0;
for (Map.Entry<Thread, Set<ConcurrencyManager>> currentEntry : unifiedMapOfThreadsStuckTryingToAcquireWriteLock
.entrySet()) {
currentThreadNumber++;
Thread thread = currentEntry.getKey();
Set<ConcurrencyManager> writeLocksCurrentThreadIsTryingToAcquire = currentEntry.getValue();
for (ConcurrencyManager cacheKey : writeLocksCurrentThreadIsTryingToAcquire) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_2", new Object[] {currentThreadNumber, thread.getName(), createToStringExplainingOwnedCacheKey(cacheKey)}));
// add as well information about what method created this trace entry
// this important in case we start leaking traces when the code is configured
// to blow up
String methodNameThatGotStuckWaitingToAcquire = mapThreadToWaitOnAcquireMethodNameClone.get(currentEntry.getKey());
if (methodNameThatGotStuckWaitingToAcquire == null) {
// this because the acquire trace was not on the
// org.eclipse.persistence.internal.helper.ConcurrencyManager.MAP_THREAD_TO_WAIT_ON_ACQUIRE
// by the concurrency manager but rather the trace of the wait on the write
// lock was created by the mapThreadToWaitOnAcquireInsideWriteLockManagerClone
// see
// org.eclipse.persistence.internal.helper.WriteLockManager.addCacheKeyToMapWriteLockManagerToCacheKeysThatCouldNotBeAcquired(Thread, ConcurrencyManager, Date)
methodNameThatGotStuckWaitingToAcquire = TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_3");
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_4", new Object[] {methodNameThatGotStuckWaitingToAcquire}));
}
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_5"));
return writer.toString();
}
/**
* In this page of log dumping information we want to give a summary to the user of threads that appear to be stuck
* doing an acquire of the cache key.
*
* @param mapThreadToWaitOnAcquireReadLockClone
* this a cloned map that has an association between thread and cache keys the thread would like to
* acquire for READING but cannot because there is some active thread (other than themselves) holding the cache key (e.g. for writing)
*/
protected String createInformationAboutAllThreadsWaitingToAcquireReadCacheKeys(Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_1", new Object[] {mapThreadToWaitOnAcquireReadLockClone.size()}));
int currentThreadNumber = 0;
for(Map.Entry<Thread, ConcurrencyManager> currentEntry : mapThreadToWaitOnAcquireReadLockClone.entrySet()) {
currentThreadNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_2", new Object[] {currentThreadNumber, currentEntry.getKey().getName(), createToStringExplainingOwnedCacheKey(currentEntry.getValue())}));
String methodNameThatGotStuckWaitingToAcquire = mapThreadToWaitOnAcquireReadLockMethodNameClone.get(currentEntry.getKey());
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_3", new Object[] {methodNameThatGotStuckWaitingToAcquire}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_4"));
return writer.toString();
}
/**
* Log information about threads not moving forward because they are waiting for the
* {@code isBuildObjectOnThreadComplete } to return true.
*
* @param setThreadWaitingToReleaseDeferredLocksClone
* threads waiting for the release deferred lock process to complete.
*/
protected String createInformationAboutAllThreadsWaitingToReleaseDeferredLocks(Set<Thread> setThreadWaitingToReleaseDeferredLocksClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_1", new Object[] {setThreadWaitingToReleaseDeferredLocksClone.size()}));
// (b) add to the string building information about each of these threads that are stuck in the
// isBuildObjectOnThreadComplete
int currentThreadNumber = 0;
for (Thread currentEntry : setThreadWaitingToReleaseDeferredLocksClone) {
currentThreadNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_2", new Object[] {currentThreadNumber, currentEntry.getName()}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_3"));
return writer.toString();
}
/**
* Log information about all threads tracked in the concurrency manager.
*
* @param concurrencyManagerState
* and object that represents a snapshot of the current state of the concurrency manager.
*/
protected String createInformationAboutAllResourcesAcquiredAndDeferredByAllThreads(
ConcurrencyManagerState concurrencyManagerState) {
// (a) Compile a union of all threads
Set<Thread> allRelevantThreads = new HashSet<>();
allRelevantThreads.addAll(concurrencyManagerState.getSetThreadWaitingToReleaseDeferredLocksClone());
allRelevantThreads.addAll(concurrencyManagerState.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLock().keySet());
allRelevantThreads.addAll(concurrencyManagerState.getDeferredLockManagerMapClone().keySet());
allRelevantThreads.addAll(concurrencyManagerState.getReadLockManagerMapClone().keySet());
// (b) print information about all threads
StringWriter writer = new StringWriter();
int currentThreadNumber = 0;
final int totalNumberOfThreads = allRelevantThreads.size();
for(Thread currentThread : allRelevantThreads) {
currentThreadNumber++;
ReadLockManager readLockManager = concurrencyManagerState.getReadLockManagerMapClone().get(currentThread);
DeferredLockManager lockManager = concurrencyManagerState.getDeferredLockManagerMapClone().get(currentThread);
String waitingToReleaseDeferredLocksJustification = concurrencyManagerState
.getMapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone().get(currentThread);
Set<ConcurrencyManager> waitingOnAcquireCacheKeys = concurrencyManagerState
.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLock()
.get(currentThread);
ConcurrencyManager waitingOnAcquireReadCacheKey = concurrencyManagerState
.getMapThreadToWaitOnAcquireReadLockClone().get(currentThread);
boolean threadWaitingToReleaseDeferredLocks = concurrencyManagerState
.getSetThreadWaitingToReleaseDeferredLocksClone().contains(currentThread);
Set<Object> writeManagerThreadPrimaryKeysWithChangesToBeMerged = concurrencyManagerState
.getMapThreadToObjectIdWithWriteLockManagerChangesClone()
.get(currentThread);
String informationAboutCurrentThread = createInformationAboutAllResourcesAcquiredAndDeferredByThread(
readLockManager, lockManager, waitingOnAcquireCacheKeys, waitingOnAcquireReadCacheKey,
threadWaitingToReleaseDeferredLocks, currentThread, currentThreadNumber, totalNumberOfThreads,
writeManagerThreadPrimaryKeysWithChangesToBeMerged, waitingToReleaseDeferredLocksJustification);
writer.write(informationAboutCurrentThread);
}
// (c) Log on the serverlog information about all the threads being tracked in the concurrency manager
return writer.toString();
}
/**
* Build a string that tries to describe in as much detail as possible the resources associated to the current
* thread.
*
* @param readLockManager
* the read lock manager for the current thread
* @param lockManager
* the lock manager for the current thread
* @param waitingOnAcquireCacheKeys
* null if the current thread is not waiting to acquire a cache key otherwise the cachekey that the
* current thread wants to acquire and that is making it block. This field evolved to be a set and not
* just one cache key because when we needed to tweak the write lock manager code to report about why the
* write lock manager is stuck we need it to create the map
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* whereby during a commit where entiteis are merged into the shared cache a thread might be trying to
* grab several write locks. so here we have a mix between the concurrency manager cache key a thread
* currently wants together with cache keys the write lock managed is not managing to grab.
*
* @param waitingOnAcquireReadCacheKey
* cache key the thread is failing to acquire in the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#acquireReadLock()}
* @param threadWaitingToReleaseDeferredLocks
* true if the curren thread is now blocked waiting to confirm the locks it deferred have finished
* building the corresponding objects.
* @param thread
* the thread eing described
* @param currentThreadNumber
* just loop incremented index to help the dump log messages give the feeling of the current thread being
* described and how many more threads are still to be described
* @param totalNumberOfThreads
* the total number of threads being described in a for loop
* @return a string describing the thread provided. We can see the active locks, deferred locks, read locks etc...
* as well sa if the thread is waiting to acquire a specific cache key or waiting for build object to
* complete.
* @param writeManagerThreadPrimaryKeysWithChangesToBeMerged
* Null for all threads excep those that are currently about to commit and merge changes to the shared
* cache. In this case it holds the primary keys of the objects that were changed by the transaction. The
* write lock manager has been tweaked to store information about objects ids that the current thread has
* in its hands and that will required for write locks to be acquired by a committing thread. This
* information is especially interesting if any thread participating in a dead lock is getting stuck in
* the acquisition of write locks as part of the commit process. This information might end up revealing
* a thread that has done too many changes and is creating a bigger risk fo dead lock. The more resources
* an individual thread tries to grab the worse it is for the concurrency layer. The size of the change
* set can be interesting.
* @param waitingToReleaseDeferredLocksJustification
* when a thread is stuck for more than 500 ms in the release defferred locks algorithm, the concurrency
* manager starts try to justify why the method isBuildObjectComplete keeps returning false. This
* information is important whenever the param thread waiting to release deferred locks is true
*/
protected String createInformationAboutAllResourcesAcquiredAndDeferredByThread(
ReadLockManager readLockManager, DeferredLockManager lockManager,
Set<ConcurrencyManager> waitingOnAcquireCacheKeys, ConcurrencyManager waitingOnAcquireReadCacheKey,
boolean threadWaitingToReleaseDeferredLocks, Thread thread,
int currentThreadNumber, int totalNumberOfThreads,
Set<Object> writeManagerThreadPrimaryKeysWithChangesToBeMerged,
String waitingToReleaseDeferredLocksJustification) {
// (a) Build a base overview summary of the thread state
StringWriter writer = new StringWriter();
String threadName = thread.getName();
// (i) A base summary about the current thread
// is the thread waiting to acquire a lock or is it waiting to release deferred locks
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_1", new Object[] {currentThreadNumber, totalNumberOfThreads, thread.getName(), threadWaitingToReleaseDeferredLocks}));
// (iii) Information is this is a thread in the process of trying to acquire for writing a cache key
if (waitingOnAcquireCacheKeys != null && !waitingOnAcquireCacheKeys.isEmpty()) {
for (ConcurrencyManager waitingOnAcquireCacheKey : waitingOnAcquireCacheKeys) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_2", new Object[] {createToStringExplainingOwnedCacheKey(waitingOnAcquireCacheKey)}));
}
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_3"));
}
// (iv) Information is this is a thread in the process of trying to acquire for reading a cache key
if (waitingOnAcquireReadCacheKey != null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_4", new Object[] {createToStringExplainingOwnedCacheKey(waitingOnAcquireReadCacheKey)}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_5"));
}
// (v) if the thread is stuck in the write lock manager trying to acquire all write locks to commit and merge
// changes to the shared
// cache this information might be interesting
boolean currentThreadIsTryingCommitToSharedCacheChanges = writeManagerThreadPrimaryKeysWithChangesToBeMerged != null
&& !writeManagerThreadPrimaryKeysWithChangesToBeMerged.isEmpty();
if (currentThreadIsTryingCommitToSharedCacheChanges) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_6", new Object[] {writeManagerThreadPrimaryKeysWithChangesToBeMerged.toString()}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_7"));
}
// Start dumping information about the deferred lock and read lock manager of this thread
// (b) Add information about the cache keys where the current thread was set as actively owning
writer.write(ConcurrencyUtil.SINGLETON.createStringWithSummaryOfActiveLocksOnThread(lockManager, threadName));
// (c) Now very interesting as well are all of the objects that current thread could not acquire the deferred locks are essential
writer.write(createStringWithSummaryOfDeferredLocksOnThread(lockManager, threadName));
// (d) On the topic of the defferred locks we can also try to do better and explain why the algorithm
// keeps returning false that the build object is not yet complete
if (waitingToReleaseDeferredLocksJustification != null && waitingToReleaseDeferredLocksJustification.length() > 0) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_8", new Object[] {waitingToReleaseDeferredLocksJustification}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_9"));
}
// (e) Add information about all cache keys te current thread acquired with READ permission
writer.write(createStringWithSummaryOfReadLocksAcquiredByThread(readLockManager, threadName));
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_10", new Object[] {currentThreadNumber, totalNumberOfThreads}));
return writer.toString();
}
/**
* Clone the static map of the concurrency manager that tells us about threads waiting to acquire locks.
*
* @param mapThreadToWaitOnAcquireOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, ConcurrencyManager> cloneMapThreadToWaitOnAcquire(Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal) {
return new HashMap<>(mapThreadToWaitOnAcquireOriginal);
}
/**
* Clone the map of the method names that tells us justification where threads acquire locks.
*
* @param mapThreadToWaitOnAcquireOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, String> cloneMapThreadToMethodName(Map<Thread, String> mapThreadToWaitOnAcquireOriginal) {
return new HashMap<>(mapThreadToWaitOnAcquireOriginal);
}
/**
* Clone the static map of the concurrency manager that tells us about threads waiting to acquire locks.
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, Set<ConcurrencyManager>> cloneMapThreadToWaitOnAcquireInsideWriteLockManagerOriginal(
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal) {
Map<Thread, Set<ConcurrencyManager>> result = new HashMap<>();
// this iterator is safe because the original map is a concurrent hashmap so the iterator should not blow up
for (Map.Entry<Thread, Set<ConcurrencyManager>> entry : mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal.entrySet()) {
Set<ConcurrencyManager> clonedSet = new HashSet<>(entry.getValue());
result.put(entry.getKey(), clonedSet);
}
return result;
}
/**
* We have two maps we are using to trace threads that are stuck acquiring locks.
* One map is found in the concurrency manager the other in the write lock manager.
* When we start dumping information we only care about working with one and only one map.
* Therefore we merge the two maps together since semantically they both mean the exact same thing:
* a thread A wants a cachekey B for writing and is not getting it.
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerClone
* this is the map we want o enrich
* @param mapThreadToWaitOnAcquireClone
* this is the map whose entries we want to copy into the map to enrich
*/
public static void enrichMapThreadToWaitOnAcquireInsideWriteLockManagerClone(
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerClone, Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireClone ) {
// (a) Loop over each of the threads the map of mapThreadToWaitOnAcquireClone
// and add the cache keys threads are waiting for into the corresponding entery of the
// mapThreadToWaitOnAcquireInsideWriteLockManagerClone
for (Map.Entry<Thread, ConcurrencyManager> entry : mapThreadToWaitOnAcquireClone.entrySet()) {
Thread currentThread = entry.getKey();
if(!mapThreadToWaitOnAcquireInsideWriteLockManagerClone.containsKey(currentThread)) {
mapThreadToWaitOnAcquireInsideWriteLockManagerClone.put(currentThread, new HashSet<>());
}
Set<ConcurrencyManager> cacheKeys = mapThreadToWaitOnAcquireInsideWriteLockManagerClone.get(currentThread);
cacheKeys.add(entry.getValue());
}
}
/**
* A set of threads that are at the end of object building and are waiting for the deferred locks to be resolved.
*
* @param setThreadWaitingToReleaseDeferredLocksOriginal
* the original set of threads that are waiting for deferred locks to be resolved.
* @return A cloned has set of threads waiting for their deferred locks to be resolved.
*/
public static Set<Thread> cloneSetThreadsThatAreCurrentlyWaitingToReleaseDeferredLocks(
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal) {
return new HashSet<>(setThreadWaitingToReleaseDeferredLocksOriginal);
}
/**
* Clone the information about threads that are in the write lock manager trying to commit and the object ids they
* are holding with some arbitrary changes.
*
* @param mapThreadToObjectIdWithWriteLockManagerChangesOriginal
* map of thread to the primary keys of of objects changed by a transaction in the commit phase. This is
* the original map grabbed from the WriteLockManager.
* @return a cloned map of thread to object id primary keys that a thread committing might have changed.
*/
public static Map<Thread, Set<Object>> cloneMapThreadToObjectIdWithWriteLockManagerChanges(
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
Map<Thread, Set<Object>> result = new HashMap<>();
for (Map.Entry<Thread, Set<Object>> currentEntry : mapThreadToObjectIdWithWriteLockManagerChangesOriginal.entrySet()) {
result.put(currentEntry.getKey(), new HashSet<>(currentEntry.getValue()));
}
return result;
}
/**
* To facilitate algorithms that want to dump a snapshot of the current state of the concurrency manager or to start
* a hunt for dead locks this api faciliates the boostraping logic of such algorithms by giving the algorithm a
* stable clone of the map of read locks that we know will not change throughout the time the algorithm is running.
*
* @param readLockManagersOriginal
* This the original map of read locks referred by the concurrency manager. This is a very bad platform
* to work with because if for whatever reason not all threads are frozen and some are actualy managing
* to complete their transactions the contents of this map are systematically changing with threds being
* added in and removed.
* @return A clone of the readLockManagersOriginal. Essentially the map instance returned is new and independent and
* the values {@link ReadLockManager} are also clones and independent. The only thing that is
* not cloned here - whose state could be changing - are the cache key themselves. The cache keys pointed by
* the vector {@link ReadLockManager#getReadLocks()} are the original values. So our clone
* from the read lock manager is not a perfectly stable clone. It will not be blowing up telling us
* concurrent access modification when we loop through the vector. But no one can guarnate the number of
* readers on the cache key stays the same nor that the active thread on a cache key stays the same... Those
* values can definitely be fluctuating (not ideal ... but it would be quite hard to get better than this).
*/
public Map<Thread, ReadLockManager> cloneReadLockManagerMap(Map<Thread, ReadLockManager> readLockManagersOriginal) {
// (a) Start by safeguarding the keys of the map we want to clone
// (e.g. avoid the risk of concurrent modification exception while looping over a keyset)
List<Thread> mapKeys = new ArrayList<>(readLockManagersOriginal.keySet());
// (b) start the the cloning process
Map<Thread, ReadLockManager> cloneResult = new HashMap<>();
for (Thread currentKey : mapKeys) {
ReadLockManager readLockManagerOriginal = readLockManagersOriginal.get(currentKey);
if (readLockManagerOriginal != null) {
ReadLockManager readLockManagerClone = readLockManagerOriginal.clone();
cloneResult.put(currentKey, readLockManagerClone);
} else {
// most likely the current thread has just finished its work
// and is no longer to be found in the original map
}
}
// (c) The caller of this method can do with it whatever it wants because no one will be modifying this map
// nor the contained
return cloneResult;
}
/**
* The exact same thing as the {@link #cloneReadLockManagerMap(Map)} but the map we are cloning here is the one of
* threads to deferred locks
*
* @param deferredLockManagersOriginal
* the original map taken from the conrruency manager itself
* @return A clone of that map that is a relatively stable data structure to work with since no new threads will
* register in or out in the map nor will the DeferredLockManager values be changing. As for the read lock
* manager we have no assurance as to what is happening with the cache keys themselves refered by the
* {@link DeferredLockManager} values, the cache keys are always changing their metadata as new threads come
* in to do work or finish doing work. So it is not a perfect snapshot of the state of the system, but it is
* as close as we can get.
*/
public Map<Thread, DeferredLockManager> cloneDeferredLockManagerMap(Map<Thread, DeferredLockManager> deferredLockManagersOriginal) {
// (a) Start by safeguarding the keys of the map we want to clone
// (e.g. avoid the risk of concurrent modification exception while looping over a keyset)
List<Thread> mapKeys = new ArrayList<>(deferredLockManagersOriginal.keySet());
// (b) start the the cloning process
Map<Thread, DeferredLockManager> cloneResult = new HashMap<>();
for (Thread currentKey : mapKeys) {
DeferredLockManager deferredLockManagerOriginal = deferredLockManagersOriginal.get(currentKey);
if (deferredLockManagerOriginal != null) {
DeferredLockManager deferredLockManagerClone = cloneDeferredLockManager(deferredLockManagerOriginal);
cloneResult.put(currentKey, deferredLockManagerClone);
} else {
// most likely the current thread has just finished its work
// and is no longer to be found in the original map
}
}
// (c) The caller of this method can do with it whatever it wants because no one will be modifying this map
// nor the contained
return cloneResult;
}
/**
* Clone an original {@link DeferredLockManager} so that our algorithms of state dump or dead lock search can safely
* work ina stable model state that is not constantly changing.
*
* @param deferredLockManagerOriginal
* an object that is originating from the map of thread to deferred locks from the concurrency manager
* class. We do not want to be carrying around the original object while try to make a dump/snapshot of
* the current state of the concurrency manager since these objects are always mutating. Locks are being
* acquired and released etc... All the tiem. The only objest thta will be stable are those of threads
* involved ina dead lock. And those are the threads that matter the most to us anyway.
* @return a cloned deferred lock manager. The newly created deferred lock manager will have its vectors of cache
* keys holding references the same cache keys as the original object. The cache keys themselves are not
* cloned. That measn that the DeferredLockManager will be immuatable in terms of its vectors and held
* references. But the objects it refers to (e.g. cache keys) can be mutating all the time if new readers or
* active threads arrive.
*/
@SuppressWarnings("rawtypes")
public DeferredLockManager cloneDeferredLockManager(DeferredLockManager deferredLockManagerOriginal) {
// (a) Start by cloning from the original the two vectors of cache keys is administers
Vector cloneOfActiveLocks = (Vector) deferredLockManagerOriginal.getActiveLocks().clone();
Vector cloneOfDeferredLocks = (Vector) deferredLockManagerOriginal.getDeferredLocks().clone();
// (b) Build our clone object
DeferredLockManager deferredLockManagerClone = new DeferredLockManager();
deferredLockManagerClone.setIsThreadComplete(deferredLockManagerOriginal.isThreadComplete());
// NOTE: the DeferredLockManager follows a very bad practice
// it gives direct acess to its internal state from outside
// it gives us direct access to its referred lists
// so the internal private state of the deferredLockManager can be modified directly from the outisde
// by anybody...
// but we use the apis we have access to.
deferredLockManagerClone.getActiveLocks().addAll(cloneOfActiveLocks);
deferredLockManagerClone.getDeferredLocks().addAll(cloneOfDeferredLocks);
return deferredLockManagerClone;
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey by setting on the cache keys the threads
* that are stuck trying to acquire the cache key.
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we are trying to enirhc with additional information
* @param unifiedMapOfThreadsStuckTryingToAcquireWriteLock
* a map telling us about threads that at a certain point in time were not progressing anywhere because
* they were waiting to acquire a write lock. These are threads either stuck on the concurrency manager
* or in the write lock manager during a transaction commmit
*
*
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquire(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock) {
// (a) Loop over each thread that registered itself as being waiting to lock a cache key
for (Map.Entry<Thread, Set<ConcurrencyManager>> currentEntry : unifiedMapOfThreadsStuckTryingToAcquireWriteLock
.entrySet()) {
Thread currentThread = currentEntry.getKey();
for (ConcurrencyManager cacheKeyThreadIsWaitingToAcquire : currentEntry.getValue()) {
CacheKeyToThreadRelationships dto = get(cacheKeyThreadIsWaitingToAcquire, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsKnownToBeStuckTryingToAcquireLock(currentThread);
}
}
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey by setting on the cache keys the threads
* that are stuck trying to acquire the cache key with a read lock. These are threads stuck on the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#acquireReadLock()}
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we are trying to enirhc with additional information
* @param mapThreadToWaitOnAcquireReadLockClone
* a map telling us about threads that at a certain point in time were not progressing anywhere because
* they were waiting to acquire a lock.
*
*
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquireLockForReading(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone) {
// (a) Loop over each thread that registered itself as being waiting to lock a cache key
for (Map.Entry<Thread, ConcurrencyManager> currentEntry : mapThreadToWaitOnAcquireReadLockClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
ConcurrencyManager cacheKeyThreadIsWaitingToAcquire = currentEntry.getValue();
CacheKeyToThreadRelationships dto = get(cacheKeyThreadIsWaitingToAcquire,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsKnownToBeStuckTryingToAcquireLockForReading(currentThread);
}
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey based on the read locks
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* a map whose metadata we need to enrich
* @param readLockManagerMapClone
* map cloned from the original map and that gives us a snapshot of threads that acquired read locks
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutReadLocks(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, ReadLockManager> readLockManagerMapClone) {
// (a) Loop over each thread that is regisered as having acquired read locks
for (Map.Entry<Thread, ReadLockManager> currentEntry : readLockManagerMapClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
ReadLockManager currentValue = currentEntry.getValue();
// (b) loop over each read lock acquired by the current thread
// enrich the map of cache key to thread doing something in respect to the cache key
for (ConcurrencyManager cacheKeyAcquiredReadLock : currentValue.getReadLocks()) {
CacheKeyToThreadRelationships dto = get(cacheKeyAcquiredReadLock,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredReadLock(currentThread);
}
}
}
/**
* Enrich our map map of cache key to threads having a relationship with that object in regards to active locks on
* the cache key and deferred locks on the cache key
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we want to enrich with more information
* @param deferredLockManagerMapClone
* the cloned map with information about threads and their deferred locks.
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutActiveAndDeferredLocks(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, DeferredLockManager> deferredLockManagerMapClone) {
// (a) Loop over each thread that has a deferred lock manager
for (Map.Entry<Thread, DeferredLockManager> currentEntry : deferredLockManagerMapClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
DeferredLockManager currentValue = currentEntry.getValue();
// (b) First we focus on the active locks owned by the thread
// enrich the map of cache key to thread doing something in respect to the cache key
for (Object activeLockObj : currentValue.getActiveLocks()) {
ConcurrencyManager activeLock = (ConcurrencyManager) activeLockObj;
CacheKeyToThreadRelationships dto = get(activeLock, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredActiveLock(currentThread);
}
// (c) Now we go over the defferred locks on this thread
// (e.g. object locks that it could not acquire because some other thread was active at the time owning the
// lock)
for (Object deferredLockObj : currentValue.getDeferredLocks()) {
ConcurrencyManager deferredLock = (ConcurrencyManager) deferredLockObj;
CacheKeyToThreadRelationships dto = get(deferredLock, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredDeferredLock(currentThread);
}
}
}
/**
* Helper method to make sure we never get null dto from the
* mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.
*
* @param cacheKey
* the cache key we are search for
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map of cache key to concurrency manager locking metadata
* @return never returls null. If the cache key is not yet in the map a ney entry is returned.
*/
protected CacheKeyToThreadRelationships get(ConcurrencyManager cacheKey,
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey) {
if (!mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.containsKey(cacheKey)) {
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.put(cacheKey,
new CacheKeyToThreadRelationships(cacheKey));
}
return mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.get(cacheKey);
}
/**
* If when we are decrement the counter of number of readers on a cache key we find ourselves lacking the read lock
* manager at the time of the decrement we want to log a big fat error on the server log protecting that the current
* thread is misbehaving.
*
* @param currentNumberOfReaders
* the current count of readers on the cache key about to be decremented
* @param decrementedNumberOfReaders
* the number of readers of the cache key if we subtract one reader
* @param cacheKey
* the cache key that is about to suffer a decrement on the number of readers
*/
public String readLockManagerProblem01CreateLogErrorMessageToIndicateThatCurrentThreadHasNullReadLockManagerWhileDecrementingNumberOfReaders(
final int currentNumberOfReaders, final int decrementedNumberOfReaders, ConcurrencyManager cacheKey) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem01", new Object[] {currentThread.getName(), currentNumberOfReaders, decrementedNumberOfReaders,
ConcurrencyUtil.SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey), enrichGenerateThreadDumpForCurrentThread(), ConversionManager.getDefaultManager().convertObject(new Date(), String.class).toString()}));
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
return writer.toString();
}
public String readLockManagerProblem02ReadLockManageHasNoEntriesForThread(ConcurrencyManager cacheKey, long threadId) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem02", new Object[] {currentThread.getName(), SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey),
threadId, enrichGenerateThreadDumpForCurrentThread(), ConversionManager.getDefaultManager().convertObject(new Date(), String.class).toString()}));
// We do log immediately the error as we spot it
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
// we also return the error message we just logged to added it to our tracing permanently
return writer.toString();
}
public String readLockManagerProblem03ReadLockManageHasNoEntriesForThread(ConcurrencyManager cacheKey, long threadId) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem03", new Object[] {currentThread.getName(), SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey),
threadId, enrichGenerateThreadDumpForCurrentThread(), ConversionManager.getDefaultManager().convertObject(new Date(), String.class).toString()}));
// We do log immediately the error as we spot it
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
// we also return the error message we just logged to added it to our tracing permanently
return writer.toString();
}
/**
* The concurrency managers about to acquire a cache key. And since we have been suffering from cache corruption on
* the acquire read locks we need to collect a lot more information about the time of acquisition of a read lock.
*
* @param concurrencyManager
* the cache key we are about to increment and acquire for reading
* @return object that have all the context information to allow us to know when and where
* exactly this key acquisition took place.
*/
public ReadLockAcquisitionMetadata createReadLockAcquisitionMetadata(ConcurrencyManager concurrencyManager) {
final boolean isAllowTakingStackTraceDuringReadLockAcquisition = isAllowTakingStackTraceDuringReadLockAcquisition();
String currentThreadStackTraceInformation = TraceLocalization.buildMessage("concurrency_util_read_lock_acquisition_metadata");
long currentThreadStackTraceInformationCpuTimeCostMs = 0l;
if (isAllowTakingStackTraceDuringReadLockAcquisition) {
long startTimeMillis = System.currentTimeMillis();
currentThreadStackTraceInformation = enrichGenerateThreadDumpForCurrentThread();
long endTimeMillis = System.currentTimeMillis();
currentThreadStackTraceInformationCpuTimeCostMs = endTimeMillis - startTimeMillis;
}
int numberOfReadersOnCacheKeyBeforeIncrementingByOne = concurrencyManager.getNumberOfReaders();
// data in ReadLockAcquisitionMetadata are immutable it reflects an accurate snapshot of the time of acquisition
return new ReadLockAcquisitionMetadata(concurrencyManager, numberOfReadersOnCacheKeyBeforeIncrementingByOne,
currentThreadStackTraceInformation, currentThreadStackTraceInformationCpuTimeCostMs);
}
private int getIntProperty(final String key, final int defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Integer.parseInt(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
private long getLongProperty(final String key, final long defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Long.parseLong(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
private boolean getBooleanProperty(final String key, final boolean defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Boolean.parseBoolean(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
}