diff --git a/fe/fe-common/src/main/java/org/apache/doris/common/Config.java b/fe/fe-common/src/main/java/org/apache/doris/common/Config.java index 2df0c7ca44..551de31252 100644 --- a/fe/fe-common/src/main/java/org/apache/doris/common/Config.java +++ b/fe/fe-common/src/main/java/org/apache/doris/common/Config.java @@ -2063,5 +2063,11 @@ public class Config extends ConfigBase { */ @ConfField public static String bdbje_file_logging_level = "ALL"; + + /** + * When holding lock time exceeds the threshold, need to report it. + */ + @ConfField + public static long lock_reporting_threshold_ms = 500L; } diff --git a/fe/fe-core/src/main/java/org/apache/doris/transaction/DatabaseTransactionMgr.java b/fe/fe-core/src/main/java/org/apache/doris/transaction/DatabaseTransactionMgr.java index 42f2a39a2e..cb34343600 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/transaction/DatabaseTransactionMgr.java +++ b/fe/fe-core/src/main/java/org/apache/doris/transaction/DatabaseTransactionMgr.java @@ -31,6 +31,7 @@ import org.apache.doris.catalog.Tablet; import org.apache.doris.catalog.TabletInvertedIndex; import org.apache.doris.catalog.TabletMeta; import org.apache.doris.common.AnalysisException; +import org.apache.doris.common.Config; import org.apache.doris.common.DuplicatedRequestException; import org.apache.doris.common.ErrorCode; import org.apache.doris.common.ErrorReport; @@ -142,6 +143,10 @@ public class DatabaseTransactionMgr { // not realtime usedQuota value to make a fast check for database data quota private volatile long usedQuotaDataBytes = -1; + private long lockWriteStart; + + private long lockReportingThresholdMs = Config.lock_reporting_threshold_ms; + protected void readLock() { this.transactionLock.readLock().lock(); } @@ -152,9 +157,11 @@ public class DatabaseTransactionMgr { protected void writeLock() { this.transactionLock.writeLock().lock(); + lockWriteStart = System.currentTimeMillis(); } protected void writeUnlock() { + checkAndLogWriteLockDuration(lockWriteStart, System.currentTimeMillis()); this.transactionLock.writeLock().unlock(); } @@ -1843,4 +1850,34 @@ public class DatabaseTransactionMgr { readUnlock(); } } + + /** + * Check write lock holding time, if it exceeds threshold, print this hint log. + * + * @param lockStart holing lock start time. + * @param lockEnd release lock time. + */ + private void checkAndLogWriteLockDuration(long lockStart, long lockEnd) { + long duration = lockEnd - lockStart; + if (duration > lockReportingThresholdMs) { + StringBuilder msgBuilder = new StringBuilder(); + msgBuilder.append("lock is held at ") + .append(lockStart) + .append(".And release after ") + .append(duration) + .append(" ms.") + .append("Call stack is :\n") + .append(getStackTrace(Thread.currentThread())); + LOG.info(msgBuilder.toString()); + } + } + + private static String getStackTrace(Thread t) { + final StackTraceElement[] stackTrace = t.getStackTrace(); + StringBuilder msgBuilder = new StringBuilder(); + for (StackTraceElement e : stackTrace) { + msgBuilder.append(e.toString() + "\n"); + } + return msgBuilder.toString(); + } }