hadoop-hdfs-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "ramkrishna.s.vasudevan (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HDFS-1951) Null pointer exception comes when Namenode recovery happens and there is no response from client to NN more than the hardlimit for NN recovery and the current block is more than the prev block size in NN
Date Sat, 21 May 2011 04:46:47 GMT

    [ https://issues.apache.org/jira/browse/HDFS-1951?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13037263#comment-13037263
] 

ramkrishna.s.vasudevan commented on HDFS-1951:
----------------------------------------------

Pls find the logs after reproducing the same.

Here my block size is 1024Bytes.



11/05/20 21:38:35 INFO http.HttpServer: Jetty bound to port 50070
11/05/20 21:38:35 INFO mortbay.log: jetty-6.1.14
11/05/20 21:38:37 INFO mortbay.log: Started SelectChannelConnector@linux76:50070
11/05/20 21:38:37 INFO namenode.NameNode: Web-server up at: linux76:50070
11/05/20 21:38:37 INFO ipc.Server: IPC Server Responder: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server listener on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 0 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 1 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 2 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 3 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 4 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 5 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 6 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 7 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 8 on 9000: starting
11/05/20 21:38:37 INFO ipc.Server: IPC Server handler 9 on 9000: starting
11/05/20 21:38:38 INFO hdfs.StateChange: BLOCK* NameSystem.registerDatanode: node registration
from 10.18.52.76:50010 storage DS-1868335495-10.18.52.76-50010-1305907718956
11/05/20 21:38:38 INFO net.NetworkTopology: Adding a new node: /default-rack/10.18.52.76:50010
11/05/20 21:38:41 INFO hdfs.StateChange: BLOCK* NameSystem.registerDatanode: node registration
from 10.18.52.5:50010 storage DS-721814011-10.18.52.5-50010-1305928120116
11/05/20 21:38:41 INFO net.NetworkTopology: Adding a new node: /default-rack/10.18.52.5:50010
11/05/20 21:38:54 INFO FSNamesystem.audit: ugi=R00902313,Tardis	ip=/10.18.47.133	cmd=create
src=/synctest0	dst=null	perm=R00902313:supergroup:rw-r--r--
11/05/20 21:38:54 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /synctest0. blk_-8455334393673385140_1001
11/05/20 21:38:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated:
10.18.52.5:50010 is added to blk_-8455334393673385140_1001 size 1024
11/05/20 21:38:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated:
10.18.52.76:50010 is added to blk_-8455334393673385140_1001 size 1024
11/05/20 21:38:55 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /synctest0. blk_8955752156241965528_1001
11/05/20 21:38:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated:
10.18.52.76:50010 is added to blk_8955752156241965528_1001 size 1024
11/05/20 21:38:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated:
10.18.52.5:50010 is added to blk_8955752156241965528_1001 size 1024
11/05/20 21:39:11 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /synctest0. blk_-5249191180607448701_1001
11/05/20 21:40:18 INFO namenode.FSNamesystem: commitBlockSynchronization(lastblock=blk_-5249191180607448701_1001,
newgenerationstamp=1002, newlength=833, newtargets=[10.18.52.76:50010], closeFile=false, deleteBlock=false)
11/05/20 21:40:18 INFO namenode.FSNamesystem: Number of transactions: 4 Total time for transactions(ms):
2Number of transactions batched in Syncs: 0 Number of syncs: 1 SyncTimes(ms): 28 
11/05/20 21:40:18 INFO namenode.FSNamesystem: commitBlockSynchronization(blk_-5249191180607448701_1002)
successful
11/05/20 21:41:41 INFO namenode.LeaseManager: Lease [Lease.  Holder: DFSClient_-676883980,
pendingcreates: 1] has expired hard limit
11/05/20 21:41:56 INFO namenode.FSNamesystem: Recovering lease=[Lease.  Holder: DFSClient_-676883980,
pendingcreates: 1], src=/synctest0
11/05/20 21:41:56 INFO hdfs.StateChange: BLOCK* blk_-5249191180607448701_1002 recovery started,
primary=10.18.52.76:50010
11/05/20 21:42:09 INFO namenode.FSNamesystem: commitBlockSynchronization(lastblock=blk_-5249191180607448701_1002,
newgenerationstamp=1003, newlength=867, newtargets=[10.18.52.76:50010], closeFile=true, deleteBlock=false)
11/05/20 21:42:26 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: addStoredBlock
request received for blk_-5249191180607448701_1003 on 10.18.52.76:50010 size 867 and it belongs
to a file under construction. 
11/05/20 21:42:52 WARN namenode.FSNamesystem: Inconsistent size for block blk_-5249191180607448701_1003
reported from 10.18.52.76:50010 current size is 833 reported size is 867
11/05/20 21:43:11 WARN namenode.FSNamesystem: Block blk_-5249191180607448701_1003 reported
from 10.18.52.76:50010 does not exist in blockMap. Surprise! Surprise!
11/05/20 21:43:13 INFO hdfs.StateChange: Removing lease on  file /synctest0 from client NN_Recovery
11/05/20 21:43:13 INFO hdfs.StateChange: BLOCK* ask 10.18.52.76:50010 to replicate blk_-5249191180607448701_1003
to datanode(s) 10.18.52.5:50010
11/05/20 21:43:13 INFO namenode.FSNamesystem: Number of transactions: 6 Total time for transactions(ms):
2Number of transactions batched in Syncs: 0 Number of syncs: 2 SyncTimes(ms): 30 
11/05/20 21:43:13 INFO namenode.FSNamesystem: commitBlockSynchronization(newblock=blk_-5249191180607448701_1003,
file=/synctest0, newgenerationstamp=1003, newlength=867, newtargets=[10.18.52.76:50010]) successful
11/05/20 21:43:15 INFO ipc.Server: IPC Server handler 6 on 9000, call blockReceived(DatanodeRegistration(10.18.52.76:50010,
storageID=DS-1868335495-10.18.52.76-50010-1305907718956, infoPort=50075, ipcPort=50020), [Lorg.apache.hadoop.hdfs.protocol.Block;@9b774e,
[Ljava.lang.String;@b5d05b) from 10.18.52.76:40343: error: java.io.IOException: java.lang.NullPointerException
java.io.IOException: java.lang.NullPointerException
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.addStoredBlock(FSNamesystem.java:3173)
	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.blockReceived(FSNamesystem.java:3592)
	at org.apache.hadoop.hdfs.server.namenode.NameNode.blockReceived(NameNode.java:756)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	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:961)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:957)
	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:955)
