You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Ferdy <fe...@kalooga.com> on 2010/01/20 17:22:59 UTC
Regionserver problems because of datanode timeouts
Hello,
I am having issues of regionservers shutting down because the underlying
DFS is having trouble. I cannot get the DFS to function properly. I
attached a log of our regionserver below. At first sight it looks like
there is a timeout that occurs while the regionservers was trying to
connect to it's own datanode:
java.net.SocketTimeoutException: 69000 millis timeout while waiting for
channel to be ready for read. ch :
java.nio.channels.SocketChannel[connected local=/172.23.122.23:39203
remote=/172.23.122.23:50010]
The datanode logs show similar timeout errors (also when trying to
connect to local host).
Our configuration:
* Hadoop 0.20.1 and Hbase 0.20.2
* 20 nodes: each datanode/tasktracker and regionserver
* ulimit = 32000 on each node
* dfs.datanode.max.xcievers=5000 (should be big enough i presume)
* dfs.namenode.handler.count=30 (3 times the default)
* dfs.datanode.handler.count=9 (3 times the default)
* Our DFS contain around 500.000 blocks (64MB blocksize). Each datanode
has 1600M heapsize. The datanodes are started with the
-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode options.
* The DFS is fairly heavily used. (Always running a few concurrent
MapRed jobs, with average IO)
Anyone a clue what might be going on?
Regards,
Ferdy.
THE REGIONSERVER LOG:
2010-01-20 13:52:15,982 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
started. Attempting to free 22928768 bytes
2010-01-20 13:52:15,988 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
completed. Freed 22985616 bytes. Priority Sizes: Single=84.519615MB
(88625240), Multi=99.30783MB (104131808),Memory=0.0MB (0)
2010-01-20 13:53:03,613 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
Total=169.96802MB (178224384), Free=48.36949MB (50719088),
Max=218.33751MB (228943472), Counts: Blocks=2683, Access=184190,
Hit=10090, Miss=174100, Evictions=7, Evicted=2443, Ratios: Hit
Ratio=5.478039011359215%, Miss Ratio=94.521963596344%, Evicted/Run=349.0
2010-01-20 13:54:03,605 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
Total=174.83826MB (183331208), Free=43.499245MB (45612264),
Max=218.33751MB (228943472), Counts: Blocks=2762, Access=184477,
Hit=10298, Miss=174179, Evictions=7, Evicted=2443, Ratios: Hit
Ratio=5.582267791032791%, Miss Ratio=94.41773295402527%, Evicted/Run=349.0
2010-01-20 13:55:45,744 WARN org.apache.hadoop.hdfs.DFSClient:
DFSOutputStream ResponseProcessor exception for block
blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
millis timeout while waiting for channel to be ready for read. ch :
java.nio.channels.SocketChannel[connected local=/172.23.122.23:39203
remote=/172.23.122.23:50010]
at
org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
at
org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
at
org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
at java.io.DataInputStream.readFully(Unknown Source)
at java.io.DataInputStream.readLong(Unknown Source)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$ResponseProcessor.run(DFSClient.java:2399)
2010-01-20 13:55:45,744 DEBUG
org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
Total=178.23663MB (186894656), Free=40.100876MB (42048816),
Max=218.33751MB (228943472), Counts: Blocks=2816, Access=184676,
Hit=10443, Miss=174233, Evictions=7, Evicted=2443, Ratios: Hit
Ratio=5.654768273234367%, Miss Ratio=94.34522986412048%, Evicted/Run=349.0
2010-01-20 13:55:45,745 WARN org.apache.zookeeper.ClientCnxn: Exception
closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@2f242b11
java.io.IOException: TIMED OUT
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper: We
slept 66554ms, ten times longer than scheduled: 3000
2010-01-20 13:55:45,911 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
state: Disconnected, type: None, path: null
2010-01-20 13:55:46,178 WARN
org.apache.hadoop.hbase.regionserver.HRegionServer: Attempt=1
org.apache.hadoop.hbase.Leases$LeaseStillHeldException
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown
Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
at
org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:571)
at java.lang.Thread.run(Unknown Source)
2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
Recovery for block blk_-209323108721490976_6065406 bad datanode[0]
172.23.122.23:50010
2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
Recovery for block blk_-209323108721490976_6065406 in pipeline
172.23.122.23:50010, 172.23.122.16:50010,172.23.122.22:50010: bad
datanode 172.23.122.23:50010
2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
IPC Server handler 3 on 60020 took 71023ms appending an edit to hlog;
editcount=41251
2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
regionserver/172.23.122.23:60020.logFlusher took 67200ms optional
sync'ing hlog; editcount=41271
2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
IPC Server handler 1 on 60020 took 69781ms appending an edit to hlog;
editcount=41271
2010-01-20 13:55:47,081 INFO org.apache.zookeeper.ClientCnxn: Attempting
connection to server c1.machines.nl/172.23.122.1:2181
2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Priming
connection to java.nio.channels.SocketChannel[connected
local=/172.23.122.23:53151 remote=c1/172.23.122.1:2181]
2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Server
connection successful
2010-01-20 13:55:47,083 WARN org.apache.zookeeper.ClientCnxn: Exception
closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@5f84f3d2
java.io.IOException: Session Expired
at
org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
at
org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:709)
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
2010-01-20 13:55:47,086 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
state: Expired, type: None, path: null
2010-01-20 13:55:47,086 ERROR
org.apache.hadoop.hbase.regionserver.HRegionServer: ZooKeeper session
expired
Re: Regionserver problems because of datanode timeouts
Posted by Stack <st...@duboce.net>.
Thanks for updating the list Ferdy.
St.Ack
On Mon, Jun 14, 2010 at 3:09 AM, Ferdy <fe...@kalooga.com> wrote:
> After running stable for quite a while (using configured long timeouts), we
> recently noticed regionservers were starting to behave bad again. During
> compaction, regionservers complained that blocks are unavailable. Every
> couple of days, a regionserver decided to terminate itself because it could
> not recover from the DFS errors.
>
> So, after looking into it again, we might have found the actual cause for
> this problem. Prior to a regionserver terminate, logs of the corresponding
> datanode told us that the "df" command could not be ran because it could not
> allocate memory. Indeed, we finetuned our nodes to use nearly all RAM for
> the Hadoop/Hbase and child task processes. We had swap disabled. But we had
> the assumption that a simple "df" check should not be that expensive,
> right..?
>
> Well it seems we had to learn a bit about "Linux memory overcommit". Without
> going into much details, spawning processes in Linux requires the new
> process the have the same memory footprint as the original process, more or
> less. Therefore, a datanode with 1.6GB heap (in our case) should have about
> the same amount of memory free when spawning a new process, even though the
> spawned process will do little to nothing. In order to accomodate, you
> should either have enough free memory available (fysical / swap) or you
> could tweak the 'overcommit' configuration of the operating system. We
> decided to increase the amount of memory by enabling swap files.
>
> We're still running Hadoop 0.20.1 and Hbase 0.20.3, presumably the newest
> releases has better handling of errors in the DFSClient/InputStreams.
> Nevertheless, we believe that we have found the root cause of our
> regionserver problems.
>
> Ferdy.
>
> Stack wrote:
>>
>> The culprit might be the fragmentation calculation. See
>> https://issues.apache.org/jira/browse/HBASE-2165.
>> St.Ack
>>
>> On Wed, Mar 10, 2010 at 9:33 AM, Andrew Purtell <ap...@apache.org>
>> wrote:
>>
>>>>
>>>> However, once and every while our Nagios (our service monitor)
>>>>
>>>
>>> detects
>>>
>>>>
>>>> that requesting the Hbase master page takes a long
>>>>
>>>
>>> time. Sometimes > 10
>>>
>>>>
>>>> sec, rarely around 30 secs but most of
>>>>
>>>
>>> the time < 10 secs. In the cases
>>>
>>>>
>>>> the page loads slowly,
>>>>
>>>
>>> there is a fair amount of load on Hbase.
>>>
>>> I've noticed this also. With 0.20.4-dev. I think others have mentioned it
>>> on the list from time to time. However, I can never seem to jump on to a
>>> console fast enough to grab a stack dump before the UI becomes responsive
>>> again. :-( It is not consistent behavior. It concerns me that perhaps
>>> whatever lock is holding up the UI is also holding up any client
>>> attempting to (re)locate a region. If I manage to capture it I will file
>>> a jira.
>>>
>>>
>>>
>>> - Andy
>>>
>>>
>>>
>>>
>>>
>>>
>
Re: Regionserver problems because of datanode timeouts
Posted by Ferdy <fe...@kalooga.com>.
After running stable for quite a while (using configured long timeouts),
we recently noticed regionservers were starting to behave bad again.
During compaction, regionservers complained that blocks are unavailable.
Every couple of days, a regionserver decided to terminate itself because
it could not recover from the DFS errors.
So, after looking into it again, we might have found the actual cause
for this problem. Prior to a regionserver terminate, logs of the
corresponding datanode told us that the "df" command could not be ran
because it could not allocate memory. Indeed, we finetuned our nodes to
use nearly all RAM for the Hadoop/Hbase and child task processes. We had
swap disabled. But we had the assumption that a simple "df" check should
not be that expensive, right..?
Well it seems we had to learn a bit about "Linux memory overcommit".
Without going into much details, spawning processes in Linux requires
the new process the have the same memory footprint as the original
process, more or less. Therefore, a datanode with 1.6GB heap (in our
case) should have about the same amount of memory free when spawning a
new process, even though the spawned process will do little to nothing.
In order to accomodate, you should either have enough free memory
available (fysical / swap) or you could tweak the 'overcommit'
configuration of the operating system. We decided to increase the amount
of memory by enabling swap files.
We're still running Hadoop 0.20.1 and Hbase 0.20.3, presumably the
newest releases has better handling of errors in the
DFSClient/InputStreams. Nevertheless, we believe that we have found the
root cause of our regionserver problems.
Ferdy.
Stack wrote:
> The culprit might be the fragmentation calculation. See
> https://issues.apache.org/jira/browse/HBASE-2165.
> St.Ack
>
> On Wed, Mar 10, 2010 at 9:33 AM, Andrew Purtell <ap...@apache.org> wrote:
>
>>> However, once and every while our Nagios (our service monitor)
>>>
>> detects
>>
>>> that requesting the Hbase master page takes a long
>>>
>> time. Sometimes > 10
>>
>>> sec, rarely around 30 secs but most of
>>>
>> the time < 10 secs. In the cases
>>
>>> the page loads slowly,
>>>
>> there is a fair amount of load on Hbase.
>>
>> I've noticed this also. With 0.20.4-dev. I think others have mentioned it
>> on the list from time to time. However, I can never seem to jump on to a
>> console fast enough to grab a stack dump before the UI becomes responsive
>> again. :-( It is not consistent behavior. It concerns me that perhaps
>> whatever lock is holding up the UI is also holding up any client
>> attempting to (re)locate a region. If I manage to capture it I will file
>> a jira.
>>
>>
>>
>> - Andy
>>
>>
>>
>>
>>
>>
Re: Regionserver problems because of datanode timeouts
Posted by Stack <st...@duboce.net>.
The culprit might be the fragmentation calculation. See
https://issues.apache.org/jira/browse/HBASE-2165.
St.Ack
On Wed, Mar 10, 2010 at 9:33 AM, Andrew Purtell <ap...@apache.org> wrote:
>> However, once and every while our Nagios (our service monitor)
> detects
>> that requesting the Hbase master page takes a long
> time. Sometimes > 10
>> sec, rarely around 30 secs but most of
> the time < 10 secs. In the cases
>> the page loads slowly,
> there is a fair amount of load on Hbase.
>
> I've noticed this also. With 0.20.4-dev. I think others have mentioned it
> on the list from time to time. However, I can never seem to jump on to a
> console fast enough to grab a stack dump before the UI becomes responsive
> again. :-( It is not consistent behavior. It concerns me that perhaps
> whatever lock is holding up the UI is also holding up any client
> attempting to (re)locate a region. If I manage to capture it I will file
> a jira.
>
>
>
> - Andy
>
>
>
>
>
Re: Regionserver problems because of datanode timeouts
Posted by Andrew Purtell <ap...@apache.org>.
> However, once and every while our Nagios (our service monitor)
detects
> that requesting the Hbase master page takes a long
time. Sometimes > 10
> sec, rarely around 30 secs but most of
the time < 10 secs. In the cases
> the page loads slowly,
there is a fair amount of load on Hbase.
I've noticed this also. With 0.20.4-dev. I think others have mentioned it
on the list from time to time. However, I can never seem to jump on to a
console fast enough to grab a stack dump before the UI becomes responsive
again. :-( It is not consistent behavior. It concerns me that perhaps
whatever lock is holding up the UI is also holding up any client
attempting to (re)locate a region. If I manage to capture it I will file
a jira.
- Andy
Re: Regionserver problems because of datanode timeouts
Posted by Ferdy <fe...@kalooga.com>.
For the moment we cannot afford to reduce the timeouts (hbase is stable,
so we're happy for now). This being said, I cannot detect any abnormal
behaviour in Munin.
However, once and every while our Nagios (our service monitor) detects
that requesting the Hbase master page takes a long time. Sometimes > 10
sec, rarely around 30 secs but most of the time < 10 secs. In the cases
the page loads slowly, there is a fair amount of load on Hbase.
I will get back on this issue when I have more information. Thanks so far.
Ferdy
Jean-Daniel Cryans wrote:
> Prior to region server failures, do you see anything in your Munin graphs?
>
> J-D
>
> On Tue, Mar 9, 2010 at 2:02 AM, Ferdy <fe...@kalooga.com> wrote:
>
>> Hi,
>>
>> @Michael
>> You must be referring to https://issues.apache.org/jira/browse/HBASE-2174.
>> This might very well be the problem. I will look into this patch.
>>
>> @J-D
>> We finetuned our configurion to the point that every process (both daemons
>> and job tasks) should have enough RAM and swapping should never occur. I can
>> verify that this indeed is the case. (We're using Muning, it does a fine
>> task at monitoring performance basics).
>>
>> To sum it up:
>> -Hbase regionservers are having troubles even when there is no direct load
>> (but there are other non-hbase hadoop jobs)
>> -all Hadoop and Hbase processes use incremental garbage collect options
>> -no swapping occurs ever
>> -we can circumvent the problem by using very long timeouts
>>
>> I have a strong feeling it's network-related, because our non-hbase hadoop
>> jobs do generate a lot of DNS requests.
>>
>> Ferdy
>>
>> Michael Segel wrote:
>>
>>> This looks similar to the problem we were having with 'flaky dns'.
>>> I just got the patched sources built. (rpmbuild was barfing on a lot of
>>> little things that had to be tweaked....) We put it in place last night and
>>> so far we're Ok.
>>>
>>> This morning our IS guys were in and looked at their logs from over the
>>> weekend. It looks like HBase was querying a bunch of different DNS servers
>>> on both IPV6 and IPV4.
>>> Not sure if this was causing the error or making HBase think our DNS was
>>> 'flaky'. (I don't know because I can't control the network or DNS.)
>>>
>>> If you look back on this thread, you should be able to find the patches.
>>>
>>> HTH
>>>
>>> -Mike
>>>
>>>
>>>
>>>
>>>> Date: Mon, 8 Mar 2010 10:00:30 -0800
>>>> Subject: Re: Regionserver problems because of datanode timeouts
>>>> From: jdcryans@apache.org
>>>> To: hbase-user@hadoop.apache.org
>>>>
>>>> Hey,
>>>>
>>>> Sorry I forgot to answer last month, your mail slipped though others.
>>>>
>>>> So you were saying that HBase would be failing even if not used, but
>>>> as you said the cluster itself is used for heavy IO jobs. This is a
>>>> problem for the default hbase configurations as you can see, but I'm
>>>> also wondering if you swapping a lot with all those concurrent tasks
>>>> running on your nodes? If so, it could explain the "random" failures
>>>> easily.
>>>>
>>>> J-D
>>>>
>>>> On Mon, Mar 8, 2010 at 3:04 AM, Ferdy <fe...@kalooga.com> wrote:
>>>>
>>>>
>>>>> Hi,
>>>>>
>>>>> Perhaps this is of use to anyone else:
>>>>>
>>>>> We tried all hbase versions up to 0.20.3 but it did not seem to make a
>>>>> difference for our problem. However when using the following properties
>>>>> the
>>>>> problem seems to be solved. The properties simply apply ridiculously
>>>>> long
>>>>> timeouts, but that doesn't bother us since we only use hbase for offline
>>>>> processing.
>>>>>
>>>>> <!--
>>>>> in hbase-site.xml:
>>>>> -->
>>>>>
>>>>> <property>
>>>>> <name>hbase.zookeeper.property.tickTime</name>
>>>>> <value>20000</value>
>>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>>> The number of milliseconds of each tick. See
>>>>> zookeeper.session.timeout description.
>>>>> </description>
>>>>> </property>
>>>>>
>>>>> <property>
>>>>> <name>hbase.zookeeper.property.initLimit</name>
>>>>> <value>20</value>
>>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>>> The number of ticks that the initial synchronization phase can take.
>>>>> </description>
>>>>> </property>
>>>>>
>>>>> <property>
>>>>> <name>hbase.zookeeper.property.syncLimit</name>
>>>>> <value>20</value>
>>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>>> The number of ticks that can pass between sending a request and getting
>>>>> an
>>>>> acknowledgment.
>>>>> </description>
>>>>> </property>
>>>>>
>>>>> <property>
>>>>> <name>zookeeper.session.timeout</name>
>>>>> <value>400000</value>
>>>>> <description>ZooKeeper session timeout.
>>>>> HBase passes this to the zk quorum as suggested maximum time for a
>>>>> session. See
>>>>>
>>>>> http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
>>>>> "The client sends a requested timeout, the server responds with the
>>>>> timeout that it can give the client. The current implementation
>>>>> requires that the timeout be a minimum of 2 times the tickTime
>>>>> (as set in the server configuration) and a maximum of 20 times
>>>>> the tickTime." Set the zk ticktime with
>>>>> hbase.zookeeper.property.tickTime.
>>>>> In milliseconds.
>>>>> </description>
>>>>> </property>
>>>>>
>>>>> <property>
>>>>> <name>hbase.regionserver.lease.period</name>
>>>>> <value>400000</value>
>>>>> <description>HRegion server lease period in milliseconds. Default is
>>>>> 60 seconds. Clients must report in within this period else they are
>>>>> considered dead.</description>
>>>>> </property>
>>>>>
>>>>> <property>
>>>>> <name>dfs.socket.timeout</name>
>>>>> <value>400000</value>
>>>>> </property>
>>>>>
>>>>>
>>>>> <!--
>>>>> in hdfs-site.xml:
>>>>> -->
>>>>>
>>>>> <property>
>>>>> <name>dfs.socket.timeout</name>
>>>>> <value>400000</value>
>>>>> </property>
>>>>>
>>>>>
>>>>>
>>> _________________________________________________________________
>>> Your E-mail and More On-the-Go. Get Windows Live Hotmail Free.
>>> http://clk.atdmt.com/GBL/go/201469229/direct/01/
>>>
>>>
Re: Regionserver problems because of datanode timeouts
Posted by Jean-Daniel Cryans <jd...@apache.org>.
Prior to region server failures, do you see anything in your Munin graphs?
J-D
On Tue, Mar 9, 2010 at 2:02 AM, Ferdy <fe...@kalooga.com> wrote:
> Hi,
>
> @Michael
> You must be referring to https://issues.apache.org/jira/browse/HBASE-2174.
> This might very well be the problem. I will look into this patch.
>
> @J-D
> We finetuned our configurion to the point that every process (both daemons
> and job tasks) should have enough RAM and swapping should never occur. I can
> verify that this indeed is the case. (We're using Muning, it does a fine
> task at monitoring performance basics).
>
> To sum it up:
> -Hbase regionservers are having troubles even when there is no direct load
> (but there are other non-hbase hadoop jobs)
> -all Hadoop and Hbase processes use incremental garbage collect options
> -no swapping occurs ever
> -we can circumvent the problem by using very long timeouts
>
> I have a strong feeling it's network-related, because our non-hbase hadoop
> jobs do generate a lot of DNS requests.
>
> Ferdy
>
> Michael Segel wrote:
>>
>> This looks similar to the problem we were having with 'flaky dns'.
>> I just got the patched sources built. (rpmbuild was barfing on a lot of
>> little things that had to be tweaked....) We put it in place last night and
>> so far we're Ok.
>>
>> This morning our IS guys were in and looked at their logs from over the
>> weekend. It looks like HBase was querying a bunch of different DNS servers
>> on both IPV6 and IPV4.
>> Not sure if this was causing the error or making HBase think our DNS was
>> 'flaky'. (I don't know because I can't control the network or DNS.)
>>
>> If you look back on this thread, you should be able to find the patches.
>>
>> HTH
>>
>> -Mike
>>
>>
>>
>>>
>>> Date: Mon, 8 Mar 2010 10:00:30 -0800
>>> Subject: Re: Regionserver problems because of datanode timeouts
>>> From: jdcryans@apache.org
>>> To: hbase-user@hadoop.apache.org
>>>
>>> Hey,
>>>
>>> Sorry I forgot to answer last month, your mail slipped though others.
>>>
>>> So you were saying that HBase would be failing even if not used, but
>>> as you said the cluster itself is used for heavy IO jobs. This is a
>>> problem for the default hbase configurations as you can see, but I'm
>>> also wondering if you swapping a lot with all those concurrent tasks
>>> running on your nodes? If so, it could explain the "random" failures
>>> easily.
>>>
>>> J-D
>>>
>>> On Mon, Mar 8, 2010 at 3:04 AM, Ferdy <fe...@kalooga.com> wrote:
>>>
>>>>
>>>> Hi,
>>>>
>>>> Perhaps this is of use to anyone else:
>>>>
>>>> We tried all hbase versions up to 0.20.3 but it did not seem to make a
>>>> difference for our problem. However when using the following properties
>>>> the
>>>> problem seems to be solved. The properties simply apply ridiculously
>>>> long
>>>> timeouts, but that doesn't bother us since we only use hbase for offline
>>>> processing.
>>>>
>>>> <!--
>>>> in hbase-site.xml:
>>>> -->
>>>>
>>>> <property>
>>>> <name>hbase.zookeeper.property.tickTime</name>
>>>> <value>20000</value>
>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>> The number of milliseconds of each tick. See
>>>> zookeeper.session.timeout description.
>>>> </description>
>>>> </property>
>>>>
>>>> <property>
>>>> <name>hbase.zookeeper.property.initLimit</name>
>>>> <value>20</value>
>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>> The number of ticks that the initial synchronization phase can take.
>>>> </description>
>>>> </property>
>>>>
>>>> <property>
>>>> <name>hbase.zookeeper.property.syncLimit</name>
>>>> <value>20</value>
>>>> <description>Property from ZooKeeper's config zoo.cfg.
>>>> The number of ticks that can pass between sending a request and getting
>>>> an
>>>> acknowledgment.
>>>> </description>
>>>> </property>
>>>>
>>>> <property>
>>>> <name>zookeeper.session.timeout</name>
>>>> <value>400000</value>
>>>> <description>ZooKeeper session timeout.
>>>> HBase passes this to the zk quorum as suggested maximum time for a
>>>> session. See
>>>>
>>>> http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
>>>> "The client sends a requested timeout, the server responds with the
>>>> timeout that it can give the client. The current implementation
>>>> requires that the timeout be a minimum of 2 times the tickTime
>>>> (as set in the server configuration) and a maximum of 20 times
>>>> the tickTime." Set the zk ticktime with
>>>> hbase.zookeeper.property.tickTime.
>>>> In milliseconds.
>>>> </description>
>>>> </property>
>>>>
>>>> <property>
>>>> <name>hbase.regionserver.lease.period</name>
>>>> <value>400000</value>
>>>> <description>HRegion server lease period in milliseconds. Default is
>>>> 60 seconds. Clients must report in within this period else they are
>>>> considered dead.</description>
>>>> </property>
>>>>
>>>> <property>
>>>> <name>dfs.socket.timeout</name>
>>>> <value>400000</value>
>>>> </property>
>>>>
>>>>
>>>> <!--
>>>> in hdfs-site.xml:
>>>> -->
>>>>
>>>> <property>
>>>> <name>dfs.socket.timeout</name>
>>>> <value>400000</value>
>>>> </property>
>>>>
>>>>
>>
>>
>> _________________________________________________________________
>> Your E-mail and More On-the-Go. Get Windows Live Hotmail Free.
>> http://clk.atdmt.com/GBL/go/201469229/direct/01/
>>
>
Re: Regionserver problems because of datanode timeouts
Posted by Ferdy <fe...@kalooga.com>.
Hi,
@Michael
You must be referring to
https://issues.apache.org/jira/browse/HBASE-2174. This might very well
be the problem. I will look into this patch.
@J-D
We finetuned our configurion to the point that every process (both
daemons and job tasks) should have enough RAM and swapping should never
occur. I can verify that this indeed is the case. (We're using Muning,
it does a fine task at monitoring performance basics).
To sum it up:
-Hbase regionservers are having troubles even when there is no direct
load (but there are other non-hbase hadoop jobs)
-all Hadoop and Hbase processes use incremental garbage collect options
-no swapping occurs ever
-we can circumvent the problem by using very long timeouts
I have a strong feeling it's network-related, because our non-hbase
hadoop jobs do generate a lot of DNS requests.
Ferdy
Michael Segel wrote:
> This looks similar to the problem we were having with 'flaky dns'.
> I just got the patched sources built. (rpmbuild was barfing on a lot of little things that had to be tweaked....) We put it in place last night and so far we're Ok.
>
> This morning our IS guys were in and looked at their logs from over the weekend.
> It looks like HBase was querying a bunch of different DNS servers on both IPV6 and IPV4.
> Not sure if this was causing the error or making HBase think our DNS was 'flaky'.
> (I don't know because I can't control the network or DNS.)
>
> If you look back on this thread, you should be able to find the patches.
>
> HTH
>
> -Mike
>
>
>
>> Date: Mon, 8 Mar 2010 10:00:30 -0800
>> Subject: Re: Regionserver problems because of datanode timeouts
>> From: jdcryans@apache.org
>> To: hbase-user@hadoop.apache.org
>>
>> Hey,
>>
>> Sorry I forgot to answer last month, your mail slipped though others.
>>
>> So you were saying that HBase would be failing even if not used, but
>> as you said the cluster itself is used for heavy IO jobs. This is a
>> problem for the default hbase configurations as you can see, but I'm
>> also wondering if you swapping a lot with all those concurrent tasks
>> running on your nodes? If so, it could explain the "random" failures
>> easily.
>>
>> J-D
>>
>> On Mon, Mar 8, 2010 at 3:04 AM, Ferdy <fe...@kalooga.com> wrote:
>>
>>> Hi,
>>>
>>> Perhaps this is of use to anyone else:
>>>
>>> We tried all hbase versions up to 0.20.3 but it did not seem to make a
>>> difference for our problem. However when using the following properties the
>>> problem seems to be solved. The properties simply apply ridiculously long
>>> timeouts, but that doesn't bother us since we only use hbase for offline
>>> processing.
>>>
>>> <!--
>>> in hbase-site.xml:
>>> -->
>>>
>>> <property>
>>> <name>hbase.zookeeper.property.tickTime</name>
>>> <value>20000</value>
>>> <description>Property from ZooKeeper's config zoo.cfg.
>>> The number of milliseconds of each tick. See
>>> zookeeper.session.timeout description.
>>> </description>
>>> </property>
>>>
>>> <property>
>>> <name>hbase.zookeeper.property.initLimit</name>
>>> <value>20</value>
>>> <description>Property from ZooKeeper's config zoo.cfg.
>>> The number of ticks that the initial synchronization phase can take.
>>> </description>
>>> </property>
>>>
>>> <property>
>>> <name>hbase.zookeeper.property.syncLimit</name>
>>> <value>20</value>
>>> <description>Property from ZooKeeper's config zoo.cfg.
>>> The number of ticks that can pass between sending a request and getting an
>>> acknowledgment.
>>> </description>
>>> </property>
>>>
>>> <property>
>>> <name>zookeeper.session.timeout</name>
>>> <value>400000</value>
>>> <description>ZooKeeper session timeout.
>>> HBase passes this to the zk quorum as suggested maximum time for a
>>> session. See
>>> http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
>>> "The client sends a requested timeout, the server responds with the
>>> timeout that it can give the client. The current implementation
>>> requires that the timeout be a minimum of 2 times the tickTime
>>> (as set in the server configuration) and a maximum of 20 times
>>> the tickTime." Set the zk ticktime with
>>> hbase.zookeeper.property.tickTime.
>>> In milliseconds.
>>> </description>
>>> </property>
>>>
>>> <property>
>>> <name>hbase.regionserver.lease.period</name>
>>> <value>400000</value>
>>> <description>HRegion server lease period in milliseconds. Default is
>>> 60 seconds. Clients must report in within this period else they are
>>> considered dead.</description>
>>> </property>
>>>
>>> <property>
>>> <name>dfs.socket.timeout</name>
>>> <value>400000</value>
>>> </property>
>>>
>>>
>>> <!--
>>> in hdfs-site.xml:
>>> -->
>>>
>>> <property>
>>> <name>dfs.socket.timeout</name>
>>> <value>400000</value>
>>> </property>
>>>
>>>
>
> _________________________________________________________________
> Your E-mail and More On-the-Go. Get Windows Live Hotmail Free.
> http://clk.atdmt.com/GBL/go/201469229/direct/01/
>
RE: Regionserver problems because of datanode timeouts
Posted by Michael Segel <mi...@hotmail.com>.
This looks similar to the problem we were having with 'flaky dns'.
I just got the patched sources built. (rpmbuild was barfing on a lot of little things that had to be tweaked....) We put it in place last night and so far we're Ok.
This morning our IS guys were in and looked at their logs from over the weekend.
It looks like HBase was querying a bunch of different DNS servers on both IPV6 and IPV4.
Not sure if this was causing the error or making HBase think our DNS was 'flaky'.
(I don't know because I can't control the network or DNS.)
If you look back on this thread, you should be able to find the patches.
HTH
-Mike
> Date: Mon, 8 Mar 2010 10:00:30 -0800
> Subject: Re: Regionserver problems because of datanode timeouts
> From: jdcryans@apache.org
> To: hbase-user@hadoop.apache.org
>
> Hey,
>
> Sorry I forgot to answer last month, your mail slipped though others.
>
> So you were saying that HBase would be failing even if not used, but
> as you said the cluster itself is used for heavy IO jobs. This is a
> problem for the default hbase configurations as you can see, but I'm
> also wondering if you swapping a lot with all those concurrent tasks
> running on your nodes? If so, it could explain the "random" failures
> easily.
>
> J-D
>
> On Mon, Mar 8, 2010 at 3:04 AM, Ferdy <fe...@kalooga.com> wrote:
> > Hi,
> >
> > Perhaps this is of use to anyone else:
> >
> > We tried all hbase versions up to 0.20.3 but it did not seem to make a
> > difference for our problem. However when using the following properties the
> > problem seems to be solved. The properties simply apply ridiculously long
> > timeouts, but that doesn't bother us since we only use hbase for offline
> > processing.
> >
> > <!--
> > in hbase-site.xml:
> > -->
> >
> > <property>
> > <name>hbase.zookeeper.property.tickTime</name>
> > <value>20000</value>
> > <description>Property from ZooKeeper's config zoo.cfg.
> > The number of milliseconds of each tick. See
> > zookeeper.session.timeout description.
> > </description>
> > </property>
> >
> > <property>
> > <name>hbase.zookeeper.property.initLimit</name>
> > <value>20</value>
> > <description>Property from ZooKeeper's config zoo.cfg.
> > The number of ticks that the initial synchronization phase can take.
> > </description>
> > </property>
> >
> > <property>
> > <name>hbase.zookeeper.property.syncLimit</name>
> > <value>20</value>
> > <description>Property from ZooKeeper's config zoo.cfg.
> > The number of ticks that can pass between sending a request and getting an
> > acknowledgment.
> > </description>
> > </property>
> >
> > <property>
> > <name>zookeeper.session.timeout</name>
> > <value>400000</value>
> > <description>ZooKeeper session timeout.
> > HBase passes this to the zk quorum as suggested maximum time for a
> > session. See
> > http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
> > "The client sends a requested timeout, the server responds with the
> > timeout that it can give the client. The current implementation
> > requires that the timeout be a minimum of 2 times the tickTime
> > (as set in the server configuration) and a maximum of 20 times
> > the tickTime." Set the zk ticktime with
> > hbase.zookeeper.property.tickTime.
> > In milliseconds.
> > </description>
> > </property>
> >
> > <property>
> > <name>hbase.regionserver.lease.period</name>
> > <value>400000</value>
> > <description>HRegion server lease period in milliseconds. Default is
> > 60 seconds. Clients must report in within this period else they are
> > considered dead.</description>
> > </property>
> >
> > <property>
> > <name>dfs.socket.timeout</name>
> > <value>400000</value>
> > </property>
> >
> >
> > <!--
> > in hdfs-site.xml:
> > -->
> >
> > <property>
> > <name>dfs.socket.timeout</name>
> > <value>400000</value>
> > </property>
> >
_________________________________________________________________
Your E-mail and More On-the-Go. Get Windows Live Hotmail Free.
http://clk.atdmt.com/GBL/go/201469229/direct/01/
Re: Regionserver problems because of datanode timeouts
Posted by Jean-Daniel Cryans <jd...@apache.org>.
Hey,
Sorry I forgot to answer last month, your mail slipped though others.
So you were saying that HBase would be failing even if not used, but
as you said the cluster itself is used for heavy IO jobs. This is a
problem for the default hbase configurations as you can see, but I'm
also wondering if you swapping a lot with all those concurrent tasks
running on your nodes? If so, it could explain the "random" failures
easily.
J-D
On Mon, Mar 8, 2010 at 3:04 AM, Ferdy <fe...@kalooga.com> wrote:
> Hi,
>
> Perhaps this is of use to anyone else:
>
> We tried all hbase versions up to 0.20.3 but it did not seem to make a
> difference for our problem. However when using the following properties the
> problem seems to be solved. The properties simply apply ridiculously long
> timeouts, but that doesn't bother us since we only use hbase for offline
> processing.
>
> <!--
> in hbase-site.xml:
> -->
>
> <property>
> <name>hbase.zookeeper.property.tickTime</name>
> <value>20000</value>
> <description>Property from ZooKeeper's config zoo.cfg.
> The number of milliseconds of each tick. See
> zookeeper.session.timeout description.
> </description>
> </property>
>
> <property>
> <name>hbase.zookeeper.property.initLimit</name>
> <value>20</value>
> <description>Property from ZooKeeper's config zoo.cfg.
> The number of ticks that the initial synchronization phase can take.
> </description>
> </property>
>
> <property>
> <name>hbase.zookeeper.property.syncLimit</name>
> <value>20</value>
> <description>Property from ZooKeeper's config zoo.cfg.
> The number of ticks that can pass between sending a request and getting an
> acknowledgment.
> </description>
> </property>
>
> <property>
> <name>zookeeper.session.timeout</name>
> <value>400000</value>
> <description>ZooKeeper session timeout.
> HBase passes this to the zk quorum as suggested maximum time for a
> session. See
> http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
> "The client sends a requested timeout, the server responds with the
> timeout that it can give the client. The current implementation
> requires that the timeout be a minimum of 2 times the tickTime
> (as set in the server configuration) and a maximum of 20 times
> the tickTime." Set the zk ticktime with
> hbase.zookeeper.property.tickTime.
> In milliseconds.
> </description>
> </property>
>
> <property>
> <name>hbase.regionserver.lease.period</name>
> <value>400000</value>
> <description>HRegion server lease period in milliseconds. Default is
> 60 seconds. Clients must report in within this period else they are
> considered dead.</description>
> </property>
>
> <property>
> <name>dfs.socket.timeout</name>
> <value>400000</value>
> </property>
>
>
> <!--
> in hdfs-site.xml:
> -->
>
> <property>
> <name>dfs.socket.timeout</name>
> <value>400000</value>
> </property>
>
Re: Regionserver problems because of datanode timeouts
Posted by Ferdy <fe...@kalooga.com>.
Hi,
Perhaps this is of use to anyone else:
We tried all hbase versions up to 0.20.3 but it did not seem to make a
difference for our problem. However when using the following properties
the problem seems to be solved. The properties simply apply ridiculously
long timeouts, but that doesn't bother us since we only use hbase for
offline processing.
<!--
in hbase-site.xml:
-->
<property>
<name>hbase.zookeeper.property.tickTime</name>
<value>20000</value>
<description>Property from ZooKeeper's config zoo.cfg.
The number of milliseconds of each tick. See
zookeeper.session.timeout description.
</description>
</property>
<property>
<name>hbase.zookeeper.property.initLimit</name>
<value>20</value>
<description>Property from ZooKeeper's config zoo.cfg.
The number of ticks that the initial synchronization phase can take.
</description>
</property>
<property>
<name>hbase.zookeeper.property.syncLimit</name>
<value>20</value>
<description>Property from ZooKeeper's config zoo.cfg.
The number of ticks that can pass between sending a request and
getting an
acknowledgment.
</description>
</property>
<property>
<name>zookeeper.session.timeout</name>
<value>400000</value>
<description>ZooKeeper session timeout.
HBase passes this to the zk quorum as suggested maximum time for a
session. See
http://hadoop.apache.org/zookeeper/docs/current/zookeeperProgrammers.html#ch_zkSessions
"The client sends a requested timeout, the server responds with the
timeout that it can give the client. The current implementation
requires that the timeout be a minimum of 2 times the tickTime
(as set in the server configuration) and a maximum of 20 times
the tickTime." Set the zk ticktime with
hbase.zookeeper.property.tickTime.
In milliseconds.
</description>
</property>
<property>
<name>hbase.regionserver.lease.period</name>
<value>400000</value>
<description>HRegion server lease period in milliseconds. Default is
60 seconds. Clients must report in within this period else they are
considered dead.</description>
</property>
<property>
<name>dfs.socket.timeout</name>
<value>400000</value>
</property>
<!--
in hdfs-site.xml:
-->
<property>
<name>dfs.socket.timeout</name>
<value>400000</value>
</property>
Ferdy wrote:
> Hi,
>
> Increasing the memory did not work. Is it possible to increase the
> time out period? All our jobs are offline processing jobs, so I'd
> rather have a low responsiveness than a Zookeeper that decides to
> terminate a regionserver.
>
> I also noticed that a regionserver crash also happens when there is no
> load at all on Hbase, in other words they seem to occur randomly.
>
> Ferdy
>
> Jean-Daniel Cryans wrote:
>> I see more than one problem here.
>>
>>
>>> DFSOutputStream ResponseProcessor exception for block
>>> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
>>>
>>
>> As you said your HDFS is getting hit a lot and this is a sign of it.
>> Some people use dfs.datanode.socket.write.timeout and
>> dfs.datanode.socket.read.timeout set to very high values in that case
>> (like more than 10 minutes). If you want to serve live data from HBase
>> it's really not the best and you should consider separating processing
>> and serving in 2 clusters OR lower the number of tasks on the nodes.
>>
>>
>>> java.io.IOException: TIMED OUT
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
>>> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper:
>>> We slept
>>> 66554ms, ten times longer than scheduled: 3000
>>>
>>
>> This means your region server was garbage collecting for more than a
>> minute, which is higher than the default time to consider a region
>> server as dead. This lead to:
>>
>>
>>> java.io.IOException: Session Expired
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
>>>
>>>
>>
>> This is how we notice a server is gone missing, each region server has
>> an ephemeral node in Zookeeper and they lose it after 40 secs in
>> 0.20.2 (and previous) and after 60 secs in 0.20.3.
>>
>> Consider giving at least 4GB of heap to the region servers and make
>> sure you never swap.
>>
>> J-D
>>
>> On Wed, Jan 20, 2010 at 8:22 AM, Ferdy <fe...@kalooga.com> wrote:
>>
>>> Hello,
>>>
>>> I am having issues of regionservers shutting down because the
>>> underlying DFS
>>> is having trouble. I cannot get the DFS to function properly. I
>>> attached a
>>> log of our regionserver below. At first sight it looks like there is a
>>> timeout that occurs while the regionservers was trying to connect to
>>> it's
>>> own datanode:
>>> java.net.SocketTimeoutException: 69000 millis timeout while waiting for
>>> channel to be ready for read. ch :
>>> java.nio.channels.SocketChannel[connected
>>> local=/172.23.122.23:39203 remote=/172.23.122.23:50010]
>>>
>>> The datanode logs show similar timeout errors (also when trying to
>>> connect
>>> to local host).
>>>
>>> Our configuration:
>>> * Hadoop 0.20.1 and Hbase 0.20.2
>>> * 20 nodes: each datanode/tasktracker and regionserver
>>> * ulimit = 32000 on each node
>>> * dfs.datanode.max.xcievers=5000 (should be big enough i presume)
>>> * dfs.namenode.handler.count=30 (3 times the default)
>>> * dfs.datanode.handler.count=9 (3 times the default)
>>> * Our DFS contain around 500.000 blocks (64MB blocksize). Each
>>> datanode has
>>> 1600M heapsize. The datanodes are started with the
>>> -XX:+UseConcMarkSweepGC
>>> -XX:+CMSIncrementalMode options.
>>> * The DFS is fairly heavily used. (Always running a few concurrent
>>> MapRed
>>> jobs, with average IO)
>>>
>>> Anyone a clue what might be going on?
>>>
>>> Regards,
>>> Ferdy.
>>>
>>> THE REGIONSERVER LOG:
>>> 2010-01-20 13:52:15,982 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU
>>> eviction
>>> started. Attempting to free 22928768 bytes
>>> 2010-01-20 13:52:15,988 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU
>>> eviction
>>> completed. Freed 22985616 bytes. Priority Sizes: Single=84.519615MB
>>> (88625240), Multi=99.30783MB (104131808),Memory=0.0MB (0)
>>> 2010-01-20 13:53:03,613 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>>> Total=169.96802MB (178224384), Free=48.36949MB (50719088),
>>> Max=218.33751MB
>>> (228943472), Counts: Blocks=2683, Access=184190, Hit=10090,
>>> Miss=174100,
>>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.478039011359215%, Miss
>>> Ratio=94.521963596344%, Evicted/Run=349.0
>>> 2010-01-20 13:54:03,605 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>>> Total=174.83826MB (183331208), Free=43.499245MB (45612264),
>>> Max=218.33751MB
>>> (228943472), Counts: Blocks=2762, Access=184477, Hit=10298,
>>> Miss=174179,
>>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.582267791032791%, Miss
>>> Ratio=94.41773295402527%, Evicted/Run=349.0
>>> 2010-01-20 13:55:45,744 WARN org.apache.hadoop.hdfs.DFSClient:
>>> DFSOutputStream ResponseProcessor exception for block
>>> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
>>> millis timeout while waiting for channel to be ready for read. ch :
>>> java.nio.channels.SocketChannel[connected local=/172.23.122.23:39203
>>> remote=/172.23.122.23:50010]
>>> at
>>> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
>>>
>>> at
>>> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
>>>
>>> at
>>> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
>>>
>>> at java.io.DataInputStream.readFully(Unknown Source)
>>> at java.io.DataInputStream.readLong(Unknown Source)
>>> at
>>> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$ResponseProcessor.run(DFSClient.java:2399)
>>>
>>>
>>> 2010-01-20 13:55:45,744 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>>> Total=178.23663MB (186894656), Free=40.100876MB (42048816),
>>> Max=218.33751MB
>>> (228943472), Counts: Blocks=2816, Access=184676, Hit=10443,
>>> Miss=174233,
>>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.654768273234367%, Miss
>>> Ratio=94.34522986412048%, Evicted/Run=349.0
>>> 2010-01-20 13:55:45,745 WARN org.apache.zookeeper.ClientCnxn: Exception
>>> closing session 0x1264b1fe3240006 to
>>> sun.nio.ch.SelectionKeyImpl@2f242b11
>>> java.io.IOException: TIMED OUT
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
>>> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper:
>>> We slept
>>> 66554ms, ten times longer than scheduled: 3000
>>> 2010-01-20 13:55:45,911 INFO
>>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper
>>> event,
>>> state: Disconnected, type: None, path: null
>>> 2010-01-20 13:55:46,178 WARN
>>> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempt=1
>>> org.apache.hadoop.hbase.Leases$LeaseStillHeldException
>>> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>>> Method)
>>> at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown
>>> Source)
>>> at
>>> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown
>>> Source)
>>> at java.lang.reflect.Constructor.newInstance(Unknown Source)
>>> at
>>> org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
>>>
>>> at
>>> org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
>>>
>>> at
>>> org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
>>>
>>> at
>>> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:571)
>>>
>>> at java.lang.Thread.run(Unknown Source)
>>> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
>>> Recovery for block blk_-209323108721490976_6065406 bad datanode[0]
>>> 172.23.122.23:50010
>>> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
>>> Recovery for block blk_-209323108721490976_6065406 in pipeline
>>> 172.23.122.23:50010, 172.23.122.16:50010,172.23.122.22:50010: bad
>>> datanode
>>> 172.23.122.23:50010
>>> 2010-01-20 13:55:46,623 WARN
>>> org.apache.hadoop.hbase.regionserver.HLog: IPC
>>> Server handler 3 on 60020 took 71023ms appending an edit to hlog;
>>> editcount=41251
>>> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
>>> regionserver/172.23.122.23:60020.logFlusher took 67200ms optional
>>> sync'ing
>>> hlog; editcount=41271
>>> 2010-01-20 13:55:46,623 WARN
>>> org.apache.hadoop.hbase.regionserver.HLog: IPC
>>> Server handler 1 on 60020 took 69781ms appending an edit to hlog;
>>> editcount=41271
>>> 2010-01-20 13:55:47,081 INFO org.apache.zookeeper.ClientCnxn:
>>> Attempting
>>> connection to server c1.machines.nl/172.23.122.1:2181
>>> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Priming
>>> connection to java.nio.channels.SocketChannel[connected
>>> local=/172.23.122.23:53151 remote=c1/172.23.122.1:2181]
>>> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Server
>>> connection successful
>>> 2010-01-20 13:55:47,083 WARN org.apache.zookeeper.ClientCnxn: Exception
>>> closing session 0x1264b1fe3240006 to
>>> sun.nio.ch.SelectionKeyImpl@5f84f3d2
>>> java.io.IOException: Session Expired
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
>>>
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:709)
>>> at
>>> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
>>> 2010-01-20 13:55:47,086 INFO
>>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper
>>> event,
>>> state: Expired, type: None, path: null
>>> 2010-01-20 13:55:47,086 ERROR
>>> org.apache.hadoop.hbase.regionserver.HRegionServer: ZooKeeper session
>>> expired
>>>
>>>
>>>
>>
>>
>
Re: Regionserver problems because of datanode timeouts
Posted by Ferdy <fe...@kalooga.com>.
Hi,
Increasing the memory did not work. Is it possible to increase the time
out period? All our jobs are offline processing jobs, so I'd rather have
a low responsiveness than a Zookeeper that decides to terminate a
regionserver.
I also noticed that a regionserver crash also happens when there is no
load at all on Hbase, in other words they seem to occur randomly.
Ferdy
Jean-Daniel Cryans wrote:
> I see more than one problem here.
>
>
>> DFSOutputStream ResponseProcessor exception for block
>> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
>>
>
> As you said your HDFS is getting hit a lot and this is a sign of it.
> Some people use dfs.datanode.socket.write.timeout and
> dfs.datanode.socket.read.timeout set to very high values in that case
> (like more than 10 minutes). If you want to serve live data from HBase
> it's really not the best and you should consider separating processing
> and serving in 2 clusters OR lower the number of tasks on the nodes.
>
>
>> java.io.IOException: TIMED OUT
>> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
>> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper: We slept
>> 66554ms, ten times longer than scheduled: 3000
>>
>
> This means your region server was garbage collecting for more than a
> minute, which is higher than the default time to consider a region
> server as dead. This lead to:
>
>
>> java.io.IOException: Session Expired
>> at
>> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
>>
>
> This is how we notice a server is gone missing, each region server has
> an ephemeral node in Zookeeper and they lose it after 40 secs in
> 0.20.2 (and previous) and after 60 secs in 0.20.3.
>
> Consider giving at least 4GB of heap to the region servers and make
> sure you never swap.
>
> J-D
>
> On Wed, Jan 20, 2010 at 8:22 AM, Ferdy <fe...@kalooga.com> wrote:
>
>> Hello,
>>
>> I am having issues of regionservers shutting down because the underlying DFS
>> is having trouble. I cannot get the DFS to function properly. I attached a
>> log of our regionserver below. At first sight it looks like there is a
>> timeout that occurs while the regionservers was trying to connect to it's
>> own datanode:
>> java.net.SocketTimeoutException: 69000 millis timeout while waiting for
>> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
>> local=/172.23.122.23:39203 remote=/172.23.122.23:50010]
>>
>> The datanode logs show similar timeout errors (also when trying to connect
>> to local host).
>>
>> Our configuration:
>> * Hadoop 0.20.1 and Hbase 0.20.2
>> * 20 nodes: each datanode/tasktracker and regionserver
>> * ulimit = 32000 on each node
>> * dfs.datanode.max.xcievers=5000 (should be big enough i presume)
>> * dfs.namenode.handler.count=30 (3 times the default)
>> * dfs.datanode.handler.count=9 (3 times the default)
>> * Our DFS contain around 500.000 blocks (64MB blocksize). Each datanode has
>> 1600M heapsize. The datanodes are started with the -XX:+UseConcMarkSweepGC
>> -XX:+CMSIncrementalMode options.
>> * The DFS is fairly heavily used. (Always running a few concurrent MapRed
>> jobs, with average IO)
>>
>> Anyone a clue what might be going on?
>>
>> Regards,
>> Ferdy.
>>
>> THE REGIONSERVER LOG:
>> 2010-01-20 13:52:15,982 DEBUG
>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
>> started. Attempting to free 22928768 bytes
>> 2010-01-20 13:52:15,988 DEBUG
>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
>> completed. Freed 22985616 bytes. Priority Sizes: Single=84.519615MB
>> (88625240), Multi=99.30783MB (104131808),Memory=0.0MB (0)
>> 2010-01-20 13:53:03,613 DEBUG
>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>> Total=169.96802MB (178224384), Free=48.36949MB (50719088), Max=218.33751MB
>> (228943472), Counts: Blocks=2683, Access=184190, Hit=10090, Miss=174100,
>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.478039011359215%, Miss
>> Ratio=94.521963596344%, Evicted/Run=349.0
>> 2010-01-20 13:54:03,605 DEBUG
>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>> Total=174.83826MB (183331208), Free=43.499245MB (45612264), Max=218.33751MB
>> (228943472), Counts: Blocks=2762, Access=184477, Hit=10298, Miss=174179,
>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.582267791032791%, Miss
>> Ratio=94.41773295402527%, Evicted/Run=349.0
>> 2010-01-20 13:55:45,744 WARN org.apache.hadoop.hdfs.DFSClient:
>> DFSOutputStream ResponseProcessor exception for block
>> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
>> millis timeout while waiting for channel to be ready for read. ch :
>> java.nio.channels.SocketChannel[connected local=/172.23.122.23:39203
>> remote=/172.23.122.23:50010]
>> at
>> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
>> at
>> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
>> at
>> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
>> at java.io.DataInputStream.readFully(Unknown Source)
>> at java.io.DataInputStream.readLong(Unknown Source)
>> at
>> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$ResponseProcessor.run(DFSClient.java:2399)
>>
>> 2010-01-20 13:55:45,744 DEBUG
>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>> Total=178.23663MB (186894656), Free=40.100876MB (42048816), Max=218.33751MB
>> (228943472), Counts: Blocks=2816, Access=184676, Hit=10443, Miss=174233,
>> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.654768273234367%, Miss
>> Ratio=94.34522986412048%, Evicted/Run=349.0
>> 2010-01-20 13:55:45,745 WARN org.apache.zookeeper.ClientCnxn: Exception
>> closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@2f242b11
>> java.io.IOException: TIMED OUT
>> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
>> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper: We slept
>> 66554ms, ten times longer than scheduled: 3000
>> 2010-01-20 13:55:45,911 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
>> state: Disconnected, type: None, path: null
>> 2010-01-20 13:55:46,178 WARN
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempt=1
>> org.apache.hadoop.hbase.Leases$LeaseStillHeldException
>> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>> Method)
>> at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown
>> Source)
>> at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown
>> Source)
>> at java.lang.reflect.Constructor.newInstance(Unknown Source)
>> at
>> org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
>> at
>> org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
>> at
>> org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
>> at
>> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:571)
>> at java.lang.Thread.run(Unknown Source)
>> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
>> Recovery for block blk_-209323108721490976_6065406 bad datanode[0]
>> 172.23.122.23:50010
>> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
>> Recovery for block blk_-209323108721490976_6065406 in pipeline
>> 172.23.122.23:50010, 172.23.122.16:50010,172.23.122.22:50010: bad datanode
>> 172.23.122.23:50010
>> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC
>> Server handler 3 on 60020 took 71023ms appending an edit to hlog;
>> editcount=41251
>> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
>> regionserver/172.23.122.23:60020.logFlusher took 67200ms optional sync'ing
>> hlog; editcount=41271
>> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC
>> Server handler 1 on 60020 took 69781ms appending an edit to hlog;
>> editcount=41271
>> 2010-01-20 13:55:47,081 INFO org.apache.zookeeper.ClientCnxn: Attempting
>> connection to server c1.machines.nl/172.23.122.1:2181
>> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Priming
>> connection to java.nio.channels.SocketChannel[connected
>> local=/172.23.122.23:53151 remote=c1/172.23.122.1:2181]
>> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Server
>> connection successful
>> 2010-01-20 13:55:47,083 WARN org.apache.zookeeper.ClientCnxn: Exception
>> closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@5f84f3d2
>> java.io.IOException: Session Expired
>> at
>> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
>> at
>> org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:709)
>> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
>> 2010-01-20 13:55:47,086 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
>> state: Expired, type: None, path: null
>> 2010-01-20 13:55:47,086 ERROR
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ZooKeeper session
>> expired
>>
>>
>>
>
>
Re: Regionserver problems because of datanode timeouts
Posted by Jean-Daniel Cryans <jd...@apache.org>.
I see more than one problem here.
> DFSOutputStream ResponseProcessor exception for block
> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
As you said your HDFS is getting hit a lot and this is a sign of it.
Some people use dfs.datanode.socket.write.timeout and
dfs.datanode.socket.read.timeout set to very high values in that case
(like more than 10 minutes). If you want to serve live data from HBase
it's really not the best and you should consider separating processing
and serving in 2 clusters OR lower the number of tasks on the nodes.
> java.io.IOException: TIMED OUT
> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper: We slept
> 66554ms, ten times longer than scheduled: 3000
This means your region server was garbage collecting for more than a
minute, which is higher than the default time to consider a region
server as dead. This lead to:
> java.io.IOException: Session Expired
> at
> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
This is how we notice a server is gone missing, each region server has
an ephemeral node in Zookeeper and they lose it after 40 secs in
0.20.2 (and previous) and after 60 secs in 0.20.3.
Consider giving at least 4GB of heap to the region servers and make
sure you never swap.
J-D
On Wed, Jan 20, 2010 at 8:22 AM, Ferdy <fe...@kalooga.com> wrote:
> Hello,
>
> I am having issues of regionservers shutting down because the underlying DFS
> is having trouble. I cannot get the DFS to function properly. I attached a
> log of our regionserver below. At first sight it looks like there is a
> timeout that occurs while the regionservers was trying to connect to it's
> own datanode:
> java.net.SocketTimeoutException: 69000 millis timeout while waiting for
> channel to be ready for read. ch : java.nio.channels.SocketChannel[connected
> local=/172.23.122.23:39203 remote=/172.23.122.23:50010]
>
> The datanode logs show similar timeout errors (also when trying to connect
> to local host).
>
> Our configuration:
> * Hadoop 0.20.1 and Hbase 0.20.2
> * 20 nodes: each datanode/tasktracker and regionserver
> * ulimit = 32000 on each node
> * dfs.datanode.max.xcievers=5000 (should be big enough i presume)
> * dfs.namenode.handler.count=30 (3 times the default)
> * dfs.datanode.handler.count=9 (3 times the default)
> * Our DFS contain around 500.000 blocks (64MB blocksize). Each datanode has
> 1600M heapsize. The datanodes are started with the -XX:+UseConcMarkSweepGC
> -XX:+CMSIncrementalMode options.
> * The DFS is fairly heavily used. (Always running a few concurrent MapRed
> jobs, with average IO)
>
> Anyone a clue what might be going on?
>
> Regards,
> Ferdy.
>
> THE REGIONSERVER LOG:
> 2010-01-20 13:52:15,982 DEBUG
> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
> started. Attempting to free 22928768 bytes
> 2010-01-20 13:52:15,988 DEBUG
> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Block cache LRU eviction
> completed. Freed 22985616 bytes. Priority Sizes: Single=84.519615MB
> (88625240), Multi=99.30783MB (104131808),Memory=0.0MB (0)
> 2010-01-20 13:53:03,613 DEBUG
> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
> Total=169.96802MB (178224384), Free=48.36949MB (50719088), Max=218.33751MB
> (228943472), Counts: Blocks=2683, Access=184190, Hit=10090, Miss=174100,
> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.478039011359215%, Miss
> Ratio=94.521963596344%, Evicted/Run=349.0
> 2010-01-20 13:54:03,605 DEBUG
> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
> Total=174.83826MB (183331208), Free=43.499245MB (45612264), Max=218.33751MB
> (228943472), Counts: Blocks=2762, Access=184477, Hit=10298, Miss=174179,
> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.582267791032791%, Miss
> Ratio=94.41773295402527%, Evicted/Run=349.0
> 2010-01-20 13:55:45,744 WARN org.apache.hadoop.hdfs.DFSClient:
> DFSOutputStream ResponseProcessor exception for block
> blk_-209323108721490976_6065406 java.net.SocketTimeoutException: 69000
> millis timeout while waiting for channel to be ready for read. ch :
> java.nio.channels.SocketChannel[connected local=/172.23.122.23:39203
> remote=/172.23.122.23:50010]
> at
> org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:164)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
> at
> org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
> at java.io.DataInputStream.readFully(Unknown Source)
> at java.io.DataInputStream.readLong(Unknown Source)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$ResponseProcessor.run(DFSClient.java:2399)
>
> 2010-01-20 13:55:45,744 DEBUG
> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
> Total=178.23663MB (186894656), Free=40.100876MB (42048816), Max=218.33751MB
> (228943472), Counts: Blocks=2816, Access=184676, Hit=10443, Miss=174233,
> Evictions=7, Evicted=2443, Ratios: Hit Ratio=5.654768273234367%, Miss
> Ratio=94.34522986412048%, Evicted/Run=349.0
> 2010-01-20 13:55:45,745 WARN org.apache.zookeeper.ClientCnxn: Exception
> closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@2f242b11
> java.io.IOException: TIMED OUT
> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
> 2010-01-20 13:55:45,746 WARN org.apache.hadoop.hbase.util.Sleeper: We slept
> 66554ms, ten times longer than scheduled: 3000
> 2010-01-20 13:55:45,911 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
> state: Disconnected, type: None, path: null
> 2010-01-20 13:55:46,178 WARN
> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempt=1
> org.apache.hadoop.hbase.Leases$LeaseStillHeldException
> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
> Method)
> at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown
> Source)
> at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown
> Source)
> at java.lang.reflect.Constructor.newInstance(Unknown Source)
> at
> org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
> at
> org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
> at
> org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
> at
> org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:571)
> at java.lang.Thread.run(Unknown Source)
> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
> Recovery for block blk_-209323108721490976_6065406 bad datanode[0]
> 172.23.122.23:50010
> 2010-01-20 13:55:46,359 WARN org.apache.hadoop.hdfs.DFSClient: Error
> Recovery for block blk_-209323108721490976_6065406 in pipeline
> 172.23.122.23:50010, 172.23.122.16:50010,172.23.122.22:50010: bad datanode
> 172.23.122.23:50010
> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC
> Server handler 3 on 60020 took 71023ms appending an edit to hlog;
> editcount=41251
> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog:
> regionserver/172.23.122.23:60020.logFlusher took 67200ms optional sync'ing
> hlog; editcount=41271
> 2010-01-20 13:55:46,623 WARN org.apache.hadoop.hbase.regionserver.HLog: IPC
> Server handler 1 on 60020 took 69781ms appending an edit to hlog;
> editcount=41271
> 2010-01-20 13:55:47,081 INFO org.apache.zookeeper.ClientCnxn: Attempting
> connection to server c1.machines.nl/172.23.122.1:2181
> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Priming
> connection to java.nio.channels.SocketChannel[connected
> local=/172.23.122.23:53151 remote=c1/172.23.122.1:2181]
> 2010-01-20 13:55:47,082 INFO org.apache.zookeeper.ClientCnxn: Server
> connection successful
> 2010-01-20 13:55:47,083 WARN org.apache.zookeeper.ClientCnxn: Exception
> closing session 0x1264b1fe3240006 to sun.nio.ch.SelectionKeyImpl@5f84f3d2
> java.io.IOException: Session Expired
> at
> org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
> at
> org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:709)
> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
> 2010-01-20 13:55:47,086 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
> state: Expired, type: None, path: null
> 2010-01-20 13:55:47,086 ERROR
> org.apache.hadoop.hbase.regionserver.HRegionServer: ZooKeeper session
> expired
>
>