You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by schubert zhang <zs...@gmail.com> on 2009/03/11 09:38:24 UTC
HRegionServer: Scanner, lease expired issue.
Hi all,
I am running a MapReduce job to read regions(row ranges) in Map task. The
job can work completely and correctly.
But, usually, I find following INFO in hbase regionservre's log file.
2009-03-11 15:57:06,428 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
-6710483098243538624 lease expired
To debug this issue, I add some new log information in:
src/java/org/apache/hadoop/hbase/regionserver/HRegionServer.java
(1) in addScanner(), I add:
LOG.info("----Schubert Add Scanner " + scannerName + " lease create!");
(2) in close(), I add:
LOG.info("----Schubert close " + scannerName + " lease cancel!");
Then I redo my mapreduce job. And I found some leases/scanners are not
closed.
I can make sure that my mapreduce RecordReader implements the close() method
and calls the close() method of the scanner.
following log info is copy from one region server of my HBase clasuer, and
to make clear, I move the Add and Close together.
2009-03-11 15:52:41,406 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
5785283094618320498 lease create!
2009-03-11 15:54:08,423 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
5785283094618320498 lease cancel!
2009-03-11 15:52:46,493 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
-3726092592914221244 lease create!
2009-03-11 15:54:11,676 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
-3726092592914221244 lease cancel!
2009-03-11 15:52:51,984 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
313013793996434532 lease create!
2009-03-11 15:54:18,428 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
313013793996434532 lease cancel!
2009-03-11 15:54:10,213 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
-5389407006476765661 lease create!
2009-03-11 15:55:48,337 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
-5389407006476765661 lease cancel!
2009-03-11 15:54:13,505 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
8463558669492796494 lease create!
2009-03-11 15:55:59,152 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
8463558669492796494 lease cancel!
2009-03-11 15:54:20,118 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
8149590914348186380 lease create!
2009-03-11 15:56:04,350 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
8149590914348186380 lease cancel!
2009-03-11 15:54:29,466 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
4137760362936278647 lease create!
2009-03-11 15:56:10,765 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
4137760362936278647 lease cancel!
2009-03-11 15:55:34,786 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
-5919619533272076177 lease create!
2009-03-11 15:56:50,472 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
-5919619533272076177 lease expired
2009-03-11 15:55:36,961 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
-7919803182075534481 lease create!
2009-03-11 15:57:04,200 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
-7919803182075534481 lease expired
2009-03-11 15:55:45,992 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
2812856283312715383 lease create!
2009-03-11 15:57:14,442 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
2812856283312715383 lease expired
2009-03-11 15:56:03,033 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
-6710483098243538624 lease create!
2009-03-11 15:57:06,428 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
-6710483098243538624 lease expired
Wen can see, the
Scanners -5919619533272076177, -7919803182075534481, 2812856283312715383
and -6710483098243538624 are not closed.
I guess, it maybe caused by MapReduce kill task (speculative).
Schubert
Re: HRegionServer: Scanner, lease expired issue.
Posted by schubert zhang <zs...@gmail.com>.
Thank you J-D.
Yes, I understand the mechanism of HBase lease. And this INFO-level logs do
not affect my mapreduce job, it is correct.
And my mapreduce job call scanner.next() to read each row, it does not take
long time between two next().
I just want to share this info to the community. :-)
I think this "lease expired" INFO is caused by maprduce framework:
When speculative
scheduling, the laggard tasks will be killed and when a task are killed, it
does not call the close() method of RecordReader. (Usually, we
implement RecordReader to read HBase rows, and in the close() method, we
close the scanner.)
Thanks :-)
Schubert
On Wed, Mar 11, 2009 at 9:10 PM, Jean-Daniel Cryans <jd...@apache.org>wrote:
> Schubert,
>
> When you see INFO-level output, it means that it is normal operations.
> A client scanner has a lease which lasts
> hbase.regionserver.lease.period which by default is 1 minute. If your
> client doesn't report back under that time (do a next() for example),
> the scanner lease expires. This way, the region servers don't have to
> support an infinite number of leases if the clients never close them.
>
> That said, what are you doing in your map tasks that requires your
> client to take more than 1 minute to do next()? If it is something
> that requires more than 1 minute, do consider changing that value in
> you hbase-site.xml to something like 120000 millis.
>
> J-D
>
> On Wed, Mar 11, 2009 at 5:30 AM, schubert zhang <zs...@gmail.com> wrote:
> > I made more test. I think my guess may be the cause.
> > In a latest test, there are 11 killed map tasks, and there are also 11
> > expired leases.
> >
> > I think may be the MapReduce code should be improved.
> >
> > Schubert
> > On Wed, Mar 11, 2009 at 4:38 PM, schubert zhang <zs...@gmail.com>
> wrote:
> >
> >> Hi all,
> >> I am running a MapReduce job to read regions(row ranges) in Map task.
> The
> >> job can work completely and correctly.
> >>
> >> But, usually, I find following INFO in hbase regionservre's log file.
> >>
> >> 2009-03-11 15:57:06,428 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> >> -6710483098243538624 lease expired
> >>
> >> To debug this issue, I add some new log information in:
> >> src/java/org/apache/hadoop/hbase/regionserver/HRegionServer.java
> >> (1) in addScanner(), I add:
> >> LOG.info("----Schubert Add Scanner " + scannerName + " lease create!");
> >> (2) in close(), I add:
> >> LOG.info("----Schubert close " + scannerName + " lease cancel!");
> >>
> >> Then I redo my mapreduce job. And I found some leases/scanners are not
> >> closed.
> >>
> >> I can make sure that my mapreduce RecordReader implements the close()
> >> method and calls the close() method of the scanner.
> >>
> >> following log info is copy from one region server of my HBase clasuer,
> and
> >> to make clear, I move the Add and Close together.
> >>
> >> 2009-03-11 15:52:41,406 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 5785283094618320498 lease create!
> >> 2009-03-11 15:54:08,423 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> 5785283094618320498 lease cancel!
> >>
> >> 2009-03-11 15:52:46,493 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> -3726092592914221244 lease create!
> >> 2009-03-11 15:54:11,676 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> -3726092592914221244 lease cancel!
> >>
> >> 2009-03-11 15:52:51,984 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 313013793996434532 lease create!
> >> 2009-03-11 15:54:18,428 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> 313013793996434532 lease cancel!
> >>
> >> 2009-03-11 15:54:10,213 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> -5389407006476765661 lease create!
> >> 2009-03-11 15:55:48,337 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> -5389407006476765661 lease cancel!
> >>
> >> 2009-03-11 15:54:13,505 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 8463558669492796494 lease create!
> >> 2009-03-11 15:55:59,152 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> 8463558669492796494 lease cancel!
> >>
> >> 2009-03-11 15:54:20,118 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 8149590914348186380 lease create!
> >> 2009-03-11 15:56:04,350 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> 8149590914348186380 lease cancel!
> >>
> >> 2009-03-11 15:54:29,466 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 4137760362936278647 lease create!
> >> 2009-03-11 15:56:10,765 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> >> 4137760362936278647 lease cancel!
> >>
> >> 2009-03-11 15:55:34,786 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> -5919619533272076177 lease create!
> >> 2009-03-11 15:56:50,472 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> >> -5919619533272076177 lease expired
> >>
> >> 2009-03-11 15:55:36,961 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> -7919803182075534481 lease create!
> >> 2009-03-11 15:57:04,200 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> >> -7919803182075534481 lease expired
> >>
> >> 2009-03-11 15:55:45,992 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> 2812856283312715383 lease create!
> >> 2009-03-11 15:57:14,442 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> >> 2812856283312715383 lease expired
> >>
> >> 2009-03-11 15:56:03,033 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add
> Scanner
> >> -6710483098243538624 lease create!
> >> 2009-03-11 15:57:06,428 INFO
> >> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> >> -6710483098243538624 lease expired
> >>
> >> Wen can see, the
> >> Scanners -5919619533272076177, -7919803182075534481,
> 2812856283312715383
> >> and -6710483098243538624 are not closed.
> >>
> >> I guess, it maybe caused by MapReduce kill task (speculative).
> >>
> >> Schubert
> >>
> >
>
Re: HRegionServer: Scanner, lease expired issue.
Posted by Jean-Daniel Cryans <jd...@apache.org>.
Schubert,
When you see INFO-level output, it means that it is normal operations.
A client scanner has a lease which lasts
hbase.regionserver.lease.period which by default is 1 minute. If your
client doesn't report back under that time (do a next() for example),
the scanner lease expires. This way, the region servers don't have to
support an infinite number of leases if the clients never close them.
That said, what are you doing in your map tasks that requires your
client to take more than 1 minute to do next()? If it is something
that requires more than 1 minute, do consider changing that value in
you hbase-site.xml to something like 120000 millis.
J-D
On Wed, Mar 11, 2009 at 5:30 AM, schubert zhang <zs...@gmail.com> wrote:
> I made more test. I think my guess may be the cause.
> In a latest test, there are 11 killed map tasks, and there are also 11
> expired leases.
>
> I think may be the MapReduce code should be improved.
>
> Schubert
> On Wed, Mar 11, 2009 at 4:38 PM, schubert zhang <zs...@gmail.com> wrote:
>
>> Hi all,
>> I am running a MapReduce job to read regions(row ranges) in Map task. The
>> job can work completely and correctly.
>>
>> But, usually, I find following INFO in hbase regionservre's log file.
>>
>> 2009-03-11 15:57:06,428 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
>> -6710483098243538624 lease expired
>>
>> To debug this issue, I add some new log information in:
>> src/java/org/apache/hadoop/hbase/regionserver/HRegionServer.java
>> (1) in addScanner(), I add:
>> LOG.info("----Schubert Add Scanner " + scannerName + " lease create!");
>> (2) in close(), I add:
>> LOG.info("----Schubert close " + scannerName + " lease cancel!");
>>
>> Then I redo my mapreduce job. And I found some leases/scanners are not
>> closed.
>>
>> I can make sure that my mapreduce RecordReader implements the close()
>> method and calls the close() method of the scanner.
>>
>> following log info is copy from one region server of my HBase clasuer, and
>> to make clear, I move the Add and Close together.
>>
>> 2009-03-11 15:52:41,406 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 5785283094618320498 lease create!
>> 2009-03-11 15:54:08,423 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> 5785283094618320498 lease cancel!
>>
>> 2009-03-11 15:52:46,493 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> -3726092592914221244 lease create!
>> 2009-03-11 15:54:11,676 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> -3726092592914221244 lease cancel!
>>
>> 2009-03-11 15:52:51,984 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 313013793996434532 lease create!
>> 2009-03-11 15:54:18,428 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> 313013793996434532 lease cancel!
>>
>> 2009-03-11 15:54:10,213 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> -5389407006476765661 lease create!
>> 2009-03-11 15:55:48,337 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> -5389407006476765661 lease cancel!
>>
>> 2009-03-11 15:54:13,505 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 8463558669492796494 lease create!
>> 2009-03-11 15:55:59,152 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> 8463558669492796494 lease cancel!
>>
>> 2009-03-11 15:54:20,118 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 8149590914348186380 lease create!
>> 2009-03-11 15:56:04,350 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> 8149590914348186380 lease cancel!
>>
>> 2009-03-11 15:54:29,466 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 4137760362936278647 lease create!
>> 2009-03-11 15:56:10,765 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
>> 4137760362936278647 lease cancel!
>>
>> 2009-03-11 15:55:34,786 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> -5919619533272076177 lease create!
>> 2009-03-11 15:56:50,472 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
>> -5919619533272076177 lease expired
>>
>> 2009-03-11 15:55:36,961 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> -7919803182075534481 lease create!
>> 2009-03-11 15:57:04,200 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
>> -7919803182075534481 lease expired
>>
>> 2009-03-11 15:55:45,992 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> 2812856283312715383 lease create!
>> 2009-03-11 15:57:14,442 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
>> 2812856283312715383 lease expired
>>
>> 2009-03-11 15:56:03,033 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
>> -6710483098243538624 lease create!
>> 2009-03-11 15:57:06,428 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
>> -6710483098243538624 lease expired
>>
>> Wen can see, the
>> Scanners -5919619533272076177, -7919803182075534481, 2812856283312715383
>> and -6710483098243538624 are not closed.
>>
>> I guess, it maybe caused by MapReduce kill task (speculative).
>>
>> Schubert
>>
>
Re: HRegionServer: Scanner, lease expired issue.
Posted by schubert zhang <zs...@gmail.com>.
I made more test. I think my guess may be the cause.
In a latest test, there are 11 killed map tasks, and there are also 11
expired leases.
I think may be the MapReduce code should be improved.
Schubert
On Wed, Mar 11, 2009 at 4:38 PM, schubert zhang <zs...@gmail.com> wrote:
> Hi all,
> I am running a MapReduce job to read regions(row ranges) in Map task. The
> job can work completely and correctly.
>
> But, usually, I find following INFO in hbase regionservre's log file.
>
> 2009-03-11 15:57:06,428 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> -6710483098243538624 lease expired
>
> To debug this issue, I add some new log information in:
> src/java/org/apache/hadoop/hbase/regionserver/HRegionServer.java
> (1) in addScanner(), I add:
> LOG.info("----Schubert Add Scanner " + scannerName + " lease create!");
> (2) in close(), I add:
> LOG.info("----Schubert close " + scannerName + " lease cancel!");
>
> Then I redo my mapreduce job. And I found some leases/scanners are not
> closed.
>
> I can make sure that my mapreduce RecordReader implements the close()
> method and calls the close() method of the scanner.
>
> following log info is copy from one region server of my HBase clasuer, and
> to make clear, I move the Add and Close together.
>
> 2009-03-11 15:52:41,406 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 5785283094618320498 lease create!
> 2009-03-11 15:54:08,423 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> 5785283094618320498 lease cancel!
>
> 2009-03-11 15:52:46,493 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> -3726092592914221244 lease create!
> 2009-03-11 15:54:11,676 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> -3726092592914221244 lease cancel!
>
> 2009-03-11 15:52:51,984 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 313013793996434532 lease create!
> 2009-03-11 15:54:18,428 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> 313013793996434532 lease cancel!
>
> 2009-03-11 15:54:10,213 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> -5389407006476765661 lease create!
> 2009-03-11 15:55:48,337 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> -5389407006476765661 lease cancel!
>
> 2009-03-11 15:54:13,505 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 8463558669492796494 lease create!
> 2009-03-11 15:55:59,152 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> 8463558669492796494 lease cancel!
>
> 2009-03-11 15:54:20,118 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 8149590914348186380 lease create!
> 2009-03-11 15:56:04,350 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> 8149590914348186380 lease cancel!
>
> 2009-03-11 15:54:29,466 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 4137760362936278647 lease create!
> 2009-03-11 15:56:10,765 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert close
> 4137760362936278647 lease cancel!
>
> 2009-03-11 15:55:34,786 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> -5919619533272076177 lease create!
> 2009-03-11 15:56:50,472 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> -5919619533272076177 lease expired
>
> 2009-03-11 15:55:36,961 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> -7919803182075534481 lease create!
> 2009-03-11 15:57:04,200 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> -7919803182075534481 lease expired
>
> 2009-03-11 15:55:45,992 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> 2812856283312715383 lease create!
> 2009-03-11 15:57:14,442 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> 2812856283312715383 lease expired
>
> 2009-03-11 15:56:03,033 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: ----Schubert Add Scanner
> -6710483098243538624 lease create!
> 2009-03-11 15:57:06,428 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Scanner
> -6710483098243538624 lease expired
>
> Wen can see, the
> Scanners -5919619533272076177, -7919803182075534481, 2812856283312715383
> and -6710483098243538624 are not closed.
>
> I guess, it maybe caused by MapReduce kill task (speculative).
>
> Schubert
>