[SLING-10254] SubscriberTest#testReceiveDelete fails randomly

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: Content Distribution Journal Core 0.1.0
• Fix Version/s: Content Distribution Journal Core 0.1.18
• Component/s: Content Distribution
• Assignee: Timothee Maret
• Reporter: Timothee Maret
• Created: 23/Mar/21 11:32
• Updated: 16/Jul/21 07:39
• Resolved: 23/Mar/21 12:24

Description

The test SubscriberTest#testReceiveDelete regularly fails in our Jenkins infrastructure. See for instance here. It fails with

Error Message
Lambda expression in org.apache.sling.distribution.journal.impl.subscriber.SubscriberTest that uses org.apache.sling.distribution.journal.impl.subscriber.DistributionSubscriber: expected <RUNNING> but was <IDLE> within 30 seconds.
Stacktrace
org.awaitility.core.ConditionTimeoutException: Lambda expression in org.apache.sling.distribution.journal.impl.subscriber.SubscriberTest that uses org.apache.sling.distribution.journal.impl.subscriber.DistributionSubscriber: expected <RUNNING> but was <IDLE> within 30 seconds.
	at org.apache.sling.distribution.journal.impl.subscriber.SubscriberTest.waitSubscriber(SubscriberTest.java:465)
	at org.apache.sling.distribution.journal.impl.subscriber.SubscriberTest.testReceiveDelete(SubscriberTest.java:304)
Standard Output
2021-03-23 11:22:26,835 INFO [main] o.a.s.d.j.b.BookKeeper [BookKeeper.java : 122] Started bookkeeper subAgentName=SUB1AGENT, subSlingId=sub1sling, editable=false, maxRetries=-1, packageHandling=Off, packageNodeName=myserver.apache.org_aemdistribution_package. -  
2021-03-23 11:22:26,835 INFO [Queue Processor for Subscriber agent sub1agent] o.a.s.d.j.i.s.DistributionSubscriber [DistributionSubscriber.java : 283] Started Queue processor -  
2021-03-23 11:22:26,836 INFO [main] o.a.s.d.j.i.s.DistributionSubscriber [DistributionSubscriber.java : 197] Started Subscriber agent sub1agent at offset 0, subscribed to agent names [pub1agent] -  
2021-03-23 11:22:26,841 INFO [Queue Processor for Subscriber agent sub1agent] o.a.s.d.j.b.BookKeeper [BookKeeper.java : 142] Importing distribution package PackageMessage(pubSlingId=pub1sling, reqType=DELETE, pkgId=myid, pkgType=journal, pkgLength=0, pubAgentName=pub1agent, userId=null, paths=[/test], deepPaths=[]) at offset=0 -  
2021-03-23 11:22:26,843 INFO [Queue Processor for Subscriber agent sub1agent] o.a.s.d.j.b.PackageHandler [PackageHandler.java : 102] Deleting paths [/test] - retries=0, paths=/test, sub-sling-id=sub1sling, module=distribution, sub-agent-name=sub1agent, pub-sling-id=pub1sling, distribution-message-type=DELETE, package-id=myid, pub-agent-name=pub1agent 
2021-03-23 11:22:56,983 INFO [Queue Processor for Subscriber agent sub1agent] o.a.s.d.j.i.s.DistributionSubscriber [DistributionSubscriber.java : 304] Stopped Queue processor -  
2021-03-23 11:22:56,984 INFO [main] o.a.s.d.j.i.s.DistributionSubscriber [DistributionSubscriber.java : 227] Stopped Subscriber agent sub1agent, subscribed to Publisher agent names [pub1agent] with package builder journal -