Mailing-List: contact dev-help@hbase.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@hbase.apache.org
Received-SPF: pass (athena.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;
  b=ZDiNgM36SUQjSrvFmk2/bs+3NHuk49H9y6SIufXzHaOvrc3e6d/+64nKjJHtzDS0PI2OqaYjWip3qwGn6yh8zjDYR21f+1V2ZU1LwC1oRmfGXyMQ5udaYYx3RwSYwOzBa+vaRTqp+j4q1Kv7hGtgqLNS5/jBBlecsuXfhVAwGMY=;
References: 
 <CAAMYKhqSPcP0wOiG8RWZw1stTeHt-iULSuazkNmx+uLLVwPyxQ@mail.gmail.com>
	<CALte62zn50G=YC6BedMA4wZ8fHm4m4xD-Q10vHezkw+kja36PA@mail.gmail.com>
	<CAAMYKhodVTd25gW+m8MHmS1H22dgOF-2MfRBBZ8Q-1C9t=xzRQ@mail.gmail.com>
	<CADcMMgHxCor5156f7fMqx7cxS=+BfC9x=tCarWsXck+q7XTBRA@mail.gmail.com>
	<DC5EBE7F3610EB4CA5C7E92D76873E1518629B58B5@exchange2007.carrieriq.com>
	<CA+RK=_Cj4gc60DAcpF8+qS5yqF7SmLo_HwLbj-miRh8D7S-3YA@mail.gmail.com>
	<CA+RK=_A8i91becrEW7Pv8V476+_TLXKN5p+yUTTKVsfSNhGO_Q@mail.gmail.com>
 <CAAg3a2qVOppckqhD9c+2p_5zMtQcHyQK7H5HAfagMfmWJa-0Uw@mail.gmail.com>
Message-ID: <1389849467.20702.YahooMailNeo@web140603.mail.bf1.yahoo.com>
Date: Wed, 15 Jan 2014 21:17:47 -0800 (PST)
From: lars hofhansl <larsh@apache.org>
Reply-To: lars hofhansl <larsh@apache.org>
Subject: Re: HBase 0.94.15: writes stalls periodically even under moderate
 steady load (AWS EC2)
To: "dev@hbase.apache.org" <dev@hbase.apache.org>
In-Reply-To: 
 <CAAg3a2qVOppckqhD9c+2p_5zMtQcHyQK7H5HAfagMfmWJa-0Uw@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/alternative;
 boundary="-1172831624-2136494398-1389849467=:20702"

---1172831624-2136494398-1389849467=:20702
Content-Type: text/plain; charset=iso-8859-1
Content-Transfer-Encoding: quoted-printable

So where's the bottleneck? You say it's not IO, not is it CPU, I presume.=
=0ANetwork? Are the writers blocked because there are too many storefiles? =
(in which case you maxed out your storage IO)=0AAre you hotspotting a regio=
n server?=0A=0AFrom the stacktrace it looks like ycsb is doing single puts,=
 each incurring an RPC. You're testing AWS' network :)=0A=0A=0AI write 10-2=
0k (small) rows per second in bulk on a single box for testing all the time=
.=0AWith 3-way replication a 5 nodes cluster is pretty puny. Each box will =
get 60% of each write on average, just to state the obvious.=0A=0AAs I said=
, if it's slow, I'd love to see where the bottleneck is, so that we can fix=
 it, if it is something we can fix in HBase.=0A=0A-- Lars=0A=0A=0A=0A______=
__________________________=0A From: Vladimir Rodionov <vladrodionov@gmail.c=
om>=0ATo: "dev@hbase.apache.org" <dev@hbase.apache.org> =0ASent: Wednesday,=
 January 15, 2014 5:32 PM=0ASubject: Re: HBase 0.94.15: writes stalls perio=
