You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ozone.apache.org by "Sammi Chen (Jira)" <ji...@apache.org> on 2026/04/24 05:39:00 UTC
[jira] [Commented] (HDDS-15068) OM start failed with exception: java.lang.IllegalStateException: gap between entry term
[ https://issues.apache.org/jira/browse/HDDS-15068?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18075893#comment-18075893 ]
Sammi Chen commented on HDDS-15068:
-----------------------------------
Issue timeline analysis:
T1: this OM is terminated due to race condition happens between om start and om install snapshot from leader(HDDS-15103), OM DB is new from leader, and ratis log file is old OM ratis log file
T2: this OM started, again, due to new DB from leader and old ratis log files, its lastAppliedIndex(t:11, i:1251978), raft log end index(975728). ratis logged a WARN message for this.
{code:java}
2026-04-19 17:28:34,305 WARN [om43-impl-thread1]-org.apache.ratis.server.raftlog.RaftLog: End log index 975728 is smaller than last index in snapshot 1251978
{code}
T3: this OM received install snapshot(t:11, i:1151853) from leader, but since 1151853 is smaller than lastAppliedIndex(1251978), OM responsed with snapshot already installed with current snapshot index: 1251978,
{code:java}
2026-04-19 17:28:34,508 INFO [grpc-default-executor-0]-org.apache.ratis.server.impl.SnapshotInstallationHandler: om43@group-A6BF76F23EF4: Received notification to install snapshot at index 1151853
2026-04-19 17:28:34,509 INFO [grpc-default-executor-0]-org.apache.ratis.server.impl.SnapshotInstallationHandler: om43@group-A6BF76F23EF4: InstallSnapshot notification result: ALREADY_INSTALLED, current snapshot index: 1251978
2026-04-19 17:28:34,516 INFO [grpc-default-executor-0]-org.apache.ratis.server.impl.SnapshotInstallationHandler: om43@group-A6BF76F23EF4: reply installSnapshot: om45<-om43#0:OK-t11,ALREADY_INSTALLED,snapshotIndex=1251978
{code}
T4: leader started to send entity from 1251979, this OM failed to apply 1251979 as there is gap between 1251979 and raft log end index 975728, but 1251979 is written to Om's raft log file. Because in SegmentRaftLog.appendEntryImpl(), gap of WriteLog entry index is only checked when adding to SegmentedRaftLogCache, there is no gap check in WriteLog.execute(). That's why even 1251979 is failed, 1251979 is still write to the raft log file. This fail cause raft server shutdown itself, all bring down the OM instance.
{code:java}
2026-04-19 17:28:34,887 ERROR [om43@group-A6BF76F23EF4-SegmentedRaftLogWorker]-org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: om43@group-A6BF76F23EF4-SegmentedRaftLogWorker hit exception
java.lang.IllegalStateException: lastWrittenIndex == 1251979, entry == term: 11
index: 1251979
metadataEntry {
commitIndex: 1251977
}
at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60)
at org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker$WriteLog.execute(SegmentedRaftLogWorker.java:563)
at org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker.run(SegmentedRaftLogWorker.java:318)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2026-04-19 17:28:34,888 INFO [om43@group-A6BF76F23EF4-SegmentedRaftLogWorker]-org.apache.ratis.server.RaftServer$Division: om43@group-A6BF76F23EF4: shutdown
{code}
T5: this OM starts again, due to the gap in raft log file, OM start failed.
What we do?
1. fix the OM start and install snapshot race condition - HDDS-15103
2. during ratis startup, if end index is smaller than snapshot index, ratis should consider termination - https://issues.apache.org/jira/browse/RATIS-2507.
> OM start failed with exception: java.lang.IllegalStateException: gap between entry term
> ---------------------------------------------------------------------------------------
>
> Key: HDDS-15068
> URL: https://issues.apache.org/jira/browse/HDDS-15068
> Project: Apache Ozone
> Issue Type: Task
> Components: Ozone Manager
> Affects Versions: 2.1.0
> Reporter: Devesh Kumar Singh
> Assignee: Sammi Chen
> Priority: Major
> Attachments: om-ratis-follower-logs.zip
>
>
> While creating bulk keys through freon, hit the below stack trace error. Freon was running smooth with all OMs up, but after 1 hour of freon running, one of the follower OM went down and I found exactly the same stack trace, so I thought of running the command :
> {code:java}
> ozone debug ratislogparser om --segment-path=log_inprogress_890723
> {code}
> and after all parsing, it failed with same below error.
> {code:java}
> java.util.concurrent.CompletionException: java.lang.IllegalStateException: gap between entry term: 11
> index: 975728
> metadataEntry {
> commitIndex: 975726
> }
> and entry term: 11
> index: 1251979
> metadataEntry {
> commitIndex: 1251977
> }
> at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332)
> at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347)
> at java.base/java.util.concurrent.CompletableFuture$BiRelay.tryFire(CompletableFuture.java:1498)
> at java.base/java.util.concurrent.CompletableFuture$CoCompletion.tryFire(CompletableFuture.java:1219)
> at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
> at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
> at org.apache.ratis.util.ConcurrentUtils.accept(ConcurrentUtils.java:191)
> at org.apache.ratis.util.ConcurrentUtils.lambda$null$4(ConcurrentUtils.java:180)
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> at java.base/java.lang.Thread.run(Thread.java:840)
> Caused by: java.lang.IllegalStateException: gap between entry term: 11
> index: 975728
> metadataEntry {
> commitIndex: 975726
> }
> and entry term: 11
> index: 1251979
> metadataEntry {
> commitIndex: 1251977
> }
> at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60)
> at org.apache.ratis.server.raftlog.segmented.LogSegment.readSegmentFile(LogSegment.java:133)
> at org.apache.ratis.server.raftlog.segmented.LogSegment.loadSegment(LogSegment.java:164)
> at org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogCache.loadSegment(SegmentedRaftLogCache.java:381)
> at org.apache.ratis.server.raftlog.segmented.SegmentedRaftLog.loadLogSegments(SegmentedRaftLog.java:241)
> at org.apache.ratis.server.raftlog.segmented.SegmentedRaftLog.openImpl(SegmentedRaftLog.java:214)
> at org.apache.ratis.server.raftlog.RaftLogBase.open(RaftLogBase.java:251)
> at org.apache.ratis.server.impl.ServerState.initRaftLog(ServerState.java:239)
> at org.apache.ratis.server.impl.ServerState.initRaftLog(ServerState.java:220)
> at org.apache.ratis.server.impl.ServerState.lambda$new$5(ServerState.java:161)
> at org.apache.ratis.util.MemoizedSupplier.get(MemoizedSupplier.java:62)
> at org.apache.ratis.server.impl.ServerState.initialize(ServerState.java:177)
> at org.apache.ratis.server.impl.RaftServerImpl.start(RaftServerImpl.java:338)
> at org.apache.ratis.util.ConcurrentUtils.accept(ConcurrentUtils.java:188)
> {code}
> {code:java}
> [root@<cluster>cluster> current]# ls -larht
> total 65M
> -rw-r--r-- 1 hdfs hdfs 54 Apr 19 16:19 raft-meta
> -rw-r--r-- 1 hdfs hdfs 186 Apr 19 16:19 raft-meta.conf
> drwxr-xr-x 2 hdfs hdfs 4.0K Apr 19 17:28 .
> -rw-r--r-- 1 hdfs hdfs 64M Apr 19 17:28 log_inprogress_890723
> drwxr-xr-x 4 hdfs hdfs 4.0K Apr 20 05:08 ..
> [root@<cluster> current]#
> [root@<cluster> sm]# pwd
> /var/lib/hadoop-ozone/om/ratis/5341b4ef-bcd6-3183-aa83-a6bf76f23ef4/sm
> [root@<cluster> sm]# ls -larht
> total 8.0K
> drwxr-xr-x 2 hdfs hdfs 4.0K Apr 17 06:57 .
> drwxr-xr-x 4 hdfs hdfs 4.0K Apr 20 05:08 ..
> [root@<cluster> sm]#
> {code}
> OM follower is failing to start. Logs for raft folder and OM follower logs are attached.
> cc: [~erose] [~Sammi]
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@ozone.apache.org
For additional commands, e-mail: issues-help@ozone.apache.org