HDFS-17815. Fix upload fsimage failure when checkpoint takes a long time (#7845). Contributed by caozhiqiang.

Reviewed-by: Tao Li <[email protected]>
Signed-off-by: Ayush Saxena <[email protected]>
Signed-off-by: He Xiaoqiao <[email protected]>

Author: lfxy

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java

@@ -7174,6 +7174,11 @@ public synchronized void verifyToken(DelegationTokenIdentifier identifier,
   public EditLogTailer getEditLogTailer() {
     return editLogTailer;
   }
+
+  @VisibleForTesting
+  public long getStandbyLastCheckpointTime() {
+    return standbyCheckpointer.getLastCheckpointTime();
+  }
 
   @VisibleForTesting
   public void setEditLogTailerForTests(EditLogTailer tailer) {

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/NNStorage.java

@@ -472,6 +472,7 @@ void writeTransactionIdFile(StorageDirectory sd, long txid)
    * @param time time of the last checkpoint, in millis since the epoch
    */
   void setMostRecentCheckpointInfo(long txid, long time) {
+    LOG.info("setMostRecentCheckpointInfo txid is {}, time is {}", txid, time);
     this.mostRecentCheckpointTxId = txid;
     this.mostRecentCheckpointTime = time;
   }
@@ -486,7 +487,7 @@ public long getMostRecentCheckpointTxId() {
   /**
    * @return the time of the most recent checkpoint in millis since the epoch.
    */
-  long getMostRecentCheckpointTime() {
+  public long getMostRecentCheckpointTime() {
     return mostRecentCheckpointTime;
   }
 

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ha/StandbyCheckpointer.java

@@ -375,6 +375,11 @@ static int getCanceledCount() {
     return canceledCount;
   }
 
+  @VisibleForTesting
+  public long getLastCheckpointTime() {
+    return lastCheckpointTime;
+  }
+
   private long countUncheckpointedTxns() {
     FSImage img = namesystem.getFSImage();
     return img.getCorrectLastAppliedOrWrittenTxId() -
@@ -461,7 +466,8 @@ private void doWork() {
           } else if (secsSinceLast >= checkpointConf.getPeriod()) {
             LOG.info("Triggering checkpoint because it has been {} seconds " +
                 "since the last checkpoint, which exceeds the configured " +
-                "interval {}", secsSinceLast, checkpointConf.getPeriod());
+                "interval {}, And now is {}, lastCheckpointTime is {}.",
+                secsSinceLast, checkpointConf.getPeriod(), now, lastCheckpointTime);
             needCheckpoint = true;
           }
 
@@ -487,8 +493,9 @@ private void doWork() {
               namesystem.setCreatedRollbackImages(true);
               namesystem.setNeedRollbackFsImage(false);
             }
-            lastCheckpointTime = now;
-            LOG.info("Checkpoint finished successfully.");
+            lastCheckpointTime = monotonicNow();
+            LOG.info("Checkpoint finished successfully, the lastCheckpointTime is:{}.",
+                lastCheckpointTime);
           }
         } catch (SaveNamespaceCancelledException ce) {
           LOG.info("Checkpoint was cancelled: {}", ce.getMessage());

hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/ha/TestStandbyCheckpoints.java

@@ -649,6 +649,52 @@ public void testCheckpointSucceedsWithLegacyOIVException() throws Exception {
     HATestUtil.waitForCheckpoint(cluster, 0, ImmutableList.of(12));
   }
 
+  /**
+   * Test that lastCheckpointTime is correctly updated at each checkpoint.
+   */
+  @Test(timeout = 300000)
+  public void testLastCheckpointTime() throws Exception {
+    for (int i = 1; i < NUM_NNS; i++) {
+      cluster.shutdownNameNode(i);
+
+      // Make true checkpoint for DFS_NAMENODE_CHECKPOINT_PERIOD_KEY
+      cluster.getConfiguration(i).setInt(DFSConfigKeys.DFS_NAMENODE_CHECKPOINT_PERIOD_KEY, 3);
+      cluster.getConfiguration(i).setInt(DFSConfigKeys.DFS_NAMENODE_CHECKPOINT_TXNS_KEY, 1000);
+    }
+    doEdits(0, 10);
+    cluster.transitionToStandby(0);
+
+    // Standby NNs do checkpoint without active NN available.
+    for (int i = 1; i < NUM_NNS; i++) {
+      cluster.restartNameNode(i, false);
+    }
+    cluster.waitClusterUp();
+    setNNs();
+
+    for (int i = 0; i < NUM_NNS; i++) {
+      // Once the standby catches up, it should do a checkpoint
+      // and save to local directories.
+      HATestUtil.waitForCheckpoint(cluster, i, ImmutableList.of(12));
+    }
+
+    long snnCheckpointTime1 = nns[1].getNamesystem().getStandbyLastCheckpointTime();
+    long annCheckpointTime1 = nns[0].getNamesystem().getLastCheckpointTime();
+    cluster.transitionToActive(0);
+    cluster.transitionToObserver(2);
+
+    doEdits(11, 20);
+    nns[0].getRpcServer().rollEditLog();
+    HATestUtil.waitForCheckpoint(cluster, 0, ImmutableList.of(23));
+
+    long snnCheckpointTime2 = nns[1].getNamesystem().getStandbyLastCheckpointTime();
+    long annCheckpointTime2 = nns[0].getNamesystem().getLastCheckpointTime();
+
+    // Make sure that both standby and active NNs' lastCheckpointTime intervals are larger
+    // than 3 DFSConfigKeys.DFS_NAMENODE_CHECKPOINT_PERIOD_KEY.
+    assertTrue(snnCheckpointTime2 - snnCheckpointTime1 >= 3000
+        && annCheckpointTime2 - annCheckpointTime1 >= 3000);
+  }
+
   private void doEdits(int start, int stop) throws IOException {
     for (int i = start; i < stop; i++) {
       Path p = new Path("/test" + i);