dically even under moderate steady load (AWS EC2)=0A =0A=0AYes, I am using =
ephemeral (local) storage. I found that iostat is most of=0Athe time idle o=
n 3K load with periodic bursts up to 10% iowait. 3-4K is=0Aprobably the max=
imum this skinny cluster can sustain w/o additional=0Aconfiguration tweakin=
g. I will try more powerful instances, of course, but=0Athe beauty of m1.xl=
arge is 0.05 price on the spot market. 5 nodes cluster=0A(+1) is ~ $7 per d=
ay. Good for experiments, but, definitely, not for real=0Atesting.=0A=0A-Vl=
adimir Rodionov=0A=0A=0A=0AOn Wed, Jan 15, 2014 at 3:27 PM, Andrew Purtell =
<apurtell@apache.org> wrote:=0A=0A> Also I assume your HDFS is provisioned =
on locally attached disk, aka=0A> instance store, and not EBS?=0A>=0A>=0A> =
On Wed, Jan 15, 2014 at 3:26 PM, Andrew Purtell <apurtell@apache.org>=0A> w=
rote:=0A>=0A> > m1.xlarge is a poorly provisioned instance type, with low P=
PS at the=0A> > network layer. Can you try a type advertised to have "high"=
 I/O=0A> > performance?=0A> >=0A> >=0A> > On Wed, Jan 15, 2014 at 12:33 PM,=
 Vladimir Rodionov <=0A> > vrodionov@carrieriq.com> wrote:=0A> >=0A> >> Thi=
s is something which needs to be definitely solved/fixed/resolved=0A> >>=0A=
> >> I am running YCSB benchmark on aws ec2 on a small HBase cluster=0A> >>=
=0A> >> 5 (m1.xlarge) as RS=0A> >> 1 (m1.xlarge) hbase-master, zookeper=0A>=
 >>=0A> >> Whirr 0.8.2 (with many hacks) is used to provision HBase.=0A> >>=
=0A> >> I am running 1 ycsb client (100% insert ops) throttled at 5K ops:=
=0A> >>=0A> >> ./bin/ycsb load hbase -P workloads/load20m -p columnfamily=
=3Dfamily -s=0A> >> -threads 10 -target 5000=0A> >>=0A> >> OUTPUT:=0A> >>=
=0A> >> 1120 sec: 5602339 operations; 4999.7 current ops/sec; [INSERT=0A> >=
> AverageLatency(us)=3D225.53]=0A> >>=A0 1130 sec: 5652117 operations; 4969=
.35 current ops/sec; [INSERT=0A> >> AverageLatency(us)=3D203.31]=0A> >>=A0 =
1140 sec: 5665210 operations; 1309.04 current ops/sec; [INSERT=0A> >> Avera=
geLatency(us)=3D17.13]=0A> >>=A0 1150 sec: 5665210 operations; 0 current op=
s/sec;=0A> >>=A0 1160 sec: 5665210 operations; 0 current ops/sec;=0A> >>=A0=
 1170 sec: 5665210 operations; 0 current ops/sec;=0A> >>=A0 1180 sec: 56652=
