Done. It's HBASE-12270 Please let me know if you have any comments/questions.
---------------------------------------- > Date: Mon, 13 Oct 2014 22:42:37 -0500 > Subject: RE: HBase read performance > From: bus...@cloudera.com > To: user@hbase.apache.org > > Yes, please file a JIRA and attach the test there. > > -- > Sean > On Oct 13, 2014 10:22 PM, "Khaled Elmeleegy" <kd...@hotmail.com> wrote: > >> Actually, it's very easy to reproduce. I have a simple program that >> reproduces it if run against a simple toy cluster with one RS. If shared >> the program with Ted. I can file a jira ticket about it if you want. >> Khaled >> >>> Date: Mon, 13 Oct 2014 19:12:13 -0700 >>> From: la...@apache.org >>> Subject: Re: HBase read performance >>> To: user@hbase.apache.org >>> >>> This looks like something to track. >>> If there's an easy way to reproduce this, could you file a jira with >> instructions? >>> (Although from the conversations here, it looks like it's not trivial to >> reproduce). >>> >>> -- Lars >>> >>> >>> >>> ________________________________ >>> From: Khaled Elmeleegy <kd...@hotmail.com> >>> To: "user@hbase.apache.org" <user@hbase.apache.org> >>> Sent: Monday, October 13, 2014 12:13 PM >>> Subject: RE: HBase read performance >>> >>> >>> I went through a lengthy testing process with Ted. I tried both >> disabling just cache on write and both COW and BC. Disabling them makes the >> problem go away. I think disabling COW in my workload effectively doesn't >> exercise the block cache as my workload is mostly writes, so disabling COW >> doesn't cause the cache blocks to churn. >>> I tried both overcommitting memory and not. This is irrelevant though. >> The cache operates on the virtual memory offered to it and it's agnostic to >> the physical memory size. Memory over commitment may only hurt performance >> due to swapping by the OS, but this has nothing to do with the bug. >>> Khaled >>> >>>> Date: Sun, 12 Oct 2014 23:17:24 -0700 >>>> Subject: Re: HBase read performance >>>> From: st...@duboce.net >>>> To: user@hbase.apache.org >>>> >>>> On Sun, Oct 12, 2014 at 8:58 PM, Khaled Elmeleegy <kd...@hotmail.com> >> wrote: >>>> >>>>> It goes away, but i think that's because i am basically churning the >> cache >>>>> far less. My workload is mostly writes. >>>>> >>>>> >>>> What exactly did you change? >>>> >>>> Did you disable both BC and cacheonwrite or just one of these configs? >>>> >>>> Disabling BC and/or cacheonwrite would churn your cache more? >>>> >>>> What about the heap config? Did you over commit mem? If so, did you >> try >>>> doing a direct memory sizing that was w/i the bounds of physical memory >>>> (well within)? Did you still see exceptions? >>>> >>>> St.Ack >>>> >>>> >>>> >>>> >>>>>> Date: Sun, 12 Oct 2014 19:43:16 -0700 >>>>>> Subject: Re: HBase read performance >>>>>> From: yuzhih...@gmail.com >>>>>> To: user@hbase.apache.org >>>>>> >>>>>> Hi, >>>>>> Can you turn off cacheonwrite and keep bucket cache to see if the >> problem >>>>>> goes away ? >>>>>> >>>>>> Cheers >>>>>> >>>>>> On Fri, Oct 10, 2014 at 10:59 AM, Khaled Elmeleegy < >> kd...@hotmail.com> >>>>>> wrote: >>>>>> >>>>>>> Yes, I can reproduce it with some work. >>>>>>> The workload is basically as follows: >>>>>>> There are writers streaming writes to a table. Then, there is a >> reader >>>>>>> (invoked via a web interface). The reader does a 1000 parallel >> reverse >>>>>>> scans, all end up hitting the same region in my case. The scans >> are >>>>>>> effectively "gets" as I just need to get one record off of each >> of >>>>> them. I >>>>>>> just need to do a "reverse" get, which is not supported (would be >>>>> great to >>>>>>> have :)), so I do it via reverse scan. After few tries, the >> reader >>>>>>> consistently hits this bug. >>>>>>> >>>>>>> This happens with these config changes: >>>>>>> hbase-env:HBASE_REGIONSERVER_OPTS=-Xmx6G >> -XX:MaxDirectMemorySize=5G >>>>>>> -XX:CMSInitiatingOccupancyFraction=88 -XX:+AggressiveOpts >> -verbose:gc >>>>>>> -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xlog >>>>>>> gc:/tmp/hbase-regionserver-gc.loghbase-site: >>>>>>> hbase.bucketcache.ioengine=offheap >>>>>>> hbase.bucketcache.size=4196 >>>>>>> hbase.rs.cacheblocksonwrite=true >>>>>>> hfile.block.index.cacheonwrite=true >>>>>>> hfile.block.bloom.cacheonwrite=true >>>>>>> >>>>>>> Interestingly, without these config changes, I can't reproduce >> the >>>>> problem. >>>>>>> Khaled >>>>>>> >>>>>>> >>>>>>>> Date: Fri, 10 Oct 2014 10:05:14 -0700 >>>>>>>> Subject: Re: HBase read performance >>>>>>>> From: st...@duboce.net >>>>>>>> To: user@hbase.apache.org >>>>>>>> >>>>>>>> It looks like we are messing up our positioning math: >>>>>>>> >>>>>>>> 233 < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java#233 >>>>>>>> >>>>>>>> >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java# >>>>>>>> >>>>>>>> >>>>>>>> public final Buffer >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java#Buffer >>>>>>>> >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java# >>>>>>>>position(int >>>>>>>> newPosition) { >>>>>>>> >>>>>>>> 234 < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java#234 >>>>>>>> >>>>>>>> >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java# >>>>>>>> >>>>>>>> >>>>>>>> if ((newPosition> limit >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java#Buffer.0limit >>>>>>>>) >>>>>>>> || (newPosition < 0)) >>>>>>>> >>>>>>>> 235 < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java#235 >>>>>>>> >>>>>>>> >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/nio/Buffer.java# >>>>>>>> >>>>>>>> >>>>>>>> throw new IllegalArgumentException >>>>>>>> < >>>>>>> >>>>> >> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/lang/IllegalArgumentException.java#IllegalArgumentException >>>>>>>>(); >>>>>>>> >>>>>>>> >>>>>>>> Is it easy to reproduce Khaled? Always same region/store or >> spread >>>>>>>> across all reads? >>>>>>>> >>>>>>>> >>>>>>>> St.Ack >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> On Fri, Oct 10, 2014 at 8:31 AM, Khaled Elmeleegy < >> kd...@hotmail.com >>>>>> >>>>>>> wrote: >>>>>>>> >>>>>>>>> Andrew thanks. I think this indeed was the problem. >>>>>>>>> To get over it, I increased the amount of memory given the >> region >>>>>>> server >>>>>>>>> to avoid IO on reads. I used the configs below. In my >> experiments, >>>>> I >>>>>>> have >>>>>>>>> writers streaming their output to HBase. The reader powers a >> web >>>>> page >>>>>>> and >>>>>>>>> does this scatter/gather, where it reads 1000 keys written >> last and >>>>>>> passes >>>>>>>>> them the the front end. With this workload, I get the >> exception >>>>> below >>>>>>> at >>>>>>>>> the region server. Again, I am using HBAse (0.98.6.1). Any >> help is >>>>>>>>> appreciated. >>>>>>>>> hbase-env:HBASE_REGIONSERVER_OPTS=-Xmx6G >> -XX:MaxDirectMemorySize=5G >>>>>>>>> -XX:CMSInitiatingOccupancyFraction=88 -XX:+AggressiveOpts >>>>> -verbose:gc >>>>>>>>> -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xlog >>>>>>>>> gc:/tmp/hbase-regionserver-gc.log >>>>>>>>> hbase-site:hbase.bucketcache.ioengine=offheap >>>>>>>>> >>>>>>>>> hfile.block.cache.size=0.4 >>>>>>>>> >>>>>>>>> >>>>>>>>> hbase.bucketcache.size=4196 >>>>>>>>> >>>>>>>>> hbase.rs.cacheblocksonwrite=true >>>>>>>>> >>>>>>>>> >>>>>>>>> hfile.block.index.cacheonwrite=true >>>>>>>>> >>>>>>>>> hfile.block.bloom.cacheonwrite=true >>>>>>>>> >>>>>>>>> 2014-10-10 15:06:44,173 ERROR >>>>>>>>> [B.DefaultRpcServer.handler=62,queue=2,port=60020] >> ipc.RpcServer: >>>>>>>>> Unexpected throwable object >>>>>>>>> java.lang.IllegalArgumentException >>>>>>>>> at java.nio.Buffer.position(Buffer.java:236) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.util.ByteBufferUtils.skip(ByteBufferUtils.java:434) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.io.hfile.HFileReaderV2$ScannerV2.readKeyValueLen(HFileReaderV2.java:849) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.io.hfile.HFileReaderV2$ScannerV2.next(HFileReaderV2.java:760) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.StoreFileScanner.seekAtOrAfter(StoreFileScanner.java:248) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.StoreFileScanner.seek(StoreFileScanner.java:152) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.StoreScanner.seekScanners(StoreScanner.java:317) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.StoreScanner.<init>(StoreScanner.java:176) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HStore.getScanner(HStore.java:1780) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HRegion$RegionScannerImpl.<init>(HRegion.java:3758) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HRegion.instantiateRegionScanner(HRegion.java:1950) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1936) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1913) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.regionserver.HRegionServer.scan(HRegionServer.java:3157) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:29587) >>>>>>>>> at >>>>>>> org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2027) >>>>>>>>> at >>>>>>> org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:108) >>>>>>>>> at >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:114) >>>>>>>>> at >>>>>>>>> >> org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:94) >>>>>>>>> at java.lang.Thread.run(Thread.java:744) >>>>>>>>>> From: apurt...@apache.org >>>>>>>>>> Date: Tue, 7 Oct 2014 17:09:35 -0700 >>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>> >>>>>>>>>>> The cluster has 2 m1.large nodes. >>>>>>>>>> >>>>>>>>>> That's the problem right there. >>>>>>>>>> >>>>>>>>>> You need to look at c3.4xlarge or i2 instances as a minimum >>>>>>> requirement. >>>>>>>>> M1 >>>>>>>>>> and even M3 instance types have ridiculously poor IO. >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On Tue, Oct 7, 2014 at 3:01 PM, Khaled Elmeleegy < >>>>> kd...@hotmail.com> >>>>>>>>> wrote: >>>>>>>>>> >>>>>>>>>>> Thanks Nicolas, Qiang. >>>>>>>>>>> >>>>>>>>>>> I was able to write a simple program that reproduces the >>>>> problem >>>>>>> on a >>>>>>>>> tiny >>>>>>>>>>> HBase cluster on ec2. The cluster has 2 m1.large nodes. >> One >>>>> node >>>>>>> runs >>>>>>>>> the >>>>>>>>>>> master, name node and zookeeper. The other node runs a >> data >>>>> node >>>>>>> and a >>>>>>>>>>> region server, with heap size configured to be 6GB. >> There, the >>>>> 1000 >>>>>>>>>>> parallel reverse gets (reverse scans) take 7-8 seconds. >> The >>>>> data >>>>>>> set is >>>>>>>>>>> tiny (10M records, each having a small number of bytes). >> As I >>>>> said >>>>>>>>> before, >>>>>>>>>>> all hardware resources are very idle there. >>>>>>>>>>> >>>>>>>>>>> Interestingly, running the same workload on my macbook, >> the >>>>> 1000 >>>>>>>>> parallel >>>>>>>>>>> gets take ~200ms on a pseudo-distributed installation. >>>>>>>>>>> >>>>>>>>>>> Any help to resolve this mystery is highly appreciated. >>>>>>>>>>> >>>>>>>>>>> P.S. please find my test program attached. >>>>>>>>>>> >>>>>>>>>>> Best, >>>>>>>>>>> Khaled >>>>>>>>>>> >>>>>>>>>>>> From: nkey...@gmail.com >>>>>>>>>>>> Date: Mon, 6 Oct 2014 09:40:48 +0200 >>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>> >>>>>>>>>>>> Hi, >>>>>>>>>>>> >>>>>>>>>>>> I haven't seen it mentioned, but if I understand >> correctly >>>>> each >>>>>>> scan >>>>>>>>>>>> returns a single row? If so you should use >> Scan#setSmall to >>>>> save >>>>>>>>> some rpc >>>>>>>>>>>> calls. >>>>>>>>>>>> >>>>>>>>>>>> Cheers, >>>>>>>>>>>> >>>>>>>>>>>> Nicolas >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> On Sun, Oct 5, 2014 at 11:28 AM, Qiang Tian < >>>>> tian...@gmail.com> >>>>>>>>> wrote: >>>>>>>>>>>> >>>>>>>>>>>>> when using separate HConnection instance, both its >>>>>>>>>>>>> RpcClient instance(maintain connection to a >> regionserver) >>>>> and >>>>>>>>> Registry >>>>>>>>>>>>> instance(maintain connection to zookeeper) will be >>>>> separate.. >>>>>>>>>>>>> >>>>>>>>>>>>> see >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> http://shammijayasinghe.blogspot.com/2012/02/zookeeper-increase-maximum-number-of.html >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> On Sun, Oct 5, 2014 at 2:24 PM, Khaled Elmeleegy < >>>>>>>>> kd...@hotmail.com> >>>>>>>>>>>>> wrote: >>>>>>>>>>>>> >>>>>>>>>>>>>> I tried creating my own HConnections pool to use >> for my >>>>> HBase >>>>>>>>> calls, >>>>>>>>>>> so >>>>>>>>>>>>>> that not all the (2K) threads share the same >> HConnection. >>>>>>>>> However, I >>>>>>>>>>>>> could >>>>>>>>>>>>>> only have 10 HConnections. Beyond that I get ZK >>>>> exceptions, >>>>>>>>> please >>>>>>>>>>> find >>>>>>>>>>>>> it >>>>>>>>>>>>>> below. Also, with 10 HConnections, I don't see >> noticeable >>>>>>>>>>> improvement in >>>>>>>>>>>>>> performance so far. >>>>>>>>>>>>>> 2014-10-05 06:11:26,490 WARN [main] >>>>>>>>> zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(253)) - >> Possibly >>>>>>>>> transient >>>>>>>>>>>>>> ZooKeeper, quorum=54.68.206.252:2181, >>>>>>>>>>>>>> >>>>>>>>>>> >>>>>>> >> exception=org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >>>>> /hbase/hbaseid2014-10-05 >>>>>>>>>>>>> 06:11:26,490 >>>>>>>>>>>>>> INFO [main] util.RetryCounter >>>>>>>>>>>>> (RetryCounter.java:sleepUntilNextRetry(155)) >>>>>>>>>>>>>> - Sleeping 1000ms before retry #0...2014-10-05 >>>>> 06:11:27,845 >>>>>>> WARN >>>>>>>>>>> [main] >>>>>>>>>>>>>> zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(253)) - >> Possibly >>>>>>>>> transient >>>>>>>>>>>>>> ZooKeeper, quorum=54.68.206.252:2181, >>>>>>>>>>>>>> >>>>>>>>>>> >>>>>>> >> exception=org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >>>>> /hbase/hbaseid2014-10-05 >>>>>>>>>>>>> 06:11:27,849 >>>>>>>>>>>>>> INFO [main] util.RetryCounter >>>>>>>>>>>>> (RetryCounter.java:sleepUntilNextRetry(155)) >>>>>>>>>>>>>> - Sleeping 2000ms before retry #1...2014-10-05 >>>>> 06:11:30,405 >>>>>>> WARN >>>>>>>>>>> [main] >>>>>>>>>>>>>> zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(253)) - >> Possibly >>>>>>>>> transient >>>>>>>>>>>>>> ZooKeeper, quorum=54.68.206.252:2181, >>>>>>>>>>>>>> >>>>>>>>>>> >>>>>>> >> exception=org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >>>>> /hbase/hbaseid2014-10-05 >>>>>>>>>>>>> 06:11:30,405 >>>>>>>>>>>>>> INFO [main] util.RetryCounter >>>>>>>>>>>>> (RetryCounter.java:sleepUntilNextRetry(155)) >>>>>>>>>>>>>> - Sleeping 4000ms before retry #2...2014-10-05 >>>>> 06:11:35,278 >>>>>>> WARN >>>>>>>>>>> [main] >>>>>>>>>>>>>> zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(253)) - >> Possibly >>>>>>>>> transient >>>>>>>>>>>>>> ZooKeeper, quorum=54.68.206.252:2181, >>>>>>>>>>>>>> >>>>>>>>>>> >>>>>>> >> exception=org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >>>>> /hbase/hbaseid2014-10-05 >>>>>>>>>>>>> 06:11:35,279 >>>>>>>>>>>>>> INFO [main] util.RetryCounter >>>>>>>>>>>>> (RetryCounter.java:sleepUntilNextRetry(155)) >>>>>>>>>>>>>> - Sleeping 8000ms before retry #3...2014-10-05 >>>>> 06:11:44,393 >>>>>>> WARN >>>>>>>>>>> [main] >>>>>>>>>>>>>> zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(253)) - >> Possibly >>>>>>>>> transient >>>>>>>>>>>>>> ZooKeeper, quorum=54.68.206.252:2181, >>>>>>>>>>>>>> >>>>>>>>>>> >>>>>>> >> exception=org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >>>>> /hbase/hbaseid2014-10-05 >>>>>>>>>>>>> 06:11:44,393 >>>>>>>>>>>>>> ERROR [main] zookeeper.RecoverableZooKeeper >>>>>>>>>>>>>> (RecoverableZooKeeper.java:retryOrThrow(255)) - >> ZooKeeper >>>>>>> exists >>>>>>>>>>> failed >>>>>>>>>>>>>> after 4 attempts2014-10-05 06:11:44,394 WARN [main] >>>>>>>>> zookeeper.ZKUtil >>>>>>>>>>>>>> (ZKUtil.java:checkExists(482)) - >> hconnection-0x4e174f3b, >>>>>>> quorum= >>>>>>>>>>>>>> 54.68.206.252:2181, baseZNode=/hbase Unable to set >>>>> watcher >>>>>>> on >>>>>>>>> znode >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> (/hbase/hbaseid)org.apache.zookeeper.KeeperException$ConnectionLossException: >>>>>>>>>>>>>> KeeperErrorCode = ConnectionLoss for >> /hbase/hbaseid at >>>>>>>>>>>>>> >>>>>>>>> >>>>> org.apache.zookeeper.KeeperException.create(KeeperException.java:99) >>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>> >>>>> org.apache.zookeeper.KeeperException.create(KeeperException.java:51) >>>>>>>>>>> at >>>>>>>>>>>>>> >>>>> org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041) at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.exists(RecoverableZooKeeper.java:199) >>>>>>>>>>>>>> at >>>>>>>>>>> >>>>>>> >> org.apache.hadoop.hbase.zookeeper.ZKUtil.checkExists(ZKUtil.java:479) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.zookeeper.ZKClusterId.readClusterIdZNode(ZKClusterId.java:65) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:83) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.retrieveClusterId(HConnectionManager.java:857) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.<init>(HConnectionManager.java:662) >>>>>>>>>>>>>> at >>>>>>> sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native >>>>>>>>>>>>>> Method) at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) >>>>>>>>>>>>>> at >>>>>>>>> >> java.lang.reflect.Constructor.newInstance(Constructor.java:526) >>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:414) >>>>>>>>>>>>>> at >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:335)... >>>>>>>>>>>>>>> From: kd...@hotmail.com >>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>> Subject: RE: HBase read performance >>>>>>>>>>>>>>> Date: Fri, 3 Oct 2014 12:37:39 -0700 >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Lars, Ted, and Qiang, >>>>>>>>>>>>>>> Thanks for all the input. >>>>>>>>>>>>>>> Qiang: yes all the threads are in the same client >>>>> process >>>>>>>>> sharing >>>>>>>>>>> the >>>>>>>>>>>>>> same connection. And since I don't see hardware >>>>> contention, >>>>>>> may >>>>>>>>> be >>>>>>>>>>> there >>>>>>>>>>>>> is >>>>>>>>>>>>>> contention over this code path. I'll try using many >>>>>>> connections >>>>>>>>> and >>>>>>>>>>> see >>>>>>>>>>>>> if >>>>>>>>>>>>>> it alleviates the problems and I'll report back. >>>>>>>>>>>>>>> Thanks again,Khaled >>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Date: Fri, 3 Oct 2014 15:18:30 +0800 >>>>>>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>>>>>> From: tian...@gmail.com >>>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Regarding to profiling, Andrew introduced >>>>>>>>>>>>>>>> >>>>>>>>>>> >>>>> http://www.brendangregg.com/blog/2014-06-12/java-flame-graphs.html >>>>>>>>>>>>>> months >>>>>>>>>>>>>>>> ago. >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> processCallTime comes from RpcServer#call, so >> it >>>>> looks >>>>>>> good? >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> I have a suspect: >>>>>>>>>>> https://issues.apache.org/jira/browse/HBASE-11306 >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> how many processes do you have for your 2000 >> threads? >>>>>>>>>>>>>>>> if olny 1 process, those threads will share >> just 1 >>>>>>>>> connection to >>>>>>>>>>> that >>>>>>>>>>>>>>>> regionserver, there might be big contention on >> the >>>>> RPC >>>>>>> code >>>>>>>>> path. >>>>>>>>>>>>>> ---for >>>>>>>>>>>>>>>> such case, could you try using different >> connections? >>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> https://hbase.apache.org/apidocs/org/apache/hadoop/hbase/client/HConnectionManager.html >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> On Fri, Oct 3, 2014 at 9:55 AM, Ted Yu < >>>>>>> yuzhih...@gmail.com> >>>>>>>>>>> wrote: >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Khaled: >>>>>>>>>>>>>>>>> Do you have profiler such as jprofiler ? >>>>>>>>>>>>>>>>> Profiling would give us more hint. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Otherwise capturing stack trace during the >> period >>>>> of >>>>>>>>> reverse >>>>>>>>>>> scan >>>>>>>>>>>>>> would >>>>>>>>>>>>>>>>> help. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Cheers >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> On Thu, Oct 2, 2014 at 4:52 PM, lars >> hofhansl < >>>>>>>>>>> la...@apache.org> >>>>>>>>>>>>>> wrote: >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> You might have the data in the OS buffer >> cache, >>>>>>> without >>>>>>>>> short >>>>>>>>>>>>>> circuit >>>>>>>>>>>>>>>>>> reading the region server has to request >> the >>>>> block >>>>>>> from >>>>>>>>> the >>>>>>>>>>> data >>>>>>>>>>>>>> node >>>>>>>>>>>>>>>>>> process, which then reads it from the block >>>>> cache. >>>>>>>>>>>>>>>>>> That is a few context switches per RPC >> that do >>>>> not >>>>>>> show >>>>>>>>> up >>>>>>>>>>> in CPU >>>>>>>>>>>>>>>>> metrics. >>>>>>>>>>>>>>>>>> In that you also would not see disk IO. >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> If - as you say - you see a lot of evicted >>>>> blocks the >>>>>>>>> data >>>>>>>>>>> *has* >>>>>>>>>>>>>> to come >>>>>>>>>>>>>>>>>> from the OS. If you do not see disk IO is >> *has* >>>>> to >>>>>>> come >>>>>>>>> from >>>>>>>>>>> the >>>>>>>>>>>>> OS >>>>>>>>>>>>>>>>> cache. >>>>>>>>>>>>>>>>>> I.e. there's more RAM on your boxes, and >> you >>>>> should >>>>>>>>> increase >>>>>>>>>>> the >>>>>>>>>>>>>> heap >>>>>>>>>>>>>>>>> block >>>>>>>>>>>>>>>>>> cache. >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> You can measure the context switches with >> vmstat. >>>>>>> Other >>>>>>>>> than >>>>>>>>>>> that >>>>>>>>>>>>>> I have >>>>>>>>>>>>>>>>>> no suggestion until I reproduce the >> problem. >>>>>>>>>>>>>>>>>> Also check the data locality index of the >> region >>>>>>> server >>>>>>>>> it >>>>>>>>>>> should >>>>>>>>>>>>>> be >>>>>>>>>>>>>>>>> close >>>>>>>>>>>>>>>>>> to 100%. >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> -- Lars >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> ________________________________ >>>>>>>>>>>>>>>>>> From: Khaled Elmeleegy <kd...@hotmail.com> >>>>>>>>>>>>>>>>>> To: "user@hbase.apache.org" < >>>>> user@hbase.apache.org> >>>>>>>>>>>>>>>>>> Sent: Thursday, October 2, 2014 3:24 PM >>>>>>>>>>>>>>>>>> Subject: RE: HBase read performance >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> Lars thanks a lot about all the tips. I'll >> make >>>>> sure >>>>>>> I >>>>>>>>> cover >>>>>>>>>>> all >>>>>>>>>>>>>> of them >>>>>>>>>>>>>>>>>> and get back to you. I am not sure they >> are the >>>>>>>>> bottleneck >>>>>>>>>>> though >>>>>>>>>>>>>> as they >>>>>>>>>>>>>>>>>> all are about optimizing physical resource >>>>> usage. As >>>>>>> I >>>>>>>>> said, >>>>>>>>>>> I >>>>>>>>>>>>>> don't see >>>>>>>>>>>>>>>>>> any contended physical resources now. I'll >> also >>>>> try >>>>>>> to >>>>>>>>>>> reproduce >>>>>>>>>>>>>> this >>>>>>>>>>>>>>>>>> problem in a simpler environment and pass >> to you >>>>> the >>>>>>> test >>>>>>>>>>> program >>>>>>>>>>>>>> to play >>>>>>>>>>>>>>>>>> with. >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> Couple of high level points to make. You >> are >>>>> right >>>>>>> that >>>>>>>>> my >>>>>>>>>>> use >>>>>>>>>>>>>> case is >>>>>>>>>>>>>>>>>> kind of a worst case for HBase reads. But, >> if >>>>> things >>>>>>> go >>>>>>>>> the >>>>>>>>>>> way >>>>>>>>>>>>> you >>>>>>>>>>>>>>>>>> described them, there should be tons of >> disk IO >>>>> and >>>>>>> that >>>>>>>>>>> should >>>>>>>>>>>>> be >>>>>>>>>>>>>>>>> clearly >>>>>>>>>>>>>>>>>> the bottleneck. This is not the case >> though. >>>>> That's >>>>>>> for >>>>>>>>> the >>>>>>>>>>>>> simple >>>>>>>>>>>>>> reason >>>>>>>>>>>>>>>>>> that this is done in a test environment (I >> am >>>>> still >>>>>>>>>>> prototyping), >>>>>>>>>>>>>> and >>>>>>>>>>>>>>>>> not a >>>>>>>>>>>>>>>>>> lot of data is yet written to HBase. >> However for >>>>> the >>>>>>>>> real use >>>>>>>>>>>>>> case, there >>>>>>>>>>>>>>>>>> should writers constantly writing data to >> HBase >>>>> and >>>>>>>>> readers >>>>>>>>>>>>>> occasionally >>>>>>>>>>>>>>>>>> doing this scatter/gather. At steady state, >>>>> things >>>>>>> should >>>>>>>>>>> only >>>>>>>>>>>>> get >>>>>>>>>>>>>> worse >>>>>>>>>>>>>>>>>> and all the issues you mentioned should >> get far >>>>> more >>>>>>>>>>> pronounced. >>>>>>>>>>>>>> At this >>>>>>>>>>>>>>>>>> point, one can try to mitigate it using >> more >>>>> memory >>>>>>> or >>>>>>>>> so. I >>>>>>>>>>> am >>>>>>>>>>>>>> not there >>>>>>>>>>>>>>>>>> yet as I think I am hitting some software >>>>> bottleneck, >>>>>>>>> which I >>>>>>>>>>>>>> don't know >>>>>>>>>>>>>>>>>> how to work around. >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> Khaled >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> ---------------------------------------- >>>>>>>>>>>>>>>>>>> Date: Thu, 2 Oct 2014 14:20:47 -0700 >>>>>>>>>>>>>>>>>>> From: la...@apache.org >>>>>>>>>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> OK... We might need to investigate this. >>>>>>>>>>>>>>>>>>> Any chance that you can provide a >> minimal test >>>>>>> program >>>>>>>>> and >>>>>>>>>>>>>> instruction >>>>>>>>>>>>>>>>>> about how to set it up. >>>>>>>>>>>>>>>>>>> We can do some profiling then. >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> One thing to note is that with scanning >> HBase >>>>>>> cannot >>>>>>>>> use >>>>>>>>>>> bloom >>>>>>>>>>>>>> filters >>>>>>>>>>>>>>>>>> to rule out HFiles ahead of time, it needs >> to >>>>> look >>>>>>> into >>>>>>>>> all >>>>>>>>>>> of >>>>>>>>>>>>>> them. >>>>>>>>>>>>>>>>>>> So you kind of hit on the absolute worst >> case: >>>>>>>>>>>>>>>>>>> - random reads that do not fit into the >> block >>>>> cache >>>>>>>>>>>>>>>>>>> - cannot use bloom filters >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> Few more question/comments: >>>>>>>>>>>>>>>>>>> - Do you have short circuit reading >> enabled? If >>>>>>> not, >>>>>>>>> you >>>>>>>>>>>>> should. >>>>>>>>>>>>>>>>>>> - Is your table major compacted? That >> will >>>>> reduce >>>>>>> the >>>>>>>>>>> number of >>>>>>>>>>>>>> files >>>>>>>>>>>>>>>>> to >>>>>>>>>>>>>>>>>> look at. >>>>>>>>>>>>>>>>>>> - Did you disable Nagle's everywhere >> (enabled >>>>>>>>> tcpnodelay)? >>>>>>>>>>> It >>>>>>>>>>>>>> disabled >>>>>>>>>>>>>>>>>> by default in HBase, but necessarily in >> your >>>>> install >>>>>>> of >>>>>>>>> HDFS. >>>>>>>>>>>>>>>>>>> - Which version of HDFS are you using as >>>>> backing >>>>>>>>>>> filesystem? >>>>>>>>>>>>>>>>>>> - If your disk is idle, it means the >> data fits >>>>> into >>>>>>>>> the OS >>>>>>>>>>>>> buffer >>>>>>>>>>>>>>>>> cache. >>>>>>>>>>>>>>>>>> In turn that means that you increase the >> heap >>>>> for the >>>>>>>>> region >>>>>>>>>>>>>> servers. You >>>>>>>>>>>>>>>>>> can also use block encoding (FAST_DIFF) to >> try to >>>>>>> make >>>>>>>>> sure >>>>>>>>>>> the >>>>>>>>>>>>>> entire >>>>>>>>>>>>>>>>>> working set fits into the cache. >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> - Also try to reduce the block size - >> although >>>>> if >>>>>>> your >>>>>>>>>>> overall >>>>>>>>>>>>>> working >>>>>>>>>>>>>>>>>> set does not fit in the heap it won't help >> much. >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> This is a good section of the book to >> read >>>>> through >>>>>>>>>>> generally >>>>>>>>>>>>>> (even >>>>>>>>>>>>>>>>>> though you might know most of this >> already): >>>>>>>>>>>>>>>>>> >>>>>>> http://hbase.apache.org/book.html#perf.configurations >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> -- Lars >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> ----- Original Message ----- >>>>>>>>>>>>>>>>>>> From: Khaled Elmeleegy < >> kd...@hotmail.com> >>>>>>>>>>>>>>>>>>> To: "user@hbase.apache.org" < >>>>> user@hbase.apache.org >>>>>>>> >>>>>>>>>>>>>>>>>>> Cc: >>>>>>>>>>>>>>>>>>> Sent: Thursday, October 2, 2014 11:27 AM >>>>>>>>>>>>>>>>>>> Subject: RE: HBase read performance >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> I do see a very brief spike in CPU >>>>> (user/system), >>>>>>> but >>>>>>>>> it's >>>>>>>>>>> no >>>>>>>>>>>>>> where >>>>>>>>>>>>>>>>> near >>>>>>>>>>>>>>>>>> 0% idle. It goes from 99% idle down to >> something >>>>>>> like 40% >>>>>>>>>>> idle >>>>>>>>>>>>> for >>>>>>>>>>>>>> a >>>>>>>>>>>>>>>>> second >>>>>>>>>>>>>>>>>> or so. The thing to note, this is all on a >> test >>>>>>> cluster, >>>>>>>>> so >>>>>>>>>>> no >>>>>>>>>>>>>> real load. >>>>>>>>>>>>>>>>>> Things are generally idle until i issue >> 2-3 of >>>>> these >>>>>>>>>>>>>> multi-scan-requests >>>>>>>>>>>>>>>>> to >>>>>>>>>>>>>>>>>> render a web page. Then, you see the spike >> in the >>>>>>> cpu and >>>>>>>>>>> some >>>>>>>>>>>>>> activity >>>>>>>>>>>>>>>>> in >>>>>>>>>>>>>>>>>> the network and disk, but nowhere near >>>>> saturation. >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> If there are specific tests you'd like >> me to >>>>> do to >>>>>>>>> debug >>>>>>>>>>> this, >>>>>>>>>>>>>> I'd be >>>>>>>>>>>>>>>>>> more than happy to do it. >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> Khaled >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> ---------------------------------------- >>>>>>>>>>>>>>>>>>>> Date: Thu, 2 Oct 2014 11:15:59 -0700 >>>>>>>>>>>>>>>>>>>> From: la...@apache.org >>>>>>>>>>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> I still think you're waiting on disk. No >>>>> IOWAIT? >>>>>>> So >>>>>>>>> CPU >>>>>>>>>>> is not >>>>>>>>>>>>>> waiting >>>>>>>>>>>>>>>>>> a lot for IO. No high User/System CPU >> either? >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> If you see a lot of evicted block then >> each >>>>> RPC >>>>>>> has a >>>>>>>>> high >>>>>>>>>>>>>> chance of >>>>>>>>>>>>>>>>>> requiring to bring an entire 64k block in. >> You'll >>>>>>> see bad >>>>>>>>>>>>>> performance >>>>>>>>>>>>>>>>> with >>>>>>>>>>>>>>>>>> this. >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> We might need to trace this specific >> scenario. >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> -- Lars >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> ________________________________ >>>>>>>>>>>>>>>>>>>> From: Khaled Elmeleegy < >> kd...@hotmail.com> >>>>>>>>>>>>>>>>>>>> To: "user@hbase.apache.org" < >>>>>>> user@hbase.apache.org> >>>>>>>>>>>>>>>>>>>> Sent: Thursday, October 2, 2014 10:46 AM >>>>>>>>>>>>>>>>>>>> Subject: RE: HBase read performance >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> I've set the heap size to 6GB and I do >> have gc >>>>>>>>> logging. No >>>>>>>>>>>>> long >>>>>>>>>>>>>> pauses >>>>>>>>>>>>>>>>>> there -- occasional 0.1s or 0.2s. >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> Other than the discrepancy between >> what's >>>>>>> reported on >>>>>>>>> the >>>>>>>>>>>>>> client and >>>>>>>>>>>>>>>>>> what's reported at the RS, there is also >> the >>>>> issue >>>>>>> of not >>>>>>>>>>> getting >>>>>>>>>>>>>> proper >>>>>>>>>>>>>>>>>> concurrency. So, even if a reverse get >> takes >>>>> 100ms >>>>>>> or so >>>>>>>>>>> (this >>>>>>>>>>>>> has >>>>>>>>>>>>>> to be >>>>>>>>>>>>>>>>>> mostly blocking on various things as no >> physical >>>>>>>>> resource is >>>>>>>>>>>>>> contended), >>>>>>>>>>>>>>>>>> then the other gets/scans should be able to >>>>> proceed >>>>>>> in >>>>>>>>>>> parallel, >>>>>>>>>>>>>> so a >>>>>>>>>>>>>>>>>> thousand concurrent gets/scans should >> finish in >>>>> few >>>>>>>>> hundreds >>>>>>>>>>> of >>>>>>>>>>>>> ms >>>>>>>>>>>>>> not >>>>>>>>>>>>>>>>> many >>>>>>>>>>>>>>>>>> seconds. That's why I thought I'd increase >> the >>>>>>> handlers >>>>>>>>>>> count to >>>>>>>>>>>>>> try to >>>>>>>>>>>>>>>>> get >>>>>>>>>>>>>>>>>> more concurrency, but it didn't help. So, >> there >>>>> must >>>>>>> be >>>>>>>>>>> something >>>>>>>>>>>>>> else. >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> Khaled >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> ---------------------------------------- >>>>>>>>>>>>>>>>>>>>> From: ndimi...@gmail.com >>>>>>>>>>>>>>>>>>>>> Date: Thu, 2 Oct 2014 10:36:39 -0700 >>>>>>>>>>>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>> Do check again on the heap size of the >> region >>>>>>>>> servers. >>>>>>>>>>> The >>>>>>>>>>>>>> default >>>>>>>>>>>>>>>>>>>>> unconfigured size is 1G; too small for >> much >>>>> of >>>>>>>>> anything. >>>>>>>>>>>>> Check >>>>>>>>>>>>>> your >>>>>>>>>>>>>>>>> RS >>>>>>>>>>>>>>>>>> logs >>>>>>>>>>>>>>>>>>>>> -- look for lines produced by the >>>>> JVMPauseMonitor >>>>>>>>> thread. >>>>>>>>>>>>> They >>>>>>>>>>>>>>>>> usually >>>>>>>>>>>>>>>>>>>>> correlate with long GC pauses or other >>>>>>> process-freeze >>>>>>>>>>> events. >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>> Get is implemented as a Scan of a >> single >>>>> row, so >>>>>>> a >>>>>>>>>>> reverse >>>>>>>>>>>>>> scan of a >>>>>>>>>>>>>>>>>> single >>>>>>>>>>>>>>>>>>>>> row should be functionally equivalent. >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>> In practice, I have seen discrepancy >> between >>>>> the >>>>>>>>>>> latencies >>>>>>>>>>>>>> reported >>>>>>>>>>>>>>>>> by >>>>>>>>>>>>>>>>>> the >>>>>>>>>>>>>>>>>>>>> RS and the latencies experienced by the >>>>> client. >>>>>>> I've >>>>>>>>> not >>>>>>>>>>>>>> investigated >>>>>>>>>>>>>>>>>> this >>>>>>>>>>>>>>>>>>>>> area thoroughly. >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>> On Thu, Oct 2, 2014 at 10:05 AM, Khaled >>>>>>> Elmeleegy < >>>>>>>>>>>>>> kd...@hotmail.com >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> wrote: >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> Thanks Lars for your quick reply. >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> Yes performance is similar with less >>>>> handlers (I >>>>>>>>> tried >>>>>>>>>>> with >>>>>>>>>>>>>> 100 >>>>>>>>>>>>>>>>>> first). >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> The payload is not big ~1KB or so. The >>>>> working >>>>>>> set >>>>>>>>>>> doesn't >>>>>>>>>>>>>> seem to >>>>>>>>>>>>>>>>>> fit in >>>>>>>>>>>>>>>>>>>>>> memory as there are many cache misses. >>>>> However, >>>>>>>>> disk is >>>>>>>>>>> far >>>>>>>>>>>>>> from >>>>>>>>>>>>>>>>>> being a >>>>>>>>>>>>>>>>>>>>>> bottleneck. I checked using iostat. I >> also >>>>>>> verified >>>>>>>>> that >>>>>>>>>>>>>> neither the >>>>>>>>>>>>>>>>>>>>>> network nor the CPU of the region >> server or >>>>> the >>>>>>>>> client >>>>>>>>>>> are a >>>>>>>>>>>>>>>>>> bottleneck. >>>>>>>>>>>>>>>>>>>>>> This leads me to believe that likely >> this >>>>> is a >>>>>>>>> software >>>>>>>>>>>>>> bottleneck, >>>>>>>>>>>>>>>>>>>>>> possibly due to a misconfiguration on >> my >>>>> side. I >>>>>>>>> just >>>>>>>>>>> don't >>>>>>>>>>>>>> know how >>>>>>>>>>>>>>>>>> to >>>>>>>>>>>>>>>>>>>>>> debug it. A clear disconnect I see is >> the >>>>>>> individual >>>>>>>>>>> request >>>>>>>>>>>>>> latency >>>>>>>>>>>>>>>>>> as >>>>>>>>>>>>>>>>>>>>>> reported by metrics on the region >> server >>>>> (IPC >>>>>>>>>>>>> processCallTime >>>>>>>>>>>>>> vs >>>>>>>>>>>>>>>>>> scanNext) >>>>>>>>>>>>>>>>>>>>>> vs what's measured on the client. >> Does this >>>>>>> sound >>>>>>>>>>> right? Any >>>>>>>>>>>>>> ideas >>>>>>>>>>>>>>>>> on >>>>>>>>>>>>>>>>>> how >>>>>>>>>>>>>>>>>>>>>> to better debug it? >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> About this trick with the timestamps >> to be >>>>> able >>>>>>> to >>>>>>>>> do a >>>>>>>>>>>>>> forward >>>>>>>>>>>>>>>>> scan, >>>>>>>>>>>>>>>>>>>>>> thanks for pointing it out. Actually, >> I am >>>>>>> aware of >>>>>>>>> it. >>>>>>>>>>> The >>>>>>>>>>>>>> problem >>>>>>>>>>>>>>>>> I >>>>>>>>>>>>>>>>>> have >>>>>>>>>>>>>>>>>>>>>> is, sometimes I want to get the key >> after a >>>>>>>>> particular >>>>>>>>>>>>>> timestamp and >>>>>>>>>>>>>>>>>>>>>> sometimes I want to get the key >> before, so >>>>> just >>>>>>>>> relying >>>>>>>>>>> on >>>>>>>>>>>>>> the key >>>>>>>>>>>>>>>>>> order >>>>>>>>>>>>>>>>>>>>>> doesn't work. Ideally, I want a >> reverse >>>>> get(). I >>>>>>>>> thought >>>>>>>>>>>>>> reverse >>>>>>>>>>>>>>>>> scan >>>>>>>>>>>>>>>>>> can >>>>>>>>>>>>>>>>>>>>>> do the trick though. >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> Khaled >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >> ---------------------------------------- >>>>>>>>>>>>>>>>>>>>>>> Date: Thu, 2 Oct 2014 09:40:37 -0700 >>>>>>>>>>>>>>>>>>>>>>> From: la...@apache.org >>>>>>>>>>>>>>>>>>>>>>> Subject: Re: HBase read performance >>>>>>>>>>>>>>>>>>>>>>> To: user@hbase.apache.org >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Hi Khaled, >>>>>>>>>>>>>>>>>>>>>>> is it the same with fewer threads? >> 1500 >>>>> handler >>>>>>>>> threads >>>>>>>>>>>>>> seems to >>>>>>>>>>>>>>>>> be a >>>>>>>>>>>>>>>>>>>>>> lot. Typically a good number of >> threads >>>>> depends >>>>>>> on >>>>>>>>> the >>>>>>>>>>>>>> hardware >>>>>>>>>>>>>>>>>> (number of >>>>>>>>>>>>>>>>>>>>>> cores, number of spindles, etc). I >> cannot >>>>> think >>>>>>> of >>>>>>>>> any >>>>>>>>>>> type >>>>>>>>>>>>> of >>>>>>>>>>>>>>>>>> scenario >>>>>>>>>>>>>>>>>>>>>> where more than 100 would give any >>>>> improvement. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> How large is the payload per KV >> retrieved >>>>> that >>>>>>>>> way? If >>>>>>>>>>>>> large >>>>>>>>>>>>>> (as >>>>>>>>>>>>>>>>> in a >>>>>>>>>>>>>>>>>>>>>> few 100k) you definitely want to >> lower the >>>>>>> number >>>>>>>>> of the >>>>>>>>>>>>>> handler >>>>>>>>>>>>>>>>>> threads. >>>>>>>>>>>>>>>>>>>>>>> How much heap do you give the region >>>>> server? >>>>>>> Does >>>>>>>>> the >>>>>>>>>>>>>> working set >>>>>>>>>>>>>>>>> fit >>>>>>>>>>>>>>>>>>>>>> into the cache? (i.e. in the metrics, >> do you >>>>>>> see the >>>>>>>>>>>>> eviction >>>>>>>>>>>>>> count >>>>>>>>>>>>>>>>>> going >>>>>>>>>>>>>>>>>>>>>> up, if so it does not fit into the >> cache). >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> If the working set does not fit into >> the >>>>> cache >>>>>>>>>>> (eviction >>>>>>>>>>>>>> count goes >>>>>>>>>>>>>>>>>> up) >>>>>>>>>>>>>>>>>>>>>> then HBase will need to bring a new >> block in >>>>>>> from >>>>>>>>> disk >>>>>>>>>>> on >>>>>>>>>>>>>> each Get >>>>>>>>>>>>>>>>>>>>>> (assuming the Gets are more or less >> random >>>>> as >>>>>>> far >>>>>>>>> as the >>>>>>>>>>>>>> server is >>>>>>>>>>>>>>>>>>>>>> concerned). >>>>>>>>>>>>>>>>>>>>>>> In case you'll benefit from reducing >> the >>>>> HFile >>>>>>>>> block >>>>>>>>>>> size >>>>>>>>>>>>>> (from 64k >>>>>>>>>>>>>>>>>> to >>>>>>>>>>>>>>>>>>>>>> 8k or even 4k). >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Lastly I don't think we tested the >>>>> performance >>>>>>> of >>>>>>>>> using >>>>>>>>>>>>>> reverse >>>>>>>>>>>>>>>>> scan >>>>>>>>>>>>>>>>>>>>>> this way, there is probably room to >> optimize >>>>>>> this. >>>>>>>>>>>>>>>>>>>>>>> Can you restructure your keys to >> allow >>>>> forwards >>>>>>>>>>> scanning? >>>>>>>>>>>>> For >>>>>>>>>>>>>>>>> example >>>>>>>>>>>>>>>>>>>>>> you could store the time as >> MAX_LONG-time. >>>>> Or >>>>>>> you >>>>>>>>> could >>>>>>>>>>>>>> invert all >>>>>>>>>>>>>>>>>> the bits >>>>>>>>>>>>>>>>>>>>>> of the time portion of the key, so >> that it >>>>> sort >>>>>>> the >>>>>>>>>>> other >>>>>>>>>>>>>> way. Then >>>>>>>>>>>>>>>>>> you >>>>>>>>>>>>>>>>>>>>>> could do a forward scan. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Let us know how it goes. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> -- Lars >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> ----- Original Message ----- >>>>>>>>>>>>>>>>>>>>>>> From: Khaled Elmeleegy < >> kd...@hotmail.com> >>>>>>>>>>>>>>>>>>>>>>> To: "user@hbase.apache.org" < >>>>>>> user@hbase.apache.org >>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Cc: >>>>>>>>>>>>>>>>>>>>>>> Sent: Thursday, October 2, 2014 >> 12:12 AM >>>>>>>>>>>>>>>>>>>>>>> Subject: HBase read performance >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Hi, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> I am trying to do a scatter/gather >> on hbase >>>>>>>>> (0.98.6.1), >>>>>>>>>>>>>> where I >>>>>>>>>>>>>>>>> have >>>>>>>>>>>>>>>>>> a >>>>>>>>>>>>>>>>>>>>>> client reading ~1000 keys from an >> HBase >>>>> table. >>>>>>> These >>>>>>>>>>> keys >>>>>>>>>>>>>> happen to >>>>>>>>>>>>>>>>>> fall on >>>>>>>>>>>>>>>>>>>>>> the same region server. For my reads >> I use >>>>>>> reverse >>>>>>>>> scan >>>>>>>>>>> to >>>>>>>>>>>>>> read each >>>>>>>>>>>>>>>>>> key as >>>>>>>>>>>>>>>>>>>>>> I want the key prior to a specific >> time >>>>> stamp >>>>>>> (time >>>>>>>>>>> stamps >>>>>>>>>>>>> are >>>>>>>>>>>>>>>>> stored >>>>>>>>>>>>>>>>>> in >>>>>>>>>>>>>>>>>>>>>> reverse order). I don't believe gets >> can >>>>>>> accomplish >>>>>>>>>>> that, >>>>>>>>>>>>>> right? so >>>>>>>>>>>>>>>>> I >>>>>>>>>>>>>>>>>> use >>>>>>>>>>>>>>>>>>>>>> scan, with caching set to 1. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> I use 2000 reader threads in the >> client >>>>> and on >>>>>>>>> HBase, >>>>>>>>>>> I've >>>>>>>>>>>>>> set >>>>>>>>>>>>>>>>>>>>>> hbase.regionserver.handler.count to >> 1500. >>>>> With >>>>>>> this >>>>>>>>>>> setup, >>>>>>>>>>>>> my >>>>>>>>>>>>>>>>> scatter >>>>>>>>>>>>>>>>>>>>>> gather is very slow and can take up >> to 10s >>>>> in >>>>>>> total. >>>>>>>>>>> Timing >>>>>>>>>>>>> an >>>>>>>>>>>>>>>>>> individual >>>>>>>>>>>>>>>>>>>>>> getScanner(..) call on the client >> side, it >>>>> can >>>>>>>>> easily >>>>>>>>>>> take >>>>>>>>>>>>> few >>>>>>>>>>>>>>>>>> hundreds of >>>>>>>>>>>>>>>>>>>>>> ms. I also got the following metrics >> from >>>>> the >>>>>>> region >>>>>>>>>>> server >>>>>>>>>>>>> in >>>>>>>>>>>>>>>>>> question: >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> "queueCallTime_mean" : >> 2.190855525775637, >>>>>>>>>>>>>>>>>>>>>>> "queueCallTime_median" : 0.0, >>>>>>>>>>>>>>>>>>>>>>> "queueCallTime_75th_percentile" : >> 0.0, >>>>>>>>>>>>>>>>>>>>>>> "queueCallTime_95th_percentile" : >> 1.0, >>>>>>>>>>>>>>>>>>>>>>> "queueCallTime_99th_percentile" : >>>>>>>>> 556.9799999999818, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_min" : 0, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_max" : 12755, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_mean" : >>>>> 105.64873440912682, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_median" : 0.0, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_75th_percentile" : >> 2.0, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_95th_percentile" : >>>>> 7917.95, >>>>>>>>>>>>>>>>>>>>>>> "processCallTime_99th_percentile" : >>>>> 8876.89, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_min" >>>>>>>>>>>>>>>>>>>>>> : 89, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_max" >>>>>>>>>>>>>>>>>>>>>> : 11300, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_mean" >>>>>>>>>>>>>>>>>>>>>> : 654.4949739797315, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_median" >>>>>>>>>>>>>>>>>>>>>> : 101.0, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_75th_percentile" >>>>>>>>>>>>>>>>>>>>>> : 101.0, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_95th_percentile" >>>>>>>>>>>>>>>>>>>>>> : 101.0, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >> "namespace_default_table_delta_region_87be70d7710f95c05cfcc90181d183b4_metric_scanNext_99th_percentile" >>>>>>>>>>>>>>>>>>>>>> : 113.0, >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Where "delta" is the name of the >> table I am >>>>>>>>> querying. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> In addition to all this, i monitored >> the >>>>>>> hardware >>>>>>>>>>> resources >>>>>>>>>>>>>> (CPU, >>>>>>>>>>>>>>>>>> disk, >>>>>>>>>>>>>>>>>>>>>> and network) of both the client and >> the >>>>> region >>>>>>>>> server >>>>>>>>>>> and >>>>>>>>>>>>>> nothing >>>>>>>>>>>>>>>>>> seems >>>>>>>>>>>>>>>>>>>>>> anywhere near saturation. So I am >> puzzled by >>>>>>> what's >>>>>>>>>>> going on >>>>>>>>>>>>>> and >>>>>>>>>>>>>>>>>> where this >>>>>>>>>>>>>>>>>>>>>> time is going. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Few things to note based on the above >>>>>>> measurements: >>>>>>>>>>> both >>>>>>>>>>>>>> medians of >>>>>>>>>>>>>>>>>> IPC >>>>>>>>>>>>>>>>>>>>>> processCallTime and queueCallTime are >>>>> basically >>>>>>> zero >>>>>>>>>>> (ms I >>>>>>>>>>>>>> presume, >>>>>>>>>>>>>>>>>>>>>> right?). However, scanNext_median is >> 101 (ms >>>>>>> too, >>>>>>>>>>> right?). I >>>>>>>>>>>>>> am not >>>>>>>>>>>>>>>>>> sure >>>>>>>>>>>>>>>>>>>>>> how this adds up. Also, even though >> the 101 >>>>>>> figure >>>>>>>>> seems >>>>>>>>>>>>>>>>> outrageously >>>>>>>>>>>>>>>>>> high >>>>>>>>>>>>>>>>>>>>>> and I don't know why, still all these >> scans >>>>>>> should >>>>>>>>> be >>>>>>>>>>>>>> happening in >>>>>>>>>>>>>>>>>>>>>> parallel, so the overall call should >> finish >>>>>>> fast, >>>>>>>>> given >>>>>>>>>>> that >>>>>>>>>>>>>> no >>>>>>>>>>>>>>>>>> hardware >>>>>>>>>>>>>>>>>>>>>> resource is contended, right? but >> this is >>>>> not >>>>>>> what's >>>>>>>>>>>>>> happening, so I >>>>>>>>>>>>>>>>>> have >>>>>>>>>>>>>>>>>>>>>> to be missing something(s). >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> So, any help is appreciated there. >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>> Thanks, >>>>>>>>>>>>>>>>>>>>>>> Khaled >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> -- >>>>>>>>>> Best regards, >>>>>>>>>> >>>>>>>>>> - Andy >>>>>>>>>> >>>>>>>>>> Problems worthy of attack prove their worth by hitting >> back. - >>>>> Piet >>>>>>> Hein >>>>>>>>>> (via Tom White) >>>>>>>>> >>>>>>>>> >>>>>>> >>>>>>> >>>>> >>>>> >>