From 1e40bf936b6dde3583281732c50a7337a5462815 Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 09:52:51 +0200 Subject: [PATCH 1/6] HDDS-1956. Aged IO Thread exits on first read --- .../hadoop/ozone/MiniOzoneLoadGenerator.java | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java index b94244721ae4d..ac4cc7364061c 100644 --- a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java +++ b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java @@ -35,6 +35,7 @@ import java.util.Arrays; import java.util.HashMap; import java.util.List; +import java.util.Optional; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.CompletableFuture; import java.util.concurrent.TimeUnit; @@ -133,7 +134,7 @@ private String writeData(int keyIndex, OzoneBucket bucket, String threadName) ByteBuffer buffer = buffers.get(keyIndex % numBuffers); int bufferCapacity = buffer.capacity(); - String keyName = threadName + keyNameDelimiter + keyIndex; + String keyName = getKeyName(keyIndex, threadName); try (OzoneOutputStream stream = bucket.createKey(keyName, bufferCapacity, ReplicationType.RATIS, ReplicationFactor.THREE, new HashMap<>())) { @@ -183,10 +184,11 @@ private void deleteKey(OzoneBucket bucket, String keyName) throws Exception { } } - private String getKeyToRead() { + private Optional randomKeyToRead() { int currentIndex = agedFileWrittenIndex.get(); - return currentIndex != 0 ? - String.valueOf(RandomUtils.nextInt(0, currentIndex)): null; + return currentIndex != 0 + ? Optional.of(RandomUtils.nextInt(0, currentIndex)) + : Optional.empty(); } private void startAgedFilesLoad(long runTimeMillis) { @@ -204,8 +206,9 @@ private void startAgedFilesLoad(long runTimeMillis) { keyName = writeData(agedFileWrittenIndex.incrementAndGet(), agedLoadBucket, threadName); } else { - keyName = getKeyToRead(); - if (keyName != null) { + Optional index = randomKeyToRead(); + if (index.isPresent()) { + keyName = getKeyName(index.get(), threadName); readData(agedLoadBucket, keyName); } } @@ -253,4 +256,8 @@ public void shutdownLoadGenerator() { LOG.error("error while closing ", e); } } + + private static String getKeyName(int keyIndex, String threadName) { + return threadName + keyNameDelimiter + keyIndex; + } } From 76a21b386a012027ac4a01bc28037a18015e4aef Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 10:10:38 +0200 Subject: [PATCH 2/6] HDDS-1956. Aged IO thread randomly exits due to key not found --- .../java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java index ac4cc7364061c..06758768fde63 100644 --- a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java +++ b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java @@ -203,7 +203,7 @@ private void startAgedFilesLoad(long runTimeMillis) { String keyName = null; try { if (agedWriteProbability.isTrue()) { - keyName = writeData(agedFileWrittenIndex.incrementAndGet(), + keyName = writeData(agedFileWrittenIndex.getAndIncrement(), agedLoadBucket, threadName); } else { Optional index = randomKeyToRead(); From 435a5c083c8f5de9de14c91d4e4317762d72afe2 Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 10:12:55 +0200 Subject: [PATCH 3/6] HDDS-1956. Log key operations at trace level --- .../org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java index 06758768fde63..469fc33b4c71a 100644 --- a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java +++ b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java @@ -50,7 +50,7 @@ */ public class MiniOzoneLoadGenerator { - static final Logger LOG = + private static final Logger LOG = LoggerFactory.getLogger(MiniOzoneLoadGenerator.class); private static String keyNameDelimiter = "_"; @@ -135,10 +135,12 @@ private String writeData(int keyIndex, OzoneBucket bucket, String threadName) int bufferCapacity = buffer.capacity(); String keyName = getKeyName(keyIndex, threadName); + LOG.trace("LOADGEN: Writing key {}", keyName); try (OzoneOutputStream stream = bucket.createKey(keyName, bufferCapacity, ReplicationType.RATIS, ReplicationFactor.THREE, new HashMap<>())) { stream.write(buffer.array()); + LOG.trace("LOADGEN: Written key {}", keyName); } catch (Throwable t) { LOG.error("LOADGEN: Create key:{} failed with exception, skipping", keyName, t); @@ -149,6 +151,8 @@ private String writeData(int keyIndex, OzoneBucket bucket, String threadName) } private void readData(OzoneBucket bucket, String keyName) throws Exception { + LOG.trace("LOADGEN: Reading key {}", keyName); + int index = Integer.valueOf(keyName.split(keyNameDelimiter)[1]); @@ -169,6 +173,7 @@ private void readData(OzoneBucket bucket, String keyName) throws Exception { throw new IOException("Read mismatch, key:" + keyName + " read data does not match the written data"); } + LOG.trace("LOADGEN: Read key {}", keyName); } catch (Throwable t) { LOG.error("LOADGEN: Read key:{} failed with exception", keyName, t); throw t; @@ -176,8 +181,10 @@ private void readData(OzoneBucket bucket, String keyName) throws Exception { } private void deleteKey(OzoneBucket bucket, String keyName) throws Exception { + LOG.trace("LOADGEN: Deleting key {}", keyName); try { bucket.deleteKey(keyName); + LOG.trace("LOADGEN: Deleted key {}", keyName); } catch (Throwable t) { LOG.error("LOADGEN: Unable to delete key:{}", keyName, t); throw t; From efd431b18b2e23ea2cbbd920be9214c5728d5ccb Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 10:13:21 +0200 Subject: [PATCH 4/6] HDDS-1956. Include thread name in log pattern --- .../integration-test/src/test/resources/log4j.properties | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/hadoop-ozone/integration-test/src/test/resources/log4j.properties b/hadoop-ozone/integration-test/src/test/resources/log4j.properties index 9ec5a922cb757..b8ad21d6c7fad 100644 --- a/hadoop-ozone/integration-test/src/test/resources/log4j.properties +++ b/hadoop-ozone/integration-test/src/test/resources/log4j.properties @@ -15,7 +15,7 @@ log4j.rootLogger=info,stdout log4j.threshold=ALL log4j.appender.stdout=org.apache.log4j.ConsoleAppender log4j.appender.stdout.layout=org.apache.log4j.PatternLayout -log4j.appender.stdout.layout.ConversionPattern=%d{ISO8601} %-5p %c{2} (%F:%M(%L)) - %m%n +log4j.appender.stdout.layout.ConversionPattern=%d{ISO8601} [%t] %-5p %c{2} (%F:%M(%L)) - %m%n log4j.logger.org.apache.hadoop.security.ShellBasedUnixGroupsMapping=ERROR log4j.logger.org.apache.hadoop.util.NativeCodeLoader=ERROR From e1152e0d8fa464dbb3c8fffca72502d09daa7325 Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 10:15:37 +0200 Subject: [PATCH 5/6] HDDS-1956. Improve log in MiniOzoneChaosCluster --- .../org/apache/hadoop/ozone/MiniOzoneChaosCluster.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneChaosCluster.java b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneChaosCluster.java index 75911df74e362..2eef206dba4d2 100644 --- a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneChaosCluster.java +++ b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneChaosCluster.java @@ -68,7 +68,7 @@ public MiniOzoneChaosCluster(OzoneConfiguration conf, this.executorService = Executors.newSingleThreadScheduledExecutor(); this.numDatanodes = getHddsDatanodes().size(); - LOG.info("Starting MiniOzoneChaosCluster with:{} datanodes" + numDatanodes); + LOG.info("Starting MiniOzoneChaosCluster with {} datanodes", numDatanodes); LogUtils.setLogLevel(GrpcClientProtocolClient.LOG, Level.WARN); } @@ -108,7 +108,7 @@ private void restartNodes() { LOG.info("{} Completed restarting Datanode: {}", failString, dn.getUuid()); } catch (Exception e) { - LOG.error("Failed to restartNodes Datanode", dn.getUuid()); + LOG.error("Failed to restartNodes Datanode {}", dn.getUuid(), e); } } } @@ -119,7 +119,7 @@ private void shutdownNodes() { for (int i = 0; i < numNodesToFail; i++) { boolean shouldStop = shouldStop(); int failedNodeIndex = getNodeToFail(); - String stopString = shouldStop ? "Stopping" : "Starting"; + String stopString = shouldStop ? "Stopping" : "Restarting"; DatanodeDetails dn = getHddsDatanodes().get(failedNodeIndex).getDatanodeDetails(); try { @@ -133,7 +133,7 @@ private void shutdownNodes() { LOG.info("Completed {} DataNode {}", stopString, dn.getUuid()); } catch (Exception e) { - LOG.error("Failed to shutdown Datanode", dn.getUuid()); + LOG.error("Failed {} Datanode {}", stopString, dn.getUuid(), e); } } } From 22d03e7271300e79413bbd9db4394a5c57ea3f26 Mon Sep 17 00:00:00 2001 From: "Doroszlai, Attila" Date: Tue, 13 Aug 2019 18:04:01 +0200 Subject: [PATCH 6/6] HDDS-1956. Pass index to readData to avoid splitting --- .../apache/hadoop/ozone/MiniOzoneLoadGenerator.java | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java index 469fc33b4c71a..6ced6d64fe343 100644 --- a/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java +++ b/hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java @@ -114,7 +114,7 @@ private void load(long runTimeMillis) { int index = RandomUtils.nextInt(); String keyName = writeData(index, bucket, threadName); - readData(bucket, keyName); + readData(bucket, keyName, index); deleteKey(bucket, keyName); } catch (Exception e) { @@ -150,12 +150,10 @@ private String writeData(int keyIndex, OzoneBucket bucket, String threadName) return keyName; } - private void readData(OzoneBucket bucket, String keyName) throws Exception { + private void readData(OzoneBucket bucket, String keyName, int index) + throws Exception { LOG.trace("LOADGEN: Reading key {}", keyName); - int index = Integer.valueOf(keyName.split(keyNameDelimiter)[1]); - - ByteBuffer buffer = buffers.get(index % numBuffers); int bufferCapacity = buffer.capacity(); @@ -216,7 +214,7 @@ private void startAgedFilesLoad(long runTimeMillis) { Optional index = randomKeyToRead(); if (index.isPresent()) { keyName = getKeyName(index.get(), threadName); - readData(agedLoadBucket, keyName); + readData(agedLoadBucket, keyName, index.get()); } } } catch (Throwable t) {