[GEODE-4312] CI failure: org.apache.geode.cache30.CacheXml80DUnitTest > testPartitionedRegionAttributesForCoLocation3 FAILED

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 1.5.0
• Component/s: gfsh
• Labels: ci pull-request-available
• Assignee: Jens Deppe
• Reporter: Jens Deppe
• Created: 18/Jan/18 14:24
• Updated: 09/Apr/18 22:37
• Resolved: 26/Jan/18 18:21

Description

Test produces this:

Suspicious strings were written to the log during this run.
Fix the strings or use IgnoredException.addIgnoredException to ignore.
-----------------------------------------------------------------------
Found suspect string in log4j at line 157

[error 2018/01/17 03:31:42.318 UTC <ResourceManagerRecoveryThread 0> tid=0x2c6] Unexpected exception during bucket recovery
java.lang.IllegalStateException: Region specified in 'colocated-with' (Customer) for region /Order does not exist. It should be created before setting 'colocated-with' attribute for this region.
	at org.apache.geode.internal.cache.ColocationHelper.getColocatedRegion(ColocationHelper.java:94)
	at org.apache.geode.internal.cache.ColocationHelper.getLeaderRegion(ColocationHelper.java:455)
	at org.apache.geode.internal.cache.partitioned.PartitionedRegionRebalanceOp.<init>(PartitionedRegionRebalanceOp.java:134)
	at org.apache.geode.internal.cache.partitioned.PartitionedRegionRebalanceOp.<init>(PartitionedRegionRebalanceOp.java:114)
	at org.apache.geode.internal.cache.PRHARedundancyProvider$3.run2(PRHARedundancyProvider.java:1568)
	at org.apache.geode.internal.cache.partitioned.RecoveryRunnable.run(RecoveryRunnable.java:61)
	at org.apache.geode.internal.OneTaskOnlyExecutor$DelegatingRunnable.run(OneTaskOnlyExecutor.java:134)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	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)

The relevant section of the log is this:

[info 2018/01/17 03:31:42.248 UTC <Test worker> tid=0x16] Initializing region __PR

[info 2018/01/17 03:31:42.248 UTC <Test worker> tid=0x16] Initialization of region __PR completed

[info 2018/01/17 03:31:42.249 UTC <Test worker> tid=0x16] Partitioned Region /Customer is born with prId=4 ident:#Customer

[info 2018/01/17 03:31:42.271 UTC <Test worker> tid=0x16] Partitioned Region /Order is born with prId=5 ident:#Order

[info 2018/01/17 03:31:42.314 UTC <Test worker> tid=0x16] GemFireCache[id = 1650399312; isClosing = true; isShutDownAll = false; created = Wed Jan 17 03:31:41 UTC 2018; server = false; copyOnRead = false; lockLease = 120; lockTimeout = 60]: Now closing.

[error 2018/01/17 03:31:42.318 UTC <ResourceManagerRecoveryThread 0> tid=0x2c6] Unexpected exception during bucket recovery
java.lang.IllegalStateException: Region specified in 'colocated-with' (Customer) for region /Order does not exist. It should be created before setting 'colocated-with' attribute for this region.
	at org.apache.geode.internal.cache.ColocationHelper.getColocatedRegion(ColocationHelper.java:94)
	at org.apache.geode.internal.cache.ColocationHelper.getLeaderRegion(ColocationHelper.java:455)
	at org.apache.geode.internal.cache.partitioned.PartitionedRegionRebalanceOp.<init>(PartitionedRegionRebalanceOp.java:134)
	at org.apache.geode.internal.cache.partitioned.PartitionedRegionRebalanceOp.<init>(PartitionedRegionRebalanceOp.java:114)
	at org.apache.geode.internal.cache.PRHARedundancyProvider$3.run2(PRHARedundancyProvider.java:1568)
	at org.apache.geode.internal.cache.partitioned.RecoveryRunnable.run(RecoveryRunnable.java:61)
	at org.apache.geode.internal.OneTaskOnlyExecutor$DelegatingRunnable.run(OneTaskOnlyExecutor.java:134)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	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)

It looks like the test is actually running quickly enough that the cache starts up and shuts down before the ResourceManager can initialize correctly.

Issue Links

• links to: GitHub Pull Request #1302