11/05/20 21:43:19 WARN hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: Redundant addStoredBlock
request received for blk_-5249191180607448701_1003 on 10.18.52.76:50010 size 867
11/05/20 21:43:19 INFO hdfs.StateChange: BLOCK* ask 10.18.52.76:50010 to replicate blk_-5249191180607448701_1003
to datanode(s) 10.18.52.5:50010
Listening for transport dt_socket at address: 8007
11/05/20 21:43:22 INFO hdfs.StateChange: BLOCK* ask 10.18.52.76:50010 to replicate blk_-5249191180607448701_1003
to datanode(s) 10.18.52.5:50010
11/05/20 21:43:41 INFO namenode.FSNamesystem: Roll Edit Log from 10.18.52.76
11/05/20 21:43:41 INFO namenode.FSNamesystem: Number of transactions: 6 Total time for transactions(ms):
2Number of transactions batched in Syncs: 0 Number of syncs: 3 SyncTimes(ms): 30 
11/05/20 21:43:42 INFO namenode.FSNamesystem: Roll FSImage from 10.18.52.76
11/05/20 21:43:42 INFO namenode.FSNamesystem: Number of transactions: 0 Total time for transactions(ms):
0Number of transactions batched in Syncs: 0 Number of syncs: 1 SyncTimes(ms): 23 
11/05/20 21:48:34 WARN namenode.FSNamesystem: PendingReplicationMonitor timed out block blk_-5249191180607448701_1003
11/05/20 21:48:37 INFO hdfs.StateChange: BLOCK* ask 10.18.52.76:50010 to replicate blk_-5249191180607448701_1003
to datanode(s) 10.18.52.5:50010


> Null pointer exception comes when Namenode recovery happens and there is no response
from client to NN more than the hardlimit for NN recovery and the current block is more than
the prev block size in NN 
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: HDFS-1951
>                 URL: https://issues.apache.org/jira/browse/HDFS-1951
>             Project: Hadoop HDFS
>          Issue Type: Bug
>          Components: name-node
>    Affects Versions: 0.20-append
>            Reporter: ramkrishna.s.vasudevan
>             Fix For: 0.20-append
>
>
> Null pointer exception comes when Namenode recovery happens and there is no response
from client to NN more than the hardlimit for NN recovery and the current block is more than
the prev block size in NN 
> 1. Write using a client to 2 datanodes
> 2. Kill one data node and allow pipeline recovery.
> 3. write somemore data to the same block
> 4. Parallely allow the namenode recovery to happen
> Null pointer exception will come in addStoreBlock api.
>  

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message