Mailing-List: contact user-help@hadoop.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@hadoop.apache.org
Received-SPF: pass (nike.apache.org: domain of
 adrien.mogenet@content-square.fr designates 209.85.216.42 as permitted
 sender)
MIME-Version: 1.0
From: Adrien Mogenet <adrien.mogenet@contentsquare.com>
Date: Fri, 16 Jan 2015 09:10:01 +0100
Message-ID: 
 <CAB4bC7_oc4o4ixK9QyqVk=uM60JNA0xy=ssw18Vo+K1x8qXa3A@mail.gmail.com>
Subject: Poor HDFS performances: "Slow BlockReceiver write packet to mirror"
To: user@hadoop.apache.org
Content-Type: multipart/alternative; boundary=001a11348fcc1c45f4050cc0816a

--001a11348fcc1c45f4050cc0816a
Content-Type: text/plain; charset=UTF-8

Hi there,

I'd like to submit a strange behavior while instanciating another new
Hadoop cluster, on a new hardware stack.

Once everything got installed, as soon as we try to perform any I/O
operation on HDFS, we can see many of these messages within the datanode
logs:

15/01/14 22:13:07 WARN datanode.DataNode: Slow BlockReceiver write packet
to mirror took 6339ms (threshold=300ms)
15/01/14 22:13:26 INFO DataNode.clienttrace: src: /10.10.5.7:17276, dest: /
10.10.5.4:50010, bytes: 176285, op: HDFS_WRITE, cliID:
DFSClient_NONMAPREDUCE_-832581408_1, offset: 0, srvID:
af886556-96db-4b03-9b5b-cd20c3d66f5a, blockid:
BP-784291941-127.0.1.1-1420922413498:blk_1073742333_1531, duration:
19383299287

Followed by the famous one:

java.net.SocketTimeoutException: 60000 millis timeout while waiting for
channel to be ready for read (...)

We've suspected dual-VLAN + bonded network interfaces (2x10 GBps) ot be
part of this, but, of course, we double-checked lots of these points and
found nothing: iperf, dd/hdparm, increasing Xmx (8 GB), sysbench...
We only found that the cluster had a pretty big `await` time on its disk
when running HDFS (>500ms, correlated to our log messages), but we can't
explain clearly what happened.

Even if you will all suspect HDDs to be the cause of our troubles, can
someone explain these log messages? We can't find anything interesting in
source code,  except it occurs while doing `flush or sync` (makes sense...).

Setup:
Hadoop 2.6.0
9 Datanodes
Debian 3.2.63-2+deb7u2 x86_64
10x 1TB SAS drives
OpenJDK Runtime Environment (IcedTea 2.5.3) (7u71-2.5.3-2~deb7u1)
OpenJDK 64-Bit Server VM (build 24.65-b04, mixed mode)

Best,

-- 

*Adrien Mogenet*
Head of Backend/Infrastructure
adrien.mogenet@contentsquare.com
(+33)6.59.16.64.22
http://www.contentsquare.com
4, avenue Franklin D. Roosevelt - 75008 Paris

--001a11348fcc1c45f4050cc0816a
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Hi there,<div><br>I&#39;d like to submit a strange behavio=
r while instanciating another new Hadoop cluster, on a new hardware stack.=
=C2=A0</div><div><br></div><div>Once everything got installed, as soon as w=
e try to perform any I/O operation on HDFS, we can see many of these messag=
es within the datanode logs:</div><div><br></div><div>15/01/14 22:13:07 WAR=
N datanode.DataNode: Slow BlockReceiver write packet to mirror took 6339ms =
(threshold=3D300ms)</div><div><div>15/01/14 22:13:26 INFO DataNode.clienttr=
ace: src: /<a href=3D"http://10.10.5.7:17276">10.10.5.7:17276</a>, dest: /<=
a href=3D"http://10.10.5.4:50010">10.10.5.4:50010</a>, bytes: 176285, op: H=
DFS_WRITE, cliID: DFSClient_NONMAPREDUCE_-832581408_1, offset: 0, srvID: af=
886556-96db-4b03-9b5b-cd20c3d66f5a, blockid: BP-784291941-127.0.1.1-1420922=
413498:blk_1073742333_1531, duration: 19383299287</div></div><div><br></div=
><div>Followed by the famous one:</div><div><br></div><div>java.net.SocketT=
imeoutException: 60000 millis timeout while waiting for channel to be ready=
 for read (...)<br></div><div><br></div><div>We&#39;ve suspected dual-VLAN =
+ bonded network interfaces (2x10 GBps) ot be part of this, but, of course,=
 we double-checked lots of these points and found nothing: iperf, dd/hdparm=
, increasing Xmx (8 GB), sysbench...</div><div>We only found that the clust=
er had a pretty big `await` time on its disk when running HDFS (&gt;500ms, =
correlated to our log messages), but we can&#39;t explain clearly what happ=
ened.</div><div><br></div><div>Even if you will all suspect HDDs to be the =
cause of our troubles, can someone explain these log messages? We can&#39;t=
 find anything interesting in source code, =C2=A0except it occurs while doi=
ng `flush or sync` (makes sense...).</div><div><br></div><div>Setup:</div><=
div>Hadoop 2.6.0</div><div>9 Datanodes</div><div>Debian 3.2.63-2+deb7u2 x86=
_64</div><div><div>10x 1TB SAS drives</div><div><div>OpenJDK Runtime Enviro=
nment (IcedTea 2.5.3) (7u71-2.5.3-2~deb7u1)</div><div>OpenJDK 64-Bit Server=
 VM (build 24.65-b04, mixed mode)</div></div><div><br></div><div>Best,<br><=
/div><div><br></div>-- <br><div class=3D"gmail_signature"><div dir=3D"ltr">=
<div><div dir=3D"ltr"><div><div dir=3D"ltr"><div><img src=3D"http://i.imgur=
.com/3y71t90.png"><br></div><div><div style=3D"color:rgb(136,136,136);font-=
family:&#39;trebuchet ms&#39;,sans-serif"><b><font color=3D"#444444">Adrien=
 Mogenet</font></b></div><div style=3D"color:rgb(136,136,136)"><font color=
=3D"#444444" face=3D"trebuchet ms, sans-serif">Head of Backend/Infrastructu=
re</font></div><div style=3D"color:rgb(136,136,136);font-family:&#39;trebuc=
het ms&#39;,sans-serif"><a href=3D"mailto:adrien.mogenet@contentsquare.com"=
 target=3D"_blank">adrien.mogenet@contentsquare.com</a></div><div style=3D"=
color:rgb(136,136,136);font-family:&#39;trebuchet ms&#39;,sans-serif">(+33)=
6.59.16.64.22<br></div><div style=3D"color:rgb(136,136,136);font-family:=
9;trebuchet ms&#39;,sans-serif"><a href=3D"http://www.contentsquare.com/" t=
arget=3D"_blank">http://www.contentsquare.com</a></div><div style=3D"color:=
rgb(136,136,136);font-family:&#39;trebuchet ms&#39;,sans-serif"><font color=
=3D"#444444">4, avenue Franklin D. Roosevelt - 75008 Paris</font></div></di=
v></div></div></div></div></div></div>
</div></div>

--001a11348fcc1c45f4050cc0816a--