Yuriy Malygin created HDFS-13236:
------------------------------------
Summary: Standby NN down with error encountered while tailing edits
Key: HDFS-13236
URL: https://issues.apache.org/jira/browse/HDFS-13236
Project: Hadoop HDFS
Issue Type: Bug
Components: journal-node, namenode
Affects Versions: 3.0.0
Reporter: Yuriy Malygin
After update Hadoop from 2.7.3 to 3.0.0 standby NN down with error encountered
while tailing edits from JN:
{code:java}
Feb 28 01:58:31 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:31,594 INFO
[FSImageSaver for /one/hadoop-data/dfs of type IMAGE_AND_EDITS]
FSImageFormatProtobuf - Image file
/one/hadoop-data/dfs/current/fsimage.ckpt_00000000012748979
98 of size 4595971949 bytes saved in 93 seconds.
Feb 28 01:58:33 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:33,445 INFO
[Standby State Checkpointer] NNStorageRetentionManager - Going to retain 2
images with txid >= 1274897935
Feb 28 01:58:33 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:33,445 INFO
[Standby State Checkpointer] NNStorageRetentionManager - Purging old image
FSImageFile(file=/one/hadoop-data/dfs/current/fsimage_0000000001274897875,
cpktTxId
=0000000001274897875)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,660 INFO
[Edit log tailer] FSImage - Reading
org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream@6a168e6f
expecting start txid #1274897999
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,660 INFO
[Edit log tailer] FSImage - Start loading edits file
http://srvd87.local:8480/getJournal?jid=datalab-hadoop-backup&segmentTxId=1274897999&storageInfo=-64%3A10
56233980%3A0%3ACID-1fba08aa-c8bd-4217-aef5-6ed206893848&inProgressOk=true,
http://srve2916.local:8480/getJournal?jid=datalab-hadoop-backup&segmentTxId=1274897999&storageInfo=-64%3A1056233980%3A0%3ACID-1fba08aa-c8bd-4217-aef5-6ed206893848&;
inProgressOk=true
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,661 INFO
[Edit log tailer] RedundantEditLogInputStream - Fast-forwarding stream
'http://srvd87.local:8480/getJournal?jid=datalab-hadoop-backup&segmentTxId=1274897999&s
torageInfo=-64%3A1056233980%3A0%3ACID-1fba08aa-c8bd-4217-aef5-6ed206893848&inProgressOk=true,
http://srve2916.local:8480/getJournal?jid=datalab-hadoop-backup&segmentTxId=1274897999&storageInfo=-64%3A1056233980%3A0%3ACID-1fba08aa-c8bd-4217
-aef5-6ed206893848&inProgressOk=true' to transaction ID 1274897999
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,661 INFO
[Edit log tailer] RedundantEditLogInputStream - Fast-forwarding stream
'http://srvd87.local:8480/getJournal?jid=datalab-hadoop-backup&segmentTxId=1274897999&storageInfo=-64%3A1056233980%3A0%3ACID-1fba08aa-c8bd-4217-aef5-6ed206893848&inProgressOk=true'
to transaction ID 1274897999
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,680 ERROR
[Edit log tailer] FSEditLogLoader - Encountered exception on operation AddOp
[length=0, inodeId=145550319,
path=/kafka/parquet/infrastructureGrace/date=2018-02-28/_temporary/1/_temporary/attempt_1516181147167_20856_r_000098_0/part-r-00098.gz.parquet,
replication=3, mtime=1519772206615, atime=1519772206615, blockSize=134217728,
blocks=[], permissions=root:supergroup:rw-r--r--, aclEntries=null,
clientName=DFSClient_attempt_1516181147167_20856_r_000098_0_1523538799_1,
clientMachine=10.137.2.142, overwrite=false, RpcClientId=, RpcCallId=271996603,
storagePolicyId=0, erasureCodingPolicyId=0, opCode=OP_ADD, txid=1274898002]
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]:
java.lang.IllegalArgumentException: Invalid clientId - length is 0 expected
length 16
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
com.google.common.base.Preconditions.checkArgument(Preconditions.java:92)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.ipc.RetryCache$CacheEntry.<init>(RetryCache.java:74)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.ipc.RetryCache$CacheEntry.<init>(RetryCache.java:86)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.ipc.RetryCache$CacheEntryWithPayload.<init>(RetryCache.java:163)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.ipc.RetryCache.addCacheEntryWithPayload(RetryCache.java:322)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.addCacheEntryWithPayload(FSNamesystem.java:946)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.applyEditLogOp(FSEditLogLoader.java:397)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadEditRecords(FSEditLogLoader.java:249)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadFSEdits(FSEditLogLoader.java:158)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:882)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:863)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer.doTailEdits(EditLogTailer.java:293)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.doWork(EditLogTailer.java:427)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.access$400(EditLogTailer.java:380)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread$1.run(EditLogTailer.java:397)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.security.SecurityUtil.doAsLoginUserOrFatal(SecurityUtil.java:481)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.run(EditLogTailer.java:393)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,688 FATAL
[Edit log tailer] EditLogTailer - Unknown error encountered while tailing
edits. Shutting down standby NN.
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: java.io.IOException:
java.lang.IllegalStateException: Cannot skip to less than the current value
(=145550319), where newValue=145550318
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSDirectory.resetLastInodeId(FSDirectory.java:1941)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadEditRecords(FSEditLogLoader.java:298)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadFSEdits(FSEditLogLoader.java:158)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:882)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:863)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer.doTailEdits(EditLogTailer.java:293)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.doWork(EditLogTailer.java:427)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.access$400(EditLogTailer.java:380)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread$1.run(EditLogTailer.java:397)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.security.SecurityUtil.doAsLoginUserOrFatal(SecurityUtil.java:481)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer$EditLogTailerThread.run(EditLogTailer.java:393)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: Caused by:
java.lang.IllegalStateException: Cannot skip to less than the current value
(=145550319), where newValue=145550318
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.util.SequentialNumber.skipTo(SequentialNumber.java:58)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: at
org.apache.hadoop.hdfs.server.namenode.FSDirectory.resetLastInodeId(FSDirectory.java:1939)
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: ... 10 more
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,708 INFO
[Edit log tailer] ExitUtil - Exiting with status 1: java.io.IOException:
java.lang.IllegalStateException: Cannot skip to less than the current value
(=145550319), where newValue=145550318
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: 2018-02-28 01:58:34,722 INFO
[pool-1-thread-1] NameNode - SHUTDOWN_MSG:
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]:
/************************************************************
Feb 28 01:58:34 srvd2135 datalab-namenode[15566]: SHUTDOWN_MSG: Shutting down
NameNode at srvd2135.local/10.137.2.39
{code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: hdfs-dev-unsubscr...@hadoop.apache.org
For additional commands, e-mail: hdfs-dev-h...@hadoop.apache.org
