LockServiceImpl implements LockService, CloseableRemoteLockService, CloseableLockService, RemoteLockService, LockServiceImplMBean { @VisibleForTesting protected void logSlowLockAcquisition(String lockId, LockClient currentHolder, long durationMillis) { final String slowLockLogMessage = "Blocked for {} ms to acquire lock {} {}."; if (isSlowLogEnabled() && durationMillis >= slowLogTriggerMillis) { SlowLockLogger.logger.warn(slowLockLogMessage, constructSlowLockLogParams(lockId, currentHolder, durationMillis)); } else if (log.isDebugEnabled() && durationMillis > DEBUG_SLOW_LOG_TRIGGER_MILLIS) { log.debug(slowLockLogMessage, constructSlowLockLogParams(lockId, currentHolder, durationMillis)); } } private  LockServiceImpl(LockServerOptions options, Runnable callOnClose, Ownable<ExecutorService> executor); static LockServiceImpl create(); static LockServiceImpl create(LockServerOptions options); static LockServiceImpl create(LockServerOptions options, ExecutorService injectedExecutor); @Override LockRefreshToken lock(String client, LockRequest request); @Override HeldLocksToken lockAndGetHeldLocks(String client, LockRequest request); @Override // We're concerned about sanitizing logs at the info level and above. This method just logs at debug and info. LockResponse lockWithFullLockResponse(LockClient client, LockRequest request); @Override boolean unlock(LockRefreshToken token); @Override boolean unlock(HeldLocksToken token); @Override boolean unlockSimple(SimpleHeldLocksToken token); @Override boolean unlockAndFreeze(HeldLocksToken token); @Override Set<HeldLocksToken> getTokens(LockClient client); @Override Set<HeldLocksToken> refreshTokens(Iterable<HeldLocksToken> tokens); @Override Set<LockRefreshToken> refreshLockRefreshTokens(Iterable<LockRefreshToken> tokens); @Override @Nullable HeldLocksGrant refreshGrant(HeldLocksGrant grant); @Override @Nullable HeldLocksGrant refreshGrant(BigInteger grantId); @Override HeldLocksGrant convertToGrant(HeldLocksToken token); @Override HeldLocksToken useGrant(LockClient client, HeldLocksGrant grant); @Override HeldLocksToken useGrant(LockClient client, BigInteger grantId); @Override @Nullable Long getMinLockedInVersionId(); @Override Long getMinLockedInVersionId(String client); @Override @Nullable Long getMinLockedInVersionId(LockClient client); @Override LockServerOptions getLockServerOptions(); @Override void logCurrentState(); @Override void close(); @Override long currentTimeMillis(); static final int RANDOM_BIT_COUNT; static final String SECURE_RANDOM_ALGORITHM; static final int SECURE_RANDOM_POOL_SIZE; }
@Test public void slowLogShouldBeLoggedWhenLockResponseIsSlowButShouldNotBeLoggedAtDebug() { long lockDurationMillis = SLOW_LOG_TRIGGER_MILLIS + 5; lockServiceWithSlowLogEnabled.logSlowLockAcquisition(TEST_LOCKID, LockClient.ANONYMOUS, lockDurationMillis); assertThat(testLockServiceImplLogger.isDebugEnabled(), is(true)); assertThat(testLockServiceImplLogger.getLoggingEvents().size(), is(0)); assertThat(testSlowLogger.getLoggingEvents().size(), is(1)); assertContainsMatchingLoggingEvent(testSlowLogger.getLoggingEvents(), warn("Blocked for {} ms to acquire lock {} {}.", lockDurationMillis, TEST_LOCKID, "unsuccessfully")); }
@Test public void debugLogShouldBeLoggedWhenLockResponseIsSlowButSlowLogIsDisabled() { long lockDurationMillis = SLOW_LOG_TRIGGER_MILLIS + 5; lockServiceWithSlowLogDisabled.logSlowLockAcquisition(TEST_LOCKID, LockClient.ANONYMOUS, lockDurationMillis); assertThat(testLockServiceImplLogger.isDebugEnabled(), is(true)); assertThat(testLockServiceImplLogger.getLoggingEvents().size(), is(1)); assertContainsMatchingLoggingEvent(testLockServiceImplLogger.getLoggingEvents(), debug("Blocked for {} ms to acquire lock {} {}.", lockDurationMillis, TEST_LOCKID, "unsuccessfully")); assertThat(testSlowLogger.getLoggingEvents().size(), is(0)); }
@Test public void debugLogShouldBeLoggedIfLockResponseTimeIsBetweenDebugTriggerTimeAndSlowLogTriggerMillis() { long lockDurationMillis = SLOW_LOG_TRIGGER_MILLIS - 5; lockServiceWithSlowLogEnabled.logSlowLockAcquisition(TEST_LOCKID, LockClient.ANONYMOUS, lockDurationMillis); assertThat(testLockServiceImplLogger.isDebugEnabled(), is(true)); assertContainsMatchingLoggingEvent(testLockServiceImplLogger.getLoggingEvents(), debug("Blocked for {} ms to acquire lock {} {}.", lockDurationMillis, TEST_LOCKID, "unsuccessfully")); assertThat(testSlowLogger.getLoggingEvents().size(), is(0)); }
@Test public void debugOrSlowLogShouldNotBeLoggedWhenLockResponseIsNotSlow() { lockServiceWithSlowLogEnabled.logSlowLockAcquisition( TEST_LOCKID, LockClient.ANONYMOUS, LockServiceImpl.DEBUG_SLOW_LOG_TRIGGER_MILLIS - 5); assertThat(testLockServiceImplLogger.getLoggingEvents().size(), is(0)); assertThat(testSlowLogger.getLoggingEvents().size(), is(0)); }