You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@geode.apache.org by up...@apache.org on 2021/10/14 17:11:29 UTC
[geode-benchmarks] branch develop updated: GEODE-9175: Reducing the
noise from the logging benchmark framework (#157)
This is an automated email from the ASF dual-hosted git repository.
upthewaterspout pushed a commit to branch develop
in repository https://gitbox.apache.org/repos/asf/geode-benchmarks.git
The following commit(s) were added to refs/heads/develop by this push:
new 0f5b877 GEODE-9175: Reducing the noise from the logging benchmark framework (#157)
0f5b877 is described below
commit 0f5b877dffc895582ee7e40d9727ad1b67dafba6
Author: Dan Smith <da...@vmware.com>
AuthorDate: Thu Oct 14 10:11:25 2021 -0700
GEODE-9175: Reducing the noise from the logging benchmark framework (#157)
Changing a bunch of debug output to info level to reduce the amount of
noise the benchmark framework is printing out.
This is not the full scope of GEODE-9195, which also is asking to
print out progress as the test runs.
---
.../org/apache/geode/perftest/TestContext.java | 7 +++-
.../infrastructure/local/LocalInfrastructure.java | 5 ++-
.../infrastructure/ssh/QuietSshLoggingConfig.java | 47 ++++++++++++++++++++++
.../infrastructure/ssh/SshInfrastructure.java | 7 ++--
.../apache/geode/perftest/jvms/JVMLauncher.java | 1 +
.../geode/perftest/jvms/RemoteJVMFactory.java | 3 +-
.../apache/geode/perftest/jvms/rmi/ChildJVM.java | 4 +-
.../apache/geode/perftest/jvms/rmi/Controller.java | 9 +++++
.../geode/perftest/jvms/rmi/ControllerRemote.java | 2 +
.../geode/perftest/runner/DefaultTestContext.java | 19 ++++++++-
.../geode/perftest/runner/DefaultTestRunner.java | 2 +-
.../yardstick/hdrhistogram/HdrHistogramProbe.java | 12 +++++-
.../perftest/yardstick/YardstickTaskTest.java | 5 ++-
infrastructure/scripts/aws/run_tests.sh | 7 ++--
14 files changed, 115 insertions(+), 15 deletions(-)
diff --git a/harness/src/main/java/org/apache/geode/perftest/TestContext.java b/harness/src/main/java/org/apache/geode/perftest/TestContext.java
index d73cd51..81f10f5 100644
--- a/harness/src/main/java/org/apache/geode/perftest/TestContext.java
+++ b/harness/src/main/java/org/apache/geode/perftest/TestContext.java
@@ -53,5 +53,10 @@ public interface TestContext extends Serializable {
Object getAttribute(String key);
-
+ /**
+ * Print a log message to the terminal about the progress of a test task
+ *
+ * @param progress The progress message to display
+ */
+ void logProgress(String progress);
}
diff --git a/harness/src/main/java/org/apache/geode/perftest/infrastructure/local/LocalInfrastructure.java b/harness/src/main/java/org/apache/geode/perftest/infrastructure/local/LocalInfrastructure.java
index 596d99d..d5687d2 100644
--- a/harness/src/main/java/org/apache/geode/perftest/infrastructure/local/LocalInfrastructure.java
+++ b/harness/src/main/java/org/apache/geode/perftest/infrastructure/local/LocalInfrastructure.java
@@ -34,6 +34,8 @@ import java.util.concurrent.CopyOnWriteArrayList;
import java.util.function.Function;
import org.apache.commons.io.FileUtils;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
import org.apache.geode.perftest.infrastructure.Infrastructure;
@@ -42,6 +44,7 @@ import org.apache.geode.perftest.infrastructure.Infrastructure;
* on the local computer, in their own working directories.
*/
public class LocalInfrastructure implements Infrastructure {
+ private static final Logger logger = LoggerFactory.getLogger(LocalInfrastructure.class);
private final Set<LocalNode> nodes = new LinkedHashSet<>();
private final List<Process> processList = new CopyOnWriteArrayList<>();
@@ -66,7 +69,7 @@ public class LocalInfrastructure implements Infrastructure {
builder.inheritIO();
builder.directory(((LocalNode) node).getWorkingDir());
- System.out.println(String.format("Launching %s>%s", ((LocalNode) node).getWorkingDir(),
+ logger.debug(String.format("Launching %s>%s", ((LocalNode) node).getWorkingDir(),
String.join(" ", shellCommand)));
Process process = builder.start();
processList.add(process);
diff --git a/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/QuietSshLoggingConfig.java b/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/QuietSshLoggingConfig.java
new file mode 100644
index 0000000..8e6272d
--- /dev/null
+++ b/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/QuietSshLoggingConfig.java
@@ -0,0 +1,47 @@
+/*
+ * 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.geode.perftest.infrastructure.ssh;
+
+import net.schmizz.sshj.DefaultConfig;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.NOPLogger;
+
+class QuietSshLoggingConfig extends DefaultConfig {
+ private static final Logger logger = LoggerFactory.getLogger(QuietSshLoggingConfig.class);
+
+ @Override
+ public net.schmizz.sshj.common.LoggerFactory getLoggerFactory() {
+ if (logger.isDebugEnabled()) {
+ return super.getLoggerFactory();
+ } else {
+ return new NOPLoggerFactory();
+ }
+ }
+
+ private static class NOPLoggerFactory implements net.schmizz.sshj.common.LoggerFactory {
+ @Override
+ public Logger getLogger(String name) {
+ return NOPLogger.NOP_LOGGER;
+ }
+
+ @Override
+ public Logger getLogger(Class<?> clazz) {
+ return NOPLogger.NOP_LOGGER;
+ }
+ }
+}
diff --git a/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/SshInfrastructure.java b/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/SshInfrastructure.java
index 6411048..db19776 100644
--- a/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/SshInfrastructure.java
+++ b/harness/src/main/java/org/apache/geode/perftest/infrastructure/ssh/SshInfrastructure.java
@@ -37,7 +37,6 @@ import java.util.function.Function;
import java.util.stream.Collectors;
import net.schmizz.sshj.Config;
-import net.schmizz.sshj.DefaultConfig;
import net.schmizz.sshj.SSHClient;
import net.schmizz.sshj.connection.channel.direct.Session;
import net.schmizz.sshj.connection.channel.direct.Signal;
@@ -54,7 +53,7 @@ public class SshInfrastructure implements Infrastructure {
private final Set<SshNode> hosts;
private final String user;
private final int port;
- public static final Config CONFIG = new DefaultConfig();
+ public static final Config CONFIG = new QuietSshLoggingConfig();
private ExecutorService streamReaderThreadPool = Executors.newCachedThreadPool();
public SshInfrastructure(Collection<String> hosts, String user) {
@@ -87,7 +86,7 @@ public class SshInfrastructure implements Infrastructure {
try (final SSHClient client = getSSHClient(node.getAddress());
final Session session = client.startSession()) {
final String script = "'" + String.join("' '", shellCommand) + "'";
- logger.info("Executing {} on {}", script, node.getAddress());
+ logger.debug("Executing {} on {}", script, node.getAddress());
try (final Session.Command cmd = session.exec(script)) {
final CompletableFuture<Void> copyStdout =
copyStreamAsynchronously(cmd.getInputStream(), System.out);
@@ -170,6 +169,7 @@ public class SshInfrastructure implements Infrastructure {
}
for (File file : files) {
+ logger.debug("Copying " + file + " to " + address);
client.newSCPFileTransfer().upload(new FileSystemFile(file), destDir);
}
} catch (IOException e) {
@@ -208,4 +208,5 @@ public class SshInfrastructure implements Infrastructure {
return host;
}
}
+
}
diff --git a/harness/src/main/java/org/apache/geode/perftest/jvms/JVMLauncher.java b/harness/src/main/java/org/apache/geode/perftest/jvms/JVMLauncher.java
index 4c0de66..f2cf17e 100644
--- a/harness/src/main/java/org/apache/geode/perftest/jvms/JVMLauncher.java
+++ b/harness/src/main/java/org/apache/geode/perftest/jvms/JVMLauncher.java
@@ -110,6 +110,7 @@ class JVMLauncher {
command.add("-D" + RemoteJVMFactory.RMI_HOST + "=" + rmiHost);
command.add("-D" + RemoteJVMFactory.RMI_PORT_PROPERTY + "=" + rmiPort);
command.add("-D" + RemoteJVMFactory.JVM_ID + "=" + jvmConfig.getId());
+ command.add("-D" + RemoteJVMFactory.ROLE + "=" + jvmConfig.getRole());
command.add("-D" + RemoteJVMFactory.OUTPUT_DIR + "=" + jvmConfig.getOutputDir());
if (jvmConfig.getJvmArgs().contains("-Dbenchmark.withSsl=true")) {
diff --git a/harness/src/main/java/org/apache/geode/perftest/jvms/RemoteJVMFactory.java b/harness/src/main/java/org/apache/geode/perftest/jvms/RemoteJVMFactory.java
index 10086c4..0294035 100644
--- a/harness/src/main/java/org/apache/geode/perftest/jvms/RemoteJVMFactory.java
+++ b/harness/src/main/java/org/apache/geode/perftest/jvms/RemoteJVMFactory.java
@@ -67,6 +67,7 @@ public class RemoteJVMFactory {
public static final String RMI_PORT_PROPERTY = "RMI_PORT";
public static final String CONTROLLER = "CONTROLLER";
public static final String OUTPUT_DIR = "OUTPUT_DIR";
+ public static final String ROLE = "ROLE";
public static final String JVM_ID = "JVM_ID";
public static final int RMI_PORT = 33333;
private static final String CLASSPATH = System.getProperty("java.class.path");
@@ -161,7 +162,7 @@ public class RemoteJVMFactory {
X509Certificate[] chain = new X509Certificate[1];
chain[0] = keyGen.getSelfCertificate(new X500Name("CN=ROOT"), DAYS.toSeconds(365));
- logger.info("Certificate : {}", chain[0]);
+ logger.debug("Certificate : {}", chain[0]);
KeyStore ks = KeyStore.getInstance(KeyStore.getDefaultType());
ks.load(null, null);
diff --git a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ChildJVM.java b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ChildJVM.java
index ff3b94e..98ef52e 100644
--- a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ChildJVM.java
+++ b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ChildJVM.java
@@ -53,6 +53,7 @@ public class ChildJVM {
String RMI_PORT = system.getProperty(RemoteJVMFactory.RMI_PORT_PROPERTY);
String OUTPUT_DIR = system.getProperty(RemoteJVMFactory.OUTPUT_DIR);
int id = system.getInteger(RemoteJVMFactory.JVM_ID);
+ String role = system.getProperty(RemoteJVMFactory.ROLE);
if (RMI_HOST == null || RMI_PORT == null || OUTPUT_DIR == null) {
throw new IllegalStateException(
@@ -68,7 +69,8 @@ public class ChildJVM {
.lookup("//" + RMI_HOST + ":" + RMI_PORT + "/" + RemoteJVMFactory.CONTROLLER);
SharedContext sharedContext = controller.getsharedContext();
- DefaultTestContext context = new DefaultTestContext(sharedContext, outputDir, id);
+ DefaultTestContext context =
+ new DefaultTestContext(sharedContext, outputDir, id, role, controller);
Worker worker = new Worker(context);
diff --git a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/Controller.java b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/Controller.java
index ea4bef2..688d275 100644
--- a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/Controller.java
+++ b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/Controller.java
@@ -29,6 +29,9 @@ import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
import org.apache.geode.perftest.Task;
import org.apache.geode.perftest.runner.SharedContext;
@@ -36,6 +39,7 @@ import org.apache.geode.perftest.runner.SharedContext;
* RMI object that lives on the main controller JVM
*/
public class Controller extends UnicastRemoteObject implements ControllerRemote {
+ Logger logger = LoggerFactory.getLogger(Controller.class);
private final Registry registry;
private final SharedContext context;
private final Map<Integer, WorkerRemote> workers = new ConcurrentHashMap<>();
@@ -72,6 +76,11 @@ public class Controller extends UnicastRemoteObject implements ControllerRemote
}
@Override
+ public void logProgress(String progress) throws RemoteException {
+ logger.info(progress);
+ }
+
+ @Override
public SharedContext getsharedContext() throws RemoteException {
return context;
}
diff --git a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ControllerRemote.java b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ControllerRemote.java
index 0a63a0c..606a2af 100644
--- a/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ControllerRemote.java
+++ b/harness/src/main/java/org/apache/geode/perftest/jvms/rmi/ControllerRemote.java
@@ -28,5 +28,7 @@ public interface ControllerRemote extends Remote {
boolean ping() throws RemoteException;
+ void logProgress(String progress) throws RemoteException;
+
SharedContext getsharedContext() throws RemoteException;
}
diff --git a/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestContext.java b/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestContext.java
index 1dae065..8433490 100644
--- a/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestContext.java
+++ b/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestContext.java
@@ -19,21 +19,28 @@ package org.apache.geode.perftest.runner;
import java.io.File;
import java.net.InetAddress;
+import java.rmi.RemoteException;
import java.util.Set;
import java.util.TreeMap;
import org.apache.geode.perftest.TestContext;
+import org.apache.geode.perftest.jvms.rmi.ControllerRemote;
public class DefaultTestContext implements TestContext {
private SharedContext sharedContext;
private File outputDir;
+ private String role;
+ private ControllerRemote controller;
private int jvmID;
TreeMap<String, Object> attributeMap;
- public DefaultTestContext(SharedContext sharedContext, File outputDir, int jvmID) {
+ public DefaultTestContext(SharedContext sharedContext, File outputDir, int jvmID,
+ String role, ControllerRemote controller) {
this.sharedContext = sharedContext;
this.outputDir = outputDir;
+ this.role = role;
+ this.controller = controller;
attributeMap = new TreeMap<>();
this.jvmID = jvmID;
}
@@ -67,4 +74,14 @@ public class DefaultTestContext implements TestContext {
public File getOutputDir() {
return outputDir;
}
+
+ @Override
+ public void logProgress(String progress) {
+ try {
+ controller.logProgress(String.format("%s-%02d: %s", role, jvmID, progress));
+ } catch (RemoteException e) {
+ throw new IllegalStateException("Controller connection lost", e);
+ }
+
+ }
}
diff --git a/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestRunner.java b/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestRunner.java
index d7d619d..c26b1c2 100644
--- a/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestRunner.java
+++ b/harness/src/main/java/org/apache/geode/perftest/runner/DefaultTestRunner.java
@@ -108,7 +108,7 @@ public class DefaultTestRunner implements TestRunner {
// Close before copy otherwise logs, stats, and profiles are incomplete or missing.
remoteJVMs.closeController();
- logger.info("Copying results...");
+ logger.info("Copying results to {}", benchmarkOutput);
remoteJVMs.copyResults(benchmarkOutput);
remoteJVMs.closeInfra();
diff --git a/harness/src/main/java/org/apache/geode/perftest/yardstick/hdrhistogram/HdrHistogramProbe.java b/harness/src/main/java/org/apache/geode/perftest/yardstick/hdrhistogram/HdrHistogramProbe.java
index d841f67..c5c6bea 100644
--- a/harness/src/main/java/org/apache/geode/perftest/yardstick/hdrhistogram/HdrHistogramProbe.java
+++ b/harness/src/main/java/org/apache/geode/perftest/yardstick/hdrhistogram/HdrHistogramProbe.java
@@ -24,6 +24,7 @@ import java.util.Arrays;
import java.util.Collection;
import java.util.Collections;
import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Consumer;
import org.HdrHistogram.Histogram;
@@ -56,6 +57,7 @@ public class HdrHistogramProbe implements BenchmarkExecutionAwareProbe, Benchmar
private final Consumer<Histogram> histogramConsumer;
private long[] startTimes;
private Histogram[] histograms;
+ private AtomicBoolean warmUpFinished = new AtomicBoolean(false);
public HdrHistogramProbe(Consumer<Histogram> histogramConsumer) {
this(1, TimeUnit.HOURS.toNanos(5), 3, () -> System.nanoTime(), histogramConsumer);
@@ -116,7 +118,9 @@ public class HdrHistogramProbe implements BenchmarkExecutionAwareProbe, Benchmar
@Override
public Collection<BenchmarkProbePoint> points() {
final Histogram aggregate = getHistogram();
- reset();
+ if (warmUpFinished.compareAndSet(false, true)) {
+ reset();
+ }
final double mean = aggregate.getMean();
final long percentile99 = aggregate.getValueAtPercentile(99);
@@ -146,7 +150,7 @@ public class HdrHistogramProbe implements BenchmarkExecutionAwareProbe, Benchmar
}
- Histogram getHistogram() {
+ public Histogram getHistogram() {
final Histogram aggregate = new Histogram(lower, upper, numDigits);
for (final Histogram histogram : histograms) {
aggregate.add(histogram);
@@ -154,4 +158,8 @@ public class HdrHistogramProbe implements BenchmarkExecutionAwareProbe, Benchmar
aggregate.setEndTimeStamp(System.currentTimeMillis());
return aggregate;
}
+
+ public boolean isWarmupFinished() {
+ return warmUpFinished.get();
+ }
}
diff --git a/harness/src/test/java/org/apache/geode/perftest/yardstick/YardstickTaskTest.java b/harness/src/test/java/org/apache/geode/perftest/yardstick/YardstickTaskTest.java
index 1d57fbc..4643b14 100644
--- a/harness/src/test/java/org/apache/geode/perftest/yardstick/YardstickTaskTest.java
+++ b/harness/src/test/java/org/apache/geode/perftest/yardstick/YardstickTaskTest.java
@@ -18,6 +18,7 @@
package org.apache.geode.perftest.yardstick;
import static org.junit.jupiter.api.Assertions.assertTrue;
+import static org.mockito.Mockito.mock;
import java.io.File;
import java.nio.file.Files;
@@ -30,6 +31,7 @@ import org.apache.geode.perftest.Task;
import org.apache.geode.perftest.TestContext;
import org.apache.geode.perftest.WorkloadConfig;
import org.apache.geode.perftest.benchmarks.EmptyBenchmark;
+import org.apache.geode.perftest.jvms.rmi.ControllerRemote;
import org.apache.geode.perftest.runner.DefaultTestContext;
import org.apache.geode.perftest.yardstick.hdrhistogram.HdrHistogramWriter;
@@ -45,7 +47,8 @@ public class YardstickTaskTest {
workloadConfig.threads(1);
Task task = new YardstickTask(benchmark, workloadConfig);
File outputDir = folder.toFile();
- TestContext context = new DefaultTestContext(null, outputDir, 1);
+ ControllerRemote controller = mock(ControllerRemote.class);
+ TestContext context = new DefaultTestContext(null, outputDir, 1, "role", controller);
task.run(context);
assertTrue(1 <= benchmark.getInvocations());
diff --git a/infrastructure/scripts/aws/run_tests.sh b/infrastructure/scripts/aws/run_tests.sh
index 7eaf49d..9617658 100755
--- a/infrastructure/scripts/aws/run_tests.sh
+++ b/infrastructure/scripts/aws/run_tests.sh
@@ -17,7 +17,7 @@
# See the License for the specific language governing permissions and
# limitations under the License.
-set -x -e -o pipefail
+set -e -o pipefail
DEFAULT_BENCHMARK_REPO='https://github.com/apache/geode-benchmarks'
BENCHMARK_REPO=${DEFAULT_BENCHMARK_REPO}
@@ -224,6 +224,7 @@ remoteShell \
mkdir -p ${OUTPUT}
-scp ${SSH_OPTIONS} -r geode@${FIRST_INSTANCE}:geode-benchmarks/geode-benchmarks/build/reports ${OUTPUT}/reports
+scp ${SSH_OPTIONS} -q -r geode@${FIRST_INSTANCE}:geode-benchmarks/geode-benchmarks/build/reports ${OUTPUT}/reports
BENCHMARK_DIRECTORY="$(remoteShell ls -l geode-benchmarks/geode-benchmarks/build/ | grep benchmark | awk 'NF>1{print $NF}')"
-scp ${SSH_OPTIONS} -r geode@${FIRST_INSTANCE}:geode-benchmarks/geode-benchmarks/build/${BENCHMARK_DIRECTORY} ${OUTPUT}
+scp ${SSH_OPTIONS} -q -r geode@${FIRST_INSTANCE}:geode-benchmarks/geode-benchmarks/build/${BENCHMARK_DIRECTORY} ${OUTPUT}
+echo "Benchmark results saved in ${OUTPUT}"