[JBoss JIRA] (ISPN-6099) ConcurrentJoinTest random failures
by Bela Ban (JIRA)
[ https://issues.jboss.org/browse/ISPN-6099?page=com.atlassian.jira.plugin.... ]
Bela Ban commented on ISPN-6099:
--------------------------------
I see that port_range in {{infinispan/core/src/test/resources/stacks/tcp.xml}} is set to 30, but set to 99 programmatically. Perhaps change this to 500, just to see if the issue disappears?
> ConcurrentJoinTest random failures
> ----------------------------------
>
> Key: ISPN-6099
> URL: https://issues.jboss.org/browse/ISPN-6099
> Project: Infinispan
> Issue Type: Bug
> Components: Test Suite - Core
> Affects Versions: 8.1.0.Final
> Environment: java version "1.8.0_60"
> Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
> Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Fix For: 8.2.0.Beta1
>
>
> Since the switch to {{TCP_NIO2}} in the test suite, I've been seeing random failures in {{ConcurrentJoinTest}} and other tests that attempt to start multiple channels in parallel (e.g. {{StateTransferFunctionalTest}} and its subclasses).
> Normally JGroups only reports a {{java.net.BindException: No available port to bind to in range [8000 .. 8099]}}, but I have modified {{org.jgroups.util.Util.createServerSocket()}} to report the cause exception and I got this:
> {noformat}
> java.net.BindException: No available port to bind to in range [8000 .. 8099]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3077) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.blocks.cs.NioServer.<init>(NioServer.java:86) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.protocols.TCP_NIO2.start(TCP_NIO2.java:97) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.stack.ProtocolStack.startStack(ProtocolStack.java:966) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.startStack(JChannel.java:890) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel._preConnect(JChannel.java:553) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:288) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:279) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.startJGroupsChannelIfNeeded(JGroupsTransport.java:199) ~[classes/:?]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.start(JGroupsTransport.java:190) ~[classes/:?]
> at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_60]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_60]
> at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:168) ~[infinispan-commons-8.2.0-SNAPSHOT.jar:8.2.0-SNAPSHOT]
> at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:870) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:639) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:628) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:531) ~[classes/:?]
> at org.infinispan.factories.GlobalComponentRegistry.start(GlobalComponentRegistry.java:229) ~[classes/:?]
> ... 11 more
> Caused by: java.net.SocketException: Invalid argument
> at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:433) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:425) ~[?:1.8.0_60]
> at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:1.8.0_60]
> at java.nio.channels.ServerSocketChannel.bind(ServerSocketChannel.java:157) ~[?:1.8.0_60]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3072) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6100) L1 entries not always stored as L1InternalCacheEntry
by Dan Berindei (JIRA)
Dan Berindei created ISPN-6100:
----------------------------------
Summary: L1 entries not always stored as L1InternalCacheEntry
Key: ISPN-6100
URL: https://issues.jboss.org/browse/ISPN-6100
Project: Infinispan
Issue Type: Bug
Components: Core, Test Suite - Core
Affects Versions: 8.1.0.Final
Reporter: Dan Berindei
Assignee: Dan Berindei
Fix For: 8.2.0.Beta1
{{DistributedClusteringLogic.commitSingleEntry}} is using regular {{Metadata}} instead of {{L1Metadata}} when storing entries that are not owned by the local node. The entry will then be stored as a regular {{MortalCacheEntry}} instead of an {{L1InternalCacheEntry}}.
In non-transactional mode, I believe this can only happen if the node was an owner at the time of entry wrapping. I'm not sure if the same applies in transactional caches.
{{BaseDistFunctionalTest.assertOwnershipAndNonOwnership()}} assumes L1 entries are stored as {{L1InternalCacheEntries}}, so at the very least the mismatch results in random test failures in {{BaseDistFunctionalTest}} subclasses like {{ConcurrentJoinTest}}. It may result in stale data as well.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6099) ConcurrentJoinTest random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-6099?page=com.atlassian.jira.plugin.... ]
Dan Berindei commented on ISPN-6099:
------------------------------------
I found 2 JDK bugs with the same error: https://bugs.openjdk.java.net/browse/JDK-8022394 and https://bugs.openjdk.java.net/browse/JDK-8024710. However, I'm running Fedora 23, and they are both specific to Mac OS X. (I ran their reproducers and they passed on my machine.)
> ConcurrentJoinTest random failures
> ----------------------------------
>
> Key: ISPN-6099
> URL: https://issues.jboss.org/browse/ISPN-6099
> Project: Infinispan
> Issue Type: Bug
> Components: Test Suite - Core
> Affects Versions: 8.1.0.Final
> Environment: java version "1.8.0_60"
> Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
> Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Fix For: 8.2.0.Beta1
>
>
> Since the switch to {{TCP_NIO2}} in the test suite, I've been seeing random failures in {{ConcurrentJoinTest}} and other tests that attempt to start multiple channels in parallel (e.g. {{StateTransferFunctionalTest}} and its subclasses).
> Normally JGroups only reports a {{java.net.BindException: No available port to bind to in range [8000 .. 8099]}}, but I have modified {{org.jgroups.util.Util.createServerSocket()}} to report the cause exception and I got this:
> {noformat}
> java.net.BindException: No available port to bind to in range [8000 .. 8099]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3077) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.blocks.cs.NioServer.<init>(NioServer.java:86) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.protocols.TCP_NIO2.start(TCP_NIO2.java:97) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.stack.ProtocolStack.startStack(ProtocolStack.java:966) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.startStack(JChannel.java:890) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel._preConnect(JChannel.java:553) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:288) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:279) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.startJGroupsChannelIfNeeded(JGroupsTransport.java:199) ~[classes/:?]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.start(JGroupsTransport.java:190) ~[classes/:?]
> at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_60]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_60]
> at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:168) ~[infinispan-commons-8.2.0-SNAPSHOT.jar:8.2.0-SNAPSHOT]
> at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:870) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:639) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:628) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:531) ~[classes/:?]
> at org.infinispan.factories.GlobalComponentRegistry.start(GlobalComponentRegistry.java:229) ~[classes/:?]
> ... 11 more
> Caused by: java.net.SocketException: Invalid argument
> at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:433) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:425) ~[?:1.8.0_60]
> at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:1.8.0_60]
> at java.nio.channels.ServerSocketChannel.bind(ServerSocketChannel.java:157) ~[?:1.8.0_60]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3072) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6099) ConcurrentJoinTest random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-6099?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-6099:
-------------------------------
Status: Open (was: New)
> ConcurrentJoinTest random failures
> ----------------------------------
>
> Key: ISPN-6099
> URL: https://issues.jboss.org/browse/ISPN-6099
> Project: Infinispan
> Issue Type: Bug
> Components: Test Suite - Core
> Affects Versions: 8.1.0.Final
> Environment: java version "1.8.0_60"
> Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
> Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Fix For: 8.2.0.Beta1
>
>
> Since the switch to {{TCP_NIO2}} in the test suite, I've been seeing random failures in {{ConcurrentJoinTest}} and other tests that attempt to start multiple channels in parallel (e.g. {{StateTransferFunctionalTest}} and its subclasses).
> Normally JGroups only reports a {{java.net.BindException: No available port to bind to in range [8000 .. 8099]}}, but I have modified {{org.jgroups.util.Util.createServerSocket()}} to report the cause exception and I got this:
> {noformat}
> java.net.BindException: No available port to bind to in range [8000 .. 8099]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3077) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.blocks.cs.NioServer.<init>(NioServer.java:86) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.protocols.TCP_NIO2.start(TCP_NIO2.java:97) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.stack.ProtocolStack.startStack(ProtocolStack.java:966) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.startStack(JChannel.java:890) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel._preConnect(JChannel.java:553) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:288) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.jgroups.JChannel.connect(JChannel.java:279) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.startJGroupsChannelIfNeeded(JGroupsTransport.java:199) ~[classes/:?]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.start(JGroupsTransport.java:190) ~[classes/:?]
> at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_60]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_60]
> at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:168) ~[infinispan-commons-8.2.0-SNAPSHOT.jar:8.2.0-SNAPSHOT]
> at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:870) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:639) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:628) ~[classes/:?]
> at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:531) ~[classes/:?]
> at org.infinispan.factories.GlobalComponentRegistry.start(GlobalComponentRegistry.java:229) ~[classes/:?]
> ... 11 more
> Caused by: java.net.SocketException: Invalid argument
> at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:433) ~[?:1.8.0_60]
> at sun.nio.ch.Net.bind(Net.java:425) ~[?:1.8.0_60]
> at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:1.8.0_60]
> at java.nio.channels.ServerSocketChannel.bind(ServerSocketChannel.java:157) ~[?:1.8.0_60]
> at org.jgroups.util.Util.createServerSocketChannel(Util.java:3072) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6099) ConcurrentJoinTest random failures
by Dan Berindei (JIRA)
Dan Berindei created ISPN-6099:
----------------------------------
Summary: ConcurrentJoinTest random failures
Key: ISPN-6099
URL: https://issues.jboss.org/browse/ISPN-6099
Project: Infinispan
Issue Type: Bug
Components: Test Suite - Core
Affects Versions: 8.1.0.Final
Environment: java version "1.8.0_60"
Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)
Reporter: Dan Berindei
Assignee: Dan Berindei
Fix For: 8.2.0.Beta1
Since the switch to {{TCP_NIO2}} in the test suite, I've been seeing random failures in {{ConcurrentJoinTest}} and other tests that attempt to start multiple channels in parallel (e.g. {{StateTransferFunctionalTest}} and its subclasses).
Normally JGroups only reports a {{java.net.BindException: No available port to bind to in range [8000 .. 8099]}}, but I have modified {{org.jgroups.util.Util.createServerSocket()}} to report the cause exception and I got this:
{noformat}
java.net.BindException: No available port to bind to in range [8000 .. 8099]
at org.jgroups.util.Util.createServerSocketChannel(Util.java:3077) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.blocks.cs.NioServer.<init>(NioServer.java:86) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.protocols.TCP_NIO2.start(TCP_NIO2.java:97) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.stack.ProtocolStack.startStack(ProtocolStack.java:966) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.JChannel.startStack(JChannel.java:890) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.JChannel._preConnect(JChannel.java:553) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.JChannel.connect(JChannel.java:288) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.jgroups.JChannel.connect(JChannel.java:279) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
at org.infinispan.remoting.transport.jgroups.JGroupsTransport.startJGroupsChannelIfNeeded(JGroupsTransport.java:199) ~[classes/:?]
at org.infinispan.remoting.transport.jgroups.JGroupsTransport.start(JGroupsTransport.java:190) ~[classes/:?]
at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_60]
at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_60]
at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:168) ~[infinispan-commons-8.2.0-SNAPSHOT.jar:8.2.0-SNAPSHOT]
at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:870) ~[classes/:?]
at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:639) ~[classes/:?]
at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:628) ~[classes/:?]
at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:531) ~[classes/:?]
at org.infinispan.factories.GlobalComponentRegistry.start(GlobalComponentRegistry.java:229) ~[classes/:?]
... 11 more
Caused by: java.net.SocketException: Invalid argument
at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_60]
at sun.nio.ch.Net.bind(Net.java:433) ~[?:1.8.0_60]
at sun.nio.ch.Net.bind(Net.java:425) ~[?:1.8.0_60]
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:1.8.0_60]
at java.nio.channels.ServerSocketChannel.bind(ServerSocketChannel.java:157) ~[?:1.8.0_60]
at org.jgroups.util.Util.createServerSocketChannel(Util.java:3072) ~[jgroups-3.6.7.Final.jar:3.6.7.Final]
{noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6098) LockManagerTest.testMultipleCounterStripped random failures
by Dan Berindei (JIRA)
Dan Berindei created ISPN-6098:
----------------------------------
Summary: LockManagerTest.testMultipleCounterStripped random failures
Key: ISPN-6098
URL: https://issues.jboss.org/browse/ISPN-6098
Project: Infinispan
Issue Type: Bug
Components: Test Suite - Core
Affects Versions: 8.1.0.Final
Reporter: Dan Berindei
Fix For: 8.2.0.Beta1
Doesn't appear to fail in CI, but I did get a couple failures running the test on my machine:
{noformat}
17:42:29,998 ERROR (testng-LockManagerTest:) [UnitTestTestNGListener] Test testMultipleCounterStripped(org.infinispan.lock.LockManagerTest) failed.
java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_60]
at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_60]
at org.infinispan.lock.LockManagerTest.doMultipleCounterTest(LockManagerTest.java:193) ~[test-classes/:?]
at org.infinispan.lock.LockManagerTest.testMultipleCounterStripped(LockManagerTest.java:67) ~[test-classes/:?]
Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236) ~[classes/:?]
at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$CompositeLockPromise.lock(DefaultLockManager.java:305) ~[classes/:?]
at org.infinispan.lock.LockManagerTest.lambda$doMultipleCounterTest$483(LockManagerTest.java:163) ~[test-classes/:?]
... 4 more
{noformat}
In another run, I got a deadlock that I think is related in {{InfinispanLockTest}}:
{noformat}
"testng-InfinispanLockTest" #19 prio=5 os_prio=0 tid=0x00007ff7f0eeb800 nid=0x4f5d waiting on condition [0x00007ff770da5000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000084202448> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
at java.util.concurrent.FutureTask.get(FutureTask.java:191)
at org.infinispan.lock.InfinispanLockTest.testSingleCounter(InfinispanLockTest.java:262)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
at org.testng.TestRunner.privateRun(TestRunner.java:767)
at org.testng.TestRunner.run(TestRunner.java:617)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers: - <0x0000000082875cc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"pool-1011-thread-7" #9840 prio=5 os_prio=0 tid=0x00007ff7380da000 nid=0x75f7 waiting on condition [0x00007ff698409000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000842020d8> (a java.util.concurrent.CompletableFuture$Signaller)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers: - <0x00000000842021f8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"pool-1011-thread-6" #9839 prio=5 os_prio=0 tid=0x00007ff738130800 nid=0x75f6 waiting on condition [0x00007ff699c21000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000842023a0> (a java.util.concurrent.CompletableFuture$Signaller)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers: - <0x0000000084202468> (a java.util.concurrent.ThreadPoolExecutor$Worker)
{noformat}
I also suggest using {{AbstractInfinispanTest.fork()}} instead of an explicit {{ExecutorService}} in both tests, because without the test name in the thread name it's impossible to filter the test logs.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6098) LockManagerTest.testMultipleCounterStripped random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-6098?page=com.atlassian.jira.plugin.... ]
Dan Berindei reassigned ISPN-6098:
----------------------------------
Assignee: Pedro Ruivo
> LockManagerTest.testMultipleCounterStripped random failures
> -----------------------------------------------------------
>
> Key: ISPN-6098
> URL: https://issues.jboss.org/browse/ISPN-6098
> Project: Infinispan
> Issue Type: Bug
> Components: Test Suite - Core
> Affects Versions: 8.1.0.Final
> Reporter: Dan Berindei
> Assignee: Pedro Ruivo
> Fix For: 8.2.0.Beta1
>
>
> Doesn't appear to fail in CI, but I did get a couple failures running the test on my machine:
> {noformat}
> 17:42:29,998 ERROR (testng-LockManagerTest:) [UnitTestTestNGListener] Test testMultipleCounterStripped(org.infinispan.lock.LockManagerTest) failed.
> java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
> at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_60]
> at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_60]
> at org.infinispan.lock.LockManagerTest.doMultipleCounterTest(LockManagerTest.java:193) ~[test-classes/:?]
> at org.infinispan.lock.LockManagerTest.testMultipleCounterStripped(LockManagerTest.java:67) ~[test-classes/:?]
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
> at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236) ~[classes/:?]
> at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$CompositeLockPromise.lock(DefaultLockManager.java:305) ~[classes/:?]
> at org.infinispan.lock.LockManagerTest.lambda$doMultipleCounterTest$483(LockManagerTest.java:163) ~[test-classes/:?]
> ... 4 more
> {noformat}
> In another run, I got a deadlock that I think is related in {{InfinispanLockTest}}:
> {noformat}
> "testng-InfinispanLockTest" #19 prio=5 os_prio=0 tid=0x00007ff7f0eeb800 nid=0x4f5d waiting on condition [0x00007ff770da5000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x0000000084202448> (a java.util.concurrent.FutureTask)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
> at java.util.concurrent.FutureTask.get(FutureTask.java:191)
> at org.infinispan.lock.InfinispanLockTest.testSingleCounter(InfinispanLockTest.java:262)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> at org.testng.TestRunner.privateRun(TestRunner.java:767)
> at org.testng.TestRunner.run(TestRunner.java:617)
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
> at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x0000000082875cc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> "pool-1011-thread-7" #9840 prio=5 os_prio=0 tid=0x00007ff7380da000 nid=0x75f7 waiting on condition [0x00007ff698409000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000842020d8> (a java.util.concurrent.CompletableFuture$Signaller)
> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
> at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
> at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
> at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
> at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
> at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
> at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x00000000842021f8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> "pool-1011-thread-6" #9839 prio=5 os_prio=0 tid=0x00007ff738130800 nid=0x75f6 waiting on condition [0x00007ff699c21000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000842023a0> (a java.util.concurrent.CompletableFuture$Signaller)
> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
> at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
> at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
> at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
> at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
> at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
> at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x0000000084202468> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> {noformat}
> I also suggest using {{AbstractInfinispanTest.fork()}} instead of an explicit {{ExecutorService}} in both tests, because without the test name in the thread name it's impossible to filter the test logs.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-6098) LockManagerTest.testMultipleCounterStripped random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-6098?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-6098:
-------------------------------
Status: Open (was: New)
> LockManagerTest.testMultipleCounterStripped random failures
> -----------------------------------------------------------
>
> Key: ISPN-6098
> URL: https://issues.jboss.org/browse/ISPN-6098
> Project: Infinispan
> Issue Type: Bug
> Components: Test Suite - Core
> Affects Versions: 8.1.0.Final
> Reporter: Dan Berindei
> Assignee: Pedro Ruivo
> Fix For: 8.2.0.Beta1
>
>
> Doesn't appear to fail in CI, but I did get a couple failures running the test on my machine:
> {noformat}
> 17:42:29,998 ERROR (testng-LockManagerTest:) [UnitTestTestNGListener] Test testMultipleCounterStripped(org.infinispan.lock.LockManagerTest) failed.
> java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
> at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_60]
> at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_60]
> at org.infinispan.lock.LockManagerTest.doMultipleCounterTest(LockManagerTest.java:193) ~[test-classes/:?]
> at org.infinispan.lock.LockManagerTest.testMultipleCounterStripped(LockManagerTest.java:67) ~[test-classes/:?]
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
> at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236) ~[classes/:?]
> at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$CompositeLockPromise.lock(DefaultLockManager.java:305) ~[classes/:?]
> at org.infinispan.lock.LockManagerTest.lambda$doMultipleCounterTest$483(LockManagerTest.java:163) ~[test-classes/:?]
> ... 4 more
> {noformat}
> In another run, I got a deadlock that I think is related in {{InfinispanLockTest}}:
> {noformat}
> "testng-InfinispanLockTest" #19 prio=5 os_prio=0 tid=0x00007ff7f0eeb800 nid=0x4f5d waiting on condition [0x00007ff770da5000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x0000000084202448> (a java.util.concurrent.FutureTask)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
> at java.util.concurrent.FutureTask.get(FutureTask.java:191)
> at org.infinispan.lock.InfinispanLockTest.testSingleCounter(InfinispanLockTest.java:262)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> at org.testng.TestRunner.privateRun(TestRunner.java:767)
> at org.testng.TestRunner.run(TestRunner.java:617)
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
> at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x0000000082875cc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> "pool-1011-thread-7" #9840 prio=5 os_prio=0 tid=0x00007ff7380da000 nid=0x75f7 waiting on condition [0x00007ff698409000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000842020d8> (a java.util.concurrent.CompletableFuture$Signaller)
> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
> at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
> at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
> at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
> at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
> at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
> at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x00000000842021f8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> "pool-1011-thread-6" #9839 prio=5 os_prio=0 tid=0x00007ff738130800 nid=0x75f6 waiting on condition [0x00007ff699c21000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000842023a0> (a java.util.concurrent.CompletableFuture$Signaller)
> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
> at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
> at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
> at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
> at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
> at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
> at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers: - <0x0000000084202468> (a java.util.concurrent.ThreadPoolExecutor$Worker)
> {noformat}
> I also suggest using {{AbstractInfinispanTest.fork()}} instead of an explicit {{ExecutorService}} in both tests, because without the test name in the thread name it's impossible to filter the test logs.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-5955) FAIL_SILENTLY doesn't always prevent rollback with pessimistic transactions
by Paul Ferraro (JIRA)
[ https://issues.jboss.org/browse/ISPN-5955?page=com.atlassian.jira.plugin.... ]
Paul Ferraro commented on ISPN-5955:
------------------------------------
[~dan.berindei] Can we backport this fix to 8.1.x?
> FAIL_SILENTLY doesn't always prevent rollback with pessimistic transactions
> ---------------------------------------------------------------------------
>
> Key: ISPN-5955
> URL: https://issues.jboss.org/browse/ISPN-5955
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 8.0.1.Final, 8.1.0.Beta1
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Labels: testsuite_stability
> Fix For: 8.2.0.Beta1
>
>
> The {{FAIL_SILENTLY}} should "prevent a failing operation from affecting any ongoing JTA transactions", but sometimes this doesn't work properly.
> {{FlagsReplicationTest}} has a transaction using both {{FAIL_SILENTLY}} and {{SKIP_LOCKING}} in the same transaction:
> # A {{lock(FAIL_SILENTLY)(key)}} operation fails.
> Both on the primary owner and on the originator, PessimisticLockingInterceptor sends a TxCompletionNotificationCommand to all the nodes affected by the tx so far, to release the locks. This marks the transaction as completed, but doesn't mark it as rolled back.
> # A {{remove(SKIP_LOCKING)(key)}} operation should then succeed.
> But the operation will invoke a {{ClusteredGetCommand(key, acquireRemoteLock=true, SKIP_LOCKING)}} on both owners, which will in turn invoke locally a {{LockControlCommand(key, SKIP_LOCKING)}}.
> At this point, {{TxInterceptor}} sees that the transaction is already completed, and invokes a {{RollbackCommand}} to mark it as rolled back, then remove it from the transaction table. The command still succeeds.
> # The test then tries to commit the transaction. Usually, the {{PrepareCommand}} doesn't find the remote transaction in the transaction table, and it succeeds.
> But some of the time, because the {{ClusteredGetCommand}} command only uses the first response, the remote transaction is not removed from the transaction table by the time the {{PrepareCommand}} is executed on one of the owners.
> If that happens, the {{PrepareCommand}} executes with a remote transaction instance that's already marked for rollback, and fails when trying to put the key in the context.
> {noformat}
> 15:42:56,736 ERROR (remote-thread-NodeF-p1112-t5:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] ISPN000136: Error executing command LockControlCommand, writing keys []
> org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 0 milliseconds for key replication.FlagsReplicationTest and requestor GlobalTx:NodeG-6318:216. Lock is held by GlobalTx:NodeG-6318:215
> 15:42:56,802 TRACE (OOB-1,NodeF-64741:) [NonTotalOrderTxPerCacheInboundInvocationHandler] Calling perform() on ClusteredGetCommand{key=replication.FlagsReplicationTest, flags=[SKIP_LOCKING]}
> 15:42:56,803 TRACE (OOB-1,NodeF-64741:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] Invoked with command LockControlCommand{cache=dist, keys=[replication.FlagsReplicationTest], flags=[SKIP_LOCKING], unlock=false, gtx=GlobalTx:NodeG-6318:216} and InvocationContext [org.infinispan.context.impl.RemoteTxInvocationContext@75bf6da7]
> 15:42:56,822 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] Invoked with command PrepareCommand {modifications=[RemoveCommand{key=replication.FlagsReplicationTest, value=null, flags=[SKIP_LOCKING], valueMatcher=MATCH_ALWAYS}], onePhaseCommit=true, gtx=GlobalTx:NodeG-6318:216, cacheName='dist', topologyId=6} and InvocationContext [org.infinispan.context.impl.RemoteTxInvocationContext@75bf6da7]
> 15:42:56,832 TRACE (OOB-1,NodeF-64741:GlobalTx:NodeG-6318:216) [TxInterceptor] Rolling back remote transaction GlobalTx:NodeG-6318:216 because either already completed (true) or originator no longer in the cluster (false).
> 15:42:56,864 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [EntryFactoryImpl] Creating new entry for key replication.FlagsReplicationTest
> 15:42:56,864 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [BaseSequentialInvocationContext] Interceptor class org.infinispan.interceptors.EntryWrappingInterceptor threw exception org.infinispan.transaction.xa.InvalidTransactionException: This remote transaction GlobalTx:NodeG-6318:216 is already rolled back
> 15:42:56,873 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [TxInterceptor] invokeNextInterceptorAndVerifyTransaction :: originatorMissing=false, alreadyCompleted=true
> 15:42:56,873 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [TxInterceptor] Rolling back remote transaction GlobalTx:NodeG-6318:216 because either already completed (true) or originator no longer in the cluster (false).
> {noformat}
> Possible actions:
> * Never try to release locks from a {{LockControlCommand}}, wait for the {{RollbackCommand}} instead. This could cause problems if the primary owner dies, the transaction tries to lock the same entry again, and the backup owner that became primary wrongfully assumes that it is a proper owner.
> * Use a {{LockControlCommand(unlock=true)}} instead of a {{TxCompletionNotificationCommand}} to release the backup locks after an operation with {{FAIL_SILENTLY}} failed.
> * Don't set {{acquireRemoteLock=true}} when the {{SKIP_LOCKING}} flag has been set.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months
[JBoss JIRA] (ISPN-5955) FAIL_SILENTLY doesn't always prevent rollback with pessimistic transactions
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5955?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5955:
-------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/infinispan/infinispan/pull/3952
> FAIL_SILENTLY doesn't always prevent rollback with pessimistic transactions
> ---------------------------------------------------------------------------
>
> Key: ISPN-5955
> URL: https://issues.jboss.org/browse/ISPN-5955
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 8.0.1.Final, 8.1.0.Beta1
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Labels: testsuite_stability
> Fix For: 8.2.0.Beta1
>
>
> The {{FAIL_SILENTLY}} should "prevent a failing operation from affecting any ongoing JTA transactions", but sometimes this doesn't work properly.
> {{FlagsReplicationTest}} has a transaction using both {{FAIL_SILENTLY}} and {{SKIP_LOCKING}} in the same transaction:
> # A {{lock(FAIL_SILENTLY)(key)}} operation fails.
> Both on the primary owner and on the originator, PessimisticLockingInterceptor sends a TxCompletionNotificationCommand to all the nodes affected by the tx so far, to release the locks. This marks the transaction as completed, but doesn't mark it as rolled back.
> # A {{remove(SKIP_LOCKING)(key)}} operation should then succeed.
> But the operation will invoke a {{ClusteredGetCommand(key, acquireRemoteLock=true, SKIP_LOCKING)}} on both owners, which will in turn invoke locally a {{LockControlCommand(key, SKIP_LOCKING)}}.
> At this point, {{TxInterceptor}} sees that the transaction is already completed, and invokes a {{RollbackCommand}} to mark it as rolled back, then remove it from the transaction table. The command still succeeds.
> # The test then tries to commit the transaction. Usually, the {{PrepareCommand}} doesn't find the remote transaction in the transaction table, and it succeeds.
> But some of the time, because the {{ClusteredGetCommand}} command only uses the first response, the remote transaction is not removed from the transaction table by the time the {{PrepareCommand}} is executed on one of the owners.
> If that happens, the {{PrepareCommand}} executes with a remote transaction instance that's already marked for rollback, and fails when trying to put the key in the context.
> {noformat}
> 15:42:56,736 ERROR (remote-thread-NodeF-p1112-t5:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] ISPN000136: Error executing command LockControlCommand, writing keys []
> org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 0 milliseconds for key replication.FlagsReplicationTest and requestor GlobalTx:NodeG-6318:216. Lock is held by GlobalTx:NodeG-6318:215
> 15:42:56,802 TRACE (OOB-1,NodeF-64741:) [NonTotalOrderTxPerCacheInboundInvocationHandler] Calling perform() on ClusteredGetCommand{key=replication.FlagsReplicationTest, flags=[SKIP_LOCKING]}
> 15:42:56,803 TRACE (OOB-1,NodeF-64741:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] Invoked with command LockControlCommand{cache=dist, keys=[replication.FlagsReplicationTest], flags=[SKIP_LOCKING], unlock=false, gtx=GlobalTx:NodeG-6318:216} and InvocationContext [org.infinispan.context.impl.RemoteTxInvocationContext@75bf6da7]
> 15:42:56,822 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [InvocationContextInterceptor] Invoked with command PrepareCommand {modifications=[RemoveCommand{key=replication.FlagsReplicationTest, value=null, flags=[SKIP_LOCKING], valueMatcher=MATCH_ALWAYS}], onePhaseCommit=true, gtx=GlobalTx:NodeG-6318:216, cacheName='dist', topologyId=6} and InvocationContext [org.infinispan.context.impl.RemoteTxInvocationContext@75bf6da7]
> 15:42:56,832 TRACE (OOB-1,NodeF-64741:GlobalTx:NodeG-6318:216) [TxInterceptor] Rolling back remote transaction GlobalTx:NodeG-6318:216 because either already completed (true) or originator no longer in the cluster (false).
> 15:42:56,864 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [EntryFactoryImpl] Creating new entry for key replication.FlagsReplicationTest
> 15:42:56,864 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [BaseSequentialInvocationContext] Interceptor class org.infinispan.interceptors.EntryWrappingInterceptor threw exception org.infinispan.transaction.xa.InvalidTransactionException: This remote transaction GlobalTx:NodeG-6318:216 is already rolled back
> 15:42:56,873 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [TxInterceptor] invokeNextInterceptorAndVerifyTransaction :: originatorMissing=false, alreadyCompleted=true
> 15:42:56,873 TRACE (remote-thread-NodeF-p1112-t6:GlobalTx:NodeG-6318:216) [TxInterceptor] Rolling back remote transaction GlobalTx:NodeG-6318:216 because either already completed (true) or originator no longer in the cluster (false).
> {noformat}
> Possible actions:
> * Never try to release locks from a {{LockControlCommand}}, wait for the {{RollbackCommand}} instead. This could cause problems if the primary owner dies, the transaction tries to lock the same entry again, and the backup owner that became primary wrongfully assumes that it is a proper owner.
> * Use a {{LockControlCommand(unlock=true)}} instead of a {{TxCompletionNotificationCommand}} to release the backup locks after an operation with {{FAIL_SILENTLY}} failed.
> * Don't set {{acquireRemoteLock=true}} when the {{SKIP_LOCKING}} flag has been set.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 11 months