10 operations; 0 current ops/sec;=0A> >>=A0 1190 sec: 5665210 operations; 0=
 current ops/sec;=0A> >> 2014-01-15 15:19:34,139 Thread-2 WARN=0A> >>=A0 [H=
ConnectionManager$HConnectionImplementation] Failed all from=0A> >>=0A> reg=
ion=3Dusertable,user6039,1389811852201.40518862106856d23b883e5d543d0b89.,=
=0A> >> hostname=3Dip-10-45-174-120.ec2.internal, port=3D60020=0A> >> java.=
util.concurrent.ExecutionException:=0A> java.net.SocketTimeoutException:=0A=
> >> Call to ip-10-45-174-120.ec2.internal/10.45.174.120:60020 failed on=0A=
> >> socket timeout exception: java.net.SocketTimeoutException: 60000 milli=
s=0A> >> timeout while waiting for channel to be ready for read. ch :=0A> >=
> java.nio.channels.SocketChannel[connected local=3D/10.180.211.173:42466=
=0A> remote=3Dip-10-45-174-120.ec2.internal/=0A> >> 10.45.174.120:60020]=0A=
> >>=A0 =A0 =A0 =A0  at=0A> >> java.util.concurrent.FutureTask$Sync.innerGe=
t(FutureTask.java:252)=0A> >>=A0 =A0 =A0 =A0  at java.util.concurrent.Futur=
eTask.get(FutureTask.java:111)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A> org.apa=
che.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.proces=
sBatchCallback(HConnectionManager.java:1708)=0A> >>=A0 =A0 =A0 =A0  at=0A> =
>>=0A> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImpleme=
ntation.processBatch(HConnectionManager.java:1560)=0A> >>=A0 =A0 =A0 =A0  a=
t=0A> >> org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:994=
)=0A> >>=A0 =A0 =A0 =A0  at org.apache.hadoop.hbase.client.HTable.doPut(HTa=
ble.java:850)=0A> >>=A0 =A0 =A0 =A0  at org.apache.hadoop.hbase.client.HTab=
le.put(HTable.java:826)=0A> >>=A0 =A0 =A0 =A0  at com.yahoo.ycsb.db.HBaseCl=
ient.update(HBaseClient.java:328)=0A> >>=A0 =A0 =A0 =A0  at com.yahoo.ycsb.=
db.HBaseClient.insert(HBaseClient.java:357)=0A> >>=A0 =A0 =A0 =A0  at com.y=
ahoo.ycsb.DBWrapper.insert(DBWrapper.java:148)=0A> >>=A0 =A0 =A0 =A0  at=0A=
> >> com.yahoo.ycsb.workloads.CoreWorkload.doInsert(CoreWorkload.java:461)=
=0A> >>=A0 =A0 =A0 =A0  at com.yahoo.ycsb.ClientThread.run(Client.java:269)=
=0A> >> Caused by: java.net.SocketTimeoutException: Call to=0A> >> ip-10-45=
-174-120.ec2.internal/10.45.174.120:60020 failed on socket=0A> >> timeout e=
xception: java.net.SocketTimeoutException: 60000 millis timeout=0A> >> whil=
e waiting for channel to be ready for read. ch :=0A> >> java.nio.channels.S=
ocketChannel[connected local=3D/10.180.211.173:42466=0A> remote=3Dip-10-45-=
174-120.ec2.internal/=0A> >> 10.45.174.120:60020]=0A> >>=A0 =A0 =A0 =A0  at=
=0A> >>=0A> org.apache.hadoop.hbase.ipc.HBaseClient.wrapException(HBaseClie=
nt.java:1043)=0A> >>=A0 =A0 =A0 =A0  at=0A> >> org.apache.hadoop.hbase.ipc.=
HBaseClient.call(HBaseClient.java:1016)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A=
> org.apache.hadoop.hbase.ipc.WritableRpcEngine$Invoker.invoke(WritableRpcE=
ngine.java:87)=0A> >>=A0 =A0 =A0 =A0  at com.sun.proxy.$Proxy5.multi(Unknow=
n Source)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A> org.apache.hadoop.hbase.clie=
nt.HConnectionManager$HConnectionImplementation$3$1.call(HConnectionManager=
.java:1537)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A> org.apache.hadoop.hbase.cl=
ient.HConnectionManager$HConnectionImplementation$3$1.call(HConnectionManag=
er.java:1535)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A> org.apache.hadoop.hbase.=
client.ServerCallable.withoutRetries(ServerCallable.java:229)=0A> >>=A0 =A0=
 =A0 =A0  at=0A> >>=0A> org.apache.hadoop.hbase.client.HConnectionManager$H=
ConnectionImplementation$3.call(HConnectionManager.java:1544)=0A> >>=A0 =A0=
 =A0 =A0  at=0A> >>=0A> org.apache.hadoop.hbase.client.HConnectionManager$H=
ConnectionImplementation$3.call(HConnectionManager.java:1532)=0A> >>=A0 =A0=
 =A0 =A0  at=0A> >> java.util.concurrent.FutureTask$Sync.innerRun(FutureTas=
k.java:334)=0A> >>=A0 =A0 =A0 =A0  at java.util.concurrent.FutureTask.run(F=
utureTask.java:166)=0A> >>=A0 =A0 =A0 =A0  at=0A> >>=0A> java.util.concurre=
nt.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)=0A> >>=A0 =A0=
 =A0 =A0  at=0A> >>=0A> java.util.concurrent.ThreadPoolExecutor$Worker.run(=
ThreadPoolExecutor.java:615)=0A> >>=A0 =A0 =A0 =A0  at java.lang.Thread.run=
(Thread.java:701)=0A> >>=0A> >>=0A> >> SKIPPED A LOT=0A> >>=0A> >>=0A> >>=
=A0 1200 sec: 5674180 operations; 896.82 current ops/sec; [INSERT=0A> >> Av=
erageLatency(us)=3D7506.37]=0A> >>=A0 1210 sec: 6022326 operations; 34811.1=
2 current ops/sec; [INSERT=0A> >> AverageLatency(us)=3D1998.26]=0A> >>=A0 1=
220 sec: 6102627 operations; 8018.07 current ops/sec; [INSERT=0A> >> Averag=
eLatency(us)=3D395.11]=0A> >>=A0 1230 sec: 6152632 operations; 5000 current=
 ops/sec; [INSERT=0A> >> AverageLatency(us)=3D182.53]=0A> >>=A0 1240 sec: 6=
