[oxlog] include files whose creation time predates the range end - #11124
[oxlog] include files whose creation time predates the range end#11124smklein wants to merge 4 commits into
Conversation
in_date_range previously tested only a file's mtime against the range, which is lossy at the range's end: mtime is the timestamp of a file's newest line, so a file whose content spans the end bound was dropped whole, in-window lines included. This is systematic for current log files, whose mtime is always recent: any end bound in the past excluded every live current log along with all of its in-window history. LogFile gains a created (crtime) field, and in_date_range now includes a file when its [created, modified] content span intersects the range. The creation time is trusted only when it is no later than the mtime: a copied file's crtime is the time of the copy, not a content bound, so such files (e.g. logs archived into crypt/debug with their mtime preserved) keep the mtime-only behavior, as do files where crtime is unavailable. Nothing populates the new field yet, so this commit carries no behavior change on its own.
On illumos, crtime is a system attribute (fsattr(7)) rather than part of stat(2): a new crtime module retrieves it with getattrat(3C) and parses the resulting nvlist's [seconds, nanoseconds] crtime entry via illumos-nvpair. On other platforms, read_metadata uses std::fs::Metadata::created(). Either way a missing or unreadable creation time leaves the field None, and the file is filtered by mtime alone.
| }; | ||
|
|
||
| true | ||
| content_start <= date_range.before && modified >= date_range.after |
There was a problem hiding this comment.
from a 10,000 ft view, this is the entire change
| /// Returns the creation time of the file at `path`, or `None` if it | ||
| /// cannot be determined (missing file, a filesystem without system | ||
| /// attribute support, or an unexpected attribute shape). | ||
| pub(crate) fn crtime(path: &Utf8Path) -> Option<Timestamp> { |
There was a problem hiding this comment.
the lack of support for "created_time" on illumos means we need to do these gymnastics to get the same benefit
The test previously assumed the workspace checkout is on ZFS and failed its crtime expectation anywhere else. Guard it with statvfs f_basetype and skip, with a message, when the tempdir's filesystem is not ZFS. Probing pathconf(_PC_SATTR_ENABLED) instead would not work: tmpfs reports system attribute support yet answers getattrat(3C) with an empty attribute list. Both branches of the guard were exercised on an illumos workstation (ZFS runs the assertions; a /tmp tempdir skips).
| } | ||
|
|
||
| #[test] | ||
| fn test_crtime_of_new_file() { |
There was a problem hiding this comment.
This whole test is:
- if we make a file
- can we observe the
crtimewith the function we just wrote
Should be easy, right? well, we don't totally know the filesystem of the development environment we're operating on. So... we have to check that, to see if it supports the created-time attribute, before continuing.
wfchandler
left a comment
There was a problem hiding this comment.
I think this is a good change, but archived logs will still be a problem. Those have their crtime set to the time of migration by sled-agent, not the original file's creation time. Something we can fix in a follow-on PR.
On colo:
# F=system-illumos-propolis-server:default.log.1778804100
# head -1 $F | jq -r .time; tail -1 $F | jq -r .time; ls -l -%all $F
2026-05-14T20:15:10.122754809Z
2026-05-15T00:15:00.944443313Z
-rw-r--r-- 1 root root 904142 May 15 00:18 system-illumos-propolis-server:default.log.1778804100
timestamp: atime Aug 21 13:31:08 2026
timestamp: ctime May 15 00:18:29 2026
timestamp: mtime May 15 00:18:29 2026
timestamp: crtime May 15 00:18:29 2026 |
I will note that this change makes oxlog noticeably slower, but I think the tradeoff is worthwhile. root@BRM42220051:# time oxlog logs oxz_switch dendrite --current --archived > /dev/null
real 0m1.048s
user 0m0.357s
sys 0m0.677s
root@BRM42220051:# time ./oxlog-crtime logs oxz_switch dendrite --current --archived > /dev/null
real 0m2.651s
user 0m0.834s
sys 0m1.801s |
wfchandler measured "oxlog logs oxz_switch dendrite --current --archived" going from ~1.0s to ~2.65s on a dogfood sled: the per-file getattrat(3C) call ran for every statted file, including runs with no date range at all, where the result is never consulted. The lookup now happens only when it can change the outcome of in_date_range: a date range must be present, and the file mtime must postdate the end of the range. An mtime within the range proves overlap by itself, and an mtime before the range is excluded through the start bound, which the creation time never weakens. In practice this limits the lookup to the handful of current logs still written past the range end; rotated and archived logs are filtered on mtime alone. Measured on BRM42220051 against the same 20,892-file log set: the unfiltered command returns to baseline (~0.95s vs ~2.6s unfixed), and a date-filtered run does too (~0.9s vs ~2.5s). Output is byte-identical to the ungated build in both shapes. Test coverage: a new unit test pins the gate at its boundaries (mtime after, at, within, and before the range, and absent) and asserts that wherever the gate skips the lookup, in_date_range answers the same with and without a creation time.
|
I really only need this crtime for scenarios where the "modified" time is greater than the end of the requested date range. I did some lazy loading of crtime to speed this up. I re-ran the benchmarks on dogfood (same machine as you). For
And If I add some explicit date-filtering with
|
oxlog's
date_rangefilter previously tested only a file's mtime against the range. Since mtime is the timestamp of a file's newest line, the end bound was lossy: a file whose content spans the end of the range was dropped whole, even though it might have entries from within the requested bounds. This is often the case for current log files, whose mtime is always recent.As a concrete example of the old behavior:
To mitigate this, the oxlog filter now chooses to include a file when its [created, modified] content span intersects the range. Creation time (crtime) is trusted only when it is no later than the mtime: a copied file's crtime is the time of the copy, not a content bound, so files copied into archive locations with their mtime preserved keep the old mtime-only behavior, as do files where crtime is unavailable.
Once #11113 lands, support bundle zone-log collection inherits this fix through the shared filter.
Commits
[oxlog] Include files whose content span overlaps the date range
Adds the
createdfield toLogFileand rewritesin_date_rangeto the span-intersection rule. Nothing populates the field yet, so this commit carries no behavior change on its own. Also fixes theDateRangefield doc comments, which described the bounds as exclusive while the code has always been inclusive.Test coverage: a new unit test covers the regression shape directly (created 1:00, mtime 2:00, range ending 1:59 is now included; the same mtime without a creation time stays excluded), the copied-file inversion in both directions, spans entirely outside the range, and inclusive boundary touches. The pre-existing
test_daterange_filtercontinues to pass unchanged, pinning mtime-only behavior.[oxlog] Populate LogFile creation times
On illumos, crtime is a system attribute (fsattr(7)) rather than part of stat(2), and
std::fs::Metadata::created()returnsUnsupported. A newcrtimemodule retrieves it with getattrat(3C) from the read-write attribute view and parses the resulting nvlist viaillumos-nvpair. On other platformsstd::fs::Metadata::created()is used. A missing or unreadable creation time leaves the fieldNoneand the file is filtered by mtime alone.Test coverage: an illumos-gated test creates a file on the ZFS-backed workspace, checks its crtime is readable, recent, and no later than its mtime, and that a missing file yields
Nonerather than an error; run on an illumos workstation along with the rest of the oxlog suite.[oxlog] Skip the crtime test on filesystems that record no crtime
Makes the illumos-gated test portable to dev environments where the workspace checkout is not on ZFS: it now checks the tempdir's filesystem via statvfs
f_basetypeand skips with a message rather than failing. Probingpathconf(_PC_SATTR_ENABLED)instead would not work: tmpfs reports system attribute support yet answers getattrat(3C) with an empty attribute list.Test coverage: both branches of the guard were exercised on an illumos workstation; the ZFS path runs the crtime assertions, and a tempdir on /tmp (tmpfs) takes the skip path.