private boolean isTestRunning() {
return (!testComplete && now() < estimatedTestEndTime) || configuration.getTestDuration() < 0;
}
private void doPeriodReport(final boolean period) {
if (period && !isTestRunning()) return;
long now = now();
int currentCount = nodeTestCount.get();
latencyStats.snapshot();
this.cumulativeLatencyStats.add(latencyStats);
if (period) {
log.info("");
log.info("------------------ Test Stats -----------------------");
if (configuration.getTestDuration() < 0) {
log.info(
"Test running for " + Util.formatTimeInSecondsToWords((now - testStartTime) / 1000));
} else {
log.info(
"Remaining Time: "
+ Util.formatTimeInSecondsToWords((estimatedTestEndTime - now) / 1000));
}
/* *******************************************************
* Node Periodic Stats
* *******************************************************/
int periodTestCount = currentCount - testCountAtLastReport;
log.info(
String.format(
"Node: Period iterations/sec = %.1f, completed = %d ",
1000.0 * periodTestCount / (now - lastReportTime), periodTestCount));
log.info("Node: Period latency: " + latencyStats);
testCountAtLastReport = currentCount;
}
/* *******************************************************
* Node Cumulative Stats
* *******************************************************/
int writes = test.getWritesCount();
if (writes > 0) {
log.info(
String.format(
"Node: Cumulative iterations/sec = %.1f, completed = %d , writes = %d (%.1f %%)",
1000.0 * currentCount / (now - testStartTime),
currentCount,
writes,
writes * 100.0 / currentCount));
} else {
log.info(
String.format(
"Node: Cumulative iterations/sec = %.1f, completed = %d",
1000.0 * currentCount / (now - testStartTime), currentCount));
}
log.info("Node: Cumulative latency: " + cumulativeLatencyStats);
latencyStats.reset();
printCacheStats(period);
if (testHasErrors) {
log.error(
"Node: Test has errors. NonstopCacheException: " + nonstopCacheExceptionCount.get());
}
lastReportTime = now;
}
private void runTest() {
log.info("Welcome on node #" + nodeId + ", total nodes: " + configuration.getNodesNum());
log.info("Starting warmup phase");
try {
log.info("Starting L2 Warmup phase.");
log.info("Loading cache: bulk load enabled : " + configuration.isBulkLoadEnabled());
setBulkLoad(configuration.isBulkLoadEnabled());
long start = now();
test.doL2WarmUp();
long end = now();
long count = configuration.getElementNum() / configuration.getNodesNum();
long time = (end - start) / 1000;
time = (time == 0) ? 1 : time;
log.info(
String.format(
"L2 Cache Warmup complete, %d reads, %d seconds, %.1f reads/sec",
count, time, count * 1.0 / time));
clusterWarmup.addAndGet(count / time);
test.processCacheStats();
int warmup = processor.getWrite();
LongStat warmupStats = processor.getWriteStat();
log.info(
String.format(
"Cache Warmup: %d puts, %d seconds, %.1f puts/sec",
warmup, time, warmup * 1.0 / time));
log.info("Cache Warmup Latency: " + warmupStats.toString());
clusterCacheWarmup.addAndGet(warmup / time);
test.resetCacheStats();
log.info("Waiting for all nodes to complete L2 warmup.");
await();
start = now();
waitUntilBulkLoadComplete();
bulkLoadCompleteTime = now() - start;
await();
if (configuration.isL1Enabled()) {
log.info("Starting L1 Warmup phase.");
setBulkLoad(configuration.isBulkLoadEnabled());
test.doL1WarmUp();
}
} catch (Exception e) {
log.fatal("Error during warm up phase!", e);
System.exit(-1);
}
log.info("Warmup phase done... Waiting for the other nodes to be ready");
setBulkLoad(false);
await();
log.info("Starting the actual test phase now!");
if (configuration.isLogMisses()) {
test.logMisses(true);
}
test.beforeTest();
if (configuration.isSearchEnabled()) {
SearchExecutor exec = new SearchExecutor(configuration, ehcacheBean);
exec.run();
}
testStartTime = now();
lastReportTime = now();
estimatedTestEndTime = testStartTime + (configuration.getTestDuration() * 1000);
this.threads = new ArrayList<Thread>(configuration.getThreadNum());
for (int i = 0; i < configuration.getThreadNum(); i++) {
threads.add(
new Thread("PerfAppThread-" + i) {
@Override
public void run() {
test.beforeTestForEachAppThread();
while (isTestRunning()) {
long start = now();
try {
test.doTestBody();
} catch (NonStopCacheException ne) {
nonstopCacheExceptionCount.incrementAndGet();
} catch (RuntimeException e) {
log.error("error in test", e);
testHasErrors = true;
}
iterationComplete(now() - start);
}
test.afterTestForEachAppThread();
}
});
}
if (configuration.isAddOwnersEnabled()) {
log.info(
"Starting add-owners thread. "
+ getConfiguration().getAddOwnersCount()
+ " new owners will be added every "
+ getConfiguration().getAddOwnersPeriodInSecs()
+ " secs.");
new Thread() {
@Override
public void run() {
while (isTestRunning()) {
try {
sleep(getConfiguration().getAddOwnersPeriodInSecs() * 1000);
} catch (InterruptedException e) {
throw new RuntimeException(e);
}
test.addNewOwners(getConfiguration().getAddOwnersCount());
}
}
}.start();
} else log.info("Not adding new owners.....");
for (Thread thread : threads) {
thread.start();
}
startReporterThread();
waitForTestThreads();
waitForReporterThread();
doFinalReport();
}
