From 08335cd4fc480fc92ded3450f288ee6ad58ac40e Mon Sep 17 00:00:00 2001
From: chaijunjie0101 <1340011734@qq.com>
Date: Fri, 26 May 2023 20:43:21 +0800
Subject: [PATCH] HBASE-27888 Record readBlock message in log when it takes too
 long time

---
 .../apache/hadoop/hbase/io/hfile/HFileBlock.java    | 13 +++++++++++++
 1 file changed, 13 insertions(+)

diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileBlock.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileBlock.java
index c84836bcd53..434529ec46f 100644
--- a/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileBlock.java
+++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileBlock.java
@@ -1385,6 +1385,13 @@ public class HFileBlock implements Cacheable {
 
     private final boolean isPreadAllBytes;
 
+    private final long readWarnTime;
+
+    /**
+     * If reading block cost time in milliseconds more than the threshold, a warning will be logged.
+     */
+    public static final String FS_READER_WARN_TIME_MS = "hbase.fs.reader.warn.time.ms";
+
     FSReaderImpl(ReaderContext readerContext, HFileContext fileContext, ByteBuffAllocator allocator,
       Configuration conf) throws IOException {
       this.fileSize = readerContext.getFileSize();
@@ -1402,6 +1409,8 @@ public class HFileBlock implements Cacheable {
       defaultDecodingCtx = new HFileBlockDefaultDecodingContext(conf, fileContext);
       encodedBlockDecodingCtx = defaultDecodingCtx;
       isPreadAllBytes = readerContext.isPreadAllBytes();
+      // Default warn threshold set to -1, it means skipping record the read block slow warning log.
+      readWarnTime = conf.getLong(FS_READER_WARN_TIME_MS, -1L);
     }
 
     @Override
@@ -1759,6 +1768,10 @@ public class HFileBlock implements Cacheable {
           hFileBlock.sanityCheckUncompressed();
         }
         LOG.trace("Read {} in {} ms", hFileBlock, duration);
+        if (!LOG.isTraceEnabled() && this.readWarnTime >= 0 && duration > this.readWarnTime) {
+          LOG.warn("Read Block Slow: read {} cost {} ms, threshold = {} ms", hFileBlock, duration,
+            this.readWarnTime);
+        }
         span.addEvent("Read block", attributesBuilder.build());
         // Cache next block header if we read it for the next time through here.
         if (nextBlockOnDiskSize != -1) {