You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by ir...@apache.org on 2018/07/05 10:30:54 UTC
ignite git commit: IGNITE-8737 Improve checkpoint logging information
- Fixes #4244.
Repository: ignite
Updated Branches:
refs/heads/master a8378003b -> a727a4c71
IGNITE-8737 Improve checkpoint logging information - Fixes #4244.
Signed-off-by: Ivan Rakov <ir...@apache.org>
Project: http://git-wip-us.apache.org/repos/asf/ignite/repo
Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/a727a4c7
Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/a727a4c7
Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/a727a4c7
Branch: refs/heads/master
Commit: a727a4c7135e57415de0756e8fdc235ba191109a
Parents: a837800
Author: AMedvedev <AM...@gridgain.com>
Authored: Thu Jul 5 13:19:23 2018 +0300
Committer: Ivan Rakov <ir...@apache.org>
Committed: Thu Jul 5 13:19:23 2018 +0300
----------------------------------------------------------------------
.../GridCacheDatabaseSharedManager.java | 13 ++-
.../checkpoint/CheckpointHistory.java | 28 ++++-
.../wal/FileWriteAheadLogManager.java | 12 +-
.../wal/FsyncModeFileWriteAheadLogManager.java | 8 +-
.../checkpoint/IgniteMassLoadSandboxTest.java | 110 ++++++++++++++++++-
5 files changed, 154 insertions(+), 17 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/ignite/blob/a727a4c7/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/GridCacheDatabaseSharedManager.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/GridCacheDatabaseSharedManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/GridCacheDatabaseSharedManager.java
index 8d9f74c..55394ae 100755
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/GridCacheDatabaseSharedManager.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/GridCacheDatabaseSharedManager.java
@@ -3193,12 +3193,13 @@ public class GridCacheDatabaseSharedManager extends IgniteCacheDatabaseSharedMan
if (printCheckpointStats) {
if (log.isInfoEnabled())
log.info(String.format("Checkpoint finished [cpId=%s, pages=%d, markPos=%s, " +
- "walSegmentsCleared=%d, markDuration=%dms, pagesWrite=%dms, fsync=%dms, " +
+ "walSegmentsCleared=%d, walSegmentsCovered=%s, markDuration=%dms, pagesWrite=%dms, fsync=%dms, " +
"total=%dms]",
chp.cpEntry != null ? chp.cpEntry.checkpointId() : "",
chp.pagesSize,
chp.cpEntry != null ? chp.cpEntry.checkpointMark() : "",
chp.walFilesDeleted,
+ chp.walSegmentsCovered,
tracker.markDuration(),
tracker.pagesWriteDuration(),
tracker.fsyncDuration(),
@@ -3870,6 +3871,9 @@ public class GridCacheDatabaseSharedManager extends IgniteCacheDatabaseSharedMan
/** Number of deleted WAL files. */
private int walFilesDeleted;
+ /** WAL segments fully covered by this checkpoint. */
+ private List<Long> walSegmentsCovered;
+
/** */
private final int pagesSize;
@@ -3903,6 +3907,13 @@ public class GridCacheDatabaseSharedManager extends IgniteCacheDatabaseSharedMan
public void walFilesDeleted(int walFilesDeleted) {
this.walFilesDeleted = walFilesDeleted;
}
+
+ /**
+ * @param walSegmentsCovered WAL segments fully covered by this checkpoint.
+ */
+ public void walSegmentsCovered(final List<Long> walSegmentsCovered) {
+ this.walSegmentsCovered = walSegmentsCovered;
+ }
}
/**
http://git-wip-us.apache.org/repos/asf/ignite/blob/a727a4c7/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/checkpoint/CheckpointHistory.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/checkpoint/CheckpointHistory.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/checkpoint/CheckpointHistory.java
index d6cc297..cef2093 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/checkpoint/CheckpointHistory.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/checkpoint/CheckpointHistory.java
@@ -193,13 +193,39 @@ public class CheckpointHistory {
}
/**
- * Clears checkpoint history after checkpoint finish.
+ * Logs and clears checkpoint history after checkpoint finish.
*
* @return List of checkpoints removed from history.
*/
public List<CheckpointEntry> onCheckpointFinished(GridCacheDatabaseSharedManager.Checkpoint chp, boolean truncateWal) {
List<CheckpointEntry> removed = new ArrayList<>();
+ final Map.Entry<Long, CheckpointEntry> lastEntry = histMap.lastEntry();
+
+ assert lastEntry != null;
+
+ final Map.Entry<Long, CheckpointEntry> previousEntry = histMap.lowerEntry(lastEntry.getKey());
+
+ final WALPointer lastWALPointer = lastEntry.getValue().checkpointMark();
+
+ long lastIdx = 0;
+
+ long prevIdx = 0;
+
+ final ArrayList<Long> walSegmentsCovered = new ArrayList<>();
+
+ if (lastWALPointer instanceof FileWALPointer) {
+ lastIdx = ((FileWALPointer)lastWALPointer).index();
+
+ if (previousEntry != null)
+ prevIdx = ((FileWALPointer)previousEntry.getValue().checkpointMark()).index();
+ }
+
+ for (long walCovered = prevIdx; walCovered < lastIdx; walCovered++)
+ walSegmentsCovered.add(walCovered);
+
+ chp.walSegmentsCovered(walSegmentsCovered);
+
int deleted = 0;
while (histMap.size() > maxCpHistMemSize) {
http://git-wip-us.apache.org/repos/asf/ignite/blob/a727a4c7/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FileWriteAheadLogManager.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FileWriteAheadLogManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FileWriteAheadLogManager.java
index 3e06e15..457a59c 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FileWriteAheadLogManager.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FileWriteAheadLogManager.java
@@ -744,8 +744,8 @@ public class FileWriteAheadLogManager extends GridCacheSharedManagerAdapter impl
currWrHandle = rollOver(currWrHandle);
- if (log != null && log.isDebugEnabled())
- log.debug("Rollover segment [" + idx + " to " + currWrHandle.idx + "], recordType=" + rec.type());
+ if (log != null && log.isInfoEnabled())
+ log.info("Rollover segment [" + idx + " to " + currWrHandle.idx + "], recordType=" + rec.type());
}
WALPointer ptr = currWrHandle.addRecord(rec);
@@ -1813,8 +1813,8 @@ public class FileWriteAheadLogManager extends GridCacheSharedManagerAdapter impl
File dstFile = new File(walArchiveDir, name);
- if (log.isDebugEnabled())
- log.debug("Starting to copy WAL segment [absIdx=" + absIdx + ", segIdx=" + segIdx +
+ if (log.isInfoEnabled())
+ log.info("Starting to copy WAL segment [absIdx=" + absIdx + ", segIdx=" + segIdx +
", origFile=" + origFile.getAbsolutePath() + ", dstFile=" + dstFile.getAbsolutePath() + ']');
try {
@@ -1836,8 +1836,8 @@ public class FileWriteAheadLogManager extends GridCacheSharedManagerAdapter impl
", dstFile=" + dstTmpFile.getAbsolutePath() + ']', e);
}
- if (log.isDebugEnabled())
- log.debug("Copied file [src=" + origFile.getAbsolutePath() +
+ if (log.isInfoEnabled())
+ log.info("Copied file [src=" + origFile.getAbsolutePath() +
", dst=" + dstFile.getAbsolutePath() + ']');
return new SegmentArchiveResult(absIdx, origFile, dstFile);
http://git-wip-us.apache.org/repos/asf/ignite/blob/a727a4c7/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FsyncModeFileWriteAheadLogManager.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FsyncModeFileWriteAheadLogManager.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FsyncModeFileWriteAheadLogManager.java
index 45cb1a7..a75dd31 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FsyncModeFileWriteAheadLogManager.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/cache/persistence/wal/FsyncModeFileWriteAheadLogManager.java
@@ -1642,8 +1642,8 @@ public class FsyncModeFileWriteAheadLogManager extends GridCacheSharedManagerAda
File dstFile = new File(walArchiveDir, name);
- if (log.isDebugEnabled())
- log.debug("Starting to copy WAL segment [absIdx=" + absIdx + ", segIdx=" + segIdx +
+ if (log.isInfoEnabled())
+ log.info("Starting to copy WAL segment [absIdx=" + absIdx + ", segIdx=" + segIdx +
", origFile=" + origFile.getAbsolutePath() + ", dstFile=" + dstFile.getAbsolutePath() + ']');
try {
@@ -1665,8 +1665,8 @@ public class FsyncModeFileWriteAheadLogManager extends GridCacheSharedManagerAda
", dstFile=" + dstTmpFile.getAbsolutePath() + ']', e);
}
- if (log.isDebugEnabled())
- log.debug("Copied file [src=" + origFile.getAbsolutePath() +
+ if (log.isInfoEnabled())
+ log.info("Copied file [src=" + origFile.getAbsolutePath() +
", dst=" + dstFile.getAbsolutePath() + ']');
return new SegmentArchiveResult(absIdx, origFile, dstFile);
http://git-wip-us.apache.org/repos/asf/ignite/blob/a727a4c7/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/persistence/db/checkpoint/IgniteMassLoadSandboxTest.java
----------------------------------------------------------------------
diff --git a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/persistence/db/checkpoint/IgniteMassLoadSandboxTest.java b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/persistence/db/checkpoint/IgniteMassLoadSandboxTest.java
index 76cd5bd..7fb277c 100644
--- a/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/persistence/db/checkpoint/IgniteMassLoadSandboxTest.java
+++ b/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/persistence/db/checkpoint/IgniteMassLoadSandboxTest.java
@@ -19,6 +19,7 @@ package org.apache.ignite.internal.processors.cache.persistence.db.checkpoint;
import java.io.File;
import java.util.ArrayList;
+import java.util.Arrays;
import java.util.Collection;
import java.util.Map;
import java.util.Random;
@@ -29,6 +30,8 @@ import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
import javax.cache.Cache;
import junit.framework.TestCase;
import org.apache.ignite.Ignite;
@@ -47,9 +50,11 @@ import org.apache.ignite.configuration.IgniteConfiguration;
import org.apache.ignite.configuration.WALMode;
import org.apache.ignite.internal.IgniteEx;
import org.apache.ignite.internal.processors.cache.persistence.wal.FileWriteAheadLogManager;
+import org.apache.ignite.internal.util.typedef.G;
import org.apache.ignite.internal.util.typedef.X;
import org.apache.ignite.internal.util.typedef.internal.S;
import org.apache.ignite.internal.util.typedef.internal.U;
+import org.apache.ignite.testframework.GridStringLogger;
import org.apache.ignite.testframework.GridTestUtils;
import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest;
@@ -165,6 +170,7 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
/**
* Runs multithreaded put scenario (no data streamer). Load is generated to page store and to WAL.
+ *
* @throws Exception if failed.
*/
public void testContinuousPutMultithreaded() throws Exception {
@@ -224,6 +230,7 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
/**
* Runs multithreaded put scenario (no data streamer). Load is generated to page store and to WAL.
+ *
* @throws Exception if failed.
*/
public void testDataStreamerContinuousPutMultithreaded() throws Exception {
@@ -234,7 +241,6 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
System.setProperty(IgniteSystemProperties.IGNITE_OVERRIDE_WRITE_THROTTLING_ENABLED, "speed");
System.setProperty(IgniteSystemProperties.IGNITE_DELAYED_REPLACED_PAGE_WRITE, "true");
-
setWalArchAndWorkToSameVal = true;
customWalMode = WALMode.BACKGROUND;
@@ -243,7 +249,8 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
ignite.active(true);
- final int threads = 1; Runtime.getRuntime().availableProcessors();
+ final int threads = 1;
+ Runtime.getRuntime().availableProcessors();
final int recsPerThread = CONTINUOUS_PUT_RECS_CNT / threads;
@@ -297,6 +304,100 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
}
}
+ /**
+ * Test that WAL segments that are fully covered by checkpoint are logged
+ *
+ * @throws Exception if failed.
+ */
+ public void testCoveredWalLogged() throws Exception {
+ GridStringLogger log0 = null;
+
+ try {
+ log0 = new GridStringLogger();
+
+ final IgniteConfiguration cfg = getConfiguration("testCoveredWalLogged");
+
+ cfg.setGridLogger(log0);
+
+ cfg.getDataStorageConfiguration().setWalAutoArchiveAfterInactivity(10);
+
+ final Ignite ignite = G.start(cfg);
+
+ ignite.cluster().active(true);
+
+ final IgniteCache<Object, Object> cache = ignite.cache(CACHE_NAME);
+
+ cache.put(1, new byte[cfg.getDataStorageConfiguration().getWalSegmentSize() - 1024]);
+
+ forceCheckpoint();
+
+ cache.put(1, new byte[cfg.getDataStorageConfiguration().getWalSegmentSize() - 1024]);
+
+ forceCheckpoint();
+
+ cache.put(1, new byte[cfg.getDataStorageConfiguration().getWalSegmentSize() - 1024]);
+
+ forceCheckpoint();
+
+ Thread.sleep(200); // needed by GridStringLogger
+
+ final String log = log0.toString();
+
+ final String lines[] = log.split("\\r?\\n");
+
+ final Pattern chPtrn = Pattern.compile("Checkpoint finished");
+
+ final Pattern idxPtrn = Pattern.compile("idx=([0-9]+),");
+
+ final Pattern covererdPtrn = Pattern.compile("walSegmentsCovered=\\[(.+)\\], ");
+
+ boolean hasCheckpoint = false;
+
+ long nextCovered = 0;
+
+ for (String line : lines) {
+ if (!chPtrn.matcher(line).find())
+ continue;
+
+ hasCheckpoint = true;
+
+ final Matcher idxMatcher = idxPtrn.matcher(line);
+
+ assertTrue(idxMatcher.find());
+
+ final long idx = Long.valueOf(idxMatcher.group(1));
+
+ final Matcher coveredMatcher = covererdPtrn.matcher(line);
+
+ if (!coveredMatcher.find()) { // no wal segments are covered by checkpoint
+ assertEquals(nextCovered, idx);
+ continue;
+ }
+
+ final String coveredMatcherGrp = coveredMatcher.group(1);
+
+ final long[] covered = coveredMatcherGrp.length() > 0 ?
+ Arrays.stream(coveredMatcherGrp.split(",")).mapToLong(e -> Integer.valueOf(e.trim())).toArray() :
+ new long[0];
+
+ assertEquals(nextCovered, covered[0]);
+
+ final long lastCovered = covered[covered.length - 1];
+
+ assertEquals(idx - 1, lastCovered); // current wal is excluded
+
+ nextCovered = lastCovered + 1;
+ }
+
+ assertTrue(hasCheckpoint);
+
+ }
+ finally {
+ System.out.println(log0 != null ? log0.toString() : "Error initializing GridStringLogger");
+
+ stopAllGrids();
+ }
+ }
/**
* Verifies data from storage.
@@ -457,14 +558,13 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
}
}
-
/** {@inheritDoc} */
@Override protected long getTestTimeout() {
return TimeUnit.MINUTES.toMillis(20);
}
/** Object with additional 40 000 bytes of payload */
- public static class HugeIndexedObject {
+ public static class HugeIndexedObject {
/** Data. */
private byte[] data;
/** */
@@ -514,4 +614,4 @@ public class IgniteMassLoadSandboxTest extends GridCommonAbstractTest {
return S.toString(HugeIndexedObject.class, this);
}
}
-}
\ No newline at end of file
+}