/*
* Licensed to the Apache Software Foundation (ASF) under one
* or more contributor license agreements. See the NOTICE file
* distributed with this work for additional information
* regarding copyright ownership. The ASF licenses this file
* to you under the Apache License, Version 2.0 (the
* "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.apache.sling.discovery.impl.cluster;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;
import org.apache.log4j.Level;
import org.apache.log4j.spi.RootLogger;
import org.apache.sling.discovery.TopologyView;
import org.apache.sling.commons.testing.junit.categories.Slow;
import org.apache.sling.discovery.TopologyEvent.Type;
import org.apache.sling.discovery.base.its.setup.VirtualInstanceBuilder;
import org.apache.sling.discovery.base.its.setup.mock.AssertingTopologyEventListener;
import org.apache.sling.discovery.impl.setup.FullJR2VirtualInstance;
import org.apache.sling.discovery.impl.setup.FullJR2VirtualInstanceBuilder;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.junit.experimental.categories.Category;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import junitx.util.PrivateAccessor;
public class RepositoryDelaysTest {
private final Logger logger = LoggerFactory.getLogger(this.getClass());
private Level logLevel;
private FullJR2VirtualInstance instance1;
private FullJR2VirtualInstance instance2;
protected FullJR2VirtualInstanceBuilder newBuilder() {
return new FullJR2VirtualInstanceBuilder();
}
@Before
public void setUp() throws Exception {
final org.apache.log4j.Logger discoveryLogger = RootLogger.getLogger("org.apache.sling.discovery");
logLevel = discoveryLogger.getLevel();
discoveryLogger.setLevel(Level.TRACE);
}
@After
public void teartDown() throws Throwable {
final org.apache.log4j.Logger discoveryLogger = RootLogger.getLogger("org.apache.sling.discovery");
discoveryLogger.setLevel(logLevel);
if (instance1!=null) {
instance1.stopViewChecker();
instance1.stop();
instance1 = null;
}
if (instance2!=null) {
instance2.stopViewChecker();
instance2.stop();
instance2 = null;
}
}
/**
* SLING-5195 : simulate slow session.saves that block
* the calling thread for non-trivial amounts of time,
* typically for longer than the configured heartbeat
* timeout
*/
@Category(Slow.class) //TODO: test takes couple minutes!
@Test
public void testSlowSessionSaves() throws Exception {
VirtualInstanceBuilder builder1 = newBuilder();
instance1 = (FullJR2VirtualInstance) builder1
.setDebugName("firstInstance")
.newRepository("/var/discovery/impl/", true)
.setMinEventDelay(0)
.setConnectorPingInterval(1)
.setConnectorPingTimeout(3)
.build();
VirtualInstanceBuilder builder2 = newBuilder();
instance2 = (FullJR2VirtualInstance) builder2
.setDebugName("secondInstance")
.useRepositoryOf(instance1)
.setMinEventDelay(0)
.setConnectorPingInterval(1)
.setConnectorPingTimeout(3)
.build();
instance1.setDelay("pre.commit", 12000);
instance1.startViewChecker(1);
instance2.startViewChecker(1);
Thread.sleep(5000);
// after 3 sec - without the 12sec pre-commit delay
// the view would normally be established - but this time
// round instance1 should still be pre-init and instance2
// should be init but alone
TopologyView t1 = instance1.getDiscoveryService().getTopology();
assertFalse(t1.isCurrent());
TopologyView t2 = instance2.getDiscoveryService().getTopology();
assertTrue(t2.isCurrent());
assertEquals(1, t2.getInstances().size());
instance1.setDelay("pre.commit", -1);
Thread.sleep(3000);
TopologyView t1b = instance1.getDiscoveryService().getTopology();
assertTrue(t1b.isCurrent());
assertEquals(2, t1b.getInstances().size());
TopologyView t2b = instance2.getDiscoveryService().getTopology();
assertTrue(t2b.isCurrent());
assertEquals(2, t2b.getInstances().size());
instance1.setDelay("pre.commit", 59876);
instance2.setDelay("pre.commit", 60000);
logger.info("<main> both instances marked as delaying 1min - but with new background checks we should go changing within 3sec");
Thread.sleep(8000);
TopologyView t1c = instance1.getDiscoveryService().getTopology();
assertFalse(t1c.isCurrent());
TopologyView t2c = instance2.getDiscoveryService().getTopology();
assertFalse(t2c.isCurrent());
}
/**
* Tests whether the not-current view returned by getTopology()
* matches what listeners get in TOPOLOGY_CHANGING - it should
* basically be the same.
*/
@Test
public void testOldView() throws Throwable {
final org.apache.log4j.Logger discoveryLogger = RootLogger.getLogger("org.apache.sling.discovery");
discoveryLogger.setLevel(Level.INFO); // info should do
FullJR2VirtualInstanceBuilder builder = newBuilder();
builder.setDebugName("firstInstanceA")
.newRepository("/var/discovery/impl/", true)
.setConnectorPingTimeout(3 /* heartbeat-timeout */)
.setMinEventDelay(3 /*min event delay*/);
instance1 = builder.fullBuild();
instance1.stopVoting();
TopologyView t1 = instance1.getDiscoveryService().getTopology();
assertFalse(t1.isCurrent()); // current it should not be
assertEquals(1, t1.getInstances().size()); // but it can as well contain the local instance
AssertingTopologyEventListener l1 = new AssertingTopologyEventListener("instance1.l1");
l1.addExpected(Type.TOPOLOGY_INIT);
instance1.bindTopologyEventListener(l1);
logger.info("testOldView: instance1 created, no events expected yet. slingId="+instance1.slingId);
instance1.heartbeatsAndCheckView();
Thread.sleep(200);
instance1.heartbeatsAndCheckView();
Thread.sleep(200);
instance1.heartbeatsAndCheckView();
Thread.sleep(200);
logger.info("testOldView: 2nd/3rd heartbeat sent - now expecting a TOPOLOGY_INIT");
instance1.dumpRepo();
assertEquals(1, l1.getEvents().size()); // one event
assertEquals(0, l1.getRemainingExpectedCount()); // the expected one
assertEquals(0, l1.getUnexpectedCount());
t1 = instance1.getDiscoveryService().getTopology();
assertTrue(t1.isCurrent()); // current it should now be
assertEquals(1, t1.getInstances().size()); // and it must contain the local instance
logger.info("testOldView: creating instance2");
l1.addExpected(Type.TOPOLOGY_CHANGING);
FullJR2VirtualInstanceBuilder builder2 = newBuilder();
builder2.setDebugName("secondInstanceB")
.useRepositoryOf(instance1)
.setConnectorPingTimeout(3)
.setMinEventDelay(3);
instance2 = builder2.fullBuild();
instance2.stopVoting();
logger.info("testOldView: instance2 created, now issuing one heartbeat with instance2 first, so that instance1 can take note of it");
instance2.heartbeatsAndCheckView();
logger.info("testOldView: now instance1 is also doing a heartbeat and should see that a new instance is there");
instance1.heartbeatsAndCheckView();
logger.info("testOldView: 500ms sleep...");
Thread.sleep(500); // allow some time for CHANGING to be sent
logger.info("testOldView: 500ms sleep done.");
assertEquals(2, l1.getEvents().size()); // INIT and CHANGING
assertEquals(0, l1.getRemainingExpectedCount()); // no remaining expected
assertEquals(0, l1.getUnexpectedCount()); // and no unexpected
t1 = instance1.getDiscoveryService().getTopology();
assertFalse(t1.isCurrent()); // current it should not be
assertEquals(1, t1.getInstances().size()); // but it should still contain the local instance from before
l1.addExpected(Type.TOPOLOGY_CHANGED);
logger.info("testOldView: now issuing 3 rounds of heartbeats/checks and expecting a TOPOLOGY_CHANGED then");
instance2.heartbeatsAndCheckView();
// instance2.analyzeVotings();
instance1.heartbeatsAndCheckView();
// instance1.analyzeVotings();
Thread.sleep(1200);
instance2.heartbeatsAndCheckView();
instance1.heartbeatsAndCheckView();
Thread.sleep(1200);
instance2.heartbeatsAndCheckView();
instance1.heartbeatsAndCheckView();
Thread.sleep(1200);
assertEquals(3, l1.getEvents().size()); // INIT, CHANGING and CHANGED
assertEquals(0, l1.getRemainingExpectedCount()); // no remaining expected
assertEquals(0, l1.getUnexpectedCount()); // and no unexpected
t1 = instance1.getDiscoveryService().getTopology();
assertTrue(t1.isCurrent()); // and we should be current again
assertEquals(2, t1.getInstances().size()); // and contain both instances now
// timeout is set to 3sec, so we now do heartbeats for 4sec with only instance1
// to let instance2 crash
// force instance1 to no longer analyze the votings
// since stopVoting() only deactivates the listener, we also
// have to set votingHandler of heartbeatHandler to null
PrivateAccessor.setField(instance1.getHeartbeatHandler(), "votingHandler", null);
l1.addExpected(Type.TOPOLOGY_CHANGING);
for(int i=0; i<8; i++) {
instance1.getHeartbeatHandler().heartbeatAndCheckView();
Thread.sleep(500);
}
assertEquals(4, l1.getEvents().size()); // INIT, CHANGING, CHANGED and CHANGED
assertEquals(0, l1.getRemainingExpectedCount()); // no remaining expected
assertEquals(0, l1.getUnexpectedCount()); // and no unexpected
t1 = instance1.getDiscoveryService().getTopology();
assertFalse(t1.isCurrent()); // we should still be !current
assertEquals(2, t1.getInstances().size()); // and contain both instances
}
}