From e0c5ee85c8acd28c309c2e840020d91392ab780a Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Mon, 21 Nov 2022 14:17:08 +0000 Subject: [PATCH 1/7] Logged errors as info without stack trace for prefetching reads --- .../hadoop/fs/impl/prefetch/CachingBlockManager.java | 9 ++++++--- .../hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java | 3 ++- 2 files changed, 8 insertions(+), 4 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 31084c7bf2648..aab1c88dd4674 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -406,7 +406,8 @@ public Void get() { try { blockManager.prefetch(data, taskQueuedStartTime); } catch (Exception e) { - LOG.error("error during prefetch", e); + LOG.info("error during prefetch"); + LOG.debug(e.getMessage(), e); } return null; } @@ -493,7 +494,8 @@ private void addToCacheAndRelease(BufferData data, Future blockFuture, return; } } catch (Exception e) { - LOG.error("error waiting on blockFuture: {}", data, e); + LOG.info("error waiting on blockFuture: {}", data); + LOG.debug(e.getMessage(), e); data.setDone(); return; } @@ -524,7 +526,8 @@ private void addToCacheAndRelease(BufferData data, Future blockFuture, } catch (Exception e) { numCachingErrors.incrementAndGet(); String message = String.format("error adding block to cache after wait: %s", data); - LOG.error(message, e); + LOG.info(message); + LOG.debug(e.getMessage(), e); data.setDone(); } diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java index c84335a763e87..395f11be007c7 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java @@ -331,7 +331,8 @@ public static boolean isCacheSpaceAvailable(long fileSize) { Files.deleteIfExists(cacheFilePath); return fileSize < freeSpace; } catch (IOException e) { - LOG.error("isCacheSpaceAvailable", e); + LOG.info("isCacheSpaceAvailable"); + LOG.debug(e.getMessage(), e); return false; } } From b6d2d9c9c37eee3c4a1ec9cfbd0b0756691c3471 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Thu, 1 Dec 2022 10:50:03 +0000 Subject: [PATCH 2/7] changed error logging style for debug --- .../fs/impl/prefetch/CachingBlockManager.java | 13 +++++++------ .../fs/impl/prefetch/SingleFilePerBlockCache.java | 4 ++-- 2 files changed, 9 insertions(+), 8 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index aab1c88dd4674..0c33f189c169d 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -369,6 +369,7 @@ private void readBlock(BufferData data, boolean isPrefetch, BufferData.State... tracker.failed(); } + numReadErrors.incrementAndGet(); data.setDone(); throw e; @@ -406,8 +407,8 @@ public Void get() { try { blockManager.prefetch(data, taskQueuedStartTime); } catch (Exception e) { - LOG.info("error during prefetch"); - LOG.debug(e.getMessage(), e); + LOG.info("error during prefetch. {}", e.getMessage()); + LOG.debug("error during prefetch", e); } return null; } @@ -494,8 +495,8 @@ private void addToCacheAndRelease(BufferData data, Future blockFuture, return; } } catch (Exception e) { - LOG.info("error waiting on blockFuture: {}", data); - LOG.debug(e.getMessage(), e); + LOG.info("error waiting on blockFuture: {}. {}", data, e.getMessage()); + LOG.debug("error waiting on blockFuture: {}", data, e); data.setDone(); return; } @@ -526,8 +527,8 @@ private void addToCacheAndRelease(BufferData data, Future blockFuture, } catch (Exception e) { numCachingErrors.incrementAndGet(); String message = String.format("error adding block to cache after wait: %s", data); - LOG.info(message); - LOG.debug(e.getMessage(), e); + LOG.info(message, e.getMessage()); + LOG.debug(message, e); data.setDone(); } diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java index 395f11be007c7..144f38f3cde74 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java @@ -331,8 +331,8 @@ public static boolean isCacheSpaceAvailable(long fileSize) { Files.deleteIfExists(cacheFilePath); return fileSize < freeSpace; } catch (IOException e) { - LOG.info("isCacheSpaceAvailable"); - LOG.debug(e.getMessage(), e); + LOG.info("isCacheSpaceAvailable {}", e.getMessage()); + LOG.debug("isCacheAvailable", e); return false; } } From 6d01128a067fc7883acd3f0cfce11b201007857e Mon Sep 17 00:00:00 2001 From: Ankit Saurabh <112006204+sauraank@users.noreply.github.com> Date: Mon, 19 Dec 2022 17:39:56 +0000 Subject: [PATCH 3/7] Logged failures during Read at error level and during prefetch at info level once. --- .../fs/impl/prefetch/CachingBlockManager.java | 37 +++++++++++-------- .../org/apache/hadoop/fs/s3a/Constants.java | 2 +- 2 files changed, 22 insertions(+), 17 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 0c33f189c169d..15aaf4a1aab87 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -302,19 +302,32 @@ public void cancelPrefetches() { private void read(BufferData data) throws IOException { synchronized (data) { - readBlock(data, false, BufferData.State.BLANK); + try { + readBlock(data, false, BufferData.State.BLANK); + } + catch(Exception e){ + String message = String.format("error during readBlock(%s) for read", data.getBlockNumber()); + LOG.error(message, e); + } } } - private void prefetch(BufferData data, Instant taskQueuedStartTime) throws IOException { + private void prefetch(BufferData data, Instant taskQueuedStartTime) { synchronized (data) { prefetchingStatistics.executorAcquired( Duration.between(taskQueuedStartTime, Instant.now())); - readBlock( - data, - true, - BufferData.State.PREFETCHING, - BufferData.State.CACHING); + try { + readBlock( + data, + true, + BufferData.State.PREFETCHING, + BufferData.State.CACHING); + } + catch (Exception e) { + String message = String.format("error during readBlock(%s) for prefetch", data.getBlockNumber()); + LOG.info(message, e.getMessage()); + LOG.debug(message, e); + } } } @@ -362,9 +375,6 @@ private void readBlock(BufferData data, boolean isPrefetch, BufferData.State... buffer.flip(); data.setReady(expectedState); } catch (Exception e) { - String message = String.format("error during readBlock(%s)", data.getBlockNumber()); - LOG.error(message, e); - if (isPrefetch && tracker != null) { tracker.failed(); } @@ -404,12 +414,7 @@ private static class PrefetchTask implements Supplier { @Override public Void get() { - try { - blockManager.prefetch(data, taskQueuedStartTime); - } catch (Exception e) { - LOG.info("error during prefetch. {}", e.getMessage()); - LOG.debug("error during prefetch", e); - } + blockManager.prefetch(data, taskQueuedStartTime); return null; } } diff --git a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java index e5b0a9b5aa163..0689b49d120f8 100644 --- a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java +++ b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java @@ -1248,7 +1248,7 @@ private Constants() { * The size of a single prefetched block in number of bytes. */ public static final String PREFETCH_BLOCK_SIZE_KEY = "fs.s3a.prefetch.block.size"; - public static final int PREFETCH_BLOCK_DEFAULT_SIZE = 8 * 1024 * 1024; + public static final int PREFETCH_BLOCK_DEFAULT_SIZE = 2 * 1024 * 1024; /** * Maximum number of blocks prefetched at any given time. From 336446114ff9a8e9ab8d1be7d866877269d30144 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh <112006204+sauraank@users.noreply.github.com> Date: Sat, 31 Dec 2022 07:09:15 +0000 Subject: [PATCH 4/7] Addressed issues of throwing errors when read fails --- .../fs/impl/prefetch/CachingBlockManager.java | 32 +++++++++---------- .../prefetch/SingleFilePerBlockCache.java | 3 +- .../org/apache/hadoop/fs/s3a/Constants.java | 2 +- 3 files changed, 18 insertions(+), 19 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 15aaf4a1aab87..2a086fb6c051a 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -306,28 +306,23 @@ private void read(BufferData data) throws IOException { readBlock(data, false, BufferData.State.BLANK); } catch(Exception e){ - String message = String.format("error during readBlock(%s) for read", data.getBlockNumber()); + String message = String.format("error reading block(%s)", data.getBlockNumber()); LOG.error(message, e); + throw e; } } } - private void prefetch(BufferData data, Instant taskQueuedStartTime) { + private void prefetch(BufferData data, Instant taskQueuedStartTime) throws IOException { synchronized (data) { prefetchingStatistics.executorAcquired( Duration.between(taskQueuedStartTime, Instant.now())); - try { - readBlock( - data, - true, - BufferData.State.PREFETCHING, - BufferData.State.CACHING); - } - catch (Exception e) { - String message = String.format("error during readBlock(%s) for prefetch", data.getBlockNumber()); - LOG.info(message, e.getMessage()); - LOG.debug(message, e); - } + + readBlock( + data, + true, + BufferData.State.PREFETCHING, + BufferData.State.CACHING); } } @@ -379,7 +374,6 @@ private void readBlock(BufferData data, boolean isPrefetch, BufferData.State... tracker.failed(); } - numReadErrors.incrementAndGet(); data.setDone(); throw e; @@ -414,7 +408,13 @@ private static class PrefetchTask implements Supplier { @Override public Void get() { - blockManager.prefetch(data, taskQueuedStartTime); + try{ + blockManager.prefetch(data, taskQueuedStartTime); + } catch (Exception e) { + String message = String.format("error prefetching block(%s)", data.getBlockNumber()); + LOG.info(message, e.getMessage()); + LOG.debug(message, e); + } return null; } } diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java index 144f38f3cde74..c84335a763e87 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/SingleFilePerBlockCache.java @@ -331,8 +331,7 @@ public static boolean isCacheSpaceAvailable(long fileSize) { Files.deleteIfExists(cacheFilePath); return fileSize < freeSpace; } catch (IOException e) { - LOG.info("isCacheSpaceAvailable {}", e.getMessage()); - LOG.debug("isCacheAvailable", e); + LOG.error("isCacheSpaceAvailable", e); return false; } } diff --git a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java index 0689b49d120f8..e5b0a9b5aa163 100644 --- a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java +++ b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/Constants.java @@ -1248,7 +1248,7 @@ private Constants() { * The size of a single prefetched block in number of bytes. */ public static final String PREFETCH_BLOCK_SIZE_KEY = "fs.s3a.prefetch.block.size"; - public static final int PREFETCH_BLOCK_DEFAULT_SIZE = 2 * 1024 * 1024; + public static final int PREFETCH_BLOCK_DEFAULT_SIZE = 8 * 1024 * 1024; /** * Maximum number of blocks prefetched at any given time. From 6c81a1f8909d6f68b5a39e2aef0dbe838fe58fb6 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh <112006204+sauraank@users.noreply.github.com> Date: Wed, 4 Jan 2023 13:12:15 +0000 Subject: [PATCH 5/7] Improved spacing and indentation --- .../apache/hadoop/fs/impl/prefetch/CachingBlockManager.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 2a086fb6c051a..32b9bbaf08835 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -306,7 +306,7 @@ private void read(BufferData data) throws IOException { readBlock(data, false, BufferData.State.BLANK); } catch(Exception e){ - String message = String.format("error reading block(%s)", data.getBlockNumber()); + String message = String.format("error reading block %s", data.getBlockNumber()); LOG.error(message, e); throw e; } @@ -408,10 +408,10 @@ private static class PrefetchTask implements Supplier { @Override public Void get() { - try{ + try { blockManager.prefetch(data, taskQueuedStartTime); } catch (Exception e) { - String message = String.format("error prefetching block(%s)", data.getBlockNumber()); + String message = String.format("error prefetching block %s", data.getBlockNumber()); LOG.info(message, e.getMessage()); LOG.debug(message, e); } From 2dd89ea3532590fc15218b4554bb85ef037e97ef Mon Sep 17 00:00:00 2001 From: Ankit Saurabh <112006204+sauraank@users.noreply.github.com> Date: Wed, 11 Jan 2023 15:48:33 +0000 Subject: [PATCH 6/7] Improved error message and checkstyle issue --- .../fs/impl/prefetch/CachingBlockManager.java | 14 +++++--------- 1 file changed, 5 insertions(+), 9 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 32b9bbaf08835..20956acf8edf1 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -304,8 +304,7 @@ private void read(BufferData data) throws IOException { synchronized (data) { try { readBlock(data, false, BufferData.State.BLANK); - } - catch(Exception e){ + } catch(Exception e) { String message = String.format("error reading block %s", data.getBlockNumber()); LOG.error(message, e); throw e; @@ -317,7 +316,6 @@ private void prefetch(BufferData data, Instant taskQueuedStartTime) throws IOExc synchronized (data) { prefetchingStatistics.executorAcquired( Duration.between(taskQueuedStartTime, Instant.now())); - readBlock( data, true, @@ -411,9 +409,8 @@ public Void get() { try { blockManager.prefetch(data, taskQueuedStartTime); } catch (Exception e) { - String message = String.format("error prefetching block %s", data.getBlockNumber()); - LOG.info(message, e.getMessage()); - LOG.debug(message, e); + LOG.info("error prefetching block {}. {}", data.getBlockNumber(), e.getMessage()); + LOG.debug("error prefetching block {}", data.getBlockNumber(), e); } return null; } @@ -531,9 +528,8 @@ private void addToCacheAndRelease(BufferData data, Future blockFuture, data.setDone(); } catch (Exception e) { numCachingErrors.incrementAndGet(); - String message = String.format("error adding block to cache after wait: %s", data); - LOG.info(message, e.getMessage()); - LOG.debug(message, e); + LOG.info("error adding block to cache after wait: {}. {}", data, e.getMessage()); + LOG.debug("error adding block to cache after wait: {}", data, e); data.setDone(); } From a4a2d2ed321d18d0d9c679fae3a193d8bccfb604 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Tue, 14 Feb 2023 10:34:44 +0000 Subject: [PATCH 7/7] Added space and and other minor changes --- .../apache/hadoop/fs/impl/prefetch/CachingBlockManager.java | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java index 20956acf8edf1..a0db4b308b67c 100644 --- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java +++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/fs/impl/prefetch/CachingBlockManager.java @@ -304,9 +304,8 @@ private void read(BufferData data) throws IOException { synchronized (data) { try { readBlock(data, false, BufferData.State.BLANK); - } catch(Exception e) { - String message = String.format("error reading block %s", data.getBlockNumber()); - LOG.error(message, e); + } catch (IOException e) { + LOG.error("error reading block {}", data.getBlockNumber(), e); throw e; } }