Fix inconsistent process start time#121935
Conversation
|
Tagging subscribers to this area: @dotnet/area-system-diagnostics-process |
There was a problem hiding this comment.
Pull request overview
This PR stabilizes Linux/Android process start time calculations by changing SystemNative_GetBootTimeTicks to use CLOCK_REALTIME (higher resolution) instead of CLOCK_REALTIME_COARSE when computing the boot-time-to-Unix-epoch offset.
Changes:
- Switch boot time offset calculation from
CLOCK_REALTIME_COARSEtoCLOCK_REALTIMEinSystemNative_GetBootTimeTicks.
|
@copilot address feedback push to this PR |
|
I believe Copilot can't modify this PR as it's on a fork. @Neo-vortex do you want to give it a shot? |
|
@danmoseley |
am11
left a comment
There was a problem hiding this comment.
LGTM, if this makes result more reliable.
adamsitnik
left a comment
There was a problem hiding this comment.
Overall it LGTM. If it turns out that the test takes too much time, we can move it to outerloop.
I am going to update the branch and apply my suggestions and hit the approve button once the CI is green.
Thank you for your contribution @Neo-vortex !
Co-authored-by: Adam Sitnik <adam.sitnik@gmail.com>
Co-authored-by: Adam Sitnik <adam.sitnik@gmail.com>
| // Makes sure multiple independent processes reading the same target process's | ||
| // StartTime all agree on the result — or at least agree as much as the math allows. | ||
| // | ||
| // We spawn 5 separate child processes, each one reads StartTime 10 times and |
There was a problem hiding this comment.
Do we need 5 processes? 2 (or 3 max) should be enough. Launching child processes is relatively expensive.
There was a problem hiding this comment.
2 seemed too few, two processes could read same number by coincidence, the more processes count the less coincide chance, if you think we are ok with 3 let's do that.
There was a problem hiding this comment.
The test does not need to find the problem 100% of the time. It is ok if the test finds the problem only fraction of the time.
| // they're all consistent. If the boot-time offset is stable, they should all | ||
| // cluster around the same value. If something is broken they'll scatter. | ||
| // | ||
| // The /10 thing: last digit of Ticks is floating-point noise (double only has |
There was a problem hiding this comment.
It is not clear what the "/10 thing" is this referring to. The actual code that this is referring to is ~50 lines below.
There was a problem hiding this comment.
Stating why we do /10 when measuring, it is also repeated ~50 lines later, if you think we can remove it from here, I am ok with it
| @@ -100,7 +100,7 @@ int64_t SystemNative_GetBootTimeTicks(void) | |||
|
|
|||
| int64_t sinceBootTicks = ((int64_t)ts.tv_sec * SecondsToTicks) + (ts.tv_nsec / TicksToNanoSeconds); | |||
There was a problem hiding this comment.
Do the tests need to account to for the thread being rescheduled at this point? We can see very significant drift when that happens.
I think the test as written is going to be flaky.
There was a problem hiding this comment.
I thought of using Yield(), but it is a no-op if nothing else wants to run so reads could stay on the same scheduling slice. Sleep(1) blocks for at least one timer tick, forcing a real
context switch so each reading comes after a genuine reschedule.
Correct me if I am wrong, I have limited knowledge in this area.
There was a problem hiding this comment.
I do not think you can reliably trick the scheduler into not rescheduling it. Also, these tricks are expensive.
I think the best way to make this reliable may be to read CLOCK_BOOTTIME second time, and keep looping if it is too far from the first read.
There was a problem hiding this comment.
Can you provide the fix yourself for the test part?
|
@jkotas |
|
I am pretty sure this test is going to be flaky. I am sorry - not merging changes that add obviously flaky tests. |
|
@jkotas, I tested a few related APIs https://godbolt.org/z/1E9eT6qve, as we can see some are deterministic across two consecutive calls and some aren't. Is this how we understood / expect them to work? If not, I think we can converge the behaviors while working on this. |
|
All APIs in this test are non-deterministic across two consecutive calls. It is by-design and expected for all APIs that return variants of current time. We would like |
|
Workflow state for the Holistic Review Orchestrator. {
"version": 5,
"last_dispatched_commit": "1dabd2970e28f1ea32fb2c7715bf70195385695b",
"last_dispatched_base_ref": "main",
"last_dispatched_base_sha": "abaf96f8a4c14179248dcbc0f73d137344303345",
"last_reviewed_commit": "1dabd2970e28f1ea32fb2c7715bf70195385695b",
"last_reviewed_base_ref": "main",
"last_reviewed_base_sha": "abaf96f8a4c14179248dcbc0f73d137344303345",
"last_recorded_worker_run_id": "29681928979",
"review_attempt_commit": "",
"review_attempt_base_ref": "",
"review_attempt_count": 0,
"max_review_attempts": 5,
"review_history_format": "holistic-review-disclosure-v1",
"review_history": [
{
"commit": "1dabd2970e28f1ea32fb2c7715bf70195385695b",
"review_id": 4730547899
}
]
} |
There was a problem hiding this comment.
Holistic Review
Motivation: The PR addresses #108959, where Process.StartTime on Linux can produce inconsistent values across processes. The root cause is SystemNative_GetBootTimeTicks, which computes a boot-time-to-realtime offset used to translate a process's /proc start time into a wall-clock timestamp. The prior implementation read CLOCK_REALTIME_COARSE, whose coarse (~jiffy) resolution injected up to ~1 ms of jitter into the offset, causing different readers to disagree.
Approach: A one-line native change swaps CLOCK_REALTIME_COARSE for CLOCK_REALTIME in pal_time.c, plus a new Linux/Android xunit test (StartTime_IsDeterministicAcrossProcesses) that spawns 5 remote-executor children, each reads StartTime 10 times, and asserts all 50 readings agree after a /10 normalization.
Summary: The native change is small, low-risk, and well-justified — CLOCK_REALTIME is the correct high-resolution clock and the negligible extra cost is acceptable on a path that is not hot. This is a reasonable, mergeable fix. My concerns are all in the test, not the product change. The core assertion demands exact equality (after only one low-order digit is dropped), but GetBootTimeTicks still performs two non-atomic clock_gettime calls and recomputes the offset per read, so real elapsed time between the two reads can shift the offset by more than a single tick under scheduling pressure. That makes the test at risk of being flaky in CI even with a correct fix. I recommend asserting a tolerance window rather than exact equality. Secondary nits: informal/uncertain wording in a committed test comment, over-claiming "jiffies" as the noise source, and trailing whitespace on many added lines that will fail formatting checks. Overall: approve the product change; please harden the test before merge.
Detailed Findings
All findings are inline on the test file:
- Exact-equality assertion may be flaky — the two-read, non-atomic offset computation is not guaranteed to be tick-stable across independent processes; prefer a tolerance-based assertion. (test line ~1363–1370)
- Informal/uncertain comment — "Or maybe I'm overthinking it and it's fine either way" should be replaced with a definitive rationale for the
/10normalization. (line ~1297) - "jiffies" over-claim — the explanatory comment overstates the precise source of the low-order noise. (line ~1282)
- Trailing whitespace on many newly added lines will trip formatting checks. (e.g. line ~1356)
The native pal_time.c change itself looks correct and I have no actionable concerns with it.
Note
This review was generated by this repository's Holistic Review agentic workflow to complement the built-in Copilot review.
Generated by Holistic Review · 128.5 AIC · ⌖ 11.2 AIC · ⊞ 10K
| Assert.All(normalized, reading => | ||
| Assert.True( | ||
| reading == referenceValue, | ||
| $"StartTime reading diverged: got {reading * 10} ticks, " + | ||
| $"expected ~{referenceValue * 10} ticks " + | ||
| $"(diff: {Math.Abs(reading - referenceValue) * 10} ticks = " + | ||
| $"{TimeSpan.FromTicks(Math.Abs(reading - referenceValue) * 10).TotalMilliseconds:F4} ms). " + | ||
| $"All readings: [{string.Join(", ", allReadings)}]")); |
There was a problem hiding this comment.
This exact-equality assertion (after only a single-digit /10 normalization) looks prone to intermittent failures. SystemNative_GetBootTimeTicks reads CLOCK_BOOTTIME and CLOCK_REALTIME in two non-atomic clock_gettime calls and recomputes the offset on every StartTime read. Any wall-clock time that elapses between the two reads (scheduling delay, preemption, page fault) is added into the computed offset, so independent processes can legitimately observe offsets that differ by more than 100 ns (one tick). Switching from CLOCK_REALTIME_COARSE to CLOCK_REALTIME reduces the quantization jitter but does not make the two reads atomic, so exact equality across 50 readings from 5 separate processes is not guaranteed. Consider asserting a tolerance (e.g. all readings within a small millisecond window of each other) instead of exact equality to avoid a flaky test.
| } | ||
|
|
||
| [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] | ||
| [PlatformSpecific(TestPlatforms.Linux | TestPlatforms.Android)] |
There was a problem hiding this comment.
The [PlatformSpecific(TestPlatforms.Linux | TestPlatforms.Android)] scoping is a bit misleading: the underlying SystemNative_GetBootTimeTicks path (#if defined(TARGET_LINUX)) that this test exercises is only compiled for Linux/Android, but the C# StartTime value is derived from /proc on all Unix flavors. That's fine for scoping, but note the comment block references "jiffies" — on Linux the process start time comes from /proc/<pid>/stat (clock ticks since boot) combined with this boot-time offset, so the value is not purely a double conversion of jiffies. Consider tightening the explanatory comment to avoid over-claiming the precise source of the low-order noise.
| // ~15-16 significant digits but Ticks needs 17-18), so two processes doing the | ||
| // same conversion independently can land on adjacent values purely by chance. | ||
| // Chopping the last digit before comparing filters that out without hiding | ||
| // any real drift. Or maybe I'm overthinking it and it's fine either way. |
There was a problem hiding this comment.
Please remove the speculative/informal closing line "Or maybe I'm overthinking it and it's fine either way." A committed test comment should assert a clear rationale for the /10 normalization rather than expressing uncertainty about whether the approach is correct. If the normalization is needed, state why definitively; if it isn't, drop it.
| // Chop last digit off everything before comparing — that digit is just | ||
| // floating-point noise from the jiffies → double → Ticks conversion and | ||
| // tells us nothing real about whether the values agree. | ||
| List<long> normalized = allReadings.Select(t => t / 10).ToList(); |
There was a problem hiding this comment.
Many of the newly added lines in this method (blank lines within the method body, e.g. here and lines 1280, 1298, 1300, 1304, 1307, 1310, etc.) contain trailing whitespace. This will trip the repository formatting checks. Please strip trailing whitespace from the added lines.
Fix: Improve Clock Offset Calculation Stability by Using CLOCK_REALTIME
fixes :#108959
Summary
This pull request updates the
SystemNative_GetBootTimeTicksfunction to useCLOCK_REALTIMEinstead ofCLOCK_REALTIME_COARSEfor calculating the time elapsed since the Unix Epoch.This change is critical because the instability of the coarse clock was causing unstable process start time reads. Switching to
CLOCK_REALTIMEsignificantly reduces the observed clock synchronization jitter, leading to a much more stable and accurate boot-time offset value.Detailed Rationale
The function calculates the boot time offset using the formula:
This calculated offset is used to determine key system timestamps, including the time when a process started.
Issue with CLOCK_REALTIME_COARSE
The coarse clock, designed for speed over accuracy, introduced substantial jitter into the offset calculation. Benchmark results showed the
CLOCK_REALTIME_COARSEpath exhibited a peak-to-peak jitter of up to approximately 1 ms (978 μs).This high variability directly results in unstable process start time reads, making the resulting boot time offset unreliable for high-precision scenarios.
Stability of CLOCK_REALTIME
The corresponding high-resolution clock path, using
CLOCK_REALTIMEinstead of COARSE, showed zero jitter, providing a stable and consistent offset value.Performance Justification
Although
CLOCK_REALTIME_COARSEis intended to be faster, performance profiling confirms that the difference in call overhead between the two clock functions is negligible in our target execution environment.Proposed Change
The function is updated to use
CLOCK_REALTIMEto ensure the final calculation relies on stable, high-precision time sources, thereby eliminating the approximately 1 ms jitter currently observed.This guarantees that
SystemNative_GetBootTimeTicksreturns a highly consistent value across all calls.