You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@iotdb.apache.org by ta...@apache.org on 2021/09/07 08:04:15 UTC

[iotdb] 01/01: add log

This is an automated email from the ASF dual-hosted git repository.

tanxinyu pushed a commit to branch cluster_sync_leader_bug
in repository https://gitbox.apache.org/repos/asf/iotdb.git

commit 06693755099251aef01d2940d548144b53b129e2
Author: LebronAl <TX...@gmail.com>
AuthorDate: Tue Sep 7 16:03:32 2021 +0800

    add log
---
 .../iotdb/cluster/log/applier/AsyncDataLogApplier.java       | 11 +++++++----
 .../org/apache/iotdb/cluster/log/manage/RaftLogManager.java  | 12 +++++++++++-
 2 files changed, 18 insertions(+), 5 deletions(-)

diff --git a/cluster/src/main/java/org/apache/iotdb/cluster/log/applier/AsyncDataLogApplier.java b/cluster/src/main/java/org/apache/iotdb/cluster/log/applier/AsyncDataLogApplier.java
index 65a5b2d..d0badaf 100644
--- a/cluster/src/main/java/org/apache/iotdb/cluster/log/applier/AsyncDataLogApplier.java
+++ b/cluster/src/main/java/org/apache/iotdb/cluster/log/applier/AsyncDataLogApplier.java
@@ -140,12 +140,10 @@ public class AsyncDataLogApplier implements LogApplier {
 
   /**
    * We can sure that the storage group of all InsertTabletPlans in InsertMultiTabletPlan are the
-   * same. this is done in {@link
-   * org.apache.iotdb.cluster.query.ClusterPlanRouter#splitAndRoutePlan(InsertMultiTabletPlan)}
+   * same. this is done in
    *
    * <p>We can also sure that the storage group of all InsertRowPlans in InsertRowsPlan are the
-   * same. this is done in {@link
-   * org.apache.iotdb.cluster.query.ClusterPlanRouter#splitAndRoutePlan(InsertRowsPlan)}
+   * same. this is done in
    *
    * @return the sg that the plan belongs to
    * @throws StorageGroupNotSetException if no sg found
@@ -203,7 +201,12 @@ public class AsyncDataLogApplier implements LogApplier {
 
   private void applyInternal(Log log) {
     long startTime = Statistic.RAFT_SENDER_DATA_LOG_APPLY.getOperationStartTime();
+    long start = System.nanoTime();
     embeddedApplier.apply(log);
+    long time = (System.nanoTime() - start) / 1_000_000L;
+    if (time > 5000) {
+      logger.warn("{}:apply log {} slowly for {}ms", name, log, time);
+    }
     if (Timer.ENABLE_INSTRUMENTING) {
       Statistic.RAFT_SENDER_DATA_LOG_APPLY.calOperationCostTimeFromStart(startTime);
     }
diff --git a/cluster/src/main/java/org/apache/iotdb/cluster/log/manage/RaftLogManager.java b/cluster/src/main/java/org/apache/iotdb/cluster/log/manage/RaftLogManager.java
index 446eefc..f3476c1 100644
--- a/cluster/src/main/java/org/apache/iotdb/cluster/log/manage/RaftLogManager.java
+++ b/cluster/src/main/java/org/apache/iotdb/cluster/log/manage/RaftLogManager.java
@@ -943,16 +943,26 @@ public abstract class RaftLogManager {
             nextToCheckIndex);
         return;
       }
+      long start = System.nanoTime();
       synchronized (log) {
         while (!log.isApplied() && maxHaveAppliedCommitIndex < log.getCurrLogIndex()) {
           // wait until the log is applied or a newer snapshot is installed
           log.wait(5);
         }
       }
+      long time = (System.nanoTime() - start) / 1_000_000L;
+      if (time > 5000) {
+        logger.warn("{}:wait log {} to apply slowly for {}ms", name, log, time);
+      }
+      start = System.nanoTime();
       synchronized (changeApplyCommitIndexCond) {
         // maxHaveAppliedCommitIndex may change if a snapshot is applied concurrently
         maxHaveAppliedCommitIndex = Math.max(maxHaveAppliedCommitIndex, nextToCheckIndex);
       }
+      time = (System.nanoTime() - start) / 1_000_000L;
+      if (time > 10000) {
+        logger.warn("{}:wait snapshot slowly for {}ms", name, time);
+      }
       logger.debug(
           "{}: log={} is applied, nextToCheckIndex={}, commitIndex={}, maxHaveAppliedCommitIndex={}",
           name,
@@ -968,7 +978,7 @@ public abstract class RaftLogManager {
         // maxHaveAppliedCommitIndex may change if a snapshot is applied concurrently
         maxHaveAppliedCommitIndex = Math.max(maxHaveAppliedCommitIndex, nextToCheckIndex);
       }
-      logger.debug(
+      logger.error(
           "{}: compacted log is assumed applied, nextToCheckIndex={}, commitIndex={}, "
               + "maxHaveAppliedCommitIndex={}",
           name,