[
https://issues.apache.org/jira/browse/HBASE-30377?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Junegunn Choi resolved HBASE-30377.
-----------------------------------
Fix Version/s: 4.0.0-alpha-1
2.7.0
3.1.0
3.0.1
2.6.8
2.5.17
Resolution: Fixed
Pushed to the following branches:
* master
* branch-3
* branch-3.0
* branch-2
* branch-2.6
* branch-2.5
Thanks to [~mosmeh] and [~zhangduo] for the review!
> WALInputFormat drops WAL files that span the requested time range
> -----------------------------------------------------------------
>
> Key: HBASE-30377
> URL: https://issues.apache.org/jira/browse/HBASE-30377
> Project: HBase
> Issue Type: Bug
> Components: mapreduce
> Affects Versions: 2.4.18, 3.0.0, 2.5.16, 2.6.7
> Reporter: Junegunn Choi
> Assignee: Junegunn Choi
> Priority: Major
> Labels: pull-request-available
> Fix For: 4.0.0-alpha-1, 2.7.0, 3.1.0, 3.0.1, 2.6.8, 2.5.17
>
>
> h2. Problem
> When we run {{WALPlayer}}, we can specify a time range via {{wal.start.time}}
> and {{wal.end.time}}.
> {{WALInputFormat.addFile}} picks a WAL file only when the timestamp in its
> filename falls inside the requested range:
> {code:java}
> if (timestamp <= endTime && timestamp >= startTime) {
> {code}
> But that timestamp is the WAL file's creation time. A WAL file stays open
> until it rolls, so a file created before {{startTime}} can still contain
> entries inside the range. The check throws the whole file away.
> For example, asking for entries between 100 and 200:
> {noformat}
> WAL created at t=50, rolled at t=150 -> contains entries 50..150
> 50 <= 200 ok
> 50 >= 100 fails -> file skipped
> lost: every entry in 100..150
> {noformat}
> h2. Origin
> Introduced by HBASE-22976, which refactored the inline file filter into
> {{addFile}} and added the {{startTime}} comparison along the way:
> {code:java}
> - long fileStartTime = Long.parseLong(name.substring(idx+1));
> - if (fileStartTime <= endTime) {
> + if (timestamp <= endTime && timestamp >= startTime) {
> {code}
> h2. Fix
> We should not compare {{wal.start.time}} with the creation time. Instead, we
> should compare it with the last modified time, which is not final until the
> file is closed.
> {code:java}
> if (timestamp > endTime) {
> skip;
> } else if (lfs.getModificationTime() < startTime && isClosed(fs,
> lfs.getPath())) {
> skip;
> } else {
> keep;
> }
> {code}
> {{DistributedFileSystem.isFileClosed}} appears to be relatively cheap,
> measured at 0.41 ms per call against a local NameNode, and it is short
> circuited. {{wal.start.time}} defaults to {{Long.MIN_VALUE}}, so a job that
> does not ask for a start time never reaches the call at all, and a job that
> does pays it only for the files that the modification time alone would prune.
> h2. An existing test asserted the old behavior
> {{TestWALRecordReader.testPartialRead}} writes two entries into a WAL, rolls
> it, then writes more into the next one. The second entry of the first file is
> written at exactly {{ts + 1}}, and the test then queries with
> {{wal.start.time}} set to {{ts + 1}}:
> {code:java}
> jobConf.setLong(WALInputFormat.START_TIME_KEY, ts + 1);
> jobConf.setLong(WALInputFormat.END_TIME_KEY, ts1 + 1);
> splits = input.getSplits(MapreduceTestingShim.createJobContext(jobConf));
> assertEquals(1, splits.size());
> // Only the 1st entry from the 2nd file is in-range.
> testSplit(splits.get(0), Bytes.toBytes("3"));
> {code}
> That entry is inside the requested range, but its file was created before
> {{startTime}} and is dropped, so the test asserts the loss as if it were
> correct. It is corrected here to expect both splits, and the entry that was
> being lost is now asserted to come back.
> h2. Workaround
> On released versions, set {{wal.start.time}} to the point you want minus
> {{hbase.regionserver.logroll.period}} (default 3600000 ms). Periodic rolls
> are forced, so no WAL stays open longer than that.
> This is not free. We replay extra WAL entries.
> h2. Behavior
> || WAL || before || after ||
> | closed, last written before the window | skipped | skipped |
> | closed, spans the start of the window | skipped, entries lost | kept |
> | still open, created before the window | skipped, entries lost | kept |
> | created inside the window | kept | kept |
> | created after the window | skipped | skipped |
> h2. End-to-end test
> I verified the fix on a test cluster running on a local Kubernetes cluster.
> Without the 1-hour {{logroll.period}} workaround, WALPlayer correctly
> processes all WAL files.
> Observed log output:
> {code}
> 2026-09-14 02:26:27,388 INFO [main] mapreduce.WALInputFormat
> (WALInputFormat.java:addFile(377)) - Found
> hdfs://sandbox-medium-yarn-hdfs/hbase-sandbox-medium-yarn/WALs/node-3.test.hbase-sandbox.svc.cluster.local,16020,1789351690680/node-3.test.hbase-sandbox.svc.cluster.local%2C16020%2C1789351690680.1789351699495
> 2026-09-14 02:26:27,393 INFO [main] mapreduce.WALInputFormat
> (WALInputFormat.java:addFile(377)) - Found
> hdfs://sandbox-medium-yarn-hdfs/hbase-sandbox-medium-yarn/WALs/node-4.test.hbase-sandbox.svc.cluster.local,16020,1789351690511/node-4.test.hbase-sandbox.svc.cluster.local%2C16020%2C1789351690511.1789351698534
> 2026-09-14 02:26:27,397 INFO [main] mapreduce.WALInputFormat
> (WALInputFormat.java:addFile(377)) - Found
> hdfs://sandbox-medium-yarn-hdfs/hbase-sandbox-medium-yarn/WALs/node-5.test.hbase-sandbox.svc.cluster.local,16020,1789351690645/node-5.test.hbase-sandbox.svc.cluster.local%2C16020%2C1789351690645.1789351698543
> 2026-09-14 02:26:27,397 INFO [main] mapreduce.WALInputFormat
> (WALInputFormat.java:addFile(377)) - Found
> hdfs://sandbox-medium-yarn-hdfs/hbase-sandbox-medium-yarn/WALs/node-5.test.hbase-sandbox.svc.cluster.local,16020,1789351690645/node-5.test.hbase-sandbox.svc.cluster.local%2C16020%2C1789351690645.meta.1789351695884.meta
> 2026-09-14 02:27:29,557 INFO [main] mapreduce.WALInputFormat
> (WALInputFormat.java:addFile(381)) - Found (no-timestamp!)
> HdfsLocatedFileStatus{path=hdfs://sandbox-medium-yarn-hdfs/hbase-sandbox-medium-yarn/oldWALs/node-1.test.hbase-sandbox.svc.cluster.local%2C16000%2C1789351667410.1789351675119$masterlocalwal$;
> isDirectory=false; length=58886; replication=3; blocksize=268435456;
> modification_time=1789352584712; access_time=1789351675134; owner=hbase;
> group=hadoop; permission=rw-r--r--; isSymlink=false; hasAcl=false;
> isEncrypted=false; isErasureCoded=false}
> {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
