[
https://issues.apache.org/jira/browse/HBASE-30377?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18117811#comment-18117811
]
Hudson commented on HBASE-30377:
--------------------------------
Results for branch branch-3.0
[build #37 on
builds.a.o|https://ci-hbase.apache.org/job/HBase-Integration-Test/job/branch-3.0/37/]:
(/) *{color:green}+1 overall{color}*
----
details (if available):
(/) {color:green}+1 client integration test for 3.3.5 {color}
(/) {color:green}+1 client integration test for 3.3.5 with shaded hadoop
client{color}
(/) {color:green}+1 client integration test for 3.3.6 {color}
(/) {color:green}+1 client integration test for 3.3.6 with shaded hadoop
client{color}
(/) {color:green}+1 client integration test for 3.4.0 {color}
(/) {color:green}+1 client integration test for 3.4.0 with shaded hadoop
client{color}
(/) {color:green}+1 client integration test for 3.4.1 {color}
(/) {color:green}+1 client integration test for 3.4.1 with shaded hadoop
client{color}
(/) {color:green}+1 client integration test for 3.4.2 {color}
(/) {color:green}+1 client integration test for 3.4.2 with shaded hadoop
client{color}
(/) {color:green}+1 client integration test for 3.4.3 {color}
(/) {color:green}+1 client integration test for 3.4.3 with shaded hadoop
client{color}
> 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)