Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Blocker Blocker
    • Resolution: Fixed
    • Affects Version/s: 0.18.0
    • Fix Version/s: 0.18.4
    • Component/s: None
    • Labels:
      None

      Description

      A write pipeline recovery fails on the error below:
      INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 53006, call recoverBlock(blk_1415000632081498137_954380, false, [Lorg.apache.hadoop.hdfs.protocol.DatanodeInfo;
      @4ec82dc6) from XX: error: org.apache.hadoop.ipc.RemoteException: java.io.IOException: blk_1415000632081498137_954380 is already commited, storedBlock == null.
      at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.nextGenerationStampForBlock(FSNamesystem.java:4487)
      at org.apache.hadoop.hdfs.server.namenode.NameNode.nextGenerationStamp(NameNode.java:473)
      at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
      at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
      at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
      at java.security.AccessController.doPrivileged(Native Method)
      at javax.security.auth.Subject.doAs(Subject.java:396)
      at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)

        Issue Links

          Activity

          Owen O'Malley made changes -
          Component/s dfs [ 12310710 ]
          Sameer Paranjpye made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          Sameer Paranjpye added a comment -

          Resolved by HADOOP-3998

          Show
          Sameer Paranjpye added a comment - Resolved by HADOOP-3998
          Sameer Paranjpye made changes -
          Assignee dhruba borthakur [ dhruba ]
          Robert Chansler made changes -
          Priority Major [ 3 ] Blocker [ 1 ]
          Hide
          Hairong Kuang added a comment -

          Nicholas is right. So there is no worry about deadlock. But it is still better that NN chooses the same primary datanode as the client because it is easier to detect concurrent pipeline recovery on the same block.

          Show
          Hairong Kuang added a comment - Nicholas is right. So there is no worry about deadlock. But it is still better that NN chooses the same primary datanode as the client because it is easier to detect concurrent pipeline recovery on the same block.
          dhruba borthakur made changes -
          Field Original Value New Value
          Link This issue is related to HADOOP-3998 [ HADOOP-3998 ]
          Hide
          Tsz Wo Nicholas Sze added a comment -

          > One side issue... DFSClient and NameNode used a different node as a primary datanode for pipeline recovery of the same block. That was why I did not see NameNode-initiated pipeline recovery at first. Will this cause the deadlock reported HADOOP-3673?

          One of the necessary conditions for a deadlock is hold-and-wait. In NameNode initiated recovery, NameNode use the so called reverse-heartbeat to send the recovery command, which does not hold Datanode RPC thread. The hold-and-wait condition cannot be satisfied.

          Show
          Tsz Wo Nicholas Sze added a comment - > One side issue... DFSClient and NameNode used a different node as a primary datanode for pipeline recovery of the same block. That was why I did not see NameNode-initiated pipeline recovery at first. Will this cause the deadlock reported HADOOP-3673 ? One of the necessary conditions for a deadlock is hold-and-wait. In NameNode initiated recovery, NameNode use the so called reverse-heartbeat to send the recovery command, which does not hold Datanode RPC thread. The hold-and-wait condition cannot be satisfied.
          Hide
          Hairong Kuang added a comment -

          One side issue... DFSClient and NameNode used a different node as a primary datanode for pipeline recovery of the same block. That was why I did not see NameNode-initiated pipeline recovery at first. Will this cause the deadlock reported HADOOP-3673?

          Show
          Hairong Kuang added a comment - One side issue... DFSClient and NameNode used a different node as a primary datanode for pipeline recovery of the same block. That was why I did not see NameNode-initiated pipeline recovery at first. Will this cause the deadlock reported HADOOP-3673 ?
          Hide
          dhruba borthakur added a comment -

          Ok, that scenario sounds good. I will post a patch to make the client terminate its forever-loop (as part of HADOOP-3998)

          Show
          dhruba borthakur added a comment - Ok, that scenario sounds good. I will post a patch to make the client terminate its forever-loop (as part of HADOOP-3998 )
          Hide
          Tsz Wo Nicholas Sze added a comment -

          It seems that the DFSClient somehow lost contact to the NameNode for at least an hour so that the lease expired and the NameNode started a lease recovery.

          Show
          Tsz Wo Nicholas Sze added a comment - It seems that the DFSClient somehow lost contact to the NameNode for at least an hour so that the lease expired and the NameNode started a lease recovery.
          Hide
          Hairong Kuang added a comment -

          After I read the NameNode log, I realized that my conclusion in the previous comment was wrong. It turned out both NameNode and DFSClient initiated the pipeline recovery. NameNode started earlier and the pipeline recovery succeeded. The log shown above was from the NN initiated pipeline recovery. As a result, the block's generation stamp were bumped up in datanodes and in NN's memory. When DFSClient initiated the pipeline recovery, it still used the old generation stamp so the recovery failed with the stack trace shown in the description. But DFSClient kept on trying forever.

          Show
          Hairong Kuang added a comment - After I read the NameNode log, I realized that my conclusion in the previous comment was wrong. It turned out both NameNode and DFSClient initiated the pipeline recovery. NameNode started earlier and the pipeline recovery succeeded. The log shown above was from the NN initiated pipeline recovery. As a result, the block's generation stamp were bumped up in datanodes and in NN's memory. When DFSClient initiated the pipeline recovery, it still used the old generation stamp so the recovery failed with the stack trace shown in the description. But DFSClient kept on trying forever.
          Hide
          Hairong Kuang added a comment -

          Here is more information regarding this failure. The log came from the same primary datanode:
          org.apache.hadoop.hdfs.server.datanode.DataNode: oldblock=blk_1415000632081498137_954380(length=31016448), newblock=blk_1415000632081498137_989001(length=31016448), datanode=XX
          org.apache.hadoop.hdfs.server.datanode.DataNode: Received block blk_1415000632081498137_989001 of size 31016448 as part of lease recovery.

          It looks that pipeline recovery succeeded at the primary datanode. The new generation stamp is 989001. But the client saw this recovery as a failure and used the old generation stamp 954380 to recover the error:
          WARN org.apache.hadoop.hdfs.DFSClient: Error Recovery for block blk_1415000632081498137_954380 failed because recovery from primary datanode XX failed 4 times. Will retry...

          This retry went on forever.

          Show
          Hairong Kuang added a comment - Here is more information regarding this failure. The log came from the same primary datanode: org.apache.hadoop.hdfs.server.datanode.DataNode: oldblock=blk_1415000632081498137_954380(length=31016448), newblock=blk_1415000632081498137_989001(length=31016448), datanode=XX org.apache.hadoop.hdfs.server.datanode.DataNode: Received block blk_1415000632081498137_989001 of size 31016448 as part of lease recovery. It looks that pipeline recovery succeeded at the primary datanode. The new generation stamp is 989001. But the client saw this recovery as a failure and used the old generation stamp 954380 to recover the error: WARN org.apache.hadoop.hdfs.DFSClient: Error Recovery for block blk_1415000632081498137_954380 failed because recovery from primary datanode XX failed 4 times. Will retry... This retry went on forever.
          Hairong Kuang created issue -

            People

            • Assignee:
              dhruba borthakur
              Reporter:
              Hairong Kuang
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development