From adde012de05a5ef007b44ada130544ff164ced0f Mon Sep 17 00:00:00 2001
From: Lei Zhang <27994433+SWJTU-ZhangLei@users.noreply.github.com>
Date: Thu, 14 Sep 2023 11:45:48 +0800
Subject: [PATCH] [enhancement](fe) Add more detail log for replayJournal
 (#24218)

---
 .../src/main/java/org/apache/doris/catalog/Env.java    | 10 ++++++++++
 .../java/org/apache/doris/journal/JournalEntity.java   |  9 +++++++++
 .../apache/doris/journal/bdbje/BDBJournalCursor.java   |  1 +
 3 files changed, 20 insertions(+)

diff --git a/fe/fe-core/src/main/java/org/apache/doris/catalog/Env.java b/fe/fe-core/src/main/java/org/apache/doris/catalog/Env.java
index a928df6e20..0fbc023345 100755
--- a/fe/fe-core/src/main/java/org/apache/doris/catalog/Env.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/catalog/Env.java
@@ -2612,6 +2612,7 @@ public class Env {
         long startTime = System.currentTimeMillis();
         boolean hasLog = false;
         while (true) {
+            long entityStartTime = System.currentTimeMillis();
             Pair<Long, JournalEntity> kv = cursor.next();
             if (kv == null) {
                 break;
@@ -2623,6 +2624,7 @@ public class Env {
             }
             hasLog = true;
             EditLog.loadJournal(this, logId, entity);
+            long loadJournalEndTime = System.currentTimeMillis();
             replayedJournalId.incrementAndGet();
             LOG.debug("journal {} replayed.", replayedJournalId);
             if (feType != FrontendNodeType.MASTER) {
@@ -2632,6 +2634,14 @@ public class Env {
                 // Metric repo may not init after this replay thread start
                 MetricRepo.COUNTER_EDIT_LOG_READ.increase(1L);
             }
+
+            long entityCost = System.currentTimeMillis() - entityStartTime;
+            if (entityCost >= 1000) {
+                long loadJournalCost = loadJournalEndTime - entityStartTime;
+                LOG.warn("entityCost:{} loadJournalCost:{} logId:{} replayedJournalId:{} code:{} size:{}",
+                        entityCost, loadJournalCost, logId, replayedJournalId, entity.getOpCode(),
+                        entity.getDataSize());
+            }
         }
         long cost = System.currentTimeMillis() - startTime;
         if (cost >= 1000) {
diff --git a/fe/fe-core/src/main/java/org/apache/doris/journal/JournalEntity.java b/fe/fe-core/src/main/java/org/apache/doris/journal/JournalEntity.java
index 179015b2bd..0415e43581 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/journal/JournalEntity.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/journal/JournalEntity.java
@@ -143,6 +143,7 @@ public class JournalEntity implements Writable {
 
     private short opCode;
     private Writable data;
+    private long dataSize;
 
     public short getOpCode() {
         return this.opCode;
@@ -164,6 +165,14 @@ public class JournalEntity implements Writable {
         return " opCode=" + opCode + " " + data;
     }
 
+    public void setDataSize(long dataSize) {
+        this.dataSize = dataSize;
+    }
+
+    public long getDataSize() {
+        return this.dataSize;
+    }
+
     @Override
     public void write(DataOutput out) throws IOException {
         out.writeShort(opCode);
diff --git a/fe/fe-core/src/main/java/org/apache/doris/journal/bdbje/BDBJournalCursor.java b/fe/fe-core/src/main/java/org/apache/doris/journal/bdbje/BDBJournalCursor.java
index 8939251925..5466df71dd 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/journal/bdbje/BDBJournalCursor.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/journal/bdbje/BDBJournalCursor.java
@@ -113,6 +113,7 @@ public class BDBJournalCursor implements JournalCursor {
                     JournalEntity entity = new JournalEntity();
                     try {
                         entity.readFields(in);
+                        entity.setDataSize(retData.length);
                     } catch (Exception e) {
                         LOG.error("fail to read journal entity key={}, will exit", currentKey, e);
                         System.exit(-1);