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();
