Thank you to anyone who has already donated - your generous donations helped make three months of treatment possible.

My brother Nate continues to fight stage IV Hodgkin's lymphoma. He's just 31, with a wife and baby girl. They have no active income (since he's been unable to return to work), no insurance, and cannot afford the treatment he needs. Nate and his family need your help. Please consider a donation, every dollar helps. Thanks.

Read Nate's story Support Nate by buying an official Pastie t-shirt Hide this message

Document@2x
|
Chain_link@2x
|
Arrow_down@2x
|
Spiral_paper@2x
A A A

Ruby on Rails       Report abuse 

2009-11-12 18:12:15,405 [IPC Server handler 10 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=52600, write=TestTable/TestTable,,1258049517024/52602
2009-11-12 18:12:15,407 [IPC Server handler 13 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=52700, write=TestTable/TestTable,,1258049517024/52702
2009-11-12 18:12:15,492 [regionserver/208.76.44.140:60020.logRoller] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Roll /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049467300, entries=52741, calcsize=63761175, filesize=58592870. New hlog /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483
2009-11-12 18:12:15,494 [regionserver/208.76.44.140:60020.logRoller] DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: Found 0 hlogs to remove  out of total 1; oldest outstanding seqnum is 1 from region .META.,,1
2009-11-12 18:12:15,494 [regionserver/208.76.44.140:60020.logSyncer] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: sync
2009-11-12 18:12:15,528 [IPC Server handler 13 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=0, write=TestTable/TestTable,,1258049517024/52746
.....

2009-11-12 18:12:19,578 [IPC Server handler 15 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=60700, write=TestTable/TestTable,,1258049517024/113447
2009-11-12 18:12:19,580 [IPC Server handler 15 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=60800, write=TestTable/TestTable,,1258049517024/113547
2009-11-12 18:12:19,584 [IPC Server handler 15 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=60900, write=TestTable/TestTable,,1258049517024/113647
2009-11-12 18:12:19,586 [IPC Server handler 15 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=61000, write=TestTable/TestTable,,1258049517024/113747
2009-11-12 18:12:19,589 [IPC Server handler 15 on 60020] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: edit=61100, write=TestTable/TestTable,,1258049517024/113847
2009-11-12 18:12:19,589 [regionserver/208.76.44.140:60020.logSyncer] INFO org.apache.hadoop.hbase.regionserver.wal.HLog: sync
2009-11-12 18:12:19,755 [regionserver/208.76.44.140:60020.cacheFlusher] DEBUG org.apache.hadoop.hbase.regionserver.Store: Added hdfs://aa0-000-12.u.powerset.com:9002/hbase/TestTable/1234347014/info/2510658122309964571, entries=60760, sequenceid=60764, memsize=67.2m, filesize=60.2m to TestTable,,1258049517024
2009-11-12 18:12:19,782 [regionserver/208.76.44.140:60020.cacheFlusher] DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~67.2m for region TestTable,,1258049517024 in 3777ms, sequence id=60764, compaction requested=false
2009-11-12 18:12:19,917 [regionserver/208.76.44.140:60020.logRoller] FATAL org.apache.hadoop.hbase.regionserver.LogRoller: Log rolling failed with ioe:
java.io.IOException: java.io.IOException: Cannot complete block: block has not been COMMITTED by the client
    at org.apache.hadoop.hdfs.server.namenode.BlockInfoUnderConstruction.convertToCompleteBlock(BlockInfoUnderConstruction.java:158)
    at org.apache.hadoop.hdfs.server.namenode.BlockManager.completeBlock(BlockManager.java:288)
    at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.finalizeINodeFileUnderConstruction(FSNamesystem.java:1846)
    at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFileInternal(FSNamesystem.java:1367)
    at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFile(FSNamesystem.java:1329)
    at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:660)
    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:516)
    at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:964)
    at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:960)
    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:958)

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
    at org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
    at org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
    at org.apache.hadoop.hbase.regionserver.LogRoller.run(LogRoller.java:98)



NN file history

[stack@aa0-000-12 logs]$ grep hlog.dat.1258049535483 hadoop-stack-namenode-aa0-000-12.u.powerset.com.log 
2009-11-12 18:12:15,486 DEBUG org.apache.hadoop.hdfs.StateChange: *DIR* NameNode.create: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995 at 208.76.44.140
2009-11-12 18:12:15,487 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.startFile: src=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483, holder=DFSClient_984022995, clientMachine=208.76.44.140, createParent=true, replication=3, overwrite=true, append=false
2009-11-12 18:12:15,488 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.addFile: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 is added to the file system
2009-11-12 18:12:15,488 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.startFile: add /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 to namespace for DFSClient_984022995
2009-11-12 18:12:15,489 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit: ugi=stack,powerset,engineering  ip=/208.76.44.140       cmd=create      src=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483   dst=null        perm=stack:supergroup:rw-r--r--
2009-11-12 18:12:15,496 DEBUG org.apache.hadoop.hdfs.StateChange: *BLOCK* NameNode.addBlock: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:15,496 DEBUG org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.getAdditionalBlock: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:15,497 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.addFile: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 with blk_-6701182023950177090_1017 block is added to the in-memory file system
2009-11-12 18:12:15,497 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483. blk_-6701182023950177090_1017{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.142:51010|RBW]]}
2009-11-12 18:12:15,516 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.fsync: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:15,526 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.persistBlocks: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 with 1 blocks is persisted to the file system
2009-11-12 18:12:19,622 DEBUG org.apache.hadoop.hdfs.StateChange: *BLOCK* NameNode.addBlock: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:19,622 DEBUG org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.getAdditionalBlock: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:19,623 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.addFile: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 with blk_1566385428527738884_1018 block is added to the in-memory file system
2009-11-12 18:12:19,623 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483. blk_1566385428527738884_1018{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}
2009-11-12 18:12:19,780 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.fsync: file /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:19,780 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.persistBlocks: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 with 2 blocks is persisted to the file system
2009-11-12 18:12:19,838 DEBUG org.apache.hadoop.hdfs.StateChange: *DIR* NameNode.complete: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:19,839 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.completeFile: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 for DFSClient_984022995
2009-11-12 18:12:19,840 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 9002, call complete(/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483, DFSClient_984022995, blk_1566385428527738884_1018) from 208.76.44.140:36475: error: java.io.IOException: Cannot complete block: block has not been COMMITTED by the client
2009-11-12 18:12:29,695 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit: ugi=stack,powerset,engineering  ip=/208.76.44.139       cmd=open        src=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483   dst=null        perm=null
2009-11-12 18:12:30,989 DEBUG org.apache.hadoop.hdfs.StateChange: *DIR* Namenode.delete: src=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483, recursive=true
2009-11-12 18:12:30,990 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* NameSystem.delete: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483
2009-11-12 18:12:30,990 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.delete: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483
2009-11-12 18:12:30,990 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedDelete: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 is removed
2009-11-12 18:12:30,990 DEBUG org.apache.hadoop.hdfs.server.namenode.LeaseManager: LeaseManager.findLease: prefix=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483
2009-11-12 18:12:30,999 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* Namesystem.delete: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 is removed
2009-11-12 18:12:31,000 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit: ugi=stack,powerset,engineering  ip=/208.76.44.139       cmd=delete      src=/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483   dst=null        perm=null



NN block history


[stack@aa0-000-12 logs]$ grep blk_1566385428527738884_1018 hadoop-stack-namenode-aa0-000-12.u.powerset.com.log 
2009-11-12 18:12:19,623 DEBUG org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.addFile: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483 with blk_1566385428527738884_1018 block is added to the in-memory file system
2009-11-12 18:12:19,623 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483. blk_1566385428527738884_1018{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}
2009-11-12 18:12:19,832 DEBUG org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.blockReceived: blk_1566385428527738884_1018 is received from 208.76.44.141:51010
2009-11-12 18:12:19,832 DEBUG org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Reported block blk_1566385428527738884_1018 on 208.76.44.141:51010 size 785772 replicaState = FINALIZED
2009-11-12 18:12:19,832 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 208.76.44.141:51010 is added to blk_1566385428527738884_1018{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]} size 785772
2009-11-12 18:12:19,835 DEBUG org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.blockReceived: blk_1566385428527738884_1018 is received from 208.76.44.139:51010
2009-11-12 18:12:19,835 DEBUG org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Reported block blk_1566385428527738884_1018 on 208.76.44.139:51010 size 785772 replicaState = FINALIZED
2009-11-12 18:12:19,836 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 208.76.44.139:51010 is added to blk_1566385428527738884_1018{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]} size 785772
2009-11-12 18:12:19,836 DEBUG org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.blockReceived: blk_1566385428527738884_1018 is received from 208.76.44.140:51010
2009-11-12 18:12:19,836 DEBUG org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Reported block blk_1566385428527738884_1018 on 208.76.44.140:51010 size 785772 replicaState = FINALIZED
2009-11-12 18:12:19,836 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 208.76.44.140:51010 is added to blk_1566385428527738884_1018{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]} size 785772
2009-11-12 18:12:19,840 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 9002, call complete(/hbase/.logs/aa0-000-13.u.powerset.com,60020,1258049466956/hlog.dat.1258049535483, DFSClient_984022995, blk_1566385428527738884_1018) from 208.76.44.140:36475: error: java.io.IOException: Cannot complete block: block has not been COMMITTED by the client
2009-11-12 18:12:29,695 DEBUG org.apache.hadoop.hdfs.server.namenode.FSNamesystem: blocks = [blk_-6701182023950177090_1017{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.142:51010|RBW]]}, blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}]
2009-11-12 18:12:29,695 DEBUG org.apache.hadoop.hdfs.server.namenode.FSNamesystem: last = blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}
2009-11-12 18:12:30,990 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]} to 208.76.44.141:51010 208.76.44.139:51010 208.76.44.140:51010 
2009-11-12 18:12:33,568 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 208.76.44.140:51010 to delete  blk_-6701182023950177090_1017{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.142:51010|RBW]]} blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}
2009-11-12 18:12:33,569 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 208.76.44.139:51010 to delete  blk_-6701182023950177090_1017{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.142:51010|RBW]]} blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]} blk_7151529243582448726_1012
2009-11-12 18:12:36,578 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* ask 208.76.44.141:51010 to delete  blk_1566385428527738884_1018{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[208.76.44.140:51010|RBW], ReplicaUnderConstruction[208.76.44.139:51010|RBW], ReplicaUnderConstruction[208.76.44.141:51010|RBW]]}