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

tkalkirill pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/ignite-3.git


The following commit(s) were added to refs/heads/main by this push:
     new 4d905ef98a IGNITE-23701 Add output of execution duration LogSyncer to 
message "Checkpoint finished" (#4744)
4d905ef98a is described below

commit 4d905ef98afaaa6644cb4588622735965d29ff82
Author: Kirill Tkalenko <tkalkir...@yandex.ru>
AuthorDate: Tue Nov 19 14:22:08 2024 +0300

    IGNITE-23701 Add output of execution duration LogSyncer to message 
"Checkpoint finished" (#4744)
---
 .../checkpoint/CheckpointMetricsTracker.java       | 20 ++++++++++++++++++
 .../persistence/checkpoint/Checkpointer.java       | 24 ++++++++++++++--------
 .../checkpoint/CheckpointMetricsTrackerTest.java   | 15 ++++++++++++++
 3 files changed, 51 insertions(+), 8 deletions(-)

diff --git 
a/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTracker.java
 
b/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTracker.java
index dbaa08e5ba..5d68995520 100644
--- 
a/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTracker.java
+++ 
b/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTracker.java
@@ -66,6 +66,8 @@ public class CheckpointMetricsTracker {
 
     private long fsyncStartNanos;
 
+    private long replicatorLogSyncStartNanos;
+
     private long endNanos;
 
     private long splitAndSortPagesStartNanos;
@@ -198,6 +200,15 @@ public class CheckpointMetricsTracker {
         splitAndSortPagesEndNanos = System.nanoTime();
     }
 
+    /**
+     * Callback at the start of the replication protocol write-ahead-log sync.
+     *
+     * <p>Not thread safe.
+     */
+    public void onReplicatorLogSyncStart() {
+        replicatorLogSyncStartNanos = System.nanoTime();
+    }
+
     /**
      * Returns total checkpoint duration.
      *
@@ -269,4 +280,13 @@ public class CheckpointMetricsTracker {
     public long splitAndSortCheckpointPagesDuration(TimeUnit timeUnit) {
         return timeUnit.convert(splitAndSortPagesEndNanos - 
splitAndSortPagesStartNanos, NANOSECONDS);
     }
+
+    /**
+     * Returns checkpoint replication protocol write-ahead-log sync duration 
in the given time unit.
+     *
+     * <p>Not thread safe.
+     */
+    public long replicatorLogSyncDuration(TimeUnit timeUnit) {
+        return timeUnit.convert(endNanos - replicatorLogSyncStartNanos, 
NANOSECONDS);
+    }
 }
diff --git 
a/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/Checkpointer.java
 
b/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/Checkpointer.java
index 19aecc7e9e..cf1de7712e 100644
--- 
a/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/Checkpointer.java
+++ 
b/modules/page-memory/src/main/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/Checkpointer.java
@@ -121,6 +121,7 @@ public class Checkpointer extends IgniteWorker {
             + "pages={}, "
             + "pagesWriteTime={}ms, "
             + "fsyncTime={}ms, "
+            + "replicatorLogSyncTime={}ms, "
             + "totalTime={}ms, "
             + "avgWriteSpeed={}MB/s]";
 
@@ -322,7 +323,7 @@ public class Checkpointer extends IgniteWorker {
         Checkpoint chp = null;
 
         try {
-            CheckpointMetricsTracker tracker = new CheckpointMetricsTracker();
+            var tracker = new CheckpointMetricsTracker();
 
             startCheckpointProgress();
 
@@ -368,13 +369,7 @@ public class Checkpointer extends IgniteWorker {
                     }
                 }
 
-                try {
-                    logSyncer.sync();
-                } catch (Exception e) {
-                    log.error("Failed to sync write-ahead log during 
checkpoint", e);
-
-                    throw new IgniteInternalCheckedException(e);
-                }
+                replicatorLogSync(tracker);
 
                 if (!writePages(tracker, chp.dirtyPages, chp.progress, this, 
this::isShutdownNow)) {
                     return;
@@ -411,6 +406,7 @@ public class Checkpointer extends IgniteWorker {
                             chp.dirtyPagesSize,
                             tracker.pagesWriteDuration(MILLISECONDS),
                             tracker.fsyncDuration(MILLISECONDS),
+                            tracker.replicatorLogSyncDuration(MICROSECONDS),
                             tracker.totalDuration(MILLISECONDS),
                             
WriteSpeedFormatter.formatWriteSpeed(avgWriteSpeedInBytes)
                     );
@@ -898,4 +894,16 @@ public class Checkpointer extends IgniteWorker {
 
         return processedPartitionFuture == null ? nullCompletedFuture() : 
processedPartitionFuture;
     }
+
+    private void replicatorLogSync(CheckpointMetricsTracker tracker) throws 
IgniteInternalCheckedException {
+        try {
+            tracker.onReplicatorLogSyncStart();
+
+            logSyncer.sync();
+        } catch (Exception e) {
+            log.error("Failed to sync write-ahead log during checkpoint", e);
+
+            throw new IgniteInternalCheckedException(e);
+        }
+    }
 }
diff --git 
a/modules/page-memory/src/test/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTrackerTest.java
 
b/modules/page-memory/src/test/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTrackerTest.java
index ad425d0af1..8ad44189ca 100644
--- 
a/modules/page-memory/src/test/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTrackerTest.java
+++ 
b/modules/page-memory/src/test/java/org/apache/ignite/internal/pagememory/persistence/checkpoint/CheckpointMetricsTrackerTest.java
@@ -109,6 +109,21 @@ public class CheckpointMetricsTrackerTest {
         assertThat(tracker.fsyncDuration(NANOSECONDS), 
greaterThanOrEqualTo(1L));
     }
 
+    @Test
+    void testReplicatorLogSync() throws Exception {
+        var tracker = new CheckpointMetricsTracker();
+
+        assertThat(tracker.replicatorLogSyncDuration(NANOSECONDS), 
equalTo(0L));
+
+        tracker.onReplicatorLogSyncStart();
+
+        waitForTimeChange();
+
+        tracker.onCheckpointEnd();
+
+        assertThat(tracker.replicatorLogSyncDuration(NANOSECONDS), 
greaterThanOrEqualTo(1L));
+    }
+
     @Test
     void testPagesWrite() throws Exception {
         CheckpointMetricsTracker tracker = new CheckpointMetricsTracker();

Reply via email to