Repository navigation
fix: key the process cache on PID and start time - #2567
arpitjain099 wants to merge 1 commit into
Conversation
Signed-off-by: Arpit Jain <arpitjain099@gmail.com>
Good find! But I thought this scenario shouldn't happen for 2 reasons.
Could you please add a failing test to demonstrate the bug? |
|
The failing test is already in the PR, On the eviction: The second test, |
bitflicker64
left a comment
There was a problem hiding this comment.
Blocking: yes. Score: 6/10. Summary: The start-time check fixes the recycled-PID attribution. But StartTime() is now the first /proc/PID/stat read and its error is wrapped, so a process that exits during a scan fails the whole refresh instead of being skipped. Evidence: go test -race -run 'TestUpdateProcessCache' ./internal/resource/ passes. A scratch test that feeds refreshProcesses one proc whose StartTime returns &fs.PathError{Op: "open", Path: "/proc/4243/stat", Err: syscall.ENOENT} fails at this head with failed to get process start time: open /proc/4243/stat: no such file or directory. The same error from CPUTime (the first read on main) is skipped. Unit tests and lint have not run in CI yet: the PR Checks workflow is action_required.
Out of scope, for a follow-up: the monitor still keys the previous snapshot by PID (internal/monitor/process.go, prev.Processes[pid]), so a recycled PID still starts from the old process's EnergyTotal. Separately, updateProcessCache replaces the cached entry in place, so the old process never appears in Processes.Terminated and never reaches the terminated tracker.
| if cached, exists := ri.procCache[pid]; exists { | ||
| startTime, err := proc.StartTime() | ||
| if err != nil { | ||
| return nil, fmt.Errorf("failed to get process start time: %w", err) |
There was a problem hiding this comment.
Important: Wrapping this error hides ENOENT from the caller's os.IsNotExist check, so an exited process now fails the refresh instead of being skipped.
refreshProcesses skips a vanished process with os.IsNotExist(err), which does not unwrap fmt.Errorf("%w"). Before this PR the first stat read was CPUTime(), which returned the raw *fs.PathError. Now StartTime() runs first, so any process that exits between AllProcs() and its stat read lands in refreshErrs. calculatePower then returns early and that cycle's snapshot is not stored. On a busy node with short-lived processes such as probes and shell scripts, this window is hit regularly.
Switch the check in refreshProcesses to errors.Is(err, fs.ErrNotExist), which also covers the already-wrapped Comm and Executable errors, and add a test for the exited-process case.
There was a problem hiding this comment.
You are right, and it is my regression: os.IsNotExist does not unwrap, so the %w on StartTime takes an exited process out of the skip path. Checked it directly: os.IsNotExist on a raw *fs.PathError with ENOENT is true, on the same error wrapped with fmt.Errorf it is false, and errors.Is against fs.ErrNotExist is true for both. Switching refreshProcesses to errors.Is is the right fix and also covers the Comm and Executable errors, which were already wrapped. I will fold the two stat reads into one for your second point and add the exited-process test.
There was a problem hiding this comment.
You are right, and it reproduces. With the wrap, os.IsNotExist is false while errors.Is(err, fs.ErrNotExist) is true, so a process that exits mid scan lands in refreshErrs and calculatePower drops the cycle. Feeding refreshProcesses one proc whose StartTime returns ENOENT fails at this head and passes with errors.Is.
The same hole already exists for Comm and Executable, wrapped at lines 542 and 549, so errors.Is picks those up as well. Switching the check and adding the exited process test. TestRefreshProcesses_PermissionDeniedHint still passes with it.
| // StartTime returns the time the process started, in clock ticks since boot. Together with | ||
| // the PID it identifies a process, since the kernel reuses PIDs. | ||
| func (p *procWrapper) StartTime() (uint64, error) { | ||
| st, err := p.proc.Stat() |
There was a problem hiding this comment.
Minor: This reads and parses /proc/PID/stat a second time per process per refresh, since CPUTime() already calls p.proc.Stat().
With a few thousand processes on a 5s interval that is a few thousand extra file reads per cycle. A single method returning both values, or caching the ProcStat on the wrapper for the refresh, would keep it to one read.
There was a problem hiding this comment.
Agreed, procfs re-reads and re-parses the file on every Stat() call, so this is a second read per process per refresh. Caching the ProcStat on the wrapper is safe here: AllProcs builds a fresh WrapProc per process on every scan, so the value cannot go stale across refreshes. I will do that rather than widen the interface, and push it with the ENOENT fix.
|
@arpitjain099 I stumbled across another PR which tries to address the same issue and uses cpuTime (which has to be read anyway) as way to identify if the cache is invalid. Please see if #2563 addresses that well enough. |
updateProcessCachekeysprocCacheon the PID alone, andpopulateProcessFieldsonly re-resolves the container, pod and VMif p.Type == UnknownProcess || commChanged. The kernel reuses PIDs, so when a PID comes back with the same 15 charactercomm, andpython3,sh,javaandnginxall collide easily, the cached entry keeps the dead process's container, pod and namespace. The new process's CPU time is then attributed to whatever pod the old one belonged to, which is exactly the number the exporter publishes.Start time is what distinguishes them, so this reads it from
/proc/PID/statand treats a cached entry with a different start time as a different process.procInfogainsStartTime(), implemented onprocWrapperfrom theStarttimefield theStat()call already parses forCPUTime.Processgains aStartTimefield alongside the other static fields.updateProcessCachereuses the cached entry only when the start time matches.MockProcInfo.StartTimereturns zero unless a test sets an expectation, so the existing tests keep working without 22 new.On(...)lines.Two tests in
informer_pidreuse_test.go. The first sends the same PID and comm twice with different start times and different cgroups: on main the second call returns the first container,expected: "second", actual: "first", and the start time stays 0. The second test sends the same process twice and asserts the cache entry is reused, so this is not just rebuilding on every refresh.go test ./internal/...has the same 11 pre-existing failures before and after on my machine, all setup failures in the GPU and procfs packages that need Linux.