Mailing-List: contact user-help@hadoop.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@hadoop.apache.org
Received-SPF: pass (athena.apache.org: domain of louis.hust.ml@gmail.com
 designates 209.85.192.178 as permitted sender)
Content-Type: text/plain; charset=utf-8
Mime-Version: 1.0 (Mac OS X Mail 7.3 \(1878.6\))
Subject: Re: Question about the QJM HA namenode
From: mail list <louis.hust.ml@gmail.com>
In-Reply-To: 
 <CAOcnVr2MosmTXeSWi=CtxXwWeempeRQkkOUQveSAiK-StFZtXg@mail.gmail.com>
Date: Wed, 3 Dec 2014 18:51:10 +0800
Content-Transfer-Encoding: quoted-printable
Message-Id: <4DDB6FBC-8B36-4F08-895E-A195F4D95E0A@gmail.com>
References: <1B699136-87C4-4E37-B752-9F707A9422E8@gmail.com>
 <29C5FDF4-3A09-47BF-8536-7BF0FD1C6F20@gmail.com>
 <383ECC5E-0010-4B23-9DE6-0DD3D7916971@gmail.com>
 <CAOcnVr2MosmTXeSWi=CtxXwWeempeRQkkOUQveSAiK-StFZtXg@mail.gmail.com>
To: user@hadoop.apache.org

hadoop-2.3.0-cdh5.1.0

hi, i move QJM from the  l-hbase1.dba.dev.cn0 to another machine, and =
the down time reduced to=20
5 mins, and the log on the l-hbase2.dba.dev.cn0 like below:

{log}
2014-12-03 15:55:51,306 INFO =
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer: Loaded 197 =
edits starting from txid 6599
2014-12-03 15:55:51,306 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.DatanodeManager: Marking =
all datandoes as stale
2014-12-03 15:55:51,307 INFO =
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Reprocessing =
replication and invalidation queues
2014-12-03 15:55:51,307 INFO =
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: initializing =
replication queues
2014-12-03 15:55:51,307 INFO =
org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Will take over =
writing edit logs at txnid 6797
2014-12-03 15:55:51,313 INFO =
org.apache.hadoop.hdfs.server.namenode.FSEditLog: Starting log segment =
at 6797
2014-12-03 15:55:51,373 INFO =
org.apache.hadoop.hdfs.server.namenode.FSEditLog: Number of =
transactions: 1 Total time for transactions(ms): 0 Number of =
transactions batched in Syncs: 0 Number of syncs: 0 SyncTimes(ms): 0 9
2014-12-03 15:55:51,385 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Starting CacheReplicationMonitor with interval 30000 milliseconds
2014-12-03 15:55:51,385 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning because of pending operations
2014-12-03 15:55:51,678 INFO org.apache.hadoop.fs.TrashPolicyDefault: =
Namenode trash configuration: Deletion interval =3D 1440 minutes, =
Emptier interval =3D 0 minutes.
2014-12-03 15:55:51,679 INFO org.apache.hadoop.fs.TrashPolicyDefault: =
The configured checkpoint interval is 0 minutes. Using an interval of =
1440 minutes that is used for deletion instead
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager: Total number =
of blocks            =3D 179
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager: Number of =
invalid blocks          =3D 0
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager: Number of =
under-replicated blocks =3D 0
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager: Number of  =
over-replicated blocks =3D 0
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager: Number of =
blocks being written    =3D 4
2014-12-03 15:55:51,693 INFO org.apache.hadoop.hdfs.StateChange: STATE* =
Replication Queue initialization scan for invalid, over- and =
under-replicated blocks completed in 386 msec
2014-12-03 15:55:51,693 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 308 millisecond(s).
2014-12-03 15:56:21,385 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:56:21,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 15:56:51,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30001 milliseconds
2014-12-03 15:56:51,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 15:57:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:57:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
2014-12-03 15:57:51,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:57:51,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 15:58:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:58:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
2014-12-03 15:58:51,386 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:58:51,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 15:59:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30001 milliseconds
2014-12-03 15:59:21,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 15:59:51,387 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Rescanning after 30000 milliseconds
2014-12-03 15:59:51,388 INFO =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor: =
Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
2014-12-03 16:00:14,295 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* =
allocateBlock: caught retry for allocation of a new block in =
/hbase/testnn/WALs/l-hbase3.dba.dev.cn0.qunar.com,60020,1417585992012/l-hb=
ase3.dba.dev.cn0.qunar.com%2C60020%2C1417585992012.1417593301483. =
Returning previously allocated block =
blk_1073743458_2634{blockUCState=3DUNDER_CONSTRUCTION, =
primaryNodeIndex=3D-1, replicas=3D[]}
{log}


It seems the from 15:55:51 to 16:00:14 , all is =
org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor,=20=

what is hadoop doing? how can i reduce the time cause 5 mins is too =
long!


On Dec 3, 2014, at 16:31, Harsh J <harsh@cloudera.com> wrote:

> What is your Hadoop version?
>=20
> On Wed, Dec 3, 2014 at 12:55 PM, mail list <louis.hust.ml@gmail.com> =
wrote:
>> hi all,
>>=20
>> Attach log again!
>>=20
>> The failover happened at about time: 2014-12-03 12:01:
>>=20
>>=20
>>=20
>>=20
>>=20
>> On Dec 3, 2014, at 14:55, mail list <louis.hust.ml@gmail.com> wrote:
>>=20
>>> Sorry forget the log, the failover time at about 2014-12-03 12:01:
>>>=20
>>> <hadoop-hadoop-namenode-l-hbase2.dba.dev.cn0.log.tar.gz>
>>> On Dec 3, 2014, at 14:48, mail list <louis.hust.ml@gmail.com> wrote:
>>>=20
>>>> Hi all,
>>>>=20
>>>> I deploy the hadoop with 3 machines:
>>>>=20
>>>> l-hbase1.dba.dev.cn0 (namenode active and QJM)
>>>> l-hbase2.dba.dev.cn0 (namenode standby and datanode and QJM)
>>>> l-hbase3.dba.dev.cn0 (datanode and QJM)
>>>>=20
>>>> Above the hadoop, i deploy a hbase:
>>>> l-hbase1.dba.dev.cn0 (HMaster active)
>>>> l-hbase2.dba.dev.cn0 (HMaster standby)
>>>> l-hbase3.dba.dev.cn0 (RegionServer)
>>>>=20
>>>>=20
>>>> I write a program which put data into hbase one row every seconds =
in a loop.
>>>> Then I use iptables to  simulate l-hbase1.dba.dev.cn0 offline=EF=BC=8C=
and after that , the program hang and can not
>>>> write to hbase. After about 15 mins, the program can write again.
>>>>=20
>>>> The time 15mins for the HA failover is too long for me!
>>>> And I=E2=80=99ve no idea about the reason.
>>>>=20
>>>> Then I check the l-hbase2.dba.dev.cn0 namenode logs, and find many =
retry like below:
>>>> {code}
>>>> 2014-12-03 12:13:35,165 INFO org.apache.hadoop.ipc.Client: Retrying =
connect to server: l-hbase1.dba.dev.cn0/10.86.36.217:8485. Already tried =
1 time(s); retry policy is =
RetryUpToMaximumCountWithFixedSleep(maxRetries=3D10, sleepTime=3D1000 =
MILLISECONDS)
>>>> {code}
>>>>=20
>>>> I have the QJM on l-hbase1.dba.dev.cn0, does it matter?
>>>>=20
>>>> I am a newbie, Any idea will be appreciated!!
>>>=20
>>=20
>>=20
>=20
>=20
>=20
> --=20
> Harsh J