202641 operations; 4999.9 current ops/sec; [INSERT=0A> >> AverageLatency(us=
)=3D201.76]=0A> >>=A0 1250 sec: 6252642 operations; 4999.6 current ops/sec;=
 [INSERT=0A> >> AverageLatency(us)=3D190.46]=0A> >>=A0 1260 sec: 6302653 op=
erations; 5000.1 current ops/sec; [INSERT=0A> >> AverageLatency(us)=3D212.3=
1]=0A> >>=A0 1270 sec: 6352660 operations; 5000.2 current ops/sec; [INSERT=
=0A> >> AverageLatency(us)=3D217.77]=0A> >>=A0 1280 sec: 6402731 operations=
; 5000.1 current ops/sec; [INSERT=0A> >> AverageLatency(us)=3D195.83]=0A> >=
>=A0 1290 sec: 6452740 operations; 4999.9 current ops/sec; [INSERT=0A> >> A=
verageLatency(us)=3D232.43]=0A> >>=A0 1300 sec: 6502743 operations; 4999.8 =
current ops/sec; [INSERT=0A> >> AverageLatency(us)=3D290.52]=0A> >>=A0 1310=
 sec: 6552755 operations; 5000.2 current ops/sec; [INSERT=0A> >> AverageLat=
ency(us)=3D259.49]=0A> >>=0A> >>=0A> >> As you can see here there is ~ 60 s=
ec total write stall on a cluster=0A> >> which I suppose 100% correlates wi=
th compactions started (minor)=0A> >>=0A> >> MAX_FILESIZE =3D 5GB=0A> >> ##=
 Regions of 'usertable' - 50=0A> >>=0A> >> I would appreciate any advices o=
n how to get rid of these stalls. 5K per=0A> >> sec is quite moderate load =
even for 5 lousy AWS servers. Or it is not?=0A> >>=0A> >> Best regards,=0A>=
 >> Vladimir Rodionov=0A> >> Principal Platform Engineer=0A> >> Carrier IQ,=
 www.carrieriq.com=0A> >> e-mail: vrodionov@carrieriq.com=0A> >>=0A> >>=0A>=
 >> Confidentiality Notice:=A0 The information contained in this message,=
=0A> >> including any attachments hereto, may be confidential and is intend=
ed=0A> to be=0A> >> read only by the individual or entity to whom this mess=
age is=0A> addressed. If=0A> >> the reader of this message is not the inten=
ded recipient or an agent or=0A> >> designee of the intended recipient, ple=
ase note that any review, use,=0A> >> disclosure or distribution of this me=
ssage or its attachments, in any=0A> form,=0A> >> is strictly prohibited.=
=A0 If you have received this message in error,=0A> please=0A> >> immediate=
ly notify the sender and/or Notifications@carrieriq.com and=0A> >> delete o=
r destroy any copy of this message and its attachments.=0A> >>=0A> >=0A> >=
=0A> >=0A> > --=0A> > Best regards,=0A> >=0A> >=A0 =A0 - Andy=0A> >=0A> > P=
roblems worthy of attack prove their worth by hitting back. - Piet Hein=0A>=
 > (via Tom White)=0A> >=0A>=0A>=0A>=0A> --=0A> Best regards,=0A>=0A>=A0 =
=A0 - Andy=0A>=0A> Problems worthy of attack prove their worth by hitting b=
ack. - Piet Hein=0A> (via Tom White)=0A>
---1172831624-2136494398-1389849467=:20702--