Details

    • Type: Sub-task Sub-task
    • Status: Resolved
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: HA branch (HDFS-1623)
    • Fix Version/s: HA branch (HDFS-1623)
    • Component/s: ha, namenode
    • Labels:
      None

      Description

      In testing I saw an AssertionError come up several times when I was trying to do failover between two NNs where one or the other was in safe-mode. Need to write some unit tests to try to trigger this – hunch is it has something to do with the treatment of "safe block count" while tailing edits in safemode.

      1. hdfs-2692.txt
        27 kB
        Todd Lipcon
      2. hdfs-2692.txt
        26 kB
        Todd Lipcon
      3. hdfs-2692.txt
        24 kB
        Todd Lipcon

        Issue Links

          Activity

          Todd Lipcon made changes -
          Link This issue is related to HDFS-2973 [ HDFS-2973 ]
          Hide
          Hudson added a comment -

          Integrated in Hadoop-Hdfs-HAbranch-build #32 (See https://builds.apache.org/job/Hadoop-Hdfs-HAbranch-build/32/)
          HDFS-2692. Fix bugs related to failover from/into safe mode. Contributed by Todd Lipcon.

          todd : http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1225709
          Files :

          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/CHANGES.HDFS-1623.txt
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/blockmanagement/BlockManager.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ha/EditLogTailer.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/MiniDFSCluster.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/ha/TestDNFencing.java
          • /hadoop/common/branches/HDFS-1623/hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/ha/TestHASafeMode.java
          Show
          Hudson added a comment - Integrated in Hadoop-Hdfs-HAbranch-build #32 (See https://builds.apache.org/job/Hadoop-Hdfs-HAbranch-build/32/ ) HDFS-2692 . Fix bugs related to failover from/into safe mode. Contributed by Todd Lipcon. todd : http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1225709 Files : /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/CHANGES. HDFS-1623 .txt /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/blockmanagement/BlockManager.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/Checkpointer.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/ha/EditLogTailer.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/MiniDFSCluster.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/ha/TestDNFencing.java /hadoop/common/branches/ HDFS-1623 /hadoop-hdfs-project/hadoop-hdfs/src/test/java/org/apache/hadoop/hdfs/server/namenode/ha/TestHASafeMode.java
          Todd Lipcon made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Hadoop Flags Reviewed [ 10343 ]
          Fix Version/s HA branch (HDFS-1623) [ 12317568 ]
          Resolution Fixed [ 1 ]
          Hide
          Todd Lipcon added a comment -

          Committed to branch, thanks for the reviews, Aaron and Eli. I filed HDFS-2730 for the test util refactor

          Show
          Todd Lipcon added a comment - Committed to branch, thanks for the reviews, Aaron and Eli. I filed HDFS-2730 for the test util refactor
          Hide
          Aaron T. Myers added a comment -

          I'd like to move a bunch of these methods into a new HATestUtil class... can I do that in a follow-up JIRA?

          Definitely. This also came up in Eli's review of HDFS-2709. Please file?

          +1, the latest patch looks good to me.

          Show
          Aaron T. Myers added a comment - I'd like to move a bunch of these methods into a new HATestUtil class... can I do that in a follow-up JIRA? Definitely. This also came up in Eli's review of HDFS-2709 . Please file? +1, the latest patch looks good to me.
          Todd Lipcon made changes -
          Attachment hdfs-2692.txt [ 12508886 ]
          Hide
          Todd Lipcon added a comment -

          In FSEditLogLoader#loadFSEdits, should we really be unconditionally calling FSNamesystem#notifyGenStampUpdate in the finally block? What if an error occurs and maxGenStamp is never updated in FSEditLogLoader#loadEditRecords

          This should be OK – we'll just call it with the argument 0, which won't cause any problem (0 is lower than any possible queued gen stamp)

          sp. "Initiatling" in TestHASafeMode#testComplexFailoverIntoSafemode

          fixed

          In FSNamesystem#notifyGenStampUpdate, could be a better log message, and the log level should probably not be info: LOG.info("=> notified of genstamp update for: " + gs);

          Fixed and changed to DEBUG level

          Why is SafeModeInfo#doConsistencyCheck costly? It doesn't seem like it should be. If it's not in fact expensive, we might as well make it run regardless of whether or not asserts are enabled

          You're right that it's not super expensive, but this code gets called on every block being reported during startup, which is a fair amount.. so I chose to maintain the current behavior, of only running the checks when asserts are enabled.

          Is there really no better way to check if assertions are enabled?

          Not that I've ever found!

          seems like they should all be made member methods and moved to MiniDFSCluster... Also seems like TestEditLogTailer#waitForStandbyToCatchUp should be moved to MiniDFSCluster.

          I'd like to move a bunch of these methods into a new HATestUtil class... can I do that in a follow-up JIRA?

          Eli said:

          Nice change and tests. Nit, I'd add a comment in TestHASafeMode#restartStandby where the safemode extension is set indicating the rationale, it looked like the asserts at the end were racy because I missed this

          Fixed

          Show
          Todd Lipcon added a comment - In FSEditLogLoader#loadFSEdits, should we really be unconditionally calling FSNamesystem#notifyGenStampUpdate in the finally block? What if an error occurs and maxGenStamp is never updated in FSEditLogLoader#loadEditRecords This should be OK – we'll just call it with the argument 0, which won't cause any problem (0 is lower than any possible queued gen stamp) sp. "Initiatling" in TestHASafeMode#testComplexFailoverIntoSafemode fixed In FSNamesystem#notifyGenStampUpdate, could be a better log message, and the log level should probably not be info: LOG.info("=> notified of genstamp update for: " + gs); Fixed and changed to DEBUG level Why is SafeModeInfo#doConsistencyCheck costly? It doesn't seem like it should be. If it's not in fact expensive, we might as well make it run regardless of whether or not asserts are enabled You're right that it's not super expensive, but this code gets called on every block being reported during startup, which is a fair amount.. so I chose to maintain the current behavior, of only running the checks when asserts are enabled. Is there really no better way to check if assertions are enabled? Not that I've ever found! seems like they should all be made member methods and moved to MiniDFSCluster... Also seems like TestEditLogTailer#waitForStandbyToCatchUp should be moved to MiniDFSCluster. I'd like to move a bunch of these methods into a new HATestUtil class... can I do that in a follow-up JIRA? Eli said: Nice change and tests. Nit, I'd add a comment in TestHASafeMode#restartStandby where the safemode extension is set indicating the rationale, it looked like the asserts at the end were racy because I missed this Fixed
          Hide
          Eli Collins added a comment -

          Nice change and tests. Nit, I'd add a comment in TestHASafeMode#restartStandby where the safemode extension is set indicating the rationale, it looked like the asserts at the end were racy because I missed this. Otherwise didn't see anything in addition to what ATM noticed.

          Show
          Eli Collins added a comment - Nice change and tests. Nit, I'd add a comment in TestHASafeMode#restartStandby where the safemode extension is set indicating the rationale, it looked like the asserts at the end were racy because I missed this. Otherwise didn't see anything in addition to what ATM noticed.
          Hide
          Aaron T. Myers added a comment -

          The patch largely looks great, Todd. Thanks a lot for figuring this out and writing such excellent tests. I also manually verified that the test scenario I described to you, and confirmed that it now works as expected with the patch applied.

          The following comments are mostly nits. Feel free to address all but the first 2 in a separate JIRA.

          1. In FSEditLogLoader#loadFSEdits, should we really be unconditionally calling FSNamesystem#notifyGenStampUpdate in the finally block? What if an error occurs and maxGenStamp is never updated in FSEditLogLoader#loadEditRecords ?
          2. sp. "Initiatling" in TestHASafeMode#testComplexFailoverIntoSafemode
          3. In FSNamesystem#notifyGenStampUpdate, could be a better log message, and the log level should probably not be info: LOG.info("=> notified of genstamp update for: " + gs);
          4. Why is SafeModeInfo#doConsistencyCheck costly? It doesn't seem like it should be. If it's not in fact expensive, we might as well make it run regardless of whether or not asserts are enabled.
          5. Is there really no better way to check if assertions are enabled?
          6. Rather than increase the visibility of TestDNFencing#(waitForTrueReplication,getTrueReplication,waitForDNDeletions,waitForNNToIssueDeletions) for use in TestHASafeMode, seems like they should all be made member methods and moved to MiniDFSCluster.
          7. Also seems like TestEditLogTailer#waitForStandbyToCatchUp should be moved to MiniDFSCluster.
          Show
          Aaron T. Myers added a comment - The patch largely looks great, Todd. Thanks a lot for figuring this out and writing such excellent tests. I also manually verified that the test scenario I described to you, and confirmed that it now works as expected with the patch applied. The following comments are mostly nits. Feel free to address all but the first 2 in a separate JIRA. In FSEditLogLoader#loadFSEdits , should we really be unconditionally calling FSNamesystem#notifyGenStampUpdate in the finally block? What if an error occurs and maxGenStamp is never updated in FSEditLogLoader#loadEditRecords ? sp. "Initiatling" in TestHASafeMode#testComplexFailoverIntoSafemode In FSNamesystem#notifyGenStampUpdate , could be a better log message, and the log level should probably not be info: LOG.info("=> notified of genstamp update for: " + gs) ; Why is SafeModeInfo#doConsistencyCheck costly? It doesn't seem like it should be. If it's not in fact expensive, we might as well make it run regardless of whether or not asserts are enabled. Is there really no better way to check if assertions are enabled? Rather than increase the visibility of TestDNFencing#(waitForTrueReplication,getTrueReplication,waitForDNDeletions,waitForNNToIssueDeletions) for use in TestHASafeMode , seems like they should all be made member methods and moved to MiniDFSCluster . Also seems like TestEditLogTailer#waitForStandbyToCatchUp should be moved to MiniDFSCluster .
          Todd Lipcon made changes -
          Attachment hdfs-2692.txt [ 12508198 ]
          Hide
          Todd Lipcon added a comment -

          Fixed patch passes those other tests

          Show
          Todd Lipcon added a comment - Fixed patch passes those other tests
          Hide
          Todd Lipcon added a comment -

          btw, this patch is on top of HDFS-2693 and HDFS-1972. It also seems to have some issues related to BackupNode and CheckpointNode tests - working through those now but the gist of it is still worth reviewing.

          Show
          Todd Lipcon added a comment - btw, this patch is on top of HDFS-2693 and HDFS-1972 . It also seems to have some issues related to BackupNode and CheckpointNode tests - working through those now but the gist of it is still worth reviewing.
          Todd Lipcon made changes -
          Field Original Value New Value
          Attachment hdfs-2692.txt [ 12508184 ]
          Hide
          Todd Lipcon added a comment -

          Attached patch fixes the issue described.

          The fix turned out to be reasonably simple: the root of the issue is that we were calling incrementSafeBlockCount after receiving edits but without calling setBlockTotal in between to update the safe mode state. So, as a fix, I delayed all of the notifyGenStampUpdate calls in FSEditLogLoader until after the edits have all been processed, and call setBlockTotal just before that.

          The only other notable code change was to remove the optimization in removeBlock that keeps the DNs from acking blocks removed due to file deletions. We should think about how important that optimization is and whether it's actually "safe" - it was breaking one of the new unit tests but it may be just fine in "real life".

          Lastly, I cleaned up the code that threw the original assertion error so that it would provide some actionable details as part of the assertion message.

          Show
          Todd Lipcon added a comment - Attached patch fixes the issue described. The fix turned out to be reasonably simple: the root of the issue is that we were calling incrementSafeBlockCount after receiving edits but without calling setBlockTotal in between to update the safe mode state. So, as a fix, I delayed all of the notifyGenStampUpdate calls in FSEditLogLoader until after the edits have all been processed, and call setBlockTotal just before that. The only other notable code change was to remove the optimization in removeBlock that keeps the DNs from acking blocks removed due to file deletions. We should think about how important that optimization is and whether it's actually "safe" - it was breaking one of the new unit tests but it may be just fine in "real life". Lastly, I cleaned up the code that threw the original assertion error so that it would provide some actionable details as part of the assertion message.
          Hide
          Todd Lipcon added a comment -

          Here's an explanation of the assertion failure - I'm able to trigger it reliably from a test now:

          • Namespace image exists with 1 block
          • Active NN has some more blocks that have been written recently in an in-progress edit log
          • NN starts up in standby mode and reads the image during the normal startup. It sets the safemode threshold to 1
          • It receives block reports, but they are delayed because the highest gen-stamp in the BR is higher than the GS from the namespace
          • Active NN rolls edit log
          • edit log tailer rolls forward edits, sees the file creations, and allows the block reports through. The block reports call incrementSafeBlocks for each of the blocks in the NS.

          This causes an assertion failure because the number of safe blocks is greater than the number of blocks indicated in SafeModeInfo during startup.

          Trying to figure out the cleanest way to deal with this issue.

          Show
          Todd Lipcon added a comment - Here's an explanation of the assertion failure - I'm able to trigger it reliably from a test now: Namespace image exists with 1 block Active NN has some more blocks that have been written recently in an in-progress edit log NN starts up in standby mode and reads the image during the normal startup. It sets the safemode threshold to 1 It receives block reports, but they are delayed because the highest gen-stamp in the BR is higher than the GS from the namespace Active NN rolls edit log edit log tailer rolls forward edits, sees the file creations, and allows the block reports through. The block reports call incrementSafeBlocks for each of the blocks in the NS. This causes an assertion failure because the number of safe blocks is greater than the number of blocks indicated in SafeModeInfo during startup. Trying to figure out the cleanest way to deal with this issue.
          Todd Lipcon created issue -

            People

            • Assignee:
              Todd Lipcon
              Reporter:
              Todd Lipcon
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development