Namenode fails to re-start after cluster shutdown - DFSClient: Could not obtain blocks even all datanodes were up & live

• Key: HADOOP-2873
• Type: Bug
• Status: Closed
• Resolution: Fixed
• Priority: Major
• Assignee: dhruba borthakur
• Reporter: André Martin
• Affects Version/s: 0.17.0
• Fix Version/s: 0.17.0

Description

Namenode fails to re-start with the following exception:

2008-02-21 14:20:48,831 INFO org.apache.hadoop.dfs.NameNode: STARTUP_MSG:
/************************************************************
STARTUP_MSG: Starting NameNode
STARTUP_MSG: host = se09/141.76.xxx.xxx
STARTUP_MSG: args = []
STARTUP_MSG: version = 2008-02-19_11-01-48
STARTUP_MSG: build = http://svn.apache.org/repos/asf/hadoop/core/trunk -r 628999; compiled by 'hudson' on Tue Feb 19 11:09:05 UTC 2008
************************************************************/
2008-02-21 14:20:49,367 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing RPC Metrics with serverName=NameNode, port=8000
2008-02-21 14:20:49,374 INFO org.apache.hadoop.dfs.NameNode: Namenode up at: se09.inf.tu-dresden.de/141.76.xxx.xxx:8000
2008-02-21 14:20:49,378 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=NameNode, sessionId=null
2008-02-21 14:20:49,381 INFO org.apache.hadoop.dfs.NameNodeMetrics: Initializing NameNodeMeterics using context object:org.apache.hadoop.metrics.spi.NullContext
2008-02-21 14:20:49,501 INFO org.apache.hadoop.fs.FSNamesystem: fsOwner=amartin,students
2008-02-21 14:20:49,501 INFO org.apache.hadoop.fs.FSNamesystem: supergroup=supergroup
2008-02-21 14:20:49,501 INFO org.apache.hadoop.fs.FSNamesystem: isPermissionEnabled=true
2008-02-21 14:20:49,788 INFO org.apache.hadoop.ipc.Server: Stopping server on 8000
2008-02-21 14:20:49,790 ERROR org.apache.hadoop.dfs.NameNode: java.io.IOException: Created 13 leases but found 4
at org.apache.hadoop.dfs.FSImage.loadFilesUnderConstruction(FSImage.java:935)
at org.apache.hadoop.dfs.FSImage.loadFSImage(FSImage.java:749)
at org.apache.hadoop.dfs.FSImage.loadFSImage(FSImage.java:634)
at org.apache.hadoop.dfs.FSImage.recoverTransitionRead(FSImage.java:223)
at org.apache.hadoop.dfs.FSDirectory.loadFSImage(FSDirectory.java:79)
at org.apache.hadoop.dfs.FSNamesystem.initialize(FSNamesystem.java:261)
at org.apache.hadoop.dfs.FSNamesystem.<init>(FSNamesystem.java:242)
at org.apache.hadoop.dfs.NameNode.initialize(NameNode.java:131)
at org.apache.hadoop.dfs.NameNode.<init>(NameNode.java:176)
at org.apache.hadoop.dfs.NameNode.<init>(NameNode.java:162)
at org.apache.hadoop.dfs.NameNode.createNameNode(NameNode.java:851)
at org.apache.hadoop.dfs.NameNode.main(NameNode.java:860)

2008-02-21 14:20:49,791 INFO org.apache.hadoop.dfs.NameNode: SHUTDOWN_MSG:
/************************************************************
SHUTDOWN_MSG: Shutting down NameNode at se09/141.76.xxx.xxx
************************************************************/

Cluster restart was needed since the DFS client produced the following error message even all datanodes were up:

08/02/21 14:04:35 INFO fs.DFSClient: Could not obtain block blk_-4008950704646490788 from any node: java.io.IOException: No live nodes contain current block

Comments

[Raghu Angadi]

This is mostly related HADOOP-2345.

[Raghu Angadi]

FSNameSystem.saveFilesUnderConstruction() and FSImage.loadFilesUnderConstruction() don't seem to match.

FSImage.loadFilesUnderConstruction() assumes there is only one file per lease.

[Raghu Angadi]

Andre,

as a temporary hack, you can just comment out the FSImage.java:749 and your restart should work, since these are last entries read from the image file.

[dhruba borthakur]

Store the number of files under construction rather than the number of leases.

[dhruba borthakur]

Must fix for 0.17. This was a regression introduced by HADOOP-2345.

[Raghu Angadi]

Do we need to increase the layout version? And to protect the users that upgraded to current trunk, we chould change FSImage.java:914 to {{ if (version >= -12) ... }}

[Konstantin Shvachko]

The layout version was increased by HADOOP-2345.
I think it should be promoted to 0.16.1. People will complain all the time.

[Konstantin Shvachko]

Sorry, it is was committed in 0.17, so the bug does not exist in 0.16.
I guess I wanted to say it should be fixed asap.

[dhruba borthakur]

Unit test. Bump layout version.

[Raghu Angadi]

There is a tmp log left in the patch. other than that,

+1. It fixes the above problem.

[dhruba borthakur]

Removed debug log message.

[dhruba borthakur]

I am going to commit this patch because it fixes a very serious problem with the Namenode transaction log. I have waited for 3 days for the HadoopQA tests to run, but is has not run yet. I think it is better to check in this fix sooner rather than wait for Hadoop QA to run.

[dhruba borthakur]

merged with latest trunk

[dhruba borthakur]

I just committed this.

[Hudson]

Integrated in Hadoop-trunk #412 (See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/412/)

[Robert Chansler]

Noted as incompatible in changes.txt