If I randomly pick a dunit test that was passing in my intellij a week ago,
I find it failing now and eventually hit a hang.
For example, try running PRBasicIndexCreationDUnitTest.
I git two GREEN tests, three RED tests (caused by SerializationException)
and then it hangs in testCreateIndexFromAccessor.
The SerializationException is pretty difficult to debug... I have no idea
what's going on here (see below).
Knowing that we have this new VALIDATE_SERIALIZABLE_OBJECTS configuration,
I tried adding more properties to this test:
@Override
public Properties getDistributedSystemProperties() {
Properties config = new Properties();
config.put(SERIALIZABLE_OBJECT_FILTER,
"org.apache.geode.cache.query.data.*");
config.put(VALIDATE_SERIALIZABLE_OBJECTS, "true");
return config;
}
But it still fails:
java.lang.AssertionError: An exception occurred during asynchronous
invocation.
at
org.apache.geode.test.dunit.AsyncInvocation.checkException(AsyncInvocation.java:150)
at
org.apache.geode.test.dunit.AsyncInvocation.await(AsyncInvocation.java:343)
at
org.apache.geode.test.dunit.AsyncInvocation.await(AsyncInvocation.java:366)
at
org.apache.geode.cache.query.partitioned.PRBasicIndexCreationDUnitTest.testPartitionedIndexCreationDuringPersistentRecovery(PRBasicIndexCreationDUnitTest.java:470)
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:498)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at
com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
at
com.intellij.rt.execution.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:47)
at
com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:242)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:70)
Caused by: java.lang.AssertionError: Creating Index in this vm failed :
at org.apache.geode.test.dunit.Assert.fail(Assert.java:66)
at
org.apache.geode.cache.query.partitioned.PRQueryDUnitHelper$26.run2(PRQueryDUnitHelper.java:1726)
at
org.apache.geode.cache30.CacheSerializableRunnable.run(CacheSerializableRunnable.java:54)
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:498)
at hydra.MethExecutor.executeObject(MethExecutor.java:244)
at
org.apache.geode.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:70)
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:498)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
at sun.rmi.transport.Transport$1.run(Transport.java:200)
at sun.rmi.transport.Transport$1.run(Transport.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.geode.cache.query.IndexInvalidException
at
org.apache.geode.internal.cache.PartitionedRegion.createIndex(PartitionedRegion.java:8310)
at
org.apache.geode.internal.cache.PartitionedRegion.createIndex(PartitionedRegion.java:8186)
at
org.apache.geode.cache.query.internal.DefaultQueryService.createIndex(DefaultQueryService.java:207)
at
org.apache.geode.cache.query.internal.DefaultQueryService.createIndex(DefaultQueryService.java:170)
at
org.apache.geode.cache.query.internal.DefaultQueryService.createIndex(DefaultQueryService.java:235)
at
org.apache.geode.cache.query.internal.DefaultQueryService.createIndex(DefaultQueryService.java:164)
at
org.apache.geode.cache.query.partitioned.PRQueryDUnitHelper$26.run2(PRQueryDUnitHelper.java:1710)
... 24 more
Caused by: java.util.concurrent.ExecutionException:
org.apache.geode.cache.query.IndexInvalidException
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at
org.apache.geode.internal.cache.PartitionedRegion.createIndex(PartitionedRegion.java:8247)
... 30 more
Caused by: org.apache.geode.cache.query.IndexInvalidException
at
org.apache.geode.cache.query.internal.index.IndexManager.createIndex(IndexManager.java:410)
at
org.apache.geode.internal.cache.PartitionedRegion$IndexTask.createIndexOnPRBuckets(PartitionedRegion.java:9566)
at
org.apache.geode.internal.cache.PartitionedRegion$IndexTask.call(PartitionedRegion.java:9511)
at
org.apache.geode.internal.cache.PartitionedRegion$IndexTask.call(PartitionedRegion.java:9450)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
org.apache.geode.internal.cache.PartitionedRegion.createIndex(PartitionedRegion.java:8246)
... 30 more
Caused by: java.util.concurrent.ExecutionException:
org.apache.geode.cache.query.IndexInvalidException
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at
org.apache.geode.cache.query.internal.index.IndexManager.createIndex(IndexManager.java:378)
... 35 more
Caused by: org.apache.geode.cache.query.IndexInvalidException
at
org.apache.geode.cache.query.internal.index.IndexManager$IndexTask.call(IndexManager.java:1687)
at
org.apache.geode.cache.query.internal.index.IndexManager$IndexTask.call(IndexManager.java:1521)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
org.apache.geode.cache.query.internal.index.IndexManager.createIndex(IndexManager.java:376)
... 35 more
Caused by: org.apache.geode.cache.query.internal.index.IMQException
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex$IMQEvaluator.initializeIndex(CompactRangeIndex.java:1404)
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex.initializeIndex(CompactRangeIndex.java:133)
at
org.apache.geode.cache.query.internal.index.IndexManager$IndexTask.call(IndexManager.java:1669)
... 38 more
Caused by: org.apache.geode.cache.query.QueryInvocationTargetException
at
org.apache.geode.cache.query.internal.AttributeDescriptor.readReflection(AttributeDescriptor.java:120)
at
org.apache.geode.cache.query.internal.AttributeDescriptor.read(AttributeDescriptor.java:83)
at
org.apache.geode.cache.query.internal.PathUtils.evaluateAttribute(PathUtils.java:77)
at
org.apache.geode.cache.query.internal.CompiledPath.evaluate(CompiledPath.java:139)
at
org.apache.geode.cache.query.internal.CompiledPath.evaluate(CompiledPath.java:92)
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex$IMQEvaluator.applyProjectionForIndexInit(CompactRangeIndex.java:1455)
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex$IMQEvaluator.doNestedIterationsForIndexInit(CompactRangeIndex.java:1417)
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex$IMQEvaluator.doNestedIterationsForIndexInit(CompactRangeIndex.java:1426)
at
org.apache.geode.cache.query.internal.index.CompactRangeIndex$IMQEvaluator.initializeIndex(CompactRangeIndex.java:1399)
... 40 more
Caused by: org.apache.geode.SerializationException: An IOException was
thrown while deserializing
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1988)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1977)
at
org.apache.geode.internal.cache.VMCachedDeserializable.getDeserializedValue(VMCachedDeserializable.java:134)
at
org.apache.geode.internal.cache.LocalRegion.getDeserialized(LocalRegion.java:1272)
at
org.apache.geode.internal.cache.LocalRegion$NonTXEntry.getValue(LocalRegion.java:8726)
at
org.apache.geode.internal.cache.LocalRegion$NonTXEntry.getValue(LocalRegion.java:8722)
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:498)
at
org.apache.geode.cache.query.internal.AttributeDescriptor.readReflection(AttributeDescriptor.java:102)
... 48 more
Caused by: java.io.InvalidClassException: filter status: REJECTED
at java.io.ObjectInputStream.filterCheck(ObjectInputStream.java:1250)
at java.io.ObjectInputStream.checkArray(ObjectInputStream.java:1289)
at java.io.ObjectInputStream.access$200(ObjectInputStream.java:213)
at java.io.ObjectInputStream$1.checkArray(ObjectInputStream.java:261)
at java.util.HashMap.readObject(HashMap.java:1399)
at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1158)
at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2173)
at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2064)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1568)
at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2282)
at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2206)
at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2064)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1568)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:428)
at
org.apache.geode.internal.InternalDataSerializer.basicReadObject(InternalDataSerializer.java:2973)
at org.apache.geode.DataSerializer.readObject(DataSerializer.java:2961)
at
org.apache.geode.internal.util.BlobHelper.deserializeBlob(BlobHelper.java:99)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1984)
... 58 more
Caused by: java.lang.NullPointerException
at
org.apache.geode.internal.ObjectInputStreamFilterWrapper.lambda$createSerializationFilter$0(ObjectInputStreamFilterWrapper.java:219)
at com.sun.proxy.$Proxy42.checkInput(Unknown Source)
at java.io.ObjectInputStream.filterCheck(ObjectInputStream.java:1234)
... 78 more
So next up, I decided to look deeper into how this is wired into dunit and
I don't think it's wired in like everyone thinks.
This method in DUnitLauncher...
public static Properties getDistributedSystemProperties() {
Properties p = new Properties();
p.setProperty(LOCATORS, getLocatorString());
p.setProperty(MCAST_PORT, "0");
p.setProperty(ENABLE_CLUSTER_CONFIGURATION, "false");
p.setProperty(USE_CLUSTER_CONFIGURATION, "false");
p.setProperty(VALIDATE_SERIALIZABLE_OBJECTS, "true");
p.setProperty(LOG_LEVEL, logLevel);
return p;
}
Has very few callers and if you trace it all the way down, it seems to be
used by maybe 8 dunit tests total.
Most dunit tests are using this method in JUnit4DistributedTestCase which
returns an empty Properties() instance:
@Override
public Properties getDistributedSystemProperties() {
if (this.distributedTestFixture != this) {
return this.distributedTestFixture.getDistributedSystemProperties();
}
return defaultGetDistributedSystemProperties();
}
final Properties defaultGetDistributedSystemProperties() {
return new Properties();
}
I've run into a deadend. I'm not sure how to fix this or what we think it's
now doing. It doesn't seem right to me though.
