Some additional log reading gave me this
Namenodes reports that
2010-02-03 15:33:35,902 INFO
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.audit:
ugi=mpodsiadlowski,devel, [some privileges]
ip=/10.0.100.50cmd=delete src=/hbase/filmContributors/1670715971
dst=null
perm=null
so no wonder that files under that dir cannot be opened after that delete
...
node 10.0.100.50 did the split
and this one is from 10.0.100.51 which has received one of the daughters.
010-02-03 15:32:37,103 INFO org.apache.hadoop.hbase.regionserver.HRegion:
region filmContributors,117416,1265207555247/314440477 available; sequence
id is 7542004
2010-02-03 15:32:37,103 DEBUG
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
requested for region filmContributors,117416,1265207555247/314440477
because: Region has references on open
2010-02-03 15:32:37,103 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: MSG_REGION_OPEN:
filmContributors,,1265207555247
2010-02-03 15:32:37,103 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Starting compaction on region filmContributors,117416,1265207555247
2010-02-03 15:32:37,104 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Opening region filmContributors,,1265207555247, encoded=1836766931
2010-02-03 15:32:37,120 DEBUG org.apache.hadoop.hbase.regionserver.Store:
Started compaction of 2 file(s), hasReferences=true, into
/hbase/filmContributors/compaction.dir/314440477, seqid=7542003
2010-02-03 15:32:37,129 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
/hbase/filmContributors/1836766931/content/3783592739034234831.1670715971,
isReference=true, sequence id=7541773, length=33390929,
majorCompaction=false
2010-02-03 15:32:37,152 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
/hbase/filmContributors/1836766931/content/6518523095287027530.1670715971,
isReference=true, sequence id=7542002, length=7890, majorCompaction=false
2010-02-03 15:32:37,165 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
/hbase/filmContributors/1836766931/description/2305635563712489918.1670715971,
isReference=true, sequence id=7542002, length=2256, majorCompaction=false
2010-02-03 15:32:37,170 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
/hbase/filmContributors/1836766931/description/6970032752270852156.1670715971,
isReference=true, sequence id=7541773, length=6664268, majorCompaction=false
2010-02-03 15:32:37,173 INFO org.apache.hadoop.hbase.regionserver.HRegion:
region filmContributors,,1265207555247/1836766931 available; sequence id is
7542003
2010-02-03 15:32:37,173 DEBUG
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction
requested for region filmContributors,,1265207555247/1836766931 because:
Region has references on open
2010-02-03 15:32:37,534 DEBUG org.apache.hadoop.hbase.regionserver.Store:
Completed compaction of content; new storefile is
hdfs://dev24:54310/hbase/filmContributors/314440477/content/1023014647016069866;
store size is 16.0m
2010-02-03 15:32:37,536 DEBUG org.apache.hadoop.hbase.regionserver.Store:
Started compaction of 2 file(s), hasReferences=true, into
/hbase/filmContributors/compaction.dir/314440477, seqid=7542003
2010-02-03 15:32:37,702 WARN org.apache.hadoop.hdfs.DFSClient: DataStreamer
Exception: org.apache.hadoop.ipc.RemoteException:
org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException: No lease on
/hbase/filmContributors/compaction.dir/314440477/1881570653429093583 File
does not exist. [Lease. Holder: DFSClient_-902184734, pendingcreates: 1]
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1328)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1319)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1247)
at
org.apache.hadoop.hdfs.server.namenode.NameNode.addBlock(NameNode.java:422)
at sun.reflect.GeneratedMethodAccessor36.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)
at org.apache.hadoop.ipc.Client.call(Client.java:739)
at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
at $Proxy1.addBlock(Unknown Source)
at sun.reflect.GeneratedMethodAccessor13.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
at
org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
at $Proxy1.addBlock(Unknown Source)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.locateFollowingBlock(DFSClient.java:2906)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:2788)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2000(DFSClient.java:2078)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2264)
2010-02-03 15:32:37,710 WARN org.apache.hadoop.hdfs.DFSClient: Error
Recovery for block null bad datanode[0] nodes == null
2010-02-03 15:32:37,710 WARN org.apache.hadoop.hdfs.DFSClient: Could not get
block locations. Source file
"/hbase/filmContributors/compaction.dir/314440477/1881570653429093583" -
Aborting...
2010-02-03 15:32:37,714 ERROR
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction/Split
failed for region filmContributors,117416,1265207555247
org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException:
org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException: No lease on
/hbase/filmContributors/compaction.dir/314440477/1881570653429093583 File
does not exist. [Lease. Holder: DFSClient_-902184734, pendingcreates: 1]
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1328)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1319)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1247)
at
org.apache.hadoop.hdfs.server.namenode.NameNode.addBlock(NameNode.java:422)
at sun.reflect.GeneratedMethodAccessor36.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)
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.CompactSplitThread.run(CompactSplitThread.java:104)
2010-02-03 15:32:37,716 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Starting compaction on region filmContributors,,1265207555247
2010-02-03 15:32:37,721 DEBUG org.apache.hadoop.hbase.regionserver.Store:
Started compaction of 2 file(s), hasReferences=true, into
/hbase/filmContributors/compaction.dir/1836766931, seqid=7542002
2010-02-03 15:32:38,423 ERROR
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction/Split
failed for region filmContributors,,1265207555247
java.io.IOException: java.io.IOException: Could not complete write to file
/hbase/filmContributors/compaction.dir/1836766931/2633146516707160051 by
DFSClient_-902184734
at
org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
at sun.reflect.GeneratedMethodAccessor37.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)
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.CompactSplitThread.run(CompactSplitThread.java:104)
2010-02-03 15:33:11,377 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
Total=155.32718MB (162872360), Free=43.39782MB (45505912), Max=198.725MB
(208378272), Counts: Blocks=2476, Access=913032, Hit=879316, Miss=33716,
Evictions=5, Evicted=1593, Ratios: Hit Ratio=96.30724787712097%, Miss
Ratio=3.692751005291939%, Evicted/Run=318.6000061035156
2010-02-03 15:33:35,259 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
started. Attempting to free 20852664 bytes
2010-02-03 15:33:35,261 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
completed. Freed 20880024 bytes. Priority Sizes: Single=48.23633MB
(50579456), Multi=119.76179MB (125579336),Memory=0.0MB (0)
2010-02-03 15:33:43,871 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
started. Attempting to free 20878368 bytes
2010-02-03 15:33:43,875 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
completed. Freed 20925368 bytes. Priority Sizes: Single=46.1288MB
(48369552), Multi=121.95667MB (127880840),Memory=0.0MB (0)
2010-02-03 15:33:43,937 INFO org.apache.hadoop.hdfs.DFSClient: Could not
obtain block blk_-2242480921702443659_12906 from any node:
java.io.IOException: No live nodes contain current block
2010-02-03 15:33:46,941 INFO org.apache.hadoop.hdfs.DFSClient: Could not
obtain block blk_-2242480921702443659_12906 from any node:
java.io.IOException: No live nodes contain current block
2010-02-03 15:33:49,943 WARN org.apache.hadoop.hdfs.DFSClient: DFS Read:
java.io.IOException: Cannot open filename
/hbase/filmContributors/1670715971/content/3783592739034234831
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.openInfo(DFSClient.java:1474)
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.chooseDataNode(DFSClient.java:1800)
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.blockSeekTo(DFSClient.java:1616)
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.read(DFSClient.java:1743)
at java.io.DataInputStream.read(DataInputStream.java:132)
and on and on pukes with
2010-02-03 15:34:01,959 ERROR
org.apache.hadoop.hbase.regionserver.HRegionServer:
java.io.IOException: Cannot open filename
/hbase/filmContributors/1670715971/content/3783592739034234831
Thanks,
Michal
