From 46898c928a6cb0a6571d50220b74911ed2652dfc Mon Sep 17 00:00:00 2001 From: Radim Vansa Date: Fri, 6 Jan 2017 18:14:39 +0100 Subject: [PATCH] HHH-11373 Silence lock acquisition failures on remote nodes (cherry picked from commit 69ba7a50ce6c1cca893529226e1813121cfa64b1) --- .../infinispan/access/LockingInterceptor.java | 20 ++++++++++++++++++ .../infinispan/util/ExpectingInterceptor.java | 21 ++++++++++++++----- 2 files changed, 36 insertions(+), 5 deletions(-) diff --git a/hibernate-infinispan/src/main/java/org/hibernate/cache/infinispan/access/LockingInterceptor.java b/hibernate-infinispan/src/main/java/org/hibernate/cache/infinispan/access/LockingInterceptor.java index 4027290a40..7e6fd4a5b8 100644 --- a/hibernate-infinispan/src/main/java/org/hibernate/cache/infinispan/access/LockingInterceptor.java +++ b/hibernate-infinispan/src/main/java/org/hibernate/cache/infinispan/access/LockingInterceptor.java @@ -7,8 +7,12 @@ package org.hibernate.cache.infinispan.access; import org.infinispan.commands.write.DataWriteCommand; +import org.infinispan.context.Flag; import org.infinispan.context.InvocationContext; import org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor; +import org.infinispan.util.concurrent.TimeoutException; +import org.infinispan.util.logging.Log; +import org.infinispan.util.logging.LogFactory; import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletionException; @@ -27,6 +31,9 @@ import java.util.concurrent.CompletionException; * {@link CompletableFuture} and we'll wait for it here. */ public class LockingInterceptor extends NonTransactionalLockingInterceptor { + private static final Log log = LogFactory.getLog(LockingInterceptor.class); + private static final boolean trace = log.isTraceEnabled(); + @Override protected Object visitDataWriteCommand(InvocationContext ctx, DataWriteCommand command) throws Throwable { Object returnValue = null; @@ -39,6 +46,19 @@ public class LockingInterceptor extends NonTransactionalLockingInterceptor { returnValue = invokeNextInterceptor(ctx, command); return returnValue; } + catch (TimeoutException e) { + if (!ctx.isOriginLocal() && command.hasFlag(Flag.ZERO_LOCK_ACQUISITION_TIMEOUT)) { + // FAIL_SILENTLY flag is not replicated to remote nodes and zero acquisition timeouts cause + // very noisy logs. + if (trace) { + log.tracef("Silently ignoring exception", e); + } + return null; + } + else { + throw e; + } + } finally { lockManager.unlockAll(ctx); if (returnValue instanceof CompletableFuture) { diff --git a/hibernate-infinispan/src/test/java/org/hibernate/test/cache/infinispan/util/ExpectingInterceptor.java b/hibernate-infinispan/src/test/java/org/hibernate/test/cache/infinispan/util/ExpectingInterceptor.java index fdc578e01f..d4a5b79caf 100644 --- a/hibernate-infinispan/src/test/java/org/hibernate/test/cache/infinispan/util/ExpectingInterceptor.java +++ b/hibernate-infinispan/src/test/java/org/hibernate/test/cache/infinispan/util/ExpectingInterceptor.java @@ -38,17 +38,23 @@ public class ExpectingInterceptor extends BaseCustomInterceptor { } public synchronized Condition when(BiPredicate predicate) { - Condition condition = new Condition(predicate, null); + Condition condition = new Condition(predicate, source(), null); conditions.add(condition); return condition; } public synchronized Condition whenFails(BiPredicate predicate) { - Condition condition = new Condition(predicate, Boolean.FALSE); + Condition condition = new Condition(predicate, source(), Boolean.FALSE); conditions.add(condition); return condition; } + private static String source() { + StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace(); + StackTraceElement ste = stackTrace[3]; + return ste.getFileName() + ":" + ste.getLineNumber(); + } + @Override protected Object handleDefault(InvocationContext ctx, VisitableCommand command) throws Throwable { boolean succeeded = false; @@ -64,7 +70,9 @@ public class ExpectingInterceptor extends BaseCustomInterceptor { for (Iterator iterator = conditions.iterator(); iterator.hasNext(); ) { Condition condition = iterator.next(); log.tracef("Testing condition %s", condition); - if ((condition.success == null || condition.success == succeeded) && condition.predicate.test(ctx, command)) { + if (condition.success != null && condition.success != succeeded) { + log.trace("Condition test failed, succeeded: " + succeeded); + } else if (condition.predicate.test(ctx, command)) { assert condition.action != null; log.trace("Condition succeeded"); toExecute.add(condition.action); @@ -86,12 +94,14 @@ public class ExpectingInterceptor extends BaseCustomInterceptor { public class Condition { private final BiPredicate predicate; + private final String source; private final Boolean success; private BooleanSupplier removeCheck; private Runnable action; - public Condition(BiPredicate predicate, Boolean success) { + public Condition(BiPredicate predicate, String source, Boolean success) { this.predicate = predicate; + this.source = source; this.success = success; } @@ -120,7 +130,8 @@ public class ExpectingInterceptor extends BaseCustomInterceptor { @Override public String toString() { final StringBuilder sb = new StringBuilder("Condition{"); - sb.append("predicate=").append(predicate); + sb.append("source=").append(source); + sb.append(", predicate=").append(predicate); sb.append(", success=").append(success); sb.append(", action=").append(action); sb.append('}');