You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@iotdb.apache.org by qi...@apache.org on 2021/07/19 07:14:48 UTC

[iotdb] branch autoai_debug_single updated: add wal cost log

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

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


The following commit(s) were added to refs/heads/autoai_debug_single by this push:
     new 2c68af0  add wal cost log
2c68af0 is described below

commit 2c68af0c86f16a469305c8512912ecf16074e94d
Author: qiaojialin <64...@qq.com>
AuthorDate: Mon Jul 19 15:14:09 2021 +0800

    add wal cost log
---
 .../cluster/server/member/DataGroupMember.java     |  7 +---
 .../db/writelog/node/ExclusiveWriteLogNode.java    | 38 +++++++++++-----------
 2 files changed, 20 insertions(+), 25 deletions(-)

diff --git a/cluster/src/main/java/org/apache/iotdb/cluster/server/member/DataGroupMember.java b/cluster/src/main/java/org/apache/iotdb/cluster/server/member/DataGroupMember.java
index 89d933a..6244ad6 100644
--- a/cluster/src/main/java/org/apache/iotdb/cluster/server/member/DataGroupMember.java
+++ b/cluster/src/main/java/org/apache/iotdb/cluster/server/member/DataGroupMember.java
@@ -696,7 +696,7 @@ public class DataGroupMember extends RaftMember {
    */
   @Override
   public TSStatus executeNonQueryPlan(PhysicalPlan plan) {
-    long startTime = System.currentTimeMillis();
+    long startTime;
     if (ClusterDescriptor.getInstance().getConfig().getReplicationNum() == 1) {
       try {
         getLocalExecutor().processNonQuery(plan);
@@ -719,11 +719,6 @@ public class DataGroupMember extends RaftMember {
           }
         }
         return handleLogExecutionException(plan, cause);
-      } finally {
-        long elapsed = System.currentTimeMillis() - startTime;
-        if (elapsed > 5000) {
-          logger.error("PlanExecutor execute slowly : time cost : {}ms", elapsed);
-        }
       }
     } else {
       TSStatus status = executeNonQueryPlanWithKnownLeader(plan);
diff --git a/server/src/main/java/org/apache/iotdb/db/writelog/node/ExclusiveWriteLogNode.java b/server/src/main/java/org/apache/iotdb/db/writelog/node/ExclusiveWriteLogNode.java
index cf998db..d28ed6b 100644
--- a/server/src/main/java/org/apache/iotdb/db/writelog/node/ExclusiveWriteLogNode.java
+++ b/server/src/main/java/org/apache/iotdb/db/writelog/node/ExclusiveWriteLogNode.java
@@ -282,7 +282,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       logger.warn("can not found file {}", identifier, e);
     } finally {
       lock.unlock();
-      //      logger.warn("[wal] {} sync end", this.hashCode());
+      logger.warn("[wal] {} sync end", this.hashCode());
     }
   }
 
@@ -311,11 +311,11 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
     } catch (InterruptedException e) {
       Thread.currentThread().interrupt();
     }
-    //    logger.warn("[wal] {} flushBuffer end", this.hashCode());
+    logger.warn("[wal] {} flushBuffer end", this.hashCode());
   }
 
   private void switchBufferWorkingToFlushing() throws InterruptedException {
-    //    logger.warn("[wal] {} switchBufferWorkingToFlushing start", this.hashCode());
+    logger.warn("[wal] {} switchBufferWorkingToFlushing start", this.hashCode());
     long start = System.currentTimeMillis();
     synchronized (switchBufferCondition) {
       while (logBufferFlushing != null && !deleted) {
@@ -326,15 +326,15 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       switchBufferCondition.notifyAll();
     }
     long elapse = System.currentTimeMillis() - start;
-    if (elapse > 5000) {
+    if (elapse > 3000) {
       logger.error("[wal] switch Working -> Flushing cost: {}ms", elapse);
     }
-    //    logger.warn("[wal] {} switchBufferWorkingToFlushing end", this.hashCode());
+    logger.warn("[wal] {} switchBufferWorkingToFlushing end", this.hashCode());
   }
 
   private void switchBufferIdleToWorking() throws InterruptedException {
-    //    logger.warn("[wal] {} switchBufferIdleToWorking start", this.hashCode());
-    //    long start = System.currentTimeMillis();
+    logger.warn("[wal] {} switchBufferIdleToWorking start", this.hashCode());
+    long start = System.currentTimeMillis();
     synchronized (switchBufferCondition) {
       while (logBufferIdle == null && !deleted) {
         switchBufferCondition.wait(100);
@@ -343,16 +343,16 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       logBufferIdle = null;
       switchBufferCondition.notifyAll();
     }
-    //    long elapse = System.currentTimeMillis() - start;
-    //    if (elapse > 5000) {
-    //      logger.error("[wal] switch Idle -> Working cost: {}ms", elapse);
-    //    }
-    //    logger.warn("[wal] {} switchBufferIdleToWorking end", this.hashCode());
+    long elapse = System.currentTimeMillis() - start;
+    if (elapse > 3000) {
+      logger.error("[wal] switch Idle -> Working cost: {}ms", elapse);
+    }
+    logger.warn("[wal] {} switchBufferIdleToWorking end", this.hashCode());
   }
 
   private void switchBufferFlushingToIdle() throws InterruptedException {
-    //    logger.warn("[wal] {} switchBufferFlushingToIdle start", this.hashCode());
-    //    long start = System.currentTimeMillis();
+    logger.warn("[wal] {} switchBufferFlushingToIdle start", this.hashCode());
+    long start = System.currentTimeMillis();
     synchronized (switchBufferCondition) {
       while (logBufferIdle != null && !deleted) {
         switchBufferCondition.wait(100);
@@ -362,11 +362,11 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       logBufferFlushing = null;
       switchBufferCondition.notifyAll();
     }
-    //    long elapse = System.currentTimeMillis() - start;
-    //    if (elapse > 5000) {
-    //      logger.error("[wal] switch Flushing -> Idle cost: {}ms", elapse);
-    //    }
-    //    logger.warn("[wal] {} switchBufferFlushingToIdle end", this.hashCode());
+    long elapse = System.currentTimeMillis() - start;
+    if (elapse > 3000) {
+      logger.error("[wal] switch Flushing -> Idle cost: {}ms", elapse);
+    }
+    logger.warn("[wal] {} switchBufferFlushingToIdle end", this.hashCode());
   }
 
   private ILogWriter getCurrentFileWriter() throws FileNotFoundException {