[iotdb] branch autoai_debug updated: add log 2: see who cost 3s

[qi...@apache.org]

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

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


The following commit(s) were added to refs/heads/autoai_debug by this push:
     new eb33413  add log 2: see who cost 3s
eb33413 is described below

commit eb33413249a2b8ccbb5c7965077a870578b6e25b
Author: qiaojialin <64...@qq.com>
AuthorDate: Wed Jul 28 13:19:20 2021 +0800

    add log 2: see who cost 3s
---
 .../db/writelog/node/ExclusiveWriteLogNode.java    | 32 ++++++++++++++++++++++
 1 file changed, 32 insertions(+)

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 e45a46c..07ee8fe 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
@@ -139,6 +139,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
   public void close() {
     sync();
     forceWal();
+    long start = System.nanoTime();
     lock.lock();
     try {
       synchronized (switchBufferCondition) {
@@ -162,6 +163,10 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
     } finally {
       lock.unlock();
     }
+    long elapse = System.nanoTime() - start;
+    if (elapse > 3_000_000_000L) {
+      logger.warn("[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse / 1_000_000L);
+    }
   }
 
   @Override
@@ -175,6 +180,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
 
   @Override
   public void notifyStartFlush() throws FileNotFoundException {
+    long start = System.nanoTime();
     lock.lock();
     try {
       close();
@@ -182,10 +188,15 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
     } finally {
       lock.unlock();
     }
+    long elapse = System.nanoTime() - start;
+    if (elapse > 3_000_000_000L) {
+      logger.warn("[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse / 1_000_000L);
+    }
   }
 
   @Override
   public void notifyEndFlush() {
+    long start = System.nanoTime();
     lock.lock();
     try {
       File logFile =
@@ -194,6 +205,10 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
     } finally {
       lock.unlock();
     }
+    long elapse = System.nanoTime() - start;
+    if (elapse > 3_000_000_000L) {
+      logger.warn("[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse / 1_000_000L);
+    }
   }
 
   @Override
@@ -208,6 +223,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
 
   @Override
   public ByteBuffer[] delete() throws IOException {
+    long start = System.nanoTime();
     lock.lock();
     try {
       close();
@@ -216,6 +232,11 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       return this.bufferArray;
     } finally {
       lock.unlock();
+      long elapse = System.nanoTime() - start;
+      if (elapse > 3_000_000_000L) {
+        logger.warn(
+            "[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse / 1_000_000L);
+      }
     }
   }
 
@@ -242,6 +263,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
   }
 
   private void forceWal() {
+    long start = System.nanoTime();
     lock.lock();
     try {
       try {
@@ -254,6 +276,10 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
     } finally {
       lock.unlock();
     }
+    long elapse = System.nanoTime() - start;
+    if (elapse > 3_000_000_000L) {
+      logger.warn("[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse / 1_000_000L);
+    }
   }
 
   private void sync() {
@@ -287,6 +313,7 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
   }
 
   private void flushBuffer(ILogWriter writer) {
+    long start1 = System.nanoTime();
     try {
       writer.write(logBufferFlushing);
     } catch (ClosedChannelException e) {
@@ -296,6 +323,11 @@ public class ExclusiveWriteLogNode implements WriteLogNode, Comparable<Exclusive
       IoTDBDescriptor.getInstance().getConfig().setReadOnly(true);
       return;
     }
+    long elapse1 = System.nanoTime() - start1;
+    if (elapse1 > 3_000_000_000L) {
+      logger.warn(
+          "[WAL] {} flushBuffer write log cost {}ms", this.hashCode(), elapse1 / 1_000_000L);
+    }
 
     // switch buffer flushing to idle and notify the sync thread
     long start = System.nanoTime();