[jira] [Assigned] (HBASE-30377) WALInputFormat drops WAL files that span the requested time range

["Junegunn Choi (Jira)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/HBASE-30377?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Junegunn Choi reassigned HBASE-30377:
-------------------------------------

    Assignee: Junegunn Choi

> 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
>            Reporter: Junegunn Choi
>            Assignee: Junegunn Choi
>            Priority: Major
>
> 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. 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 |



--
This message was sent by Atlassian Jira
(v8.20.10#820010)