diff --git a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/entities/EntityManagerImpl.java b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/entities/EntityManagerImpl.java index b9632119..76e25270 100644 --- a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/entities/EntityManagerImpl.java +++ b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/entities/EntityManagerImpl.java @@ -118,9 +118,11 @@ private void register(EntityObject entity, BigInteger id) { if (state == State.FLUSHING) { flushQueue.add(entity); } - Object previous1 = entities.put(entity, id); - Object previous2 = entitiesById.put(id, entity); - assert previous1 == null && previous2 == null : "Registered an entity twise: " + entity + ", " + id; + BigInteger prevIdOfSameEntity = entities.put(entity, id); + EntityObject prevEntityWithSameId = entitiesById.put(id, entity); + assert prevIdOfSameEntity == null && prevEntityWithSameId == null : "" + + "Registered an entity twise: " + entity + ", " + id + + " (Previous was: " + prevEntityWithSameId + ", " + prevIdOfSameEntity + ")"; } public BigInteger firstKey() { diff --git a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/modules/LifecycleModule.java b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/modules/LifecycleModule.java index ded4e30b..15fc40f3 100644 --- a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/modules/LifecycleModule.java +++ b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/modules/LifecycleModule.java @@ -56,8 +56,10 @@ public SystemStartupListener[] get() { } private static class SystemShutdownListenerProvider implements Provider { + @Inject public TaskSchedulingLifecycleManager listener1; + public SystemShutdownListener[] get() { - return new SystemShutdownListener[0]; + return new SystemShutdownListener[]{listener1}; } } } diff --git a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingLifecycleManager.java b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingLifecycleManager.java index b2312ae8..c31d9f69 100644 --- a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingLifecycleManager.java +++ b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingLifecycleManager.java @@ -32,13 +32,13 @@ package net.orfjackal.dimdwarf.scheduler; import com.google.inject.Inject; -import net.orfjackal.dimdwarf.events.SystemStartupListener; +import net.orfjackal.dimdwarf.events.*; /** * @author Esko Luontola * @since 28.11.2008 */ -public class TaskSchedulingLifecycleManager implements SystemStartupListener { +public class TaskSchedulingLifecycleManager implements SystemStartupListener, SystemShutdownListener { private final TaskSchedulerImpl taskScheduler; private final TaskThreadPool taskThreadPool; @@ -53,4 +53,8 @@ public void onStartup() { taskScheduler.start(); taskThreadPool.start(); } + + public void onShutdown() { + taskThreadPool.shutdown(); + } } diff --git a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPool.java b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPool.java index 193f9685..df6d3eeb 100644 --- a/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPool.java +++ b/dimdwarf-core/src/main/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPool.java @@ -31,7 +31,7 @@ package net.orfjackal.dimdwarf.scheduler; -import com.google.inject.Inject; +import com.google.inject.*; import net.orfjackal.dimdwarf.tasks.TaskExecutor; import org.slf4j.*; @@ -43,7 +43,7 @@ * @author Esko Luontola * @since 26.11.2008 */ -//@Singleton // TODO: a test must fail first +@Singleton @ThreadSafe public class TaskThreadPool { private static final Logger DEFAULT_LOGGER = LoggerFactory.getLogger(TaskThreadPool.class); @@ -77,7 +77,7 @@ public int getRunningTasks() { } public void shutdown() { - logger.info("Shutting down..."); + logger.info("Shutting down {}...", getClass().getSimpleName()); consumer.interrupt(); try { consumer.join(); @@ -85,7 +85,7 @@ public void shutdown() { logger.error("Interrupted while shutting down", e); } workers.shutdown(); - logger.info("Shutdown finished"); + logger.info("{} has been shut down", getClass().getSimpleName()); } @SuppressWarnings({"ToArrayCallWithZeroLengthArrayArgument"}) @@ -129,7 +129,7 @@ public void run() { runningTasks.add(taskHasFinished); taskContext.execute(task); } catch (Throwable t) { - logger.error("Task threw an exception", t); + logger.warn("Task threw an exception", t); } finally { runningTasks.remove(taskHasFinished); taskHasFinished.countDown(); diff --git a/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingIntegrationSpec.java b/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingIntegrationSpec.java index b59525a1..b497975c 100644 --- a/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingIntegrationSpec.java +++ b/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskSchedulingIntegrationSpec.java @@ -35,13 +35,15 @@ import jdave.*; import jdave.junit4.JDaveRunner; import net.orfjackal.dimdwarf.api.TaskScheduler; +import net.orfjackal.dimdwarf.db.inmemory.InMemoryDatabaseManager; +import net.orfjackal.dimdwarf.entities.EntityIdFactoryImpl; import net.orfjackal.dimdwarf.modules.CommonModules; import net.orfjackal.dimdwarf.server.ServerLifecycleManager; import net.orfjackal.dimdwarf.tasks.TaskExecutor; import org.junit.runner.RunWith; import java.util.*; -import java.util.concurrent.Semaphore; +import java.util.concurrent.*; /** * @author Esko Luontola @@ -51,29 +53,52 @@ @Group({"fast"}) public class TaskSchedulingIntegrationSpec extends Specification { + private Injector injector; private TaskExecutor taskContext; private Provider scheduler; - private TaskThreadPool pool; private TestSpy spy; private Provider server; public void create() throws Exception { - Injector injector = Guice.createInjector(new CommonModules()); + startupTheServer(new CommonModules()); + } + + private void startupTheServer(Module... modules) { + injector = Guice.createInjector(modules); + server = injector.getProvider(ServerLifecycleManager.class); + server.get().start(); + taskContext = injector.getInstance(TaskExecutor.class); scheduler = injector.getProvider(TaskScheduler.class); - pool = injector.getInstance(TaskThreadPool.class); spy = injector.getInstance(TestSpy.class); + } - server = injector.getProvider(ServerLifecycleManager.class); - server.get().start(); + private void shutdownTheServer() { + server.get().shutdown(); + } + + private void restartTheServer() { + shutdownTheServer(); + final InMemoryDatabaseManager db = injector.getInstance(InMemoryDatabaseManager.class); + final EntityIdFactoryImpl idFactory = injector.getInstance(EntityIdFactoryImpl.class); + + startupTheServer( + new CommonModules(), + new AbstractModule() { + protected void configure() { + bind(InMemoryDatabaseManager.class).toInstance(db); + bind(EntityIdFactoryImpl.class).toInstance(idFactory); + } + }); } public void destroy() throws Exception { - server.get().shutdown(); + shutdownTheServer(); } - public class WhenAOneTimeTasksIsScheduled { + + public class WhenAOneTimeTaskIsScheduled { public void create() throws InterruptedException { taskContext.execute(new Runnable() { @@ -89,6 +114,36 @@ public void itIsExecutedOnce() { } } + public class WhenARepeatedTaskIsScheduled { + + public void create() throws InterruptedException { + taskContext.execute(new Runnable() { + public void run() { + scheduler.get().scheduleAtFixedRate(new ExecutionLoggingTask("A"), 0, 0, TimeUnit.MILLISECONDS); + } + }); + spy.executionCount.acquire(2); + } + + public void itIsExecutedManyTimes() { + specify(spy.executions, should.containAll("A:1", "A:2")); + } + + public void afterShuttingDownItIsNoMoreExecuted() throws InterruptedException { + shutdownTheServer(); + spy.executions.clear(); + Thread.sleep(10); // TODO: figure out a more reliable thread synchronization method than sleeping + specify(spy.executions, should.containExactly()); + } + + public void afterRestartTheExecutionIsContinued() throws InterruptedException { + restartTheServer(); + spy.executionCount.acquire(1); + specify(spy.executions, should.not().containAny("A:1", "A:2")); + specify(spy.executions, should.containAny("A:3", "A:4")); + } + } + @Singleton public static class TestSpy { @@ -114,9 +169,9 @@ public ExecutionLoggingTask(String dummyId) { public void run() { myExecutionCount++; spy.logExecution(getDummyId(), myExecutionCount); - System.out.println("TaskSchedulingIntegrationSpec$ExecutionLoggingTask.run"); - System.out.println("getDummyId() = " + getDummyId()); - System.out.println("myExecutionCount = " + myExecutionCount); + System.err.println("TaskSchedulingIntegrationSpec$ExecutionLoggingTask.run"); + System.err.println("getDummyId() = " + getDummyId()); + System.err.println("myExecutionCount = " + myExecutionCount); } } diff --git a/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPoolSpec.java b/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPoolSpec.java index be24b11e..95a02990 100644 --- a/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPoolSpec.java +++ b/dimdwarf-core/src/test/java/net/orfjackal/dimdwarf/scheduler/TaskThreadPoolSpec.java @@ -81,7 +81,7 @@ public TaskBootstrap takeNextTask() throws InterruptedException { @SuppressWarnings("ThrowableResultOfMethodCallIgnored") public void destroy() throws Exception { checking(new Expectations() {{ - allowing(logger).info(with(any(String.class))); + allowing(logger).info(with(any(String.class)), with(any(Object.class))); allowing(logger).info(with(any(String.class)), with(any(Throwable.class))); }}); pool.shutdown(); @@ -292,7 +292,7 @@ public void run() { public Expectations theExceptionIsLogged() { return new Expectations() {{ - one(logger).error("Task threw an exception", exception); + one(logger).warn("Task threw an exception", exception); }}; } @@ -317,9 +317,9 @@ public void run() { @SuppressWarnings("ThrowableResultOfMethodCallIgnored") private Expectations theShutdownIsLogged() { return new Expectations() {{ - one(logger).info("Shutting down..."); + one(logger).info("Shutting down {}...", "TaskThreadPool"); allowing(logger).info(with(equal("Task consumer was interrupted")), with(aNonNull(InterruptedException.class))); - one(logger).info("Shutdown finished"); + one(logger).info("{} has been shut down", "TaskThreadPool"); }}; }