INT-4083: RedisLockRegistryTests - Diagnostics

JIRA: https://jira.spring.io/browse/INT-4083

spring-integration-redis/src/main/java/org/springframework/integration/redis/util/RedisLockRegistry.java

@@ -87,7 +87,7 @@ import org.springframework.util.Assert;
  */
 public final class RedisLockRegistry implements LockRegistry {
 
-	private static final Log logger = LogFactory.getLog(LockRegistry.class);
+	private static final Log logger = LogFactory.getLog(RedisLockRegistry.class);
 
 	private static final byte[] hostName;
 
@@ -444,7 +444,7 @@ public final class RedisLockRegistry implements LockRegistry {
 				else {
 					this.thread = currentThread;
 					if (logger.isDebugEnabled()) {
-						logger.debug("New lock; " + this.toString());
+						logger.debug("New lock; " + this);
 					}
 				}
 
@@ -481,9 +481,9 @@ public final class RedisLockRegistry implements LockRegistry {
 		public void unlock() {
 			if (!Thread.currentThread().equals(this.thread)) {
 				if (this.thread == null) {
-					throw new IllegalStateException("Lock is not locked; " + this.toString());
+					throw new IllegalStateException("Lock is not locked; " + this);
 				}
-				throw new IllegalStateException("Lock is owned by " + this.thread.getName() + "; " + this.toString());
+				throw new IllegalStateException("Lock is owned by " + this.thread.getName() + "; " + this);
 			}
 
 			try {
@@ -492,7 +492,7 @@ public final class RedisLockRegistry implements LockRegistry {
 						this.assertLockInRedisIsUnchanged();
 						RedisLockRegistry.this.redisTemplate.delete(constructLockKey());
 						if (logger.isDebugEnabled()) {
-							logger.debug("Released lock; " + this.toString());
+							logger.debug("Released lock; " + this);
 						}
 					}
 					finally {
@@ -512,8 +512,8 @@ public final class RedisLockRegistry implements LockRegistry {
 			RedisLock lockInStore = RedisLockRegistry.this.redisTemplate.boundValueOps(
 					constructLockKey()).get();
 			if (lockInStore == null || !this.equals(lockInStore)) {
-				throw new IllegalStateException("Lock was released due to expiration; " + this.toString()
-						+ (lockInStore == null ? "" : "; lock in store: " + lockInStore.toString()));
+				throw new IllegalStateException("Lock was released due to expiration; " + this
+						+ (lockInStore == null ? "" : "; lock in store: " + lockInStore));
 			}
 		}
 

spring-integration-redis/src/test/java/org/springframework/integration/redis/util/RedisLockRegistryTests.java

@@ -38,8 +38,12 @@ import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.locks.Lock;
 
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+import org.apache.log4j.Level;
 import org.junit.After;
 import org.junit.Before;
+import org.junit.Rule;
 import org.junit.Test;
 
 import org.springframework.data.redis.connection.RedisConnectionFactory;
@@ -47,6 +51,7 @@ import org.springframework.data.redis.core.RedisTemplate;
 import org.springframework.data.redis.serializer.StringRedisSerializer;
 import org.springframework.integration.redis.rules.RedisAvailable;
 import org.springframework.integration.redis.rules.RedisAvailableTests;
+import org.springframework.integration.test.rule.Log4jLevelAdjuster;
 import org.springframework.integration.test.util.TestUtils;
 
 /**
@@ -57,6 +62,11 @@ import org.springframework.integration.test.util.TestUtils;
  */
 public class RedisLockRegistryTests extends RedisAvailableTests {
 
+	private final Log logger = LogFactory.getLog(getClass());
+
+	@Rule
+	public Log4jLevelAdjuster adjuster = new Log4jLevelAdjuster(Level.TRACE, "org.springframework.integration.redis");
+
 	@Before
 	@After
 	public void setupShutDown() {
@@ -282,10 +292,16 @@ public class RedisLockRegistryTests extends RedisAvailableTests {
 				}
 				catch (InterruptedException e) {
 					Thread.currentThread().interrupt();
+					logger.error("Interrupted while locking: " + lock2, e);
 				}
 				finally {
-					lock2.unlock();
-					latch3.countDown();
+					try {
+						lock2.unlock();
+						latch3.countDown();
+					}
+					catch (IllegalStateException e) {
+						logger.error("Failed to unlock: " + lock2, e);
+					}
 				}
 			}
 		});

spring-integration-test/src/main/java/org/springframework/integration/test/rule/Log4jLevelAdjuster.java

@@ -16,9 +16,12 @@
 
 package org.springframework.integration.test.rule;
 
+import java.util.ArrayList;
 import java.util.Arrays;
 import java.util.HashMap;
+import java.util.LinkedHashSet;
 import java.util.Map;
+import java.util.Set;
 
 import org.apache.commons.logging.Log;
 import org.apache.commons.logging.LogFactory;
@@ -58,7 +61,9 @@ public class Log4jLevelAdjuster implements MethodRule {
 	public Log4jLevelAdjuster(Level level, String... categories) {
 		this.level = level;
 		this.classes = new Class<?>[0];
-		this.categories = categories;
+		Set<String> cats = new LinkedHashSet<String>(Arrays.asList(categories));
+		cats.add(getClass().getPackage().getName());
+		this.categories = new ArrayList<String>(cats).toArray(new String[cats.size()]);
 	}
 
 	@Override
@@ -66,9 +71,6 @@ public class Log4jLevelAdjuster implements MethodRule {
 		return new Statement() {
 			@Override
 			public void evaluate() throws Throwable {
-				logger.debug("++++++++++++++++++++++++++++ "
-						+ "Overriding log level setting for: " + Arrays.asList(classes) + " for test "
-						+ method.getName());
 				Map<Class<?>, Level> oldLevels = new HashMap<Class<?>, Level>();
 				for (Class<?> cls : classes) {
 					oldLevels.put(cls, LogManager.getLogger(cls).getEffectiveLevel());
@@ -79,6 +81,9 @@ public class Log4jLevelAdjuster implements MethodRule {
 					oldCatLevels.put(category, LogManager.getLogger(category).getEffectiveLevel());
 					LogManager.getLogger(category).setLevel(level);
 				}
+				logger.debug("++++++++++++++++++++++++++++ "
+						+ "Overridden log level setting for: " + Arrays.asList(classes) + " and "
+						+ Arrays.asList(categories) + " for test " + method.getName());
 				try {
 					base.evaluate();
 				}