Author: stefanegli Date: Wed Nov 18 12:12:21 2015 New Revision: 1714984 URL: http://svn.apache.org/viewvc?rev=1714984&view=rev Log: SLING-5310: adding cancelDelaying to MinEventDelayHandler - plus added a testReactivate test method which checks the scenario described in this ticket. Plus also added somewhat more logging to the HeartbeatHandler to help debugging should something similar reoccur
Modified: sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/MinEventDelayHandler.java sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/ViewStateManagerImpl.java sling/trunk/bundles/extensions/discovery/commons/src/test/java/org/apache/sling/discovery/commons/providers/base/TestMinEventDelayHandler.java sling/trunk/bundles/extensions/discovery/impl/src/main/java/org/apache/sling/discovery/impl/common/heartbeat/HeartbeatHandler.java Modified: sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/MinEventDelayHandler.java URL: http://svn.apache.org/viewvc/sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/MinEventDelayHandler.java?rev=1714984&r1=1714983&r2=1714984&view=diff ============================================================================== --- sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/MinEventDelayHandler.java (original) +++ sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/MinEventDelayHandler.java Wed Nov 18 12:12:21 2015 @@ -49,6 +49,8 @@ class MinEventDelayHandler { private Lock lock; + private volatile int cancelCnt = 0; + MinEventDelayHandler(ViewStateManagerImpl viewStateManager, Lock lock, DiscoveryService discoveryService, Scheduler scheduler, long minEventDelaySecs) { @@ -117,11 +119,17 @@ class MinEventDelayHandler { } private boolean triggerAsyncDelaying(BaseTopologyView newView) { + final int validCancelCnt = cancelCnt; final boolean triggered = runAfter(minEventDelaySecs /*seconds*/ , new Runnable() { public void run() { lock.lock(); try{ + if (cancelCnt!=validCancelCnt) { + logger.info("asyncDelay.run: got cancelled (validCancelCnt="+validCancelCnt+", cancelCnt="+cancelCnt+"), quitting."); + return; + } + // unlock the CHANGED event for any subsequent call to handleTopologyChanged() isDelaying = false; @@ -192,4 +200,10 @@ class MinEventDelayHandler { return isDelaying; } + public void cancelDelaying() { + logger.info("cancelDelaying: flagging cancelCnt as invalid: "+cancelCnt); + cancelCnt++; + isDelaying = false; + } + } Modified: sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/ViewStateManagerImpl.java URL: http://svn.apache.org/viewvc/sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/ViewStateManagerImpl.java?rev=1714984&r1=1714983&r2=1714984&view=diff ============================================================================== --- sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/ViewStateManagerImpl.java (original) +++ sling/trunk/bundles/extensions/discovery/commons/src/main/java/org/apache/sling/discovery/commons/providers/base/ViewStateManagerImpl.java Wed Nov 18 12:12:21 2015 @@ -336,6 +336,10 @@ public class ViewStateManagerImpl implem if (consistencyService!=null) { consistencyService.cancelSync(); } + + if (minEventDelayHandler!=null) { + minEventDelayHandler.cancelDelaying(); + } logger.trace("handleDeactivated: setting isChanging to false"); isChanging = false; Modified: sling/trunk/bundles/extensions/discovery/commons/src/test/java/org/apache/sling/discovery/commons/providers/base/TestMinEventDelayHandler.java URL: http://svn.apache.org/viewvc/sling/trunk/bundles/extensions/discovery/commons/src/test/java/org/apache/sling/discovery/commons/providers/base/TestMinEventDelayHandler.java?rev=1714984&r1=1714983&r2=1714984&view=diff ============================================================================== --- sling/trunk/bundles/extensions/discovery/commons/src/test/java/org/apache/sling/discovery/commons/providers/base/TestMinEventDelayHandler.java (original) +++ sling/trunk/bundles/extensions/discovery/commons/src/test/java/org/apache/sling/discovery/commons/providers/base/TestMinEventDelayHandler.java Wed Nov 18 12:12:21 2015 @@ -20,7 +20,9 @@ package org.apache.sling.discovery.commo import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNotNull; +import java.lang.reflect.Field; import java.util.Random; import java.util.UUID; import java.util.concurrent.locks.ReentrantLock; @@ -86,11 +88,82 @@ public class TestMinEventDelayHandler { discoveryLogger.setLevel(logLevel); } + + @Test + public void testReactivate() throws Exception { + logger.info("testReactivate: start"); + // install a minEventDelayHandler with a longer delay of 2sec + mgr.installMinEventDelayHandler(sds, scheduler, 2); + + final DummyListener listener = new DummyListener(); + logger.info("testReactivate: calling handleActivated"); + mgr.bind(listener); + mgr.handleActivated(); + TestHelper.assertNoEvents(listener); + final DummyTopologyView view1 = new DummyTopologyView().addInstance(); + final DummyTopologyView view2 = DummyTopologyView.clone(view1).addInstance(UUID.randomUUID().toString(), + (DefaultClusterView) view1.getLocalInstance().getClusterView(), false, false); + final DummyTopologyView view3 = DummyTopologyView.clone(view1).addInstance(UUID.randomUUID().toString(), + (DefaultClusterView) view1.getLocalInstance().getClusterView(), false, false); + logger.info("testReactivate: calling handleNewView..."); + mgr.handleNewView(view1); + logger.info("testReactivate: asserting init event"); + TestHelper.assertEvents(mgr, listener, EventHelper.newInitEvent(view1)); + logger.info("testReactivate: calling handleChanging..."); + mgr.handleChanging(); + TestHelper.assertEvents(mgr, listener, EventHelper.newChangingEvent(view1)); + logger.info("testReactivate: calling handleNewView 2nd time..."); + mgr.handleNewView(view2); + TestHelper.assertNoEvents(listener); + // make sure the MinEventDelayHandler finds a topology when coming back from the delaying, so: + sds.setTopoology(view2); + logger.info("testReactivate: waiting for async events to have been processed - max 4sec"); + assertEquals(0, mgr.waitForAsyncEvents(4000)); + logger.info("testReactivate: asserting CHANGED event"); + TestHelper.assertEvents(mgr, listener, EventHelper.newChangedEvent(view1, view2)); + + // now do the above again, but this time do a handleDeactivated before receiving another changed event + logger.info("testReactivate: calling handleChanging..."); + mgr.handleChanging(); + TestHelper.assertEvents(mgr, listener, EventHelper.newChangingEvent(view2)); + logger.info("testReactivate: calling handleNewView 2nd time..."); + mgr.handleNewView(view3); + TestHelper.assertNoEvents(listener); + // make sure the MinEventDelayHandler finds a topology when coming back from the delaying, so: + sds.setTopoology(view3); + + logger.info("testReactivate: doing handleDeactivated"); + final AsyncEventSender asyncEventSender = mgr.getAsyncEventSender(); + Field field = mgr.getClass().getDeclaredField("minEventDelayHandler"); + field.setAccessible(true); + MinEventDelayHandler minEventDelayHandler = (MinEventDelayHandler) field.get(mgr); + assertNotNull(minEventDelayHandler); + + // marking view3 as not current + view3.setNotCurrent(); + sds.setTopoology(view3); + + mgr.handleDeactivated(); + TestHelper.assertNoEvents(listener); + + logger.info("testReactivate: now waiting 5 sec to make sure the MinEventDelayHandler would be finished"); + TestHelper.assertNoEvents(listener); + Thread.sleep(5000); + logger.info("testReactivate: after those 5 sec there should however still not be any new event"); + TestHelper.assertNoEvents(listener); + + int cnt = asyncEventSender.getInFlightEventCnt(); + if (minEventDelayHandler!=null && minEventDelayHandler.isDelaying()) { + cnt++; + } + assertEquals(0, cnt); + } + private void assertNoEvents(DummyListener listener) { assertEquals(0, listener.countEvents()); } - @Test @Ignore + @Test public void testNormalDelaying() throws Exception { final DummyListener listener = new DummyListener(); // first activate @@ -115,7 +188,7 @@ public class TestMinEventDelayHandler { } } - @Test @Ignore + @Test public void testFailedDelaying() throws Exception { scheduler.failMode(); final DummyListener listener = new DummyListener(); Modified: sling/trunk/bundles/extensions/discovery/impl/src/main/java/org/apache/sling/discovery/impl/common/heartbeat/HeartbeatHandler.java URL: http://svn.apache.org/viewvc/sling/trunk/bundles/extensions/discovery/impl/src/main/java/org/apache/sling/discovery/impl/common/heartbeat/HeartbeatHandler.java?rev=1714984&r1=1714983&r2=1714984&view=diff ============================================================================== --- sling/trunk/bundles/extensions/discovery/impl/src/main/java/org/apache/sling/discovery/impl/common/heartbeat/HeartbeatHandler.java (original) +++ sling/trunk/bundles/extensions/discovery/impl/src/main/java/org/apache/sling/discovery/impl/common/heartbeat/HeartbeatHandler.java Wed Nov 18 12:12:21 2015 @@ -471,7 +471,9 @@ public class HeartbeatHandler extends Ba } resetLeaderElectionId = false; } + logger.debug("issueClusterLocalHeartbeat: committing cluster-local heartbeat to repository for {}", slingId); resourceResolver.commit(); + logger.debug("issueClusterLocalHeartbeat: committed cluster-local heartbeat to repository for {}", slingId); // SLING-2892: only in success case: remember the last heartbeat value written lastHeartbeatWritten = currentTime;