Mailing-List: contact user-help@hbase.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@hbase.apache.org
Received-SPF: pass (nike.apache.org: local policy)
DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws;
  s=s1024; d=yahoo.com;
  h=X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-RocketYMMF:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type:Content-Transfer-Encoding;
  b=0CSzjnp01TPLsdWJR99eKf83lAYnAIEA+qZf3F7NSBtw3NBHKg6aDSKJwJKB0eJDFb7BNbaEM2/vcWVzibhLpk47Csi38FJX9Q9BSpRkOqs4sbKUffC7rcBvG86Gt8Zz2gIce6EX6qnIG9qELGqjIhZIuap/JuzN/jC5C3Bh330=;
References: 
 <CALckxSMi58XRCB+8X5z4ayjc8=hwGQOPOpZnbbPQaT5qE0QpPw@mail.gmail.com>
Message-ID: <1368772687.12945.YahooMailNeo@web140606.mail.bf1.yahoo.com>
Date: Thu, 16 May 2013 23:38:07 -0700 (PDT)
From: lars hofhansl <larsh@apache.org>
Reply-To: lars hofhansl <larsh@apache.org>
Subject: Re: GET performance degrades over time
To: "user@hbase.apache.org" <user@hbase.apache.org>
In-Reply-To: 
 <CALckxSMi58XRCB+8X5z4ayjc8=hwGQOPOpZnbbPQaT5qE0QpPw@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
Content-Transfer-Encoding: quoted-printable

Hi Viral,=0A=0Asome questions:=0A=0A=0AAre you adding new data or deleting =
data over time?=0ADo you have bloom filters enabled?=0AWhich version of Had=
oop?=0A=0A=0AAnything funny the Datanode logs?=0A=0A-- Lars=0A=0A=0A=0A----=
- Original Message -----=0AFrom: Viral Bajaria <viral.bajaria@gmail.com>=0A=
To: "user@hbase.apache.org" <user@hbase.apache.org>=0ACc: =0ASent: Thursday=
, May 16, 2013 2:16 AM=0ASubject: GET performance degrades over time=0A=0AH=
i,=0A=0AMy setup is as follows:=0A24 regionservers (7GB RAM, 8-core CPU, 5G=
B heap space)=0Ahbase 0.94.4=0A5-7 regions per regionserver=0A=0AI am doing=
 an avg of 4k-5k random gets per regionserver per second and the=0Aperforma=
nce is acceptable in the beginning. I have also done ~10K gets for=0Aa sing=
le regionserver and got the results back in 600-800ms. After a while=0Athe =
performance of the GETs starts degrading. The same ~10K random gets=0Astart=
 taking upwards of 9s-10s.=0A=0AWith regards to hbase settings that I have =
modified, I have disabled major=0Acompaction, increase region size to 100G =
and bumped up the handler count to=0A100.=0A=0AI monitored ganglia for metr=
ics that vary when the performance shifts from=0Agood to bad and found that=
 the fsPreadLatency_avg_time is almost 25x in the=0Abad performing regionse=
rver. fsReadLatency_avg_time is also slightly higher=0Abut not that much (i=
t's around 2x).=0A=0AI took a thread dump of the regionserver process and a=
lso did CPU=0Autilization monitoring. The CPU cycles were being spent=0Aon =
org.apache.hadoop.hdfs.BlockReaderLocal.read and stack trace for threads=0A=
running that function is below this email.=0A=0AAny pointers on why positio=
nal reads degrade over time ? Or is this just an=0Aissue of disk I/O and I =
should start looking into that ?=0A=0AThanks,=0AViral=0A=0A=3D=3D=3D=3Dstac=
ktrace for one of the handler doing blockread=3D=3D=3D=3D=0A"IPC Server han=
dler 98 on 60020" - Thread t@147=0A=A0  java.lang.Thread.State: RUNNABLE=0A=
at java.io.FileInputStream.readBytes(Native Method)=0Aat java.io.FileInputS=
tream.read(FileInputStream.java:220)=0Aat org.apache.hadoop.hdfs.BlockReade=
rLocal.read(BlockReaderLocal.java:324)=0A- locked <3215ed96> (a org.apache.=
hadoop.hdfs.BlockReaderLocal)=0Aat org.apache.hadoop.fs.FSInputChecker.read=
Fully(FSInputChecker.java:384)=0Aat org.apache.hadoop.hdfs.DFSClient$BlockR=
eader.readAll(DFSClient.java:1763)=0Aat=0Aorg.apache.hadoop.hdfs.DFSClient$=
DFSInputStream.fetchBlockByteRange(DFSClient.java:2333)=0Aat org.apache.had=
oop.hdfs.DFSClient$DFSInputStream.read(DFSClient.java:2400)=0Aat org.apache=
.hadoop.fs.FSDataInputStream.read(FSDataInputStream.java:46)=0Aat=0Aorg.apa=
che.hadoop.hbase.io.hfile.HFileBlock$AbstractFSReader.readAtOffset(HFileBlo=
ck.java:1363)=0Aat=0Aorg.apache.hadoop.hbase.io.hfile.HFileBlock$FSReaderV2=
.readBlockDataInternal(HFileBlock.java:1799)=0Aat=0Aorg.apache.hadoop.hbase=
.io.hfile.HFileBlock$FSReaderV2.readBlockData(HFileBlock.java:1643)=0Aat=0A=
org.apache.hadoop.hbase.io.hfile.HFileReaderV2.readBlock(HFileReaderV2.java=
:338)=0Aat=0Aorg.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexRea=
der.loadDataBlockWithScanInfo(HFileBlockIndex.java:254)=0Aat=0Aorg.apache.h=
adoop.hbase.io.hfile.HFileReaderV2$AbstractScannerV2.seekTo(HFileReaderV2.j=
ava:480)=0Aat=0Aorg.apache.hadoop.hbase.io.hfile.HFileReaderV2$AbstractScan=
nerV2.seekTo(HFileReaderV2.java:501)=0Aat=0Aorg.apache.hadoop.hbase.regions=
erver.StoreFileScanner.seekAtOrAfter(StoreFileScanner.java:226)=0Aat=0Aorg.=
apache.hadoop.hbase.regionserver.StoreFileScanner.seek(StoreFileScanner.jav=
a:145)=0Aat=0Aorg.apache.hadoop.hbase.regionserver.StoreFileScanner.enforce=
Seek(StoreFileScanner.java:351)=0Aat=0Aorg.apache.hadoop.hbase.regionserver=
.KeyValueHeap.pollRealKV(KeyValueHeap.java:354)=0Aat=0Aorg.apache.hadoop.hb=
ase.regionserver.KeyValueHeap.generalizedSeek(KeyValueHeap.java:312)=0Aat=
=0Aorg.apache.hadoop.hbase.regionserver.KeyValueHeap.requestSeek(KeyValueHe=
ap.java:277)=0Aat=0Aorg.apache.hadoop.hbase.regionserver.StoreScanner.resee=
k(StoreScanner.java:543)=0A- locked <3da12c8a> (a org.apache.hadoop.hbase.r=
egionserver.StoreScanner)=0Aat=0Aorg.apache.hadoop.hbase.regionserver.Store=
Scanner.next(StoreScanner.java:411)=0A- locked <3da12c8a> (a org.apache.had=
oop.hbase.regionserver.StoreScanner)=0Aat=0Aorg.apache.hadoop.hbase.regions=
erver.KeyValueHeap.next(KeyValueHeap.java:143)=0Aat=0Aorg.apache.hadoop.hba=
se.regionserver.HRegion$RegionScannerImpl.nextInternal(HRegion.java:3643)=
=0Aat=0Aorg.apache.hadoop.hbase.regionserver.HRegion$RegionScannerImpl.next=
Raw(HRegion.java:3578)=0Aat=0Aorg.apache.hadoop.hbase.regionserver.HRegion$=
RegionScannerImpl.next(HRegion.java:3561)=0A- locked <74d81ea7> (a=0Aorg.ap=
ache.hadoop.hbase.regionserver.HRegion$RegionScannerImpl)=0Aat=0Aorg.apache=
.hadoop.hbase.regionserver.HRegion$RegionScannerImpl.next(HRegion.java:3599=
)=0Aat org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:4407)=
=0Aat org.apache.hadoop.hbase.regionserver.HRegion.get(HRegion.java:4380)=
=0Aat=0Aorg.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServe=
r.java:2039)=0Aat sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Sour=
ce)=0Aat=0Asun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethod=
AccessorImpl.java:25)=0Aat java.lang.reflect.Method.invoke(Method.java:597)=
=0Aat=0Aorg.apache.hadoop.hbase.ipc.WritableRpcEngine$Server.call(WritableR=
pcEngine.java:364)=0Aat=0Aorg.apache.hadoop.hbase.ipc.HBaseServer$Handler.r=
un(HBaseServer.java:1426)=0A