You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Mikael Sitruk <mi...@gmail.com> on 2011/11/29 09:46:31 UTC
Failed in connection to self
Hi
I have a strange error in log of HBase (0.90.2)
2011-11-28 15:12:53,049 INFO
org.apache.hadoop.hbase.regionserver.StoreFile$Reader: Loaded col bloom
filter metadata
for hdfs://hadoop89:8020/hbase/TC/2833a916eba1c562cdc5533b6af3ddc0/PI/569772658705731893
2011-11-28 15:12:53,052 INFO org.apache.hadoop.hdfs.DFSClient: Failed to
connect to /10.232.83.107:50010, add to deadNodes and continue
java.io.IOException: Got error in response to OP_READ_BLOCK self=/
10.232.83.107:33694, remote=/10.232.83.107:50010 for file
/hbase/TC/2833a916eba1c562cdc5533b6af3ddc0/PI/6153988896004900741 for block
2491155619874165730_1067272
at
org.apache.hadoop.hdfs.DFSClient$BlockReader.newBlockReader(DFSClient.java:1487)
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.blockSeekTo(DFSClient.java:1811)
at
org.apache.hadoop.hdfs.DFSClient$DFSInputStream.read(DFSClient.java:1948)
at java.io.DataInputStream.readFully(DataInputStream.java:178)
at java.io.DataInputStream.readFully(DataInputStream.java:152)
at
org.apache.hadoop.hbase.io.hfile.HFile$FixedFileTrailer.deserialize(HFile.java:1521)
at
org.apache.hadoop.hbase.io.hfile.HFile$Reader.readTrailer(HFile.java:885)
at
org.apache.hadoop.hbase.io.hfile.HFile$Reader.loadFileInfo(HFile.java:819)
at
org.apache.hadoop.hbase.regionserver.StoreFile$Reader.loadFileInfo(StoreFile.java:1002)
at
org.apache.hadoop.hbase.regionserver.StoreFile.open(StoreFile.java:382)
at
org.apache.hadoop.hbase.regionserver.StoreFile.createReader(StoreFile.java:438)
at
org.apache.hadoop.hbase.regionserver.Store.loadStoreFiles(Store.java:266)
at org.apache.hadoop.hbase.regionserver.Store.<init>(Store.java:208)
at
org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:2003)
at
org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:345)
at
org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2546)
at
org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2532)
at
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:262)
at
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:94)
at
org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2011-11-28 15:12:53,053 INFO
org.apache.hadoop.hbase.regionserver.StoreFile$Reader: Loaded col bloom
filter metadata
for hdfs://hadoop89:8020/hbase/TC/4dff91c02a4a7617457e9628318c1ff3/EVENT/7559787874595222989
then few line later i can see
2011-11-28 15:12:53,139 INFO
org.apache.hadoop.hbase.regionserver.StoreFile$Reader: Loaded col bloom
filter metadata
for hdfs://hadoop89:8020/hbase/TC/2833a916eba1c562cdc5533b6af3ddc0/PI/6153988896004900741
So can i deduce that even if the first operation failed everything is ok,
or is something is lost?
Second and Certainly i need to post this question to hdfs guys, (since this
is a dfs output) - from the first line i see that the same node that is the
source of the request will add itself as a dead node isn't it strange?
Regards,
Mikael.S
Re: Failed in connection to self
Posted by Jean-Daniel Cryans <jd...@apache.org>.
I agree with you, it's not the best. I talked briefly about this
yesterday at the developers meetup, there are a lot of stack traces
that are coming from the DFSClient that we have no control over and we
don't even have the opportunity to clarify them on our side. Silencing
them is obviously not an option in case things go really wrong and
those INFO-level messages become useful. Nor can we change them
directly in the Hadoop code to suit us better since we're only one use
case among others.
So it's an open issue.
J-D
On Wed, Nov 30, 2011 at 2:01 PM, Mikael Sitruk <mi...@gmail.com> wrote:
> J.D hi
>
> Well from the HBase POV at the end every thing is ok, but from the user POV
> he sees that HBase encontourned a problem while opening a Region. Then few
> line later HBase is fine with the file that previously got error. This is
> confusing for the user a little bit.
> But you are right, nothing can really be done to clarify the confusion
> untill the user get use to.
>
> Thanks.
> Mikael.S
> On Wed, Nov 30, 2011 at 8:38 PM, Jean-Daniel Cryans <jd...@apache.org>wrote:
>
>> On Tue, Nov 29, 2011 at 10:28 PM, Mikael Sitruk <mi...@gmail.com>
>> wrote:
>> > First thanks for answering, second i still have some question see inline
>> >
>> > Thanks
>> > Mikael.S
>> >
>> > ---
>> > Shouldn't be an added value to add some information in the original
>> message
>> > like (failed to load ... will try later), then when the bloom filter is
>> > successfully loaded to print a corresponding message like - (loaded col
>> > bloom filter .... successfully after x attempt)?
>>
>> We have 0 control on that stack trace because it comes from the depths
>> of the DFSClient:
>>
>> 2011-11-28 15:12:53,052 INFO org.apache.hadoop.hdfs.DFSClient
>>
>> So from the HBase POV, nothing wrong happened. Also I don't know why
>> it would say it failed to load something because it didn't, if you
>> look at you log carefully you'll see that each loaded bloom filter is
>> for a different file and none failed.
>>
>> >
>> > Let assume that the 2 other replica are lost too, what hbase will
>> indicate
>> > in this case? will an error be created (big enough to bring attention to
>> > someone)?
>>
>> It would fail in a flamboyant way.
>>
>> J-D
>>
>
>
>
> --
> Mikael.S
Re: Failed in connection to self
Posted by Mikael Sitruk <mi...@gmail.com>.
J.D hi
Well from the HBase POV at the end every thing is ok, but from the user POV
he sees that HBase encontourned a problem while opening a Region. Then few
line later HBase is fine with the file that previously got error. This is
confusing for the user a little bit.
But you are right, nothing can really be done to clarify the confusion
untill the user get use to.
Thanks.
Mikael.S
On Wed, Nov 30, 2011 at 8:38 PM, Jean-Daniel Cryans <jd...@apache.org>wrote:
> On Tue, Nov 29, 2011 at 10:28 PM, Mikael Sitruk <mi...@gmail.com>
> wrote:
> > First thanks for answering, second i still have some question see inline
> >
> > Thanks
> > Mikael.S
> >
> > ---
> > Shouldn't be an added value to add some information in the original
> message
> > like (failed to load ... will try later), then when the bloom filter is
> > successfully loaded to print a corresponding message like - (loaded col
> > bloom filter .... successfully after x attempt)?
>
> We have 0 control on that stack trace because it comes from the depths
> of the DFSClient:
>
> 2011-11-28 15:12:53,052 INFO org.apache.hadoop.hdfs.DFSClient
>
> So from the HBase POV, nothing wrong happened. Also I don't know why
> it would say it failed to load something because it didn't, if you
> look at you log carefully you'll see that each loaded bloom filter is
> for a different file and none failed.
>
> >
> > Let assume that the 2 other replica are lost too, what hbase will
> indicate
> > in this case? will an error be created (big enough to bring attention to
> > someone)?
>
> It would fail in a flamboyant way.
>
> J-D
>
--
Mikael.S
Re: Failed in connection to self
Posted by Jean-Daniel Cryans <jd...@apache.org>.
On Tue, Nov 29, 2011 at 10:28 PM, Mikael Sitruk <mi...@gmail.com> wrote:
> First thanks for answering, second i still have some question see inline
>
> Thanks
> Mikael.S
>
> ---
> Shouldn't be an added value to add some information in the original message
> like (failed to load ... will try later), then when the bloom filter is
> successfully loaded to print a corresponding message like - (loaded col
> bloom filter .... successfully after x attempt)?
We have 0 control on that stack trace because it comes from the depths
of the DFSClient:
2011-11-28 15:12:53,052 INFO org.apache.hadoop.hdfs.DFSClient
So from the HBase POV, nothing wrong happened. Also I don't know why
it would say it failed to load something because it didn't, if you
look at you log carefully you'll see that each loaded bloom filter is
for a different file and none failed.
>
> Let assume that the 2 other replica are lost too, what hbase will indicate
> in this case? will an error be created (big enough to bring attention to
> someone)?
It would fail in a flamboyant way.
J-D
Re: Failed in connection to self
Posted by Mikael Sitruk <mi...@gmail.com>.
First thanks for answering, second i still have some question see inline
Thanks
Mikael.S
On Tue, Nov 29, 2011 at 8:04 PM, Jean-Daniel Cryans <jd...@apache.org>wrote:
> Inline.
>
> J-D
>
> On Tue, Nov 29, 2011 at 12:46 AM, Mikael Sitruk <mi...@gmail.com>
> wrote:
> > Hi
> >
> > I have a strange error in log of HBase (0.90.2)
> >
> > 2011-11-28 15:12:53,049 INFO
>
> This part right up here is important, it's INFO level.
>
> > then few line later i can see
> > 2011-11-28 15:12:53,139 INFO
> > org.apache.hadoop.hbase.regionserver.StoreFile$Reader: Loaded col bloom
> > filter metadata
> > for
> hdfs://hadoop89:8020/hbase/TC/2833a916eba1c562cdc5533b6af3ddc0/PI/6153988896004900741
> > So can i deduce that even if the first operation failed everything is ok,
> > or is something is lost?
>
> The client failed to connect for some reason to the local data node,
> you might get a clue by looking at the DN's log. But since there's 2
> other replicas, it's all good. Worst case if the replica is really
> lost the Namenode is going to fix it in the background.
>
---
Shouldn't be an added value to add some information in the original message
like (failed to load ... will try later), then when the bloom filter is
successfully loaded to print a corresponding message like - (loaded col
bloom filter .... successfully after x attempt)?
Let assume that the 2 other replica are lost too, what hbase will indicate
in this case? will an error be created (big enough to bring attention to
someone)?
>
>
>
> > Second and Certainly i need to post this question to hdfs guys, (since
> this
> > is a dfs output) - from the first line i see that the same node that is
> the
> > source of the request will add itself as a dead node isn't it strange?
>
> No, it adds the _local datanode_ as a dead node.
>
> J-D
>
--
Mikael.S
Re: Failed in connection to self
Posted by Jean-Daniel Cryans <jd...@apache.org>.
Inline.
J-D
On Tue, Nov 29, 2011 at 12:46 AM, Mikael Sitruk <mi...@gmail.com> wrote:
> Hi
>
> I have a strange error in log of HBase (0.90.2)
>
> 2011-11-28 15:12:53,049 INFO
This part right up here is important, it's INFO level.
> then few line later i can see
> 2011-11-28 15:12:53,139 INFO
> org.apache.hadoop.hbase.regionserver.StoreFile$Reader: Loaded col bloom
> filter metadata
> for hdfs://hadoop89:8020/hbase/TC/2833a916eba1c562cdc5533b6af3ddc0/PI/6153988896004900741
> So can i deduce that even if the first operation failed everything is ok,
> or is something is lost?
The client failed to connect for some reason to the local data node,
you might get a clue by looking at the DN's log. But since there's 2
other replicas, it's all good. Worst case if the replica is really
lost the Namenode is going to fix it in the background.
>
> Second and Certainly i need to post this question to hdfs guys, (since this
> is a dfs output) - from the first line i see that the same node that is the
> source of the request will add itself as a dead node isn't it strange?
No, it adds the _local datanode_ as a dead node.
J-D