hadoop-mapreduce-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "scArcer" <53308...@qq.com>
Subject Hadoop HA active NN keep crashing, and auto failover doesn't work
Date Sat, 26 Sep 2015 22:54:25 GMT
hi, I'm using hadoop 2.2.0 HA.
Here is my configuration.


core-site.xml
 <property>
    <name>ha.zookeeper.quorum</name>
    <value>zk01.bi.lietou.inc:2181,zk02.bi.lietou.inc:2181,zk03.bi.lietou.inc:2181</value>
 </property>
 <property>
  <name>ipc.client.connect.timeout</name>
  <value>20000</value>
  <description>Indicates the number of milliseconds a client will wait for the
               socket to establish a server connection.
  </description>
</property>


hdfs-site.xml


<property>
  <name>dfs.nameservices</name>
  <value>lynxcluster</value>
</property>
<property>
  <name>dfs.ha.namenodes.lynxcluster</name>
  <value>nn1,nn2</value>
</property>
<property>
  <name>dfs.namenode.rpc-address.lynxcluster.nn1</name>
  <value>192.168.30.133:2020</value>
</property>
<property>
  <name>dfs.namenode.rpc-address.lynxcluster.nn2</name>
  <value>192.168.30.129:2020</value>
</property>
<property>
  <name>dfs.namenode.http-address.lynxcluster.nn1</name>
  <value>192.168.30.133:2070</value>
</property>
<property>
  <name>dfs.namenode.http-address.lynxcluster.nn2</name>
  <value>192.168.30.129:2070</value>
</property>
<property>
  <name>dfs.namenode.shared.edits.dir</name>
  <value>qjournal://192.168.30.134:8485;192.168.30.135:8485;192.168.30.136:8485/mycluster</value>
</property>
<property>
  <name>dfs.client.failover.proxy.provider.lynxcluster</name>
  <value>org.apache.hadoop.hdfs.server.namenode.ha.ConfiguredFailoverProxyProvider</value>
</property>
<property>
   <name>dfs.ha.automatic-failover.enabled</name>
   <value>true</value>
</property>
<property>
   <name>dfs.qjournal.write-txns.timeout.ms</name>
   <value>6000000</value>
</property>


192.168.30.129 is active NN, and 192.168.30.133 is standby NN.


active NN get error when start log segment.
2015-09-26 22:09:06,044 INFO org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Roll Edit
Log from 192.168.30.133
2015-09-26 22:09:06,044 INFO org.apache.hadoop.hdfs.server.namenode.FSEditLog: Rolling edit
logs
2015-09-26 22:09:06,044 INFO org.apache.hadoop.hdfs.server.namenode.FSEditLog: Ending log
segment 522618707
2015-09-26 22:09:06,179 INFO org.apache.hadoop.hdfs.server.namenode.FSEditLog: Number of transactions:
16 Total time for transactions(ms): 7 Number of transactions batched in Sync
s: 0 Number of syncs: 10 SyncTimes(ms): 670 2033 142
2015-09-26 22:09:06,185 INFO org.apache.hadoop.hdfs.server.namenode.FileJournalManager: Finalizing
edits file /data1/hadoop/name/current/edits_inprogress_0000000000522618707 -> /d
ata1/hadoop/name/current/edits_0000000000522618707-0000000000522618722
2015-09-26 22:09:06,294 INFO org.apache.hadoop.hdfs.server.namenode.FileJournalManager: Finalizing
edits file /data2/hadoop/name/current/edits_inprogress_0000000000522618707 -> /d
ata2/hadoop/name/current/edits_0000000000522618707-0000000000522618722
2015-09-26 22:09:06,307 INFO org.apache.hadoop.hdfs.server.namenode.FSEditLog: Starting log
segment at 522618723
2015-09-26 22:09:12,308 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 6001 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeede
d so far: [192.168.30.134:8485]
2015-09-26 22:09:13,310 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 7002 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeede
d so far: [192.168.30.134:8485]
2015-09-26 22:09:14,310 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 8003 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeede
d so far: [192.168.30.134:8485]
2015-09-26 22:09:15,312 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 9004 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeede
d so far: [192.168.30.134:8485]
2015-09-26 22:09:16,312 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 10005 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:17,313 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 11006 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:18,314 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 12007 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:19,315 INFO org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 13008 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:20,317 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 14009 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:21,317 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 15010 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:22,319 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 16011 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:23,319 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 17012 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:24,321 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 18013 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:25,321 WARN org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager:
Waited 19014 ms (timeout=20000 ms) for a response for startLogSegment(522618723). Succeed
ed so far: [192.168.30.134:8485]
2015-09-26 22:09:26,308 FATAL org.apache.hadoop.hdfs.server.namenode.FSEditLog: Error: starting
log segment 522618723 failed for required journal (JournalAndStream(mgr=QJM to [192
.168.30.134:8485, 192.168.30.135:8485, 192.168.30.136:8485], stream=null))
java.io.IOException: Timed out waiting 20000ms for a quorum of nodes to respond.
        at org.apache.hadoop.hdfs.qjournal.client.AsyncLoggerSet.waitForWriteQuorum(AsyncLoggerSet.java:137)
        at org.apache.hadoop.hdfs.qjournal.client.QuorumJournalManager.startLogSegment(QuorumJournalManager.java:387)
        at org.apache.hadoop.hdfs.server.namenode.JournalSet$JournalAndStream.startLogSegment(JournalSet.java:91)
        at org.apache.hadoop.hdfs.server.namenode.JournalSet$2.apply(JournalSet.java:199)
        at org.apache.hadoop.hdfs.server.namenode.JournalSet.mapJournalsAndReportErrors(JournalSet.java:352)
        at org.apache.hadoop.hdfs.server.namenode.JournalSet.startLogSegment(JournalSet.java:196)
        at org.apache.hadoop.hdfs.server.namenode.FSEditLog.startLogSegment(FSEditLog.java:1029)
        at org.apache.hadoop.hdfs.server.namenode.FSEditLog.rollEditLog(FSEditLog.java:998)
        at org.apache.hadoop.hdfs.server.namenode.FSImage.rollEditLog(FSImage.java:1082)
        at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.rollEditLog(FSNamesystem.java:5050)
        at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.rollEditLog(NameNodeRpcServer.java:832)
        at org.apache.hadoop.hdfs.protocolPB.NamenodeProtocolServerSideTranslatorPB.rollEditLog(NamenodeProtocolServerSideTranslatorPB.java:139)
        at org.apache.hadoop.hdfs.protocol.proto.NamenodeProtocolProtos$NamenodeProtocolService$2.callBlockingMethod(NamenodeProtocolProtos.java:11214)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:585)
        at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:928)
        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2048)
        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2044)
        at java.security.AccessController.doPrivileged(Native Method) 
        at javax.security.auth.Subject.doAs(Subject.java:415)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1491)
        at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2042)
2015-09-26 22:09:26,312 INFO org.apache.hadoop.util.ExitUtil: Exiting with status 1
2015-09-26 22:09:26,319 INFO org.apache.hadoop.hdfs.server.namenode.NameNode: SHUTDOWN_MSG:
/************************************************************
SHUTDOWN_MSG: Shutting down NameNode at lynx001-bi-30-129.liepin.inc/192.168.30.129
************************************************************/
After 129 shutting down, 133 was still in standby status.
standby NN logs
2015-09-26 22:09:27,651 WARN org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer: Unable
to trigger a roll of the active NN
java.io.IOException: Failed on local exception: java.io.EOFException; Host Details : local
host is: "lynx-bi-30-133.liepin.inc/192.168.30.133"; destination host is: "lynx001-bi-30
-129.liepin.inc":2020;
        at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:764)
        at org.apache.hadoop.ipc.Client.call(Client.java:1351)
        at org.apache.hadoop.ipc.Client.call(Client.java:1300)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:206)
        at com.sun.proxy.$Proxy11.rollEditLog(Unknown Source)
        at org.apache.hadoop.hdfs.protocolPB.NamenodeProtocolTranslatorPB.rollEditLog(NamenodeProtocolTranslatorPB.java:139)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer.triggerActiveLogRoll(EditLogTailer.java:268)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer.access$600(EditLogTailer.java:61)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.doWork(EditLogTailer.java:310)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.access$200(EditLogTailer.java:279)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread$1.run(EditLogTailer.java:296)
        at org.apache.hadoop.security.SecurityUtil.doAsLoginUserOrFatal(SecurityUtil.java:456)
        at org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.run(EditLogTailer.java:292)
Caused by: java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.hadoop.ipc.Client$Connection.receiveRpcResponse(Client.java:995)
        at org.apache.hadoop.ipc.Client$Connection.run(Client.java:891)
right before this error, it started to spill out 
2015-09-26 22:03:00,941 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
as:hadoop (auth:SIMPLE) cause:org.apache.hadoop.ipc.StandbyException: Operation category READ
is not supported in state standby
2015-09-26 22:03:00,941 INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 2020, call
org.apache.hadoop.hdfs.protocol.ClientProtocol.getFileInfo from 192.168.30.131:35882Call#7495335
Retry#0: error: org.apache.hadoop.ipc.StandbyException: Operation category READ is not supported
in state standby
2015-09-26 22:03:01,135 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
as:hadoop (auth:SIMPLE) cause:org.apache.hadoop.ipc.StandbyException: Operation category READ
is not supported in state standby
2015-09-26 22:03:01,135 INFO org.apache.hadoop.ipc.Server: IPC Server handler 45 on 2020,
call org.apache.hadoop.hdfs.protocol.ClientProtocol.getFileInfo from 192.168.30.131:35886
Call#7495346 Retry#0: error: org.apache.hadoop.ipc.StandbyException: Operation category READ
is not supported in state standby
2015-09-26 22:03:06,050 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException
as:hadoop (auth:SIMPLE) cause:org.apache.hadoop.ipc.StandbyException: Operation category READ
is not supported in state standby
2015-09-26 22:03:06,050 INFO org.apache.hadoop.ipc.Server: IPC Server handler 19 on 2020,
call org.apache.hadoop.hdfs.protocol.ClientProtocol.getBlockLocations from 192.168.30.131:35891
Call#1 Retry#0: error: org.apache.hadoop.ipc.StandbyException: Operation category READ is
not supported in state standby
JN logs
2015-09-26 22:09:44,395 WARN org.apache.hadoop.ipc.Server: IPC Server Responder, call org.apache.hadoop.hdfs.qjournal.protocol.QJournalProtocol.startLogSegment
from 192.168.30.129:30015 Call#157803 Retry#0: output error
2015-09-26 22:09:45,400 INFO org.apache.hadoop.ipc.Server: IPC Server handler 4 on 8485 caught
an exception
java.nio.channels.ClosedChannelException
        at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:265)
        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:474)
        at org.apache.hadoop.ipc.Server.channelWrite(Server.java:2577)
        at org.apache.hadoop.ipc.Server.access$2200(Server.java:122)
        at org.apache.hadoop.ipc.Server$Responder.processResponse(Server.java:1011)
        at org.apache.hadoop.ipc.Server$Responder.doRespond(Server.java:1076)
        at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2104)


I've tried to increase the ipc timeout to 60s, but it doesn't work.
Mime
View raw message