From a7bc4d43ebbeb79453c6983783175d580153d3b1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=C3=93scar=20Gonz=C3=A1lez=20Fern=C3=A1ndez?= Date: Sun, 12 Sep 2010 17:21:00 +0200 Subject: [PATCH] Report some statistics and execution times for snapshot creation FEA: ItEr60S04ValidacionEProbasFuncionaisItEr59S04 --- ...ibernateDatabaseModificationsListener.java | 5 +- .../ISnapshotRefresherService.java | 2 +- .../NotBlockingAutoUpdatedSnapshot.java | 82 ++++++++++++++++++- .../PredefinedDatabaseSnapshots.java | 33 +++++--- 4 files changed, 102 insertions(+), 20 deletions(-) diff --git a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/HibernateDatabaseModificationsListener.java b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/HibernateDatabaseModificationsListener.java index fd60b7631..175a600c6 100644 --- a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/HibernateDatabaseModificationsListener.java +++ b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/HibernateDatabaseModificationsListener.java @@ -106,9 +106,10 @@ public class HibernateDatabaseModificationsListener implements } @Override - public IAutoUpdatedSnapshot takeSnapshot(Callable callable, ReloadOn reloadOn) { + public IAutoUpdatedSnapshot takeSnapshot(String name, + Callable callable, ReloadOn reloadOn) { final NotBlockingAutoUpdatedSnapshot result; - result = new NotBlockingAutoUpdatedSnapshot(callable); + result = new NotBlockingAutoUpdatedSnapshot(name, callable); for (Class each : reloadOn.getClassesOnWhichToReload()) { interested.putIfAbsent(each, emptyQueue()); BlockingQueue> queue = interested diff --git a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/ISnapshotRefresherService.java b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/ISnapshotRefresherService.java index d54b1fd92..d287850d0 100644 --- a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/ISnapshotRefresherService.java +++ b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/ISnapshotRefresherService.java @@ -27,6 +27,6 @@ import java.util.concurrent.Callable; */ public interface ISnapshotRefresherService { - public IAutoUpdatedSnapshot takeSnapshot(Callable callable, ReloadOn reloadOn); + public IAutoUpdatedSnapshot takeSnapshot(String name, Callable callable, ReloadOn reloadOn); } diff --git a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/NotBlockingAutoUpdatedSnapshot.java b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/NotBlockingAutoUpdatedSnapshot.java index 2b82fb94b..dbbf2b139 100644 --- a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/NotBlockingAutoUpdatedSnapshot.java +++ b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/NotBlockingAutoUpdatedSnapshot.java @@ -41,6 +41,10 @@ class NotBlockingAutoUpdatedSnapshot implements IAutoUpdatedSnapshot { private final AtomicReference currentState; + private final String name; + + private final ExecutionsReport executionsReport; + private abstract class State { abstract T getValue(); @@ -156,10 +160,13 @@ class NotBlockingAutoUpdatedSnapshot implements IAutoUpdatedSnapshot { } - public NotBlockingAutoUpdatedSnapshot(Callable callable) { + public NotBlockingAutoUpdatedSnapshot(String name, Callable callable) { Validate.notNull(callable); + Validate.notNull(name); + this.name = "*" + name + "*"; this.callable = callable; - currentState = new AtomicReference(new NotLaunchState()); + this.currentState = new AtomicReference(new NotLaunchState()); + this.executionsReport = new ExecutionsReport(); } @Override @@ -168,7 +175,8 @@ class NotBlockingAutoUpdatedSnapshot implements IAutoUpdatedSnapshot { } public void reloadNeeded(ExecutorService executorService) { - Future future = executorService.submit(callable); + Future future = executorService + .submit(callableDecoratedWithStatistics()); State previousState; State newState = null; do { @@ -185,7 +193,8 @@ class NotBlockingAutoUpdatedSnapshot implements IAutoUpdatedSnapshot { if (hasBeenInitialized()) { return; } - Future future = executorService.submit(callable); + Future future = executorService + .submit(callableDecoratedWithStatistics()); State previous = currentState.get(); State newState = previous.nextState(future); boolean compareAndSet = currentState.compareAndSet(previous, newState); @@ -198,4 +207,69 @@ class NotBlockingAutoUpdatedSnapshot implements IAutoUpdatedSnapshot { return currentState.get().hasBeenInitialized(); } + private Callable callableDecoratedWithStatistics() { + final long requestTime = System.currentTimeMillis(); + return new Callable() { + + @Override + public T call() throws Exception { + long start = System.currentTimeMillis(); + long timeWaiting = start - requestTime; + try { + return callable.call(); + } finally { + long timeExecuting = System.currentTimeMillis() - start; + executionsReport.newData(timeWaiting, timeExecuting); + } + } + }; + } + + private static class Data { + final int executionTimes; + long totalMsWaiting; + long totalMsExecuting; + + private Data(int executionTimes, long totalMsWaiting, + long totalMsExecuting) { + this.executionTimes = executionTimes; + this.totalMsWaiting = totalMsWaiting; + this.totalMsExecuting = totalMsExecuting; + } + + public Data newData(long timeWaiting, long timeExcuting) { + return new Data(executionTimes + 1, totalMsWaiting + timeWaiting, + totalMsExecuting + timeExcuting); + } + + } + + private class ExecutionsReport { + + private AtomicReference data = new AtomicReference( + new Data(0, 0, 0)); + + public void newData(long timeWaiting, long timeExecuting) { + Data previousData; + Data newData; + do { + previousData = data.get(); + newData = previousData.newData(timeWaiting, timeExecuting); + } while (!data.compareAndSet(previousData, newData)); + report(timeWaiting, timeExecuting, newData); + } + + private void report(long timeWaiting, long timeExecuting, Data data) { + LOG.info(name + " took " + timeExecuting + " ms executing"); + LOG.info(name + " waited for " + timeWaiting + + " ms until executing"); + LOG.info(name + " mean time waiting for execution: " + + data.totalMsWaiting / data.executionTimes + " ms"); + LOG.info(name + " mean time executing: " + + data.totalMsExecuting / data.executionTimes + " ms"); + LOG.info(name + " has been executed " + data.executionTimes + + " times"); + } + } + } diff --git a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/PredefinedDatabaseSnapshots.java b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/PredefinedDatabaseSnapshots.java index af2742d4f..be8d04eaf 100644 --- a/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/PredefinedDatabaseSnapshots.java +++ b/navalplanner-business/src/main/java/org/navalplanner/business/hibernate/notification/PredefinedDatabaseSnapshots.java @@ -125,25 +125,32 @@ public class PredefinedDatabaseSnapshots { @PostConstruct @SuppressWarnings("unused") private void postConstruct() { - criterionsMap = snapshot(calculateCriterionsMap(), CriterionType.class, - Criterion.class); - labelsMap = snapshot(calculateLabelsMap(), LabelType.class, Label.class); - listWorkers = snapshot(calculateWorkers(), Worker.class); - listCostCategories = snapshot(calculateListCostCategories(), + criterionsMap = snapshot("criterions map", calculateCriterionsMap(), + CriterionType.class, Criterion.class); + labelsMap = snapshot("labels map", calculateLabelsMap(), + LabelType.class, Label.class); + listWorkers = snapshot("workers", calculateWorkers(), Worker.class); + listCostCategories = snapshot("list cost categories", + calculateListCostCategories(), CostCategory.class); - listCriterion = snapshot(calculateListCriterion(), Criterion.class); - mapResources = snapshot(calculateMapResources(), Resource.class, - Worker.class, Machine.class, VirtualWorker.class); - externalCompanies = snapshot(calculateExternalCompanies(), + listCriterion = snapshot("list criterions", calculateListCriterion(), + Criterion.class); + mapResources = snapshot("map resources", calculateMapResources(), + Resource.class, Worker.class, Machine.class, + VirtualWorker.class); + externalCompanies = snapshot("external companies", + calculateExternalCompanies(), ExternalCompany.class); - customerReferences = snapshot(calculateCustomerReferences(), + customerReferences = snapshot("customer references", + calculateCustomerReferences(), Order.class); + ordersCodes = snapshot("order codes", calculateOrdersCodes(), Order.class); - ordersCodes = snapshot(calculateOrdersCodes(), Order.class); } - private IAutoUpdatedSnapshot snapshot(Callable callable, + private IAutoUpdatedSnapshot snapshot(String name, + Callable callable, Class... reloadOnChangesOf) { - return snapshotRefresherService.takeSnapshot( + return snapshotRefresherService.takeSnapshot(name, callableOnReadOnlyTransaction(callable), ReloadOn.onChangeOf(reloadOnChangesOf)); }