You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-user@hadoop.apache.org by 闫雪冰 <ya...@alibaba-inc.com> on 2007/11/16 03:08:54 UTC
答复: HBase PerformanceEvaluation failing
Are you working on FreeBSD 4.11? Did you ever succeed in doing a 'dfs -put'
operation?
I went into a very similar trouble a few days ago. In my case, I got an
"only be replicated to 0 nodes, instead of 1" msg when I tried to run the PE
program, I found that I couldn't even managed to make a 'dfs -put' which
would also give me the previous error msg, though I succeeded in doing 'dfs
-makedir'.
The reason is SecureRandom doesn't work on my FreeBSD 4.11, I finally get
two solutions:
a) Get back to hadoop-0.14.3, which will work fine with the same
configuration, or
b) Comment off the SecureRandom block like below
----------------------------------------------------------
/*
try {
rand =
SecureRandom.getInstance("SHA1PRNG").nextInt(Integer.MAX_VALUE);
} catch (NoSuchAlgorithmException e) {
LOG.warn("Could not use SecureRandom");
rand = (new Random()).nextInt(Integer.MAX_VALUE);
}
*/
rand = (new Random()).nextInt(Integer.MAX_VALUE);
----------------------------------------------------------
May it help.
-Xuebing Yan
-----邮件原件-----
发件人: Kareem Dana [mailto:kareem.dana@gmail.com]
发送时间: 2007年11月16日 9:32
收件人: hadoop-user@lucene.apache.org
主题: Re: HBase PerformanceEvaluation failing
My DFS appears healthy. After the PE fails, the datanodes are still
running but all the HRegionServers have exited. My initial concern is
free harddrive space or memory. Each node has ~1.5GB free space for
DFS and 400MB ram/256mb swap. Is this enough for the PE? I tried
monitoring the free space as the PE ran and it never completely filled
up but it is kind of tight.
On Nov 15, 2007 8:01 PM, stack <st...@duboce.net> wrote:
> Your DFS is healthy? This seems odd: "File
>
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/datacould
> only be replicated to 0 nodes, instead of 1;" In my experience, IIRC,
> it means no datanodes running.
>
> (I just tried the PE from TRUNK and it ran to completion).
>
> St.Ack
>
>
> Kareem Dana wrote:
> > I'm trying to run the HBase PerformanceEvaluation program on a cluster
> > of 5 hadoop nodes (on virtual machines).
> >
> > hadoop07 is a DFS Master and HBase master
> > hadoop08-12 are HBase region servers
> >
> > I start the test as follows:
> >
> > $ bin/hadoop jar
> > ${HADOOP_HOME}build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> > sequentialWrite 2
> >
> > This starts the sequentialWrite test with 2 clients. After about 25
> > minutes the map tasks are about 25% complete and reduce at 6% the test
> > fails with the following error:
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.TaskInProgress:
> > TaskInProgress tip_200711151626_0001_m_000002 has failed 1 times.
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.JobInProgress:
> > Aborting job job_200711151626_0001
> > 2007-11-15 17:06:35,101 INFO org.apache.hadoop.mapred.TaskInProgress:
> > Error from task_200711151626_0001_m_000006_0:
> > org.apache.hadoop.hbase.NoServerForRegionException: failed to find
> > server for TestTable after 5 retries
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.scanOneMetaRegion(HC
onnectionManager.java:761)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.findServersForTable(
HConnectionManager.java:521)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.reloadTableServers(H
ConnectionManager.java:317)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:671)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:636)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(Pe
rformanceEvaluation.java:493)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluatio
n.java:356)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvalua
tion.java:529)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(Performa
nceEvaluation.java:184)
> > at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
> > at org.apache.hadoop.mapred.MapTask.run(MapTask.java:192)
> > at
org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:1760)
> >
> >
> > An HBase region server log shows these errors:
> > 2007-11-15 17:03:00,017 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,2102165,6843477525281170954
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,615 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,3147654,8929124532081908894
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,3147654,8929124532081908894/info/map
files/3451857497397493742/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,639 ERROR org.apache.hadoop.hbase.HRegionServer:
> > Close and delete failed
> > java.io.IOException: java.io.IOException: File
> >
/tmp/hadoop-kcd/hbase/log_172.16.6.57_-3889232888673408171_60020/hlog.dat.00
5
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
> > at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
sorImpl.java:39)
> > at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
torAccessorImpl.java:27)
> > at
java.lang.reflect.Constructor.newInstance(Constructor.java:494)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteE
xceptionHandler.java:82)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExcept
ionHandler.java:48)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:597)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,640 INFO org.apache.hadoop.hbase.HRegionServer:
> > telling master that region server is shutting down at:
> > 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > stopping server at: 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > regionserver/0.0.0.0:60020 exiting
> >
> > I can provide some more logs if necessary. Any ideas or suggestions
> > about how I track this down? Running sequentialWrite test with just 1
> > client works fine but using 2 or more causes these errors.
> >
> > Thanks for any help,
> > Kareem Dana
> >
>
>
Re: HBase PerformanceEvaluation failing
Posted by Ted Dunning <td...@veoh.com>.
This sounds like a platform issue. SecureRandom requires a real seed and on
BSD/Linux platforms, that is usually provided by /dev/random. If your
instance doesn't have access to enough sources of entropy or if some other
consumer is eating too many random bits, then /dev/random can hang.
On 11/19/07 10:30 AM, "Raghu Angadi" <ra...@yahoo-inc.com> wrote:
> Do you know if this is a known issue with JVM and a bug is filed?
>
> 闫雪冰 wrote:
...
>> I've written a little program on my box (running FreeBSD4.11-YAHOO-20070423,
>> you might be familiar with , :P) to test the call to
>> SecureRandom.getInstance("SHA1PRNG").nextInt, at which the program always
>> hung up, and there was no any exception thrown.
Re: HBase PerformanceEvaluation failing
Posted by Raghu Angadi <ra...@yahoo-inc.com>.
Do you know if this is a known issue with JVM and a bug is filed? If
this is not expected to be fixed anytime soon, we might be able to work
around.
If you can, please try some other varition of SecureRandom that works on
your platform. Otherwise we might replace it with something else. We
used SecureRandom only because we didn't want random number based on
only time as seed. We could change the seed to something else.
Raghu.
闫雪冰 wrote:
> Hi dhruba,
>
> What pointed us to SecureRandom was the stack trace in log file for
> DataNode, after the 'hadoop dfs -put' failed, my colleague York stepped in
> from there and found the problem out.
>
> I've written a little program on my box (running FreeBSD4.11-YAHOO-20070423,
> you might be familiar with , :P) to test the call to
> SecureRandom.getInstance("SHA1PRNG").nextInt, at which the program always
> hung up, and there was no any exception thrown.
>
> Xuebing
>
RE: HBase PerformanceEvaluation failing
Posted by 闫雪冰 <ya...@alibaba-inc.com>.
Hi dhruba,
What pointed us to SecureRandom was the stack trace in log file for
DataNode, after the 'hadoop dfs -put' failed, my colleague York stepped in
from there and found the problem out.
I've written a little program on my box (running FreeBSD4.11-YAHOO-20070423,
you might be familiar with , :P) to test the call to
SecureRandom.getInstance("SHA1PRNG").nextInt, at which the program always
hung up, and there was no any exception thrown.
Xuebing
-----邮件原件-----
发件人: dhruba Borthakur [mailto:dhruba@yahoo-inc.com]
发送时间: 2007年11月16日 14:05
收件人: hadoop-user@lucene.apache.org
主题: RE: HBase PerformanceEvaluation failing
Hello Xuebing Yan,
Your finding is interesting. The DataNode uses SecureRandom to generate a
random number. If the call throws a NoSuchAlgorithmException then it is
supposed to fall back to using a Random object. In your test case, did you
see this exception being generated? If not, can you pl describe the
behaviour you saw that pointed you to the reasoning that SecureRandom was
causing the problem?
Thanks a lot,
dhruba
-----Original Message-----
From: 闫雪冰 [mailto:yaxuebing@alibaba-inc.com]
Sent: Thursday, November 15, 2007 6:09 PM
To: hadoop-user@lucene.apache.org
Subject: 答复: HBase PerformanceEvaluation failing
Are you working on FreeBSD 4.11? Did you ever succeed in doing a 'dfs -put'
operation?
I went into a very similar trouble a few days ago. In my case, I got an
"only be replicated to 0 nodes, instead of 1" msg when I tried to run the PE
program, I found that I couldn't even managed to make a 'dfs -put' which
would also give me the previous error msg, though I succeeded in doing 'dfs
-makedir'.
The reason is SecureRandom doesn't work on my FreeBSD 4.11, I finally get
two solutions:
a) Get back to hadoop-0.14.3, which will work fine with the same
configuration, or
b) Comment off the SecureRandom block like below
----------------------------------------------------------
/*
try {
rand =
SecureRandom.getInstance("SHA1PRNG").nextInt(Integer.MAX_VALUE);
} catch (NoSuchAlgorithmException e) {
LOG.warn("Could not use SecureRandom");
rand = (new Random()).nextInt(Integer.MAX_VALUE);
}
*/
rand = (new Random()).nextInt(Integer.MAX_VALUE);
----------------------------------------------------------
May it help.
-Xuebing Yan
-----邮件原件-----
发件人: Kareem Dana [mailto:kareem.dana@gmail.com]
发送时间: 2007年11月16日 9:32
收件人: hadoop-user@lucene.apache.org
主题: Re: HBase PerformanceEvaluation failing
My DFS appears healthy. After the PE fails, the datanodes are still
running but all the HRegionServers have exited. My initial concern is
free harddrive space or memory. Each node has ~1.5GB free space for
DFS and 400MB ram/256mb swap. Is this enough for the PE? I tried
monitoring the free space as the PE ran and it never completely filled
up but it is kind of tight.
On Nov 15, 2007 8:01 PM, stack <st...@duboce.net> wrote:
> Your DFS is healthy? This seems odd: "File
>
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/datacould
> only be replicated to 0 nodes, instead of 1;" In my experience, IIRC,
> it means no datanodes running.
>
> (I just tried the PE from TRUNK and it ran to completion).
>
> St.Ack
>
>
> Kareem Dana wrote:
> > I'm trying to run the HBase PerformanceEvaluation program on a cluster
> > of 5 hadoop nodes (on virtual machines).
> >
> > hadoop07 is a DFS Master and HBase master
> > hadoop08-12 are HBase region servers
> >
> > I start the test as follows:
> >
> > $ bin/hadoop jar
> > ${HADOOP_HOME}build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> > sequentialWrite 2
> >
> > This starts the sequentialWrite test with 2 clients. After about 25
> > minutes the map tasks are about 25% complete and reduce at 6% the test
> > fails with the following error:
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.TaskInProgress:
> > TaskInProgress tip_200711151626_0001_m_000002 has failed 1 times.
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.JobInProgress:
> > Aborting job job_200711151626_0001
> > 2007-11-15 17:06:35,101 INFO org.apache.hadoop.mapred.TaskInProgress:
> > Error from task_200711151626_0001_m_000006_0:
> > org.apache.hadoop.hbase.NoServerForRegionException: failed to find
> > server for TestTable after 5 retries
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.scanOneMetaRegion(HC
onnectionManager.java:761)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.findServersForTable(
HConnectionManager.java:521)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.reloadTableServers(H
ConnectionManager.java:317)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:671)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:636)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(Pe
rformanceEvaluation.java:493)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluatio
n.java:356)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvalua
tion.java:529)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(Performa
nceEvaluation.java:184)
> > at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
> > at org.apache.hadoop.mapred.MapTask.run(MapTask.java:192)
> > at
org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:1760)
> >
> >
> > An HBase region server log shows these errors:
> > 2007-11-15 17:03:00,017 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,2102165,6843477525281170954
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,615 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,3147654,8929124532081908894
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,3147654,8929124532081908894/info/map
files/3451857497397493742/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,639 ERROR org.apache.hadoop.hbase.HRegionServer:
> > Close and delete failed
> > java.io.IOException: java.io.IOException: File
> >
/tmp/hadoop-kcd/hbase/log_172.16.6.57_-3889232888673408171_60020/hlog.dat.00
5
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
> > at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
sorImpl.java:39)
> > at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
torAccessorImpl.java:27)
> > at
java.lang.reflect.Constructor.newInstance(Constructor.java:494)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteE
xceptionHandler.java:82)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExcept
ionHandler.java:48)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:597)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,640 INFO org.apache.hadoop.hbase.HRegionServer:
> > telling master that region server is shutting down at:
> > 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > stopping server at: 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > regionserver/0.0.0.0:60020 exiting
> >
> > I can provide some more logs if necessary. Any ideas or suggestions
> > about how I track this down? Running sequentialWrite test with just 1
> > client works fine but using 2 or more causes these errors.
> >
> > Thanks for any help,
> > Kareem Dana
> >
>
>
RE: HBase PerformanceEvaluation failing
Posted by dhruba Borthakur <dh...@yahoo-inc.com>.
Hello Xuebing Yan,
Your finding is interesting. The DataNode uses SecureRandom to generate a random number. If the call throws a NoSuchAlgorithmException then it is supposed to fall back to using a Random object. In your test case, did you see this exception being generated? If not, can you pl describe the behaviour you saw that pointed you to the reasoning that SecureRandom was causing the problem?
Thanks a lot,
dhruba
-----Original Message-----
From: 闫雪冰 [mailto:yaxuebing@alibaba-inc.com]
Sent: Thursday, November 15, 2007 6:09 PM
To: hadoop-user@lucene.apache.org
Subject: 答复: HBase PerformanceEvaluation failing
Are you working on FreeBSD 4.11? Did you ever succeed in doing a 'dfs -put'
operation?
I went into a very similar trouble a few days ago. In my case, I got an
"only be replicated to 0 nodes, instead of 1" msg when I tried to run the PE
program, I found that I couldn't even managed to make a 'dfs -put' which
would also give me the previous error msg, though I succeeded in doing 'dfs
-makedir'.
The reason is SecureRandom doesn't work on my FreeBSD 4.11, I finally get
two solutions:
a) Get back to hadoop-0.14.3, which will work fine with the same
configuration, or
b) Comment off the SecureRandom block like below
----------------------------------------------------------
/*
try {
rand =
SecureRandom.getInstance("SHA1PRNG").nextInt(Integer.MAX_VALUE);
} catch (NoSuchAlgorithmException e) {
LOG.warn("Could not use SecureRandom");
rand = (new Random()).nextInt(Integer.MAX_VALUE);
}
*/
rand = (new Random()).nextInt(Integer.MAX_VALUE);
----------------------------------------------------------
May it help.
-Xuebing Yan
-----邮件原件-----
发件人: Kareem Dana [mailto:kareem.dana@gmail.com]
发送时间: 2007年11月16日 9:32
收件人: hadoop-user@lucene.apache.org
主题: Re: HBase PerformanceEvaluation failing
My DFS appears healthy. After the PE fails, the datanodes are still
running but all the HRegionServers have exited. My initial concern is
free harddrive space or memory. Each node has ~1.5GB free space for
DFS and 400MB ram/256mb swap. Is this enough for the PE? I tried
monitoring the free space as the PE ran and it never completely filled
up but it is kind of tight.
On Nov 15, 2007 8:01 PM, stack <st...@duboce.net> wrote:
> Your DFS is healthy? This seems odd: "File
>
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/datacould
> only be replicated to 0 nodes, instead of 1;" In my experience, IIRC,
> it means no datanodes running.
>
> (I just tried the PE from TRUNK and it ran to completion).
>
> St.Ack
>
>
> Kareem Dana wrote:
> > I'm trying to run the HBase PerformanceEvaluation program on a cluster
> > of 5 hadoop nodes (on virtual machines).
> >
> > hadoop07 is a DFS Master and HBase master
> > hadoop08-12 are HBase region servers
> >
> > I start the test as follows:
> >
> > $ bin/hadoop jar
> > ${HADOOP_HOME}build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> > sequentialWrite 2
> >
> > This starts the sequentialWrite test with 2 clients. After about 25
> > minutes the map tasks are about 25% complete and reduce at 6% the test
> > fails with the following error:
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.TaskInProgress:
> > TaskInProgress tip_200711151626_0001_m_000002 has failed 1 times.
> > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.JobInProgress:
> > Aborting job job_200711151626_0001
> > 2007-11-15 17:06:35,101 INFO org.apache.hadoop.mapred.TaskInProgress:
> > Error from task_200711151626_0001_m_000006_0:
> > org.apache.hadoop.hbase.NoServerForRegionException: failed to find
> > server for TestTable after 5 retries
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.scanOneMetaRegion(HC
onnectionManager.java:761)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.findServersForTable(
HConnectionManager.java:521)
> > at
org.apache.hadoop.hbase.HConnectionManager$TableServers.reloadTableServers(H
ConnectionManager.java:317)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:671)
> > at org.apache.hadoop.hbase.HTable.commit(HTable.java:636)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(Pe
rformanceEvaluation.java:493)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluatio
n.java:356)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvalua
tion.java:529)
> > at
org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(Performa
nceEvaluation.java:184)
> > at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
> > at org.apache.hadoop.mapred.MapTask.run(MapTask.java:192)
> > at
org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:1760)
> >
> >
> > An HBase region server log shows these errors:
> > 2007-11-15 17:03:00,017 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,2102165,6843477525281170954
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
files/6464987859396543981/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,615 ERROR org.apache.hadoop.hbase.HRegionServer:
> > error closing region TestTable,3147654,8929124532081908894
> > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > File
/tmp/hadoop-kcd/hbase/hregion_TestTable,3147654,8929124532081908894/info/map
files/3451857497397493742/data
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at
org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > at
org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,639 ERROR org.apache.hadoop.hbase.HRegionServer:
> > Close and delete failed
> > java.io.IOException: java.io.IOException: File
> >
/tmp/hadoop-kcd/hbase/log_172.16.6.57_-3889232888673408171_60020/hlog.dat.00
5
> > could only be replicated to 0 nodes, instead of 1
> > at
org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
)
> > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:585)
> > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> >
> > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
> > at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
sorImpl.java:39)
> > at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
torAccessorImpl.java:27)
> > at
java.lang.reflect.Constructor.newInstance(Constructor.java:494)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteE
xceptionHandler.java:82)
> > at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExcept
ionHandler.java:48)
> > at
org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:597)
> > at java.lang.Thread.run(Thread.java:595)
> > 2007-11-15 17:03:00,640 INFO org.apache.hadoop.hbase.HRegionServer:
> > telling master that region server is shutting down at:
> > 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > stopping server at: 172.16.6.57:60020
> > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > regionserver/0.0.0.0:60020 exiting
> >
> > I can provide some more logs if necessary. Any ideas or suggestions
> > about how I track this down? Running sequentialWrite test with just 1
> > client works fine but using 2 or more causes these errors.
> >
> > Thanks for any help,
> > Kareem Dana
> >
>
>
hbase corrupting HDFS in 0.15.0: Was -> Re: 答复: HBase PerformanceEvaluation failing
Posted by stack <st...@duboce.net>.
Odd how corruption is in key hbase files. For example, here is
complaint about the hbase -ROOT- block from namenode log:
2007-11-24 23:43:31,966 INFO org.apache.hadoop.dfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data. blk_3947372034074506449
2007-11-24 23:43:31,966 WARN org.apache.hadoop.fs.FSNamesystem: Not able to place enough replicas, still in need of 1
2007-11-24 23:43:31,966 INFO org.apache.hadoop.ipc.Server: IPC Server handler 7 on 54310, call addBlock(/tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data, DFSClient_550313675) from 172.16.6.57:37157: error: java.io.IOException: File /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data could only be replicated to 0 nodes, instead of 1
java.io.IOException: File /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data could only be replicated to 0 nodes, instead of 1
at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
It looks like your FS goes bad of a sudden and is no longer able to
allocate blocks (Nothing in /var/log/messages on any of the HDFS nodes
58 and 59?). If you run w/ DEBUG enabled, perhaps it will give a clue
as to why its going bad? Perhaps the HDFS experts from this list have
input on what could be going wrong? You might also try w/ a
replication-level > 1?
The NotServingRegionException in regionserver logs is 'normal'. They
are running fine until they run into the failure-to-replicate complaint
from the HDFS.
Thanks Kareem,
St.Ack
Kareem Dana wrote:
> I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
> mapred, and hbase.
> Ran fsck just to make sure:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....Status: HEALTHY
> Total size: 450 B
> Total blocks: 3 (avg. block size 150 B)
> Total dirs: 16
> Total files: 5
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is HEALTHY
>
> Started the PE Test:
> kcd@hadoop07:~/hadoop$ bin/hadoop jar
> /usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> sequentialWrite 2
> 07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
> TestTable, families: {info:={name: info, max versions: 3, compression:
> NONE, in memory: false, max length: 2147483647, bloom filter: none}}
> created
> 07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
> 07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
> 07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
> 07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
> 07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
> 07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
> 07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
> 07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
> 07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
> 07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
> 07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
> 07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
> 07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
> 07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
> 07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
> 07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
> 07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
> 07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
> 07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
> 07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
> 07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
> 07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
> 07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
> java.io.IOException: Job failed!
> at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
> at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
> at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
> 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:585)
> at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
>
>
> Checked DFS status again:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....
> /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
> MISSING 1 blocks of total size 0 B.
> .......
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
> MISSING 1 blocks of total size 0 B.
> ....................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
> MISSING 1 blocks of total size 0 B.
> ....................................................
> ....................................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
> MISSING 1 blocks of total size 0 B.
> ...........
> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
> MISSING 1 blocks of total size 0 B.
> .Status: CORRUPT
> Total size: 1823865158 B
> Total blocks: 174 (avg. block size 10481983 B)
> Total dirs: 180
> Total files: 164
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is CORRUPT
>
> All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
>
> The namenode log looks fine until the very end when it has a few of
> these errors:
> 2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
> NameSystem.allocateBlock:
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
> blk_-6879410450276751752
> 2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
> able to place enough replicas, still in need of 1
> 2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 1 on 54310, call
> addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
> DFSClient_-1049549396) from 172.16.6.56:56970: error:
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>
> The hbase-region servers seem to be having a lot of problems though
> according to their logs. Not quite sure what could be the cause.
>
> - Kareem
>
> On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>
>> Can you clear the logs, clean out the file system and run the test again?
>>
>> The namenode logs should tell an interesting story.
>>
>>
>>
>> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>
>>
>>> I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
>>> the PerformanceEvaluation test is corrupting it. Before I run the
>>> test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
>>> fails, the DFS is reported as corrupt. I tried to simplify my setup
>>> and run the PE again. My new config is as follows:
>>>
>>> hadoop07 - DFS Master, Mapred master, hbase master
>>> hadoop09-10 - 2 hbase region servers
>>> hadoop11-12 - 2 datanodes, task trackers
>>>
>>> mapred.map.tasks = 2
>>> mapred.reduce.tasks = 1
>>> dfs.replication = 1
>>>
>>> I ran the distributed PE in that configuration and it still failed
>>> with similar errors. The output of the hadoop fsck for this run was:
>>>
>>> ..........
>>>
>>>
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
>> :
>>
>>> MISSING 1 blocks of total size 0 B.
>>> ......................................
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
>>> iles/5263238643231358600/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/2024298319068625138/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/5071453667327337040/data:
>>> MISSING 1 blocks of total size 0 B.
>>> .........
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
>>> s/4400784113695734765/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ...................................
>>> ........................................................................
>>> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
>>> MISSING 1 blocks of total size 0 B.
>>> .Status: CORRUPT
>>> Total size: 1890454330 B
>>> Total blocks: 180 (avg. block size 10502524 B)
>>> Total dirs: 190
>>> Total files: 173
>>> Over-replicated blocks: 0 (0.0 %)
>>> Under-replicated blocks: 0 (0.0 %)
>>> Target replication factor: 1
>>> Real replication factor: 1.0
>>>
>>>
>>> The filesystem under path '/' is CORRUPT
>>>
>>>
>>> On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>>>
>>>> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>>>>
>>>> Try [hadoop fsck /]
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>>>
>>>>
>>>>> I do not have root access on the xen cluster I'm using. I will ask the
>>>>> admin to make sure the disk is working properly. Regarding the
>>>>> mismatch versions though, are you suggesting that different region
>>>>> servers might be running different versions of hbase/hadoop? They are
>>>>> all running the same code from the same shared storage. There isn't
>>>>> even another version of hadoop anywhere for the other nodes to run. I
>>>>> think I'll try dropping my cluster down to 2 nodes and working back
>>>>> up... maybe I can pin point a specific problem node. Thanks for taking
>>>>> a look at my logs.
>>>>>
>>>>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>>>>>
>>>>>> I took a quick look Kareem. As with the last time, hbase keeps having
>>>>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>>>>>> because can't write reliably to the hdfs -- a variety of reasons. You
>>>>>> then seem to restart the cluster around 17:37 or so and things seem to
>>>>>> go along fine for a while until 19:05 when again, all regionservers
>>>>>> report trouble writing the hdfs. Have you run an fsck?
>>>>>>
>>>>
>>
Re: 答复: HBase PerformanceEvaluation failing
Posted by stack <st...@duboce.net>.
dhruba Borthakur wrote:
> Hi there,
>
> The "failing to allocate a datanode for a block" already shows up as an exception in the namenode logs:
>
>
>> java.io.IOException: File
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
>> could only be replicated to 0 nodes, instead of 1
>>
>
> Do you agree that this message is sufficient?
>
>
IMO, its missing *why* the block '...could only be replicated to 0
nodes...'. Is there a shortage of some critical resource that needs
addressing? (Memory? Data nodes? Is it a timing issue?)
Thanks Dhurba,
St.Ack
> Thanks,
> dhruba
>
> -----Original Message-----
> From: stack [mailto:stack@duboce.net]
> Sent: Monday, November 26, 2007 9:21 AM
> To: hadoop-user@lucene.apache.org
> Subject: Re: 答复: HBase PerformanceEvaluation failing
>
> Thanks from jumpingin Dhruba.
>
> Should the 'failing to allocate a datanode for a block' show in the logs
> as an exception? (I don't see one). Would something show in logs if we
> were at DEBUG level?
>
> Thanks,
> St.Ack
>
>
> dhruba Borthakur wrote:
>
>> Hi Kareem,
>>
>> I think you have run into
>> http://issues.apache.org/jira/browse/HADOOP-2275
>>
>> I have a fix for this problem. You can find that fix as an attachment to the above JIRA. If you typically build your Hadoop distribution from source, can you pl apply the above patch to your source and then try out your experiment? If not, that's fine.. this fix will probably go into the next release of hadoop.
>>
>> Thanks for your help,
>> dhruba
>>
>> -----Original Message-----
>> From: Kareem Dana [mailto:kareem.dana@gmail.com]
>> Sent: Saturday, November 24, 2007 9:13 PM
>> To: hadoop-user@lucene.apache.org
>> Subject: Re: 答复: HBase PerformanceEvaluation failing
>>
>> I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
>> mapred, and hbase.
>> Ran fsck just to make sure:
>> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
>> .....Status: HEALTHY
>> Total size: 450 B
>> Total blocks: 3 (avg. block size 150 B)
>> Total dirs: 16
>> Total files: 5
>> Over-replicated blocks: 0 (0.0 %)
>> Under-replicated blocks: 0 (0.0 %)
>> Target replication factor: 1
>> Real replication factor: 1.0
>>
>>
>> The filesystem under path '/' is HEALTHY
>>
>> Started the PE Test:
>> kcd@hadoop07:~/hadoop$ bin/hadoop jar
>> /usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
>> sequentialWrite 2
>> 07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
>> TestTable, families: {info:={name: info, max versions: 3, compression:
>> NONE, in memory: false, max length: 2147483647, bloom filter: none}}
>> created
>> 07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
>> 07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
>> 07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
>> 07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
>> 07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
>> 07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
>> 07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
>> 07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
>> 07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
>> 07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
>> 07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
>> 07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
>> 07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
>> 07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
>> 07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
>> 07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
>> 07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
>> 07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
>> 07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
>> 07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
>> 07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
>> 07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
>> 07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
>> java.io.IOException: Job failed!
>> at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
>> at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
>> at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
>> at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
>> at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
>> 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:585)
>> at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
>>
>>
>> Checked DFS status again:
>> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
>> .....
>> /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
>> MISSING 1 blocks of total size 0 B.
>> .......
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
>> MISSING 1 blocks of total size 0 B.
>> ....................................
>> /tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
>> MISSING 1 blocks of total size 0 B.
>> ....................................................
>> ....................................................
>> /tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
>> MISSING 1 blocks of total size 0 B.
>> ...........
>> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
>> MISSING 1 blocks of total size 0 B.
>> .Status: CORRUPT
>> Total size: 1823865158 B
>> Total blocks: 174 (avg. block size 10481983 B)
>> Total dirs: 180
>> Total files: 164
>> Over-replicated blocks: 0 (0.0 %)
>> Under-replicated blocks: 0 (0.0 %)
>> Target replication factor: 1
>> Real replication factor: 1.0
>>
>>
>> The filesystem under path '/' is CORRUPT
>>
>> All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
>>
>> The namenode log looks fine until the very end when it has a few of
>> these errors:
>> 2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
>> NameSystem.allocateBlock:
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
>> blk_-6879410450276751752
>> 2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
>> able to place enough replicas, still in need of 1
>> 2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
>> handler 1 on 54310, call
>> addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
>> DFSClient_-1049549396) from 172.16.6.56:56970: error:
>> java.io.IOException: File
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
>> could only be replicated to 0 nodes, instead of 1
>> java.io.IOException: File
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
>> could only be replicated to 0 nodes, instead of 1
>> at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
>> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
>> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
>> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>>
>> The hbase-region servers seem to be having a lot of problems though
>> according to their logs. Not quite sure what could be the cause.
>>
>> - Kareem
>>
>> On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>>
>>
>>> Can you clear the logs, clean out the file system and run the test again?
>>>
>>> The namenode logs should tell an interesting story.
>>>
>>>
>>>
>>> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>>
>>>
>>>
>>>> I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
>>>> the PerformanceEvaluation test is corrupting it. Before I run the
>>>> test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
>>>> fails, the DFS is reported as corrupt. I tried to simplify my setup
>>>> and run the PE again. My new config is as follows:
>>>>
>>>> hadoop07 - DFS Master, Mapred master, hbase master
>>>> hadoop09-10 - 2 hbase region servers
>>>> hadoop11-12 - 2 datanodes, task trackers
>>>>
>>>> mapred.map.tasks = 2
>>>> mapred.reduce.tasks = 1
>>>> dfs.replication = 1
>>>>
>>>> I ran the distributed PE in that configuration and it still failed
>>>> with similar errors. The output of the hadoop fsck for this run was:
>>>>
>>>> ..........
>>>>
>>>>
>>>>
>>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
>>> :
>>>
>>>
>>>> MISSING 1 blocks of total size 0 B.
>>>> ......................................
>>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
>>>> iles/5263238643231358600/data:
>>>> MISSING 1 blocks of total size 0 B.
>>>> ....
>>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>>> iles/2024298319068625138/data:
>>>> MISSING 1 blocks of total size 0 B.
>>>> ....
>>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>>> iles/5071453667327337040/data:
>>>> MISSING 1 blocks of total size 0 B.
>>>> .........
>>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
>>>> s/4400784113695734765/data:
>>>> MISSING 1 blocks of total size 0 B.
>>>> ...................................
>>>> ........................................................................
>>>> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
>>>> MISSING 1 blocks of total size 0 B.
>>>> .Status: CORRUPT
>>>> Total size: 1890454330 B
>>>> Total blocks: 180 (avg. block size 10502524 B)
>>>> Total dirs: 190
>>>> Total files: 173
>>>> Over-replicated blocks: 0 (0.0 %)
>>>> Under-replicated blocks: 0 (0.0 %)
>>>> Target replication factor: 1
>>>> Real replication factor: 1.0
>>>>
>>>>
>>>> The filesystem under path '/' is CORRUPT
>>>>
>>>>
>>>> On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>>>>
>>>>
>>>>> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>>>>>
>>>>> Try [hadoop fsck /]
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>>>>
>>>>>
>>>>>
>>>>>> I do not have root access on the xen cluster I'm using. I will ask the
>>>>>> admin to make sure the disk is working properly. Regarding the
>>>>>> mismatch versions though, are you suggesting that different region
>>>>>> servers might be running different versions of hbase/hadoop? They are
>>>>>> all running the same code from the same shared storage. There isn't
>>>>>> even another version of hadoop anywhere for the other nodes to run. I
>>>>>> think I'll try dropping my cluster down to 2 nodes and working back
>>>>>> up... maybe I can pin point a specific problem node. Thanks for taking
>>>>>> a look at my logs.
>>>>>>
>>>>>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>>>>>>
>>>>>>
>>>>>>> I took a quick look Kareem. As with the last time, hbase keeps having
>>>>>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>>>>>>> because can't write reliably to the hdfs -- a variety of reasons. You
>>>>>>> then seem to restart the cluster around 17:37 or so and things seem to
>>>>>>> go along fine for a while until 19:05 when again, all regionservers
>>>>>>> report trouble writing the hdfs. Have you run an fsck?
>>>>>>>
>>>>>>>
>>>>>
>>>>>
>>>
>>>
>
>
RE: 答复: HBase PerformanceEvaluation failing
Posted by dhruba Borthakur <dh...@yahoo-inc.com>.
Hi there,
The "failing to allocate a datanode for a block" already shows up as an exception in the namenode logs:
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
Do you agree that this message is sufficient?
Thanks,
dhruba
-----Original Message-----
From: stack [mailto:stack@duboce.net]
Sent: Monday, November 26, 2007 9:21 AM
To: hadoop-user@lucene.apache.org
Subject: Re: 答复: HBase PerformanceEvaluation failing
Thanks from jumpingin Dhruba.
Should the 'failing to allocate a datanode for a block' show in the logs
as an exception? (I don't see one). Would something show in logs if we
were at DEBUG level?
Thanks,
St.Ack
dhruba Borthakur wrote:
> Hi Kareem,
>
> I think you have run into
> http://issues.apache.org/jira/browse/HADOOP-2275
>
> I have a fix for this problem. You can find that fix as an attachment to the above JIRA. If you typically build your Hadoop distribution from source, can you pl apply the above patch to your source and then try out your experiment? If not, that's fine.. this fix will probably go into the next release of hadoop.
>
> Thanks for your help,
> dhruba
>
> -----Original Message-----
> From: Kareem Dana [mailto:kareem.dana@gmail.com]
> Sent: Saturday, November 24, 2007 9:13 PM
> To: hadoop-user@lucene.apache.org
> Subject: Re: 答复: HBase PerformanceEvaluation failing
>
> I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
> mapred, and hbase.
> Ran fsck just to make sure:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....Status: HEALTHY
> Total size: 450 B
> Total blocks: 3 (avg. block size 150 B)
> Total dirs: 16
> Total files: 5
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is HEALTHY
>
> Started the PE Test:
> kcd@hadoop07:~/hadoop$ bin/hadoop jar
> /usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> sequentialWrite 2
> 07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
> TestTable, families: {info:={name: info, max versions: 3, compression:
> NONE, in memory: false, max length: 2147483647, bloom filter: none}}
> created
> 07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
> 07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
> 07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
> 07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
> 07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
> 07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
> 07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
> 07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
> 07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
> 07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
> 07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
> 07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
> 07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
> 07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
> 07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
> 07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
> 07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
> 07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
> 07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
> 07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
> 07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
> 07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
> 07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
> java.io.IOException: Job failed!
> at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
> at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
> at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
> 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:585)
> at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
>
>
> Checked DFS status again:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....
> /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
> MISSING 1 blocks of total size 0 B.
> .......
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
> MISSING 1 blocks of total size 0 B.
> ....................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
> MISSING 1 blocks of total size 0 B.
> ....................................................
> ....................................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
> MISSING 1 blocks of total size 0 B.
> ...........
> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
> MISSING 1 blocks of total size 0 B.
> .Status: CORRUPT
> Total size: 1823865158 B
> Total blocks: 174 (avg. block size 10481983 B)
> Total dirs: 180
> Total files: 164
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is CORRUPT
>
> All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
>
> The namenode log looks fine until the very end when it has a few of
> these errors:
> 2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
> NameSystem.allocateBlock:
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
> blk_-6879410450276751752
> 2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
> able to place enough replicas, still in need of 1
> 2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 1 on 54310, call
> addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
> DFSClient_-1049549396) from 172.16.6.56:56970: error:
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>
> The hbase-region servers seem to be having a lot of problems though
> according to their logs. Not quite sure what could be the cause.
>
> - Kareem
>
> On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>
>> Can you clear the logs, clean out the file system and run the test again?
>>
>> The namenode logs should tell an interesting story.
>>
>>
>>
>> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>
>>
>>> I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
>>> the PerformanceEvaluation test is corrupting it. Before I run the
>>> test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
>>> fails, the DFS is reported as corrupt. I tried to simplify my setup
>>> and run the PE again. My new config is as follows:
>>>
>>> hadoop07 - DFS Master, Mapred master, hbase master
>>> hadoop09-10 - 2 hbase region servers
>>> hadoop11-12 - 2 datanodes, task trackers
>>>
>>> mapred.map.tasks = 2
>>> mapred.reduce.tasks = 1
>>> dfs.replication = 1
>>>
>>> I ran the distributed PE in that configuration and it still failed
>>> with similar errors. The output of the hadoop fsck for this run was:
>>>
>>> ..........
>>>
>>>
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
>> :
>>
>>> MISSING 1 blocks of total size 0 B.
>>> ......................................
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
>>> iles/5263238643231358600/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/2024298319068625138/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/5071453667327337040/data:
>>> MISSING 1 blocks of total size 0 B.
>>> .........
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
>>> s/4400784113695734765/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ...................................
>>> ........................................................................
>>> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
>>> MISSING 1 blocks of total size 0 B.
>>> .Status: CORRUPT
>>> Total size: 1890454330 B
>>> Total blocks: 180 (avg. block size 10502524 B)
>>> Total dirs: 190
>>> Total files: 173
>>> Over-replicated blocks: 0 (0.0 %)
>>> Under-replicated blocks: 0 (0.0 %)
>>> Target replication factor: 1
>>> Real replication factor: 1.0
>>>
>>>
>>> The filesystem under path '/' is CORRUPT
>>>
>>>
>>> On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>>>
>>>> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>>>>
>>>> Try [hadoop fsck /]
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>>>
>>>>
>>>>> I do not have root access on the xen cluster I'm using. I will ask the
>>>>> admin to make sure the disk is working properly. Regarding the
>>>>> mismatch versions though, are you suggesting that different region
>>>>> servers might be running different versions of hbase/hadoop? They are
>>>>> all running the same code from the same shared storage. There isn't
>>>>> even another version of hadoop anywhere for the other nodes to run. I
>>>>> think I'll try dropping my cluster down to 2 nodes and working back
>>>>> up... maybe I can pin point a specific problem node. Thanks for taking
>>>>> a look at my logs.
>>>>>
>>>>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>>>>>
>>>>>> I took a quick look Kareem. As with the last time, hbase keeps having
>>>>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>>>>>> because can't write reliably to the hdfs -- a variety of reasons. You
>>>>>> then seem to restart the cluster around 17:37 or so and things seem to
>>>>>> go along fine for a while until 19:05 when again, all regionservers
>>>>>> report trouble writing the hdfs. Have you run an fsck?
>>>>>>
>>>>
>>
Re: 答复: HBase PerformanceEvaluation failing
Posted by stack <st...@duboce.net>.
Thanks from jumpingin Dhruba.
Should the 'failing to allocate a datanode for a block' show in the logs
as an exception? (I don't see one). Would something show in logs if we
were at DEBUG level?
Thanks,
St.Ack
dhruba Borthakur wrote:
> Hi Kareem,
>
> I think you have run into
> http://issues.apache.org/jira/browse/HADOOP-2275
>
> I have a fix for this problem. You can find that fix as an attachment to the above JIRA. If you typically build your Hadoop distribution from source, can you pl apply the above patch to your source and then try out your experiment? If not, that's fine.. this fix will probably go into the next release of hadoop.
>
> Thanks for your help,
> dhruba
>
> -----Original Message-----
> From: Kareem Dana [mailto:kareem.dana@gmail.com]
> Sent: Saturday, November 24, 2007 9:13 PM
> To: hadoop-user@lucene.apache.org
> Subject: Re: 答复: HBase PerformanceEvaluation failing
>
> I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
> mapred, and hbase.
> Ran fsck just to make sure:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....Status: HEALTHY
> Total size: 450 B
> Total blocks: 3 (avg. block size 150 B)
> Total dirs: 16
> Total files: 5
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is HEALTHY
>
> Started the PE Test:
> kcd@hadoop07:~/hadoop$ bin/hadoop jar
> /usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> sequentialWrite 2
> 07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
> TestTable, families: {info:={name: info, max versions: 3, compression:
> NONE, in memory: false, max length: 2147483647, bloom filter: none}}
> created
> 07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
> 07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
> 07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
> 07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
> 07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
> 07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
> 07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
> 07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
> 07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
> 07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
> 07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
> 07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
> 07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
> 07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
> 07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
> 07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
> 07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
> 07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
> 07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
> 07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
> 07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
> 07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
> 07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
> java.io.IOException: Job failed!
> at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
> at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
> at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
> at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
> 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:585)
> at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
>
>
> Checked DFS status again:
> kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
> .....
> /tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
> MISSING 1 blocks of total size 0 B.
> .......
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
> MISSING 1 blocks of total size 0 B.
> ....................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
> MISSING 1 blocks of total size 0 B.
> ....................................................
> ....................................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
> MISSING 1 blocks of total size 0 B.
> ...........
> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
> MISSING 1 blocks of total size 0 B.
> .Status: CORRUPT
> Total size: 1823865158 B
> Total blocks: 174 (avg. block size 10481983 B)
> Total dirs: 180
> Total files: 164
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is CORRUPT
>
> All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
>
> The namenode log looks fine until the very end when it has a few of
> these errors:
> 2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
> NameSystem.allocateBlock:
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
> blk_-6879410450276751752
> 2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
> able to place enough replicas, still in need of 1
> 2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 1 on 54310, call
> addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
> DFSClient_-1049549396) from 172.16.6.56:56970: error:
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> java.io.IOException: File
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
> could only be replicated to 0 nodes, instead of 1
> at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>
> The hbase-region servers seem to be having a lot of problems though
> according to their logs. Not quite sure what could be the cause.
>
> - Kareem
>
> On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>
>> Can you clear the logs, clean out the file system and run the test again?
>>
>> The namenode logs should tell an interesting story.
>>
>>
>>
>> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>
>>
>>> I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
>>> the PerformanceEvaluation test is corrupting it. Before I run the
>>> test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
>>> fails, the DFS is reported as corrupt. I tried to simplify my setup
>>> and run the PE again. My new config is as follows:
>>>
>>> hadoop07 - DFS Master, Mapred master, hbase master
>>> hadoop09-10 - 2 hbase region servers
>>> hadoop11-12 - 2 datanodes, task trackers
>>>
>>> mapred.map.tasks = 2
>>> mapred.reduce.tasks = 1
>>> dfs.replication = 1
>>>
>>> I ran the distributed PE in that configuration and it still failed
>>> with similar errors. The output of the hadoop fsck for this run was:
>>>
>>> ..........
>>>
>>>
>> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
>> :
>>
>>> MISSING 1 blocks of total size 0 B.
>>> ......................................
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
>>> iles/5263238643231358600/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/2024298319068625138/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ....
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
>>> iles/5071453667327337040/data:
>>> MISSING 1 blocks of total size 0 B.
>>> .........
>>> /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
>>> s/4400784113695734765/data:
>>> MISSING 1 blocks of total size 0 B.
>>> ...................................
>>> ........................................................................
>>> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
>>> MISSING 1 blocks of total size 0 B.
>>> .Status: CORRUPT
>>> Total size: 1890454330 B
>>> Total blocks: 180 (avg. block size 10502524 B)
>>> Total dirs: 190
>>> Total files: 173
>>> Over-replicated blocks: 0 (0.0 %)
>>> Under-replicated blocks: 0 (0.0 %)
>>> Target replication factor: 1
>>> Real replication factor: 1.0
>>>
>>>
>>> The filesystem under path '/' is CORRUPT
>>>
>>>
>>> On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>>>
>>>> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>>>>
>>>> Try [hadoop fsck /]
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>>>
>>>>
>>>>> I do not have root access on the xen cluster I'm using. I will ask the
>>>>> admin to make sure the disk is working properly. Regarding the
>>>>> mismatch versions though, are you suggesting that different region
>>>>> servers might be running different versions of hbase/hadoop? They are
>>>>> all running the same code from the same shared storage. There isn't
>>>>> even another version of hadoop anywhere for the other nodes to run. I
>>>>> think I'll try dropping my cluster down to 2 nodes and working back
>>>>> up... maybe I can pin point a specific problem node. Thanks for taking
>>>>> a look at my logs.
>>>>>
>>>>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>>>>>
>>>>>> I took a quick look Kareem. As with the last time, hbase keeps having
>>>>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>>>>>> because can't write reliably to the hdfs -- a variety of reasons. You
>>>>>> then seem to restart the cluster around 17:37 or so and things seem to
>>>>>> go along fine for a while until 19:05 when again, all regionservers
>>>>>> report trouble writing the hdfs. Have you run an fsck?
>>>>>>
>>>>
>>
RE: 答复: HBase PerformanceEvaluation failing
Posted by dhruba Borthakur <dh...@yahoo-inc.com>.
Hi Kareem,
I think you have run into
http://issues.apache.org/jira/browse/HADOOP-2275
I have a fix for this problem. You can find that fix as an attachment to the above JIRA. If you typically build your Hadoop distribution from source, can you pl apply the above patch to your source and then try out your experiment? If not, that's fine.. this fix will probably go into the next release of hadoop.
Thanks for your help,
dhruba
-----Original Message-----
From: Kareem Dana [mailto:kareem.dana@gmail.com]
Sent: Saturday, November 24, 2007 9:13 PM
To: hadoop-user@lucene.apache.org
Subject: Re: 答复: HBase PerformanceEvaluation failing
I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
mapred, and hbase.
Ran fsck just to make sure:
kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
.....Status: HEALTHY
Total size: 450 B
Total blocks: 3 (avg. block size 150 B)
Total dirs: 16
Total files: 5
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 0 (0.0 %)
Target replication factor: 1
Real replication factor: 1.0
The filesystem under path '/' is HEALTHY
Started the PE Test:
kcd@hadoop07:~/hadoop$ bin/hadoop jar
/usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
sequentialWrite 2
07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
TestTable, families: {info:={name: info, max versions: 3, compression:
NONE, in memory: false, max length: 2147483647, bloom filter: none}}
created
07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
java.io.IOException: Job failed!
at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
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:585)
at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
Checked DFS status again:
kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
.....
/tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
MISSING 1 blocks of total size 0 B.
.......
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
MISSING 1 blocks of total size 0 B.
....................................
/tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
MISSING 1 blocks of total size 0 B.
....................................................
....................................................
/tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
MISSING 1 blocks of total size 0 B.
...........
/tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
MISSING 1 blocks of total size 0 B.
.Status: CORRUPT
Total size: 1823865158 B
Total blocks: 174 (avg. block size 10481983 B)
Total dirs: 180
Total files: 164
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 0 (0.0 %)
Target replication factor: 1
Real replication factor: 1.0
The filesystem under path '/' is CORRUPT
All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
The namenode log looks fine until the very end when it has a few of
these errors:
2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
blk_-6879410450276751752
2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
able to place enough replicas, still in need of 1
2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 1 on 54310, call
addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
DFSClient_-1049549396) from 172.16.6.56:56970: error:
java.io.IOException: File
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
could only be replicated to 0 nodes, instead of 1
java.io.IOException: File
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
could only be replicated to 0 nodes, instead of 1
at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
The hbase-region servers seem to be having a lot of problems though
according to their logs. Not quite sure what could be the cause.
- Kareem
On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>
> Can you clear the logs, clean out the file system and run the test again?
>
> The namenode logs should tell an interesting story.
>
>
>
> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>
> > I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
> > the PerformanceEvaluation test is corrupting it. Before I run the
> > test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
> > fails, the DFS is reported as corrupt. I tried to simplify my setup
> > and run the PE again. My new config is as follows:
> >
> > hadoop07 - DFS Master, Mapred master, hbase master
> > hadoop09-10 - 2 hbase region servers
> > hadoop11-12 - 2 datanodes, task trackers
> >
> > mapred.map.tasks = 2
> > mapred.reduce.tasks = 1
> > dfs.replication = 1
> >
> > I ran the distributed PE in that configuration and it still failed
> > with similar errors. The output of the hadoop fsck for this run was:
> >
> > ..........
> >
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
> :
> > MISSING 1 blocks of total size 0 B.
> > ......................................
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
> > iles/5263238643231358600/data:
> > MISSING 1 blocks of total size 0 B.
> > ....
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> > iles/2024298319068625138/data:
> > MISSING 1 blocks of total size 0 B.
> > ....
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> > iles/5071453667327337040/data:
> > MISSING 1 blocks of total size 0 B.
> > .........
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
> > s/4400784113695734765/data:
> > MISSING 1 blocks of total size 0 B.
> > ...................................
> > ........................................................................
> > /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
> > MISSING 1 blocks of total size 0 B.
> > .Status: CORRUPT
> > Total size: 1890454330 B
> > Total blocks: 180 (avg. block size 10502524 B)
> > Total dirs: 190
> > Total files: 173
> > Over-replicated blocks: 0 (0.0 %)
> > Under-replicated blocks: 0 (0.0 %)
> > Target replication factor: 1
> > Real replication factor: 1.0
> >
> >
> > The filesystem under path '/' is CORRUPT
> >
> >
> > On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
> >>
> >> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
> >>
> >> Try [hadoop fsck /]
> >>
> >>
> >>
> >>
> >>
> >> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
> >>
> >>> I do not have root access on the xen cluster I'm using. I will ask the
> >>> admin to make sure the disk is working properly. Regarding the
> >>> mismatch versions though, are you suggesting that different region
> >>> servers might be running different versions of hbase/hadoop? They are
> >>> all running the same code from the same shared storage. There isn't
> >>> even another version of hadoop anywhere for the other nodes to run. I
> >>> think I'll try dropping my cluster down to 2 nodes and working back
> >>> up... maybe I can pin point a specific problem node. Thanks for taking
> >>> a look at my logs.
> >>>
> >>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
> >>>> I took a quick look Kareem. As with the last time, hbase keeps having
> >>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
> >>>> because can't write reliably to the hdfs -- a variety of reasons. You
> >>>> then seem to restart the cluster around 17:37 or so and things seem to
> >>>> go along fine for a while until 19:05 when again, all regionservers
> >>>> report trouble writing the hdfs. Have you run an fsck?
> >>
> >>
>
>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Kareem Dana <ka...@gmail.com>.
I cleaned the logs, cleaned and reformatted the DFS. Started up DFS,
mapred, and hbase.
Ran fsck just to make sure:
kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
.....Status: HEALTHY
Total size: 450 B
Total blocks: 3 (avg. block size 150 B)
Total dirs: 16
Total files: 5
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 0 (0.0 %)
Target replication factor: 1
Real replication factor: 1.0
The filesystem under path '/' is HEALTHY
Started the PE Test:
kcd@hadoop07:~/hadoop$ bin/hadoop jar
/usr/research/home/kcd/hadoop/build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
sequentialWrite 2
07/11/24 23:14:03 INFO hbase.PerformanceEvaluation: Table name:
TestTable, families: {info:={name: info, max versions: 3, compression:
NONE, in memory: false, max length: 2147483647, bloom filter: none}}
created
07/11/24 23:14:04 INFO mapred.FileInputFormat: Total input paths to process : 1
07/11/24 23:14:06 INFO mapred.JobClient: Running job: job_200711242311_0001
07/11/24 23:14:07 INFO mapred.JobClient: map 0% reduce 0%
07/11/24 23:20:53 INFO mapred.JobClient: map 5% reduce 0%
07/11/24 23:21:03 INFO mapred.JobClient: map 5% reduce 1%
07/11/24 23:22:35 INFO mapred.JobClient: map 10% reduce 1%
07/11/24 23:22:46 INFO mapred.JobClient: map 10% reduce 3%
07/11/24 23:24:10 INFO mapred.JobClient: map 14% reduce 3%
07/11/24 23:24:22 INFO mapred.JobClient: map 19% reduce 3%
07/11/24 23:24:34 INFO mapred.JobClient: map 19% reduce 5%
07/11/24 23:29:31 INFO mapred.JobClient: map 24% reduce 5%
07/11/24 23:29:42 INFO mapred.JobClient: map 24% reduce 6%
07/11/24 23:31:37 INFO mapred.JobClient: map 29% reduce 6%
07/11/24 23:31:45 INFO mapred.JobClient: map 30% reduce 6%
07/11/24 23:31:56 INFO mapred.JobClient: map 30% reduce 10%
07/11/24 23:32:12 INFO mapred.JobClient: map 35% reduce 10%
07/11/24 23:32:18 INFO mapred.JobClient: map 35% reduce 11%
07/11/24 23:37:33 INFO mapred.JobClient: map 40% reduce 11%
07/11/24 23:37:39 INFO mapred.JobClient: map 40% reduce 13%
07/11/24 23:37:45 INFO mapred.JobClient: map 45% reduce 13%
07/11/24 23:37:54 INFO mapred.JobClient: map 45% reduce 15%
07/11/24 23:42:02 INFO mapred.JobClient: map 50% reduce 15%
07/11/24 23:52:14 INFO mapred.JobClient: map 100% reduce 100%
java.io.IOException: Job failed!
at org.apache.hadoop.mapred.JobClient.runJob(JobClient.java:831)
at org.apache.hadoop.hbase.PerformanceEvaluation.runNIsMoreThanOne(PerformanceEvaluation.java:248)
at org.apache.hadoop.hbase.PerformanceEvaluation.runTest(PerformanceEvaluation.java:588)
at org.apache.hadoop.hbase.PerformanceEvaluation.doCommandLine(PerformanceEvaluation.java:680)
at org.apache.hadoop.hbase.PerformanceEvaluation.main(PerformanceEvaluation.java:699)
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:585)
at org.apache.hadoop.util.RunJar.main(RunJar.java:155)
Checked DFS status again:
kcd@hadoop07:~/hadoop$ bin/hadoop fsck /
.....
/tmp/hadoop-kcd/hbase/hregion_-ROOT-,,0/info/mapfiles/3562020000090370572/data:
MISSING 1 blocks of total size 0 B.
.......
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/434460773960343228/data:
MISSING 1 blocks of total size 0 B.
....................................
/tmp/hadoop-kcd/hbase/hregion_TestTable,1152738,8007445145595019431/info/mapfiles/5636229081894866081/data:
MISSING 1 blocks of total size 0 B.
....................................................
....................................................
/tmp/hadoop-kcd/hbase/hregion_TestTable,8426559,7501417187825603851/info/mapfiles/6826621922173844792/data:
MISSING 1 blocks of total size 0 B.
...........
/tmp/hadoop-kcd/hbase/log_172.16.6.56_-1556193815149242895_60020/hlog.dat.025:
MISSING 1 blocks of total size 0 B.
.Status: CORRUPT
Total size: 1823865158 B
Total blocks: 174 (avg. block size 10481983 B)
Total dirs: 180
Total files: 164
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 0 (0.0 %)
Target replication factor: 1
Real replication factor: 1.0
The filesystem under path '/' is CORRUPT
All my logs are uploaded at http://www.cs.duke.edu/~kcd/hadoop-logs2/
The namenode log looks fine until the very end when it has a few of
these errors:
2007-11-24 23:43:00,798 INFO org.apache.hadoop.dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data.
blk_-6879410450276751752
2007-11-24 23:43:00,798 WARN org.apache.hadoop.fs.FSNamesystem: Not
able to place enough replicas, still in need of 1
2007-11-24 23:43:00,808 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 1 on 54310, call
addBlock(/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data,
DFSClient_-1049549396) from 172.16.6.56:56970: error:
java.io.IOException: File
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
could only be replicated to 0 nodes, instead of 1
java.io.IOException: File
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/9146068477937578655/data
could only be replicated to 0 nodes, instead of 1
at org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003)
at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
The hbase-region servers seem to be having a lot of problems though
according to their logs. Not quite sure what could be the cause.
- Kareem
On Nov 24, 2007 9:56 PM, Ted Dunning <td...@veoh.com> wrote:
>
> Can you clear the logs, clean out the file system and run the test again?
>
> The namenode logs should tell an interesting story.
>
>
>
> On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>
> > I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
> > the PerformanceEvaluation test is corrupting it. Before I run the
> > test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
> > fails, the DFS is reported as corrupt. I tried to simplify my setup
> > and run the PE again. My new config is as follows:
> >
> > hadoop07 - DFS Master, Mapred master, hbase master
> > hadoop09-10 - 2 hbase region servers
> > hadoop11-12 - 2 datanodes, task trackers
> >
> > mapred.map.tasks = 2
> > mapred.reduce.tasks = 1
> > dfs.replication = 1
> >
> > I ran the distributed PE in that configuration and it still failed
> > with similar errors. The output of the hadoop fsck for this run was:
> >
> > ..........
> >
> /tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
> :
> > MISSING 1 blocks of total size 0 B.
> > ......................................
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
> > iles/5263238643231358600/data:
> > MISSING 1 blocks of total size 0 B.
> > ....
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> > iles/2024298319068625138/data:
> > MISSING 1 blocks of total size 0 B.
> > ....
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> > iles/5071453667327337040/data:
> > MISSING 1 blocks of total size 0 B.
> > .........
> > /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
> > s/4400784113695734765/data:
> > MISSING 1 blocks of total size 0 B.
> > ...................................
> > ........................................................................
> > /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
> > MISSING 1 blocks of total size 0 B.
> > .Status: CORRUPT
> > Total size: 1890454330 B
> > Total blocks: 180 (avg. block size 10502524 B)
> > Total dirs: 190
> > Total files: 173
> > Over-replicated blocks: 0 (0.0 %)
> > Under-replicated blocks: 0 (0.0 %)
> > Target replication factor: 1
> > Real replication factor: 1.0
> >
> >
> > The filesystem under path '/' is CORRUPT
> >
> >
> > On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
> >>
> >> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
> >>
> >> Try [hadoop fsck /]
> >>
> >>
> >>
> >>
> >>
> >> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
> >>
> >>> I do not have root access on the xen cluster I'm using. I will ask the
> >>> admin to make sure the disk is working properly. Regarding the
> >>> mismatch versions though, are you suggesting that different region
> >>> servers might be running different versions of hbase/hadoop? They are
> >>> all running the same code from the same shared storage. There isn't
> >>> even another version of hadoop anywhere for the other nodes to run. I
> >>> think I'll try dropping my cluster down to 2 nodes and working back
> >>> up... maybe I can pin point a specific problem node. Thanks for taking
> >>> a look at my logs.
> >>>
> >>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
> >>>> I took a quick look Kareem. As with the last time, hbase keeps having
> >>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
> >>>> because can't write reliably to the hdfs -- a variety of reasons. You
> >>>> then seem to restart the cluster around 17:37 or so and things seem to
> >>>> go along fine for a while until 19:05 when again, all regionservers
> >>>> report trouble writing the hdfs. Have you run an fsck?
> >>
> >>
>
>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Ted Dunning <td...@veoh.com>.
Can you clear the logs, clean out the file system and run the test again?
The namenode logs should tell an interesting story.
On 11/24/07 6:12 PM, "Kareem Dana" <ka...@gmail.com> wrote:
> I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
> the PerformanceEvaluation test is corrupting it. Before I run the
> test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
> fails, the DFS is reported as corrupt. I tried to simplify my setup
> and run the PE again. My new config is as follows:
>
> hadoop07 - DFS Master, Mapred master, hbase master
> hadoop09-10 - 2 hbase region servers
> hadoop11-12 - 2 datanodes, task trackers
>
> mapred.map.tasks = 2
> mapred.reduce.tasks = 1
> dfs.replication = 1
>
> I ran the distributed PE in that configuration and it still failed
> with similar errors. The output of the hadoop fsck for this run was:
>
> ..........
>
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data>
:
> MISSING 1 blocks of total size 0 B.
> ......................................
> /tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapf
> iles/5263238643231358600/data:
> MISSING 1 blocks of total size 0 B.
> ....
> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> iles/2024298319068625138/data:
> MISSING 1 blocks of total size 0 B.
> ....
> /tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapf
> iles/5071453667327337040/data:
> MISSING 1 blocks of total size 0 B.
> .........
> /tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfile
> s/4400784113695734765/data:
> MISSING 1 blocks of total size 0 B.
> ...................................
> ........................................................................
> /tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
> MISSING 1 blocks of total size 0 B.
> .Status: CORRUPT
> Total size: 1890454330 B
> Total blocks: 180 (avg. block size 10502524 B)
> Total dirs: 190
> Total files: 173
> Over-replicated blocks: 0 (0.0 %)
> Under-replicated blocks: 0 (0.0 %)
> Target replication factor: 1
> Real replication factor: 1.0
>
>
> The filesystem under path '/' is CORRUPT
>
>
> On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>>
>> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>>
>> Try [hadoop fsck /]
>>
>>
>>
>>
>>
>> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>>
>>> I do not have root access on the xen cluster I'm using. I will ask the
>>> admin to make sure the disk is working properly. Regarding the
>>> mismatch versions though, are you suggesting that different region
>>> servers might be running different versions of hbase/hadoop? They are
>>> all running the same code from the same shared storage. There isn't
>>> even another version of hadoop anywhere for the other nodes to run. I
>>> think I'll try dropping my cluster down to 2 nodes and working back
>>> up... maybe I can pin point a specific problem node. Thanks for taking
>>> a look at my logs.
>>>
>>> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>>>> I took a quick look Kareem. As with the last time, hbase keeps having
>>>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>>>> because can't write reliably to the hdfs -- a variety of reasons. You
>>>> then seem to restart the cluster around 17:37 or so and things seem to
>>>> go along fine for a while until 19:05 when again, all regionservers
>>>> report trouble writing the hdfs. Have you run an fsck?
>>
>>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Kareem Dana <ka...@gmail.com>.
I ran hadoop fsck and sure enough the DFS was corrupted. It seems that
the PerformanceEvaluation test is corrupting it. Before I run the
test, I ran fsck and the DFS was reported as HEALTHY. Once the PE
fails, the DFS is reported as corrupt. I tried to simplify my setup
and run the PE again. My new config is as follows:
hadoop07 - DFS Master, Mapred master, hbase master
hadoop09-10 - 2 hbase region servers
hadoop11-12 - 2 datanodes, task trackers
mapred.map.tasks = 2
mapred.reduce.tasks = 1
dfs.replication = 1
I ran the distributed PE in that configuration and it still failed
with similar errors. The output of the hadoop fsck for this run was:
..........
/tmp/hadoop-kcd/hbase/hregion_.META.,,1/info/mapfiles/6434881831082231493/data:
MISSING 1 blocks of total size 0 B.
......................................
/tmp/hadoop-kcd/hbase/hregion_TestTable,11566878,1227092681544002579/info/mapfiles/5263238643231358600/data:
MISSING 1 blocks of total size 0 B.
....
/tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapfiles/2024298319068625138/data:
MISSING 1 blocks of total size 0 B.
....
/tmp/hadoop-kcd/hbase/hregion_TestTable,12612310,1652062411016999689/info/mapfiles/5071453667327337040/data:
MISSING 1 blocks of total size 0 B.
.........
/tmp/hadoop-kcd/hbase/hregion_TestTable,13932,4738192747521322482/info/mapfiles/4400784113695734765/data:
MISSING 1 blocks of total size 0 B.
...................................
........................................................................
/tmp/hadoop-kcd/hbase/log_172.16.6.56_-1823376333333123807_60020/hlog.dat.027:
MISSING 1 blocks of total size 0 B.
.Status: CORRUPT
Total size: 1890454330 B
Total blocks: 180 (avg. block size 10502524 B)
Total dirs: 190
Total files: 173
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 0 (0.0 %)
Target replication factor: 1
Real replication factor: 1.0
The filesystem under path '/' is CORRUPT
On Nov 24, 2007 6:21 PM, Ted Dunning <td...@veoh.com> wrote:
>
> I think that stack was suggesting an HDFS fsck, not a disk level fsck.
>
> Try [hadoop fsck /]
>
>
>
>
>
> On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
>
> > I do not have root access on the xen cluster I'm using. I will ask the
> > admin to make sure the disk is working properly. Regarding the
> > mismatch versions though, are you suggesting that different region
> > servers might be running different versions of hbase/hadoop? They are
> > all running the same code from the same shared storage. There isn't
> > even another version of hadoop anywhere for the other nodes to run. I
> > think I'll try dropping my cluster down to 2 nodes and working back
> > up... maybe I can pin point a specific problem node. Thanks for taking
> > a look at my logs.
> >
> > On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
> >> I took a quick look Kareem. As with the last time, hbase keeps having
> >> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
> >> because can't write reliably to the hdfs -- a variety of reasons. You
> >> then seem to restart the cluster around 17:37 or so and things seem to
> >> go along fine for a while until 19:05 when again, all regionservers
> >> report trouble writing the hdfs. Have you run an fsck?
>
>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Ted Dunning <td...@veoh.com>.
I think that stack was suggesting an HDFS fsck, not a disk level fsck.
Try [hadoop fsck /]
On 11/24/07 4:09 PM, "Kareem Dana" <ka...@gmail.com> wrote:
> I do not have root access on the xen cluster I'm using. I will ask the
> admin to make sure the disk is working properly. Regarding the
> mismatch versions though, are you suggesting that different region
> servers might be running different versions of hbase/hadoop? They are
> all running the same code from the same shared storage. There isn't
> even another version of hadoop anywhere for the other nodes to run. I
> think I'll try dropping my cluster down to 2 nodes and working back
> up... maybe I can pin point a specific problem node. Thanks for taking
> a look at my logs.
>
> On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
>> I took a quick look Kareem. As with the last time, hbase keeps having
>> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
>> because can't write reliably to the hdfs -- a variety of reasons. You
>> then seem to restart the cluster around 17:37 or so and things seem to
>> go along fine for a while until 19:05 when again, all regionservers
>> report trouble writing the hdfs. Have you run an fsck?
Re: 答复: HBase PerformanceEvaluation failing
Posted by Kareem Dana <ka...@gmail.com>.
I do not have root access on the xen cluster I'm using. I will ask the
admin to make sure the disk is working properly. Regarding the
mismatch versions though, are you suggesting that different region
servers might be running different versions of hbase/hadoop? They are
all running the same code from the same shared storage. There isn't
even another version of hadoop anywhere for the other nodes to run. I
think I'll try dropping my cluster down to 2 nodes and working back
up... maybe I can pin point a specific problem node. Thanks for taking
a look at my logs.
On Nov 24, 2007 5:49 PM, stack <st...@duboce.net> wrote:
> I took a quick look Kareem. As with the last time, hbase keeps having
> trouble w/ the hdfs. Things start out fine around 16:00 then go bad
> because can't write reliably to the hdfs -- a variety of reasons. You
> then seem to restart the cluster around 17:37 or so and things seem to
> go along fine for a while until 19:05 when again, all regionservers
> report trouble writing the hdfs. Have you run an fsck?
>
> I also saw this strange message in a few regionserver logs which makes
> me think there a mismatch versions somewhere:
>
> 2007-11-15 16:58:28,783 ERROR org.apache.hadoop.hbase.HRegionServer: Split or compaction failed
> java.io.IOException: Mismatch in writeChunk() args
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.writeChunk(DFSClient.java:1575)
> at org.apache.hadoop.fs.FSOutputSummer.writeChecksumChunk(FSOutputSummer.java:140)
> at org.apache.hadoop.fs.FSOutputSummer.flushBuffer(FSOutputSummer.java:122)
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java:1715)
> at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:49)
> at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:64)
> at org.apache.hadoop.io.SequenceFile$Writer.close(SequenceFile.java:918)
> at org.apache.hadoop.io.MapFile$Writer.close(MapFile.java:172)
> at org.apache.hadoop.hbase.HStore.compactHelper(HStore.java:631)
> at org.apache.hadoop.hbase.HStore.compactHelper(HStore.java:561)
> at org.apache.hadoop.hbase.HStore.compact(HStore.java:556)
> at org.apache.hadoop.hbase.HRegion.compactStores(HRegion.java:711)
> at org.apache.hadoop.hbase.HRegionServer$SplitOrCompactChecker.checkForSplitsOrCompactions(HRegionServer.java:196)
> at org.apache.hadoop.hbase.HRegionServer$SplitOrCompactChecker.chore(HRegionServer.java:186)
> at org.apache.hadoop.hbase.Chore.run(Chore.java:58)
>
>
> St.Ack
>
>
> Kareem Dana wrote:
>
> > Sure. I uploaded all my logs to my website:
> >
> > http://cs.duke.edu/~kcd/hadoop-logs/
> >
> > My cluster consists of hadoop07-hadoop12. hadoop07 acts as the dfs
> > master, mapred master, and hbase master. hadoop08-12 are dfs slaves,
> > mapred task servers, and hbase regionservers.
> >
> > I also uploaded my hadoop-site.xml and hbase-site.xml on there also.
> > Those are the only configuration values I changed. Each node in the
> > cluster has these specs
> >
> > - Linux hadoop07 2.6.18-xenU #4 SMP Mon Oct 22 11:03:58 EDT 2007 i686 GNU/Linux
> > - java version "1.5.0_06"
> > Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_06-b05)
> > Java HotSpot(TM) Client VM (build 1.5.0_06-b05, mixed mode, sharing)
> > - Hadoop 0.15.0 release with no modifications and included hbase.
> >
> > Each machine has 2GB of local storage space, 400MB ram, 256mb swap.
> > Let me know if anymore information will be helpful. Thanks for looking
> > at the logs.
> >
> > - Kareem
> >
> > On Nov 20, 2007 10:01 AM, stack <st...@duboce.net> wrote:
> >
> >> May I see your logs Kareem? What version of hbase? Can I see your
> >> config. too?
> >> Thanks,
> >>
> >> St.Ack
> >>
> >>
>
>
Re: 答复: HBase PerformanceEvaluation failing
Posted by stack <st...@duboce.net>.
I took a quick look Kareem. As with the last time, hbase keeps having
trouble w/ the hdfs. Things start out fine around 16:00 then go bad
because can't write reliably to the hdfs -- a variety of reasons. You
then seem to restart the cluster around 17:37 or so and things seem to
go along fine for a while until 19:05 when again, all regionservers
report trouble writing the hdfs. Have you run an fsck?
I also saw this strange message in a few regionserver logs which makes
me think there a mismatch versions somewhere:
2007-11-15 16:58:28,783 ERROR org.apache.hadoop.hbase.HRegionServer: Split or compaction failed
java.io.IOException: Mismatch in writeChunk() args
at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.writeChunk(DFSClient.java:1575)
at org.apache.hadoop.fs.FSOutputSummer.writeChecksumChunk(FSOutputSummer.java:140)
at org.apache.hadoop.fs.FSOutputSummer.flushBuffer(FSOutputSummer.java:122)
at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java:1715)
at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:49)
at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:64)
at org.apache.hadoop.io.SequenceFile$Writer.close(SequenceFile.java:918)
at org.apache.hadoop.io.MapFile$Writer.close(MapFile.java:172)
at org.apache.hadoop.hbase.HStore.compactHelper(HStore.java:631)
at org.apache.hadoop.hbase.HStore.compactHelper(HStore.java:561)
at org.apache.hadoop.hbase.HStore.compact(HStore.java:556)
at org.apache.hadoop.hbase.HRegion.compactStores(HRegion.java:711)
at org.apache.hadoop.hbase.HRegionServer$SplitOrCompactChecker.checkForSplitsOrCompactions(HRegionServer.java:196)
at org.apache.hadoop.hbase.HRegionServer$SplitOrCompactChecker.chore(HRegionServer.java:186)
at org.apache.hadoop.hbase.Chore.run(Chore.java:58)
St.Ack
Kareem Dana wrote:
> Sure. I uploaded all my logs to my website:
>
> http://cs.duke.edu/~kcd/hadoop-logs/
>
> My cluster consists of hadoop07-hadoop12. hadoop07 acts as the dfs
> master, mapred master, and hbase master. hadoop08-12 are dfs slaves,
> mapred task servers, and hbase regionservers.
>
> I also uploaded my hadoop-site.xml and hbase-site.xml on there also.
> Those are the only configuration values I changed. Each node in the
> cluster has these specs
>
> - Linux hadoop07 2.6.18-xenU #4 SMP Mon Oct 22 11:03:58 EDT 2007 i686 GNU/Linux
> - java version "1.5.0_06"
> Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_06-b05)
> Java HotSpot(TM) Client VM (build 1.5.0_06-b05, mixed mode, sharing)
> - Hadoop 0.15.0 release with no modifications and included hbase.
>
> Each machine has 2GB of local storage space, 400MB ram, 256mb swap.
> Let me know if anymore information will be helpful. Thanks for looking
> at the logs.
>
> - Kareem
>
> On Nov 20, 2007 10:01 AM, stack <st...@duboce.net> wrote:
>
>> May I see your logs Kareem? What version of hbase? Can I see your
>> config. too?
>> Thanks,
>>
>> St.Ack
>>
>>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Kareem Dana <ka...@gmail.com>.
Sure. I uploaded all my logs to my website:
http://cs.duke.edu/~kcd/hadoop-logs/
My cluster consists of hadoop07-hadoop12. hadoop07 acts as the dfs
master, mapred master, and hbase master. hadoop08-12 are dfs slaves,
mapred task servers, and hbase regionservers.
I also uploaded my hadoop-site.xml and hbase-site.xml on there also.
Those are the only configuration values I changed. Each node in the
cluster has these specs
- Linux hadoop07 2.6.18-xenU #4 SMP Mon Oct 22 11:03:58 EDT 2007 i686 GNU/Linux
- java version "1.5.0_06"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_06-b05)
Java HotSpot(TM) Client VM (build 1.5.0_06-b05, mixed mode, sharing)
- Hadoop 0.15.0 release with no modifications and included hbase.
Each machine has 2GB of local storage space, 400MB ram, 256mb swap.
Let me know if anymore information will be helpful. Thanks for looking
at the logs.
- Kareem
On Nov 20, 2007 10:01 AM, stack <st...@duboce.net> wrote:
> May I see your logs Kareem? What version of hbase? Can I see your
> config. too?
> Thanks,
>
> St.Ack
>
Re: 答复: HBase PerformanceEvaluation failing
Posted by stack <st...@duboce.net>.
May I see your logs Kareem? What version of hbase? Can I see your
config. too?
Thanks,
St.Ack
Kareem Dana wrote:
> I am using xen with Linux 2.6.18. dfs -put works fine. I can read data
> I have put and all other dfs operations work. They work before I run
> the PE test and then after the PE test fails dfs still works fine on
> its own. However I found some more DFS errors in the logs that happen
> right before the PE test fails. My DFS datanodes are hadoop08-12
>
> On hadoop08:
> 2007-11-15 19:13:52,751 INFO org.apache.hadoop.dfs.DataNode: Starting
> thread to transfer block blk_6384396336224061547 to
> [Lorg.apache.hadoop.dfs.DatanodeInfo;@1d349e2
> 2007-11-15 19:13:52,755 WARN org.apache.hadoop.dfs.DataNode: Failed to
> transfer blk_6384396336224061547 to 172.16.6.56:50010 got
> java.net.SocketException: Connection reset
>
> hadoop09:
> 2007-11-15 19:13:58,788 ERROR org.apache.hadoop.dfs.DataNode:
> DataXceiver: java.io.IOException: Block blk_6384396336224061547 has
> already been started (thoug
> h not completed), and thus cannot be created.
>
> hadoop10:
> 2007-11-15 19:14:13,119 WARN org.apache.hadoop.dfs.DataNode:
> Unexpected error trying to delete block blk_-6070535147471430901.
> Block not found in blockMap.
> 2007-11-15 19:14:13,120 INFO org.apache.hadoop.dfs.DataNode: Deleting
> block blk_4063930368628711897 file
> /tmp/hadoop-kcd/dfs/data/current/blk_4063930368628711897
> 2007-11-15 19:14:13,136 INFO org.apache.hadoop.dfs.DataNode: Deleting
> block blk_-2206654761004087942 file
> /tmp/hadoop-kcd/dfs/data/current/blk_-2206654761004087942
> 2007-11-15 19:14:13,157 WARN org.apache.hadoop.dfs.DataNode:
> java.io.IOException: Error in deleting blocks.
>
> hadoop12:
> 2007-11-15 19:14:13,119 WARN org.apache.hadoop.dfs.DataNode:
> Unexpected error trying to delete block blk_-6070535147471430901.
> Block not found in blockMap.
> 2007-11-15 19:14:13,120 INFO org.apache.hadoop.dfs.DataNode: Deleting
> block blk_4063930368628711897 file
> /tmp/hadoop-kcd/dfs/data/current/blk_4063930368628711897
> 2007-11-15 19:14:13,136 INFO org.apache.hadoop.dfs.DataNode: Deleting
> block blk_-2206654761004087942 file
> /tmp/hadoop-kcd/dfs/data/current/blk_-2206654761004087942
> 2007-11-15 19:14:13,157 WARN org.apache.hadoop.dfs.DataNode:
> java.io.IOException: Error in deleting blocks.
>
> hadoop07 Namenode:
> 2007-11-15 19:10:33,090 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 3 on 54310, call
> open(/tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769,
> 0, 671088640) from 172.16.6.58:57409: error: java.io.IOException:
> Cannot open filename
> /tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769
> java.io.IOException: Cannot open filename
> /tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769
>
> It looks like something wrong with DFS but DFS is working fine
> otherwise and when I run a PE with just 1 client it finishes to
> completion. Does that put the same stress on DFS or does a 2 client
> test effectively double the IO through DFS?
>
> Regards,
> Kareem
>
> On Nov 15, 2007 9:08 PM, 闫雪冰 <ya...@alibaba-inc.com> wrote:
>
>> Are you working on FreeBSD 4.11? Did you ever succeed in doing a 'dfs -put'
>> operation?
>>
>> I went into a very similar trouble a few days ago. In my case, I got an
>> "only be replicated to 0 nodes, instead of 1" msg when I tried to run the PE
>> program, I found that I couldn't even managed to make a 'dfs -put' which
>> would also give me the previous error msg, though I succeeded in doing 'dfs
>> -makedir'.
>>
>> The reason is SecureRandom doesn't work on my FreeBSD 4.11, I finally get
>> two solutions:
>> a) Get back to hadoop-0.14.3, which will work fine with the same
>> configuration, or
>> b) Comment off the SecureRandom block like below
>> ----------------------------------------------------------
>> /*
>> try {
>> rand =
>> SecureRandom.getInstance("SHA1PRNG").nextInt(Integer.MAX_VALUE);
>> } catch (NoSuchAlgorithmException e) {
>> LOG.warn("Could not use SecureRandom");
>> rand = (new Random()).nextInt(Integer.MAX_VALUE);
>> }
>> */
>> rand = (new Random()).nextInt(Integer.MAX_VALUE);
>> ----------------------------------------------------------
>> May it help.
>> -Xuebing Yan
>>
>> -----邮件原件-----
>> 发件人: Kareem Dana [mailto:kareem.dana@gmail.com]
>> 发送时间: 2007年11月16日 9:32
>> 收件人: hadoop-user@lucene.apache.org
>> 主题: Re: HBase PerformanceEvaluation failing
>>
>> My DFS appears healthy. After the PE fails, the datanodes are still
>> running but all the HRegionServers have exited. My initial concern is
>> free harddrive space or memory. Each node has ~1.5GB free space for
>> DFS and 400MB ram/256mb swap. Is this enough for the PE? I tried
>> monitoring the free space as the PE ran and it never completely filled
>> up but it is kind of tight.
>>
>>
>> On Nov 15, 2007 8:01 PM, stack <st...@duboce.net> wrote:
>>
>>> Your DFS is healthy? This seems odd: "File
>>>
>>>
>> /tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
>> files/6464987859396543981/datacould
>>
>>
>>> only be replicated to 0 nodes, instead of 1;" In my experience, IIRC,
>>> it means no datanodes running.
>>>
>>> (I just tried the PE from TRUNK and it ran to completion).
>>>
>>> St.Ack
>>>
>>>
>>> Kareem Dana wrote:
>>>
>>>> I'm trying to run the HBase PerformanceEvaluation program on a cluster
>>>> of 5 hadoop nodes (on virtual machines).
>>>>
>>>> hadoop07 is a DFS Master and HBase master
>>>> hadoop08-12 are HBase region servers
>>>>
>>>> I start the test as follows:
>>>>
>>>> $ bin/hadoop jar
>>>> ${HADOOP_HOME}build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
>>>> sequentialWrite 2
>>>>
>>>> This starts the sequentialWrite test with 2 clients. After about 25
>>>> minutes the map tasks are about 25% complete and reduce at 6% the test
>>>> fails with the following error:
>>>> 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.TaskInProgress:
>>>> TaskInProgress tip_200711151626_0001_m_000002 has failed 1 times.
>>>> 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.JobInProgress:
>>>> Aborting job job_200711151626_0001
>>>> 2007-11-15 17:06:35,101 INFO org.apache.hadoop.mapred.TaskInProgress:
>>>> Error from task_200711151626_0001_m_000006_0:
>>>> org.apache.hadoop.hbase.NoServerForRegionException: failed to find
>>>> server for TestTable after 5 retries
>>>> at
>>>>
>> org.apache.hadoop.hbase.HConnectionManager$TableServers.scanOneMetaRegion(HC
>> onnectionManager.java:761)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HConnectionManager$TableServers.findServersForTable(
>> HConnectionManager.java:521)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HConnectionManager$TableServers.reloadTableServers(H
>> ConnectionManager.java:317)
>>
>>>> at org.apache.hadoop.hbase.HTable.commit(HTable.java:671)
>>>> at org.apache.hadoop.hbase.HTable.commit(HTable.java:636)
>>>> at
>>>>
>> org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(Pe
>> rformanceEvaluation.java:493)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluatio
>> n.java:356)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvalua
>> tion.java:529)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(Performa
>> nceEvaluation.java:184)
>>
>>>> at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
>>>> at org.apache.hadoop.mapred.MapTask.run(MapTask.java:192)
>>>> at
>>>>
>> org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:1760)
>>
>>>> An HBase region server log shows these errors:
>>>> 2007-11-15 17:03:00,017 ERROR org.apache.hadoop.hbase.HRegionServer:
>>>> error closing region TestTable,2102165,6843477525281170954
>>>> org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
>>>> File
>>>>
>> /tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
>> files/6464987859396543981/data
>>
>>>> could only be replicated to 0 nodes, instead of 1
>>>> at
>>>>
>> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
>> )
>>
>>>> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
>>>> at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
>>>> at
>>>>
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
>> .java:25)
>>
>>>> at java.lang.reflect.Method.invoke(Method.java:585)
>>>> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
>>>> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>>>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
>>
>>>> at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
>> )
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
>>
>>>> at java.lang.Thread.run(Thread.java:595)
>>>> 2007-11-15 17:03:00,615 ERROR org.apache.hadoop.hbase.HRegionServer:
>>>> error closing region TestTable,3147654,8929124532081908894
>>>> org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
>>>> File
>>>>
>> /tmp/hadoop-kcd/hbase/hregion_TestTable,3147654,8929124532081908894/info/map
>> files/3451857497397493742/data
>>
>>>> could only be replicated to 0 nodes, instead of 1
>>>> at
>>>>
>> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
>> )
>>
>>>> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
>>>> at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
>>>> at
>>>>
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
>> .java:25)
>>
>>>> at java.lang.reflect.Method.invoke(Method.java:585)
>>>> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
>>>> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>>>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
>>
>>>> at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
>> )
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
>>
>>>> at java.lang.Thread.run(Thread.java:595)
>>>> 2007-11-15 17:03:00,639 ERROR org.apache.hadoop.hbase.HRegionServer:
>>>> Close and delete failed
>>>> java.io.IOException: java.io.IOException: File
>>>>
>>>>
>> /tmp/hadoop-kcd/hbase/log_172.16.6.57_-3889232888673408171_60020/hlog.dat.00
>> 5
>>
>>>> could only be replicated to 0 nodes, instead of 1
>>>> at
>>>>
>> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
>> )
>>
>>>> at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
>>>> at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
>>>> at
>>>>
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
>> .java:25)
>>
>>>> at java.lang.reflect.Method.invoke(Method.java:585)
>>>> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
>>>> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
>>>>
>>>> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>>>>
>> Method)
>>
>>>> at
>>>>
>> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
>> sorImpl.java:39)
>>
>>>> at
>>>>
>> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
>> torAccessorImpl.java:27)
>>
>>>> at
>>>>
>> java.lang.reflect.Constructor.newInstance(Constructor.java:494)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteE
>> xceptionHandler.java:82)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExcept
>> ionHandler.java:48)
>>
>>>> at
>>>>
>> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:597)
>>
>>>> at java.lang.Thread.run(Thread.java:595)
>>>> 2007-11-15 17:03:00,640 INFO org.apache.hadoop.hbase.HRegionServer:
>>>> telling master that region server is shutting down at:
>>>> 172.16.6.57:60020
>>>> 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
>>>> stopping server at: 172.16.6.57:60020
>>>> 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
>>>> regionserver/0.0.0.0:60020 exiting
>>>>
>>>> I can provide some more logs if necessary. Any ideas or suggestions
>>>> about how I track this down? Running sequentialWrite test with just 1
>>>> client works fine but using 2 or more causes these errors.
>>>>
>>>> Thanks for any help,
>>>> Kareem Dana
>>>>
>>>>
>>>
Re: 答复: HBase PerformanceEvaluation failing
Posted by Kareem Dana <ka...@gmail.com>.
I am using xen with Linux 2.6.18. dfs -put works fine. I can read data
I have put and all other dfs operations work. They work before I run
the PE test and then after the PE test fails dfs still works fine on
its own. However I found some more DFS errors in the logs that happen
right before the PE test fails. My DFS datanodes are hadoop08-12
On hadoop08:
2007-11-15 19:13:52,751 INFO org.apache.hadoop.dfs.DataNode: Starting
thread to transfer block blk_6384396336224061547 to
[Lorg.apache.hadoop.dfs.DatanodeInfo;@1d349e2
2007-11-15 19:13:52,755 WARN org.apache.hadoop.dfs.DataNode: Failed to
transfer blk_6384396336224061547 to 172.16.6.56:50010 got
java.net.SocketException: Connection reset
hadoop09:
2007-11-15 19:13:58,788 ERROR org.apache.hadoop.dfs.DataNode:
DataXceiver: java.io.IOException: Block blk_6384396336224061547 has
already been started (thoug
h not completed), and thus cannot be created.
hadoop10:
2007-11-15 19:14:13,119 WARN org.apache.hadoop.dfs.DataNode:
Unexpected error trying to delete block blk_-6070535147471430901.
Block not found in blockMap.
2007-11-15 19:14:13,120 INFO org.apache.hadoop.dfs.DataNode: Deleting
block blk_4063930368628711897 file
/tmp/hadoop-kcd/dfs/data/current/blk_4063930368628711897
2007-11-15 19:14:13,136 INFO org.apache.hadoop.dfs.DataNode: Deleting
block blk_-2206654761004087942 file
/tmp/hadoop-kcd/dfs/data/current/blk_-2206654761004087942
2007-11-15 19:14:13,157 WARN org.apache.hadoop.dfs.DataNode:
java.io.IOException: Error in deleting blocks.
hadoop12:
2007-11-15 19:14:13,119 WARN org.apache.hadoop.dfs.DataNode:
Unexpected error trying to delete block blk_-6070535147471430901.
Block not found in blockMap.
2007-11-15 19:14:13,120 INFO org.apache.hadoop.dfs.DataNode: Deleting
block blk_4063930368628711897 file
/tmp/hadoop-kcd/dfs/data/current/blk_4063930368628711897
2007-11-15 19:14:13,136 INFO org.apache.hadoop.dfs.DataNode: Deleting
block blk_-2206654761004087942 file
/tmp/hadoop-kcd/dfs/data/current/blk_-2206654761004087942
2007-11-15 19:14:13,157 WARN org.apache.hadoop.dfs.DataNode:
java.io.IOException: Error in deleting blocks.
hadoop07 Namenode:
2007-11-15 19:10:33,090 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 3 on 54310, call
open(/tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769,
0, 671088640) from 172.16.6.58:57409: error: java.io.IOException:
Cannot open filename
/tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769
java.io.IOException: Cannot open filename
/tmp/hadoop-kcd/hbase/hregion_TestTable,4204932,5347114880093364680/info/info/5829185525592087769
It looks like something wrong with DFS but DFS is working fine
otherwise and when I run a PE with just 1 client it finishes to
completion. Does that put the same stress on DFS or does a 2 client
test effectively double the IO through DFS?
Regards,
Kareem
On Nov 15, 2007 9:08 PM, 闫雪冰 <ya...@alibaba-inc.com> wrote:
> Are you working on FreeBSD 4.11? Did you ever succeed in doing a 'dfs -put'
> operation?
>
> I went into a very similar trouble a few days ago. In my case, I got an
> "only be replicated to 0 nodes, instead of 1" msg when I tried to run the PE
> program, I found that I couldn't even managed to make a 'dfs -put' which
> would also give me the previous error msg, though I succeeded in doing 'dfs
> -makedir'.
>
> The reason is SecureRandom doesn't work on my FreeBSD 4.11, I finally get
> two solutions:
> a) Get back to hadoop-0.14.3, which will work fine with the same
> configuration, or
> b) Comment off the SecureRandom block like below
> ----------------------------------------------------------
> /*
> try {
> rand =
> SecureRandom.getInstance("SHA1PRNG").nextInt(Integer.MAX_VALUE);
> } catch (NoSuchAlgorithmException e) {
> LOG.warn("Could not use SecureRandom");
> rand = (new Random()).nextInt(Integer.MAX_VALUE);
> }
> */
> rand = (new Random()).nextInt(Integer.MAX_VALUE);
> ----------------------------------------------------------
> May it help.
> -Xuebing Yan
>
> -----邮件原件-----
> 发件人: Kareem Dana [mailto:kareem.dana@gmail.com]
> 发送时间: 2007年11月16日 9:32
> 收件人: hadoop-user@lucene.apache.org
> 主题: Re: HBase PerformanceEvaluation failing
>
> My DFS appears healthy. After the PE fails, the datanodes are still
> running but all the HRegionServers have exited. My initial concern is
> free harddrive space or memory. Each node has ~1.5GB free space for
> DFS and 400MB ram/256mb swap. Is this enough for the PE? I tried
> monitoring the free space as the PE ran and it never completely filled
> up but it is kind of tight.
>
>
> On Nov 15, 2007 8:01 PM, stack <st...@duboce.net> wrote:
> > Your DFS is healthy? This seems odd: "File
> >
> /tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
> files/6464987859396543981/datacould
>
> > only be replicated to 0 nodes, instead of 1;" In my experience, IIRC,
> > it means no datanodes running.
> >
> > (I just tried the PE from TRUNK and it ran to completion).
> >
> > St.Ack
> >
> >
> > Kareem Dana wrote:
> > > I'm trying to run the HBase PerformanceEvaluation program on a cluster
> > > of 5 hadoop nodes (on virtual machines).
> > >
> > > hadoop07 is a DFS Master and HBase master
> > > hadoop08-12 are HBase region servers
> > >
> > > I start the test as follows:
> > >
> > > $ bin/hadoop jar
> > > ${HADOOP_HOME}build/contrib/hbase/hadoop-0.15.0-dev-hbase-test.jar
> > > sequentialWrite 2
> > >
> > > This starts the sequentialWrite test with 2 clients. After about 25
> > > minutes the map tasks are about 25% complete and reduce at 6% the test
> > > fails with the following error:
> > > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.TaskInProgress:
> > > TaskInProgress tip_200711151626_0001_m_000002 has failed 1 times.
> > > 2007-11-15 17:06:35,100 INFO org.apache.hadoop.mapred.JobInProgress:
> > > Aborting job job_200711151626_0001
> > > 2007-11-15 17:06:35,101 INFO org.apache.hadoop.mapred.TaskInProgress:
> > > Error from task_200711151626_0001_m_000006_0:
> > > org.apache.hadoop.hbase.NoServerForRegionException: failed to find
> > > server for TestTable after 5 retries
> > > at
> org.apache.hadoop.hbase.HConnectionManager$TableServers.scanOneMetaRegion(HC
> onnectionManager.java:761)
> > > at
> org.apache.hadoop.hbase.HConnectionManager$TableServers.findServersForTable(
> HConnectionManager.java:521)
> > > at
> org.apache.hadoop.hbase.HConnectionManager$TableServers.reloadTableServers(H
> ConnectionManager.java:317)
> > > at org.apache.hadoop.hbase.HTable.commit(HTable.java:671)
> > > at org.apache.hadoop.hbase.HTable.commit(HTable.java:636)
> > > at
> org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(Pe
> rformanceEvaluation.java:493)
> > > at
> org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluatio
> n.java:356)
> > > at
> org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvalua
> tion.java:529)
> > > at
> org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(Performa
> nceEvaluation.java:184)
> > > at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
> > > at org.apache.hadoop.mapred.MapTask.run(MapTask.java:192)
> > > at
> org.apache.hadoop.mapred.TaskTracker$Child.main(TaskTracker.java:1760)
> > >
> > >
> > > An HBase region server log shows these errors:
> > > 2007-11-15 17:03:00,017 ERROR org.apache.hadoop.hbase.HRegionServer:
> > > error closing region TestTable,2102165,6843477525281170954
> > > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > > File
> /tmp/hadoop-kcd/hbase/hregion_TestTable,2102165,6843477525281170954/info/map
> files/6464987859396543981/data
> > > could only be replicated to 0 nodes, instead of 1
> > > at
> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
> )
> > > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > > at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
> .java:25)
> > > at java.lang.reflect.Method.invoke(Method.java:585)
> > > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> > >
> > > at
> org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > > at
> org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
> )
> > > at
> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > > at java.lang.Thread.run(Thread.java:595)
> > > 2007-11-15 17:03:00,615 ERROR org.apache.hadoop.hbase.HRegionServer:
> > > error closing region TestTable,3147654,8929124532081908894
> > > org.apache.hadoop.hbase.DroppedSnapshotException: java.io.IOException:
> > > File
> /tmp/hadoop-kcd/hbase/hregion_TestTable,3147654,8929124532081908894/info/map
> files/3451857497397493742/data
> > > could only be replicated to 0 nodes, instead of 1
> > > at
> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
> )
> > > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > > at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
> .java:25)
> > > at java.lang.reflect.Method.invoke(Method.java:585)
> > > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> > >
> > > at
> org.apache.hadoop.hbase.HRegion.internalFlushcache(HRegion.java:886)
> > > at org.apache.hadoop.hbase.HRegion.close(HRegion.java:388)
> > > at
> org.apache.hadoop.hbase.HRegionServer.closeAllRegions(HRegionServer.java:978
> )
> > > at
> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:593)
> > > at java.lang.Thread.run(Thread.java:595)
> > > 2007-11-15 17:03:00,639 ERROR org.apache.hadoop.hbase.HRegionServer:
> > > Close and delete failed
> > > java.io.IOException: java.io.IOException: File
> > >
> /tmp/hadoop-kcd/hbase/log_172.16.6.57_-3889232888673408171_60020/hlog.dat.00
> 5
> > > could only be replicated to 0 nodes, instead of 1
> > > at
> org.apache.hadoop.dfs.FSNamesystem.getAdditionalBlock(FSNamesystem.java:1003
> )
> > > at org.apache.hadoop.dfs.NameNode.addBlock(NameNode.java:293)
> > > at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> > > at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
> .java:25)
> > > at java.lang.reflect.Method.invoke(Method.java:585)
> > > at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:379)
> > > at org.apache.hadoop.ipc.Server$Handler.run(Server.java:596)
> > >
> > > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
> Method)
> > > at
> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAcces
> sorImpl.java:39)
> > > at
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
> torAccessorImpl.java:27)
> > > at
> java.lang.reflect.Constructor.newInstance(Constructor.java:494)
> > > at
> org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteE
> xceptionHandler.java:82)
> > > at
> org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExcept
> ionHandler.java:48)
> > > at
> org.apache.hadoop.hbase.HRegionServer.run(HRegionServer.java:597)
> > > at java.lang.Thread.run(Thread.java:595)
> > > 2007-11-15 17:03:00,640 INFO org.apache.hadoop.hbase.HRegionServer:
> > > telling master that region server is shutting down at:
> > > 172.16.6.57:60020
> > > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > > stopping server at: 172.16.6.57:60020
> > > 2007-11-15 17:03:00,643 INFO org.apache.hadoop.hbase.HRegionServer:
> > > regionserver/0.0.0.0:60020 exiting
> > >
> > > I can provide some more logs if necessary. Any ideas or suggestions
> > > about how I track this down? Running sequentialWrite test with just 1
> > > client works fine but using 2 or more causes these errors.
> > >
> > > Thanks for any help,
> > > Kareem Dana
> > >
> >
> >
>