diff --git a/internal/accounts/setuid_pace.go b/internal/accounts/setuid_pace.go new file mode 100644 index 0000000..ff91e57 --- /dev/null +++ b/internal/accounts/setuid_pace.go @@ -0,0 +1,134 @@ +package accounts + +// The walk for setuid programs yields to a busy disk (novox/hq issue 433). The walk is put in the idle I/O class +// (idle_linux.go), but only a disk scheduler that schedules by class honours that (BFQ does). The control-node's +// disks run mq-deadline, which does not, and there the walk read at full priority: on 2026-10-11 it kept two +// spinning disks saturated for sixteen minutes, the bus whose store shares those disks stalled for half a minute +// twice, and the controller lost its lease each time. So the walk also paces itself by the machine's I/O pressure +// (PSI), which reads the same whatever the scheduler: while some task has waited on I/O for more than PaceAbove +// of the last ten seconds, the walk pauses before it reads the next directory. +// +// The walk's own reads count in that pressure, so on a machine where nothing else waits it slows itself to keep +// the disk below the bound; that is the yielding the idle class promised. A pause in a row is at most PaceAtMost, +// then one more directory is read: on a machine that is never quiet the walk is slow, but it still ends, so a +// machine is never left unjudged for good (the fault issue 361 repaired). + +import ( + "bufio" + "bytes" + "context" + "fmt" + "log" + "os" + "strconv" + "strings" + "time" +) + +const ( + // PaceAbove is the I/O pressure, as the percentage of the last ten seconds in which some task waited on I/O + // (PSI's "some avg10"), above which the walk pauses. + PaceAbove = 10.0 + // PaceLook is how often the walk looks at the pressure while it walks. + PaceLook = 250 * time.Millisecond + // PacePause is one pause. + PacePause = 2 * time.Second + // PaceAtMost is the longest the walk pauses in a row before it reads one more directory. + PaceAtMost = 30 * time.Second + // ioPressureFile is where the kernel says the machine's I/O pressure. + ioPressureFile = "/proc/pressure/io" +) + +// pacer is what the walk asks before it reads a directory. A nil pacer never pauses. +type pacer struct { + pressure func() (float64, error) // some avg10, in percent + sleep func(context.Context, time.Duration) error + now func() time.Time + logf func(format string, args ...any) + + lastLook time.Time + saidBlind bool +} + +// newPacer paces by the machine's own I/O pressure. +func newPacer() *pacer { + return &pacer{ + pressure: func() (float64, error) { return readIOPressure(ioPressureFile) }, + sleep: sleepCtx, + now: time.Now, + logf: log.Printf, + } +} + +// yield pauses while the machine's I/O pressure is above PaceAbove, PacePause at a time and PaceAtMost in a row, +// looking at most every PaceLook. It ends early only with ctx, whose error ends the walk as incomplete. Pressure +// that cannot be read pauses nothing, and is said once: the walk then yields only where the idle class does. +func (pc *pacer) yield(ctx context.Context) error { + if pc == nil || pc.pressure == nil { + return nil + } + if !pc.lastLook.IsZero() && pc.now().Sub(pc.lastLook) < PaceLook { + return nil + } + defer func() { pc.lastLook = pc.now() }() + for waited := time.Duration(0); waited < PaceAtMost; waited += PacePause { + p, err := pc.pressure() + if err != nil { + if !pc.saidBlind && pc.logf != nil { + pc.logf("the walk for setuid programs cannot read the machine's I/O pressure, so it does not pace "+ + "itself and yields only where the disk's scheduler honours the idle class: %v", err) + } + pc.saidBlind = true + return nil + } + if p <= PaceAbove { + return nil + } + if err := pc.sleep(ctx, PacePause); err != nil { + return err + } + } + return nil +} + +// readIOPressure is the "some avg10" of a PSI file: the percentage of the last ten seconds in which some task +// waited on I/O. +func readIOPressure(path string) (float64, error) { + b, err := os.ReadFile(path) + if err != nil { + return 0, err + } + return parseIOPressure(b) +} + +func parseIOPressure(b []byte) (float64, error) { + sc := bufio.NewScanner(bytes.NewReader(b)) + for sc.Scan() { + fields := strings.Fields(sc.Text()) + if len(fields) == 0 || fields[0] != "some" { + continue + } + for _, f := range fields[1:] { + if v, ok := strings.CutPrefix(f, "avg10="); ok { + p, err := strconv.ParseFloat(v, 64) + if err != nil { + return 0, fmt.Errorf("the I/O pressure's avg10 is not a number: %q", v) + } + return p, nil + } + } + } + return 0, fmt.Errorf("the I/O pressure names no \"some\" line with avg10") +} + +// sleepCtx waits d, or until ctx ends. +func sleepCtx(ctx context.Context, d time.Duration) error { + t := time.NewTimer(d) + defer t.Stop() + select { + case <-ctx.Done(): + return ctx.Err() + case <-t.C: + return nil + } +} diff --git a/internal/accounts/setuid_pace_test.go b/internal/accounts/setuid_pace_test.go new file mode 100644 index 0000000..c0771fb --- /dev/null +++ b/internal/accounts/setuid_pace_test.go @@ -0,0 +1,179 @@ +package accounts + +import ( + "context" + "errors" + "fmt" + "slices" + "testing" + "time" +) + +// The walk for setuid programs yields to a busy disk by the machine's I/O pressure (novox/hq issue 433), because +// the idle I/O class it is put in is ignored by a disk scheduler that does not schedule by class, as the +// control-node's mq-deadline does not. + +// fakePace is a pacer whose pressure readings, sleeps and clock a test controls. +type fakePace struct { + readings []float64 // said in turn; the last is said again once they run out + read int + slept []time.Duration + clock time.Time + said []string + fail error +} + +func (f *fakePace) pacer() *pacer { + return &pacer{ + pressure: func() (float64, error) { + if f.fail != nil { + return 0, f.fail + } + i := min(f.read, len(f.readings)-1) + f.read++ + return f.readings[i], nil + }, + sleep: func(ctx context.Context, d time.Duration) error { + if err := ctx.Err(); err != nil { + return err + } + f.slept = append(f.slept, d) + f.clock = f.clock.Add(d) + return nil + }, + now: func() time.Time { return f.clock }, + logf: func(format string, args ...any) { f.said = append(f.said, fmt.Sprintf(format, args...)) }, + } +} + +func TestTheWalkPausesWhileTheDiskIsUnderPressure(t *testing.T) { + f := &fakePace{readings: []float64{42, 18, PaceAbove, 3}, clock: time.Unix(1_000_000, 0)} + pc := f.pacer() + if err := pc.yield(t.Context()); err != nil { + t.Fatal(err) + } + // 42 and 18 are above the bound; PaceAbove itself is not. + if want := []time.Duration{PacePause, PacePause}; !slices.Equal(f.slept, want) { + t.Fatalf("slept %v, want %v", f.slept, want) + } + if f.read != 3 { + t.Fatalf("read the pressure %d times, want 3", f.read) + } +} + +func TestTheWalkDoesNotPauseOnAQuietDisk(t *testing.T) { + f := &fakePace{readings: []float64{0.4}, clock: time.Unix(1_000_000, 0)} + if err := f.pacer().yield(t.Context()); err != nil { + t.Fatal(err) + } + if len(f.slept) != 0 { + t.Fatalf("slept %v on a quiet disk", f.slept) + } +} + +// A machine that is never quiet still sees the walk end: a pause in a row is bounded, then one more directory. +func TestTheWalkPausesAtMostPaceAtMostInARow(t *testing.T) { + f := &fakePace{readings: []float64{95}, clock: time.Unix(1_000_000, 0)} + pc := f.pacer() + if err := pc.yield(t.Context()); err != nil { + t.Fatal(err) + } + var total time.Duration + for _, d := range f.slept { + total += d + } + if total != PaceAtMost { + t.Fatalf("paused %v in a row, want %v", total, PaceAtMost) + } +} + +func TestTheWalkLooksAtThePressureAtMostEveryPaceLook(t *testing.T) { + f := &fakePace{readings: []float64{1}, clock: time.Unix(1_000_000, 0)} + pc := f.pacer() + for range 5 { + if err := pc.yield(t.Context()); err != nil { + t.Fatal(err) + } + f.clock = f.clock.Add(PaceLook / 10) + } + if f.read != 1 { + t.Fatalf("read the pressure %d times within %v, want once", f.read, PaceLook) + } + f.clock = f.clock.Add(PaceLook) + if err := pc.yield(t.Context()); err != nil { + t.Fatal(err) + } + if f.read != 2 { + t.Fatalf("read the pressure %d times after %v, want twice", f.read, PaceLook) + } +} + +// Pressure that cannot be read pauses nothing, and is said once rather than at every directory. +func TestAPressureThatCannotBeReadIsSaidOnce(t *testing.T) { + f := &fakePace{fail: errors.New("no such file"), clock: time.Unix(1_000_000, 0)} + pc := f.pacer() + for range 3 { + if err := pc.yield(t.Context()); err != nil { + t.Fatal(err) + } + f.clock = f.clock.Add(PaceLook) + } + if len(f.slept) != 0 || len(f.said) != 1 { + t.Fatalf("slept %v, said %q; want no pause and one line", f.slept, f.said) + } +} + +// A walk ended while it pauses is an incomplete walk, never one that found nothing. +func TestAWalkEndedWhileItPausesIsIncomplete(t *testing.T) { + top := tree(t, "bin/", "bin/su!") + f := &fakePace{readings: []float64{80}, clock: time.Unix(1_000_000, 0)} + ctx, cancel := context.WithCancel(t.Context()) + defer cancel() + pc := f.pacer() + // The engine stops while the walk waits for the disk: the context ends inside the pause, not before the walk. + pc.sleep = func(ctx context.Context, d time.Duration) error { + f.slept = append(f.slept, d) + cancel() + return ctx.Err() + } + w := mine() + w.pace = pc + p := &SetuidProgress{Mounts: []string{top}} + err := w.walk(ctx, p, func() {}) + if len(f.slept) == 0 { + t.Fatal("the walk never paused, so this proves nothing about a walk ended while it pauses") + } + if !errors.Is(err, context.Canceled) { + t.Fatalf("a walk ended while it paused answered %v", err) + } +} + +// Paced, the walk finds what it finds unpaced: pausing changes when, never what. +func TestAPacedWalkFindsWhatAnUnpacedWalkFinds(t *testing.T) { + top := tree(t, "bin/", "bin/su!", "bin/ls", "sbin/", "sbin/mount!", "usr/", "usr/lib/", "usr/lib/helper%") + plain := walkAll(t, mine(), top) + + f := &fakePace{readings: []float64{50, 2}, clock: time.Unix(1_000_000, 0)} + w := mine() + w.pace = f.pacer() + paced := walkAll(t, w, top) + if !slices.Equal(plain, paced) { + t.Fatalf("paced walk found %v, unpaced %v", paced, plain) + } + if len(f.slept) == 0 { + t.Fatal("the walk read its directories without asking the pacer: it never paused under pressure") + } +} + +func TestTheIOPressureIsReadAsTheKernelWritesIt(t *testing.T) { + got, err := parseIOPressure([]byte("some avg10=26.24 avg60=20.07 avg300=27.47 total=123456789\n" + + "full avg10=21.90 avg60=15.77 avg300=22.47 total=98765432\n")) + if err != nil || got != 26.24 { + t.Fatalf("read %v, %v; want 26.24", got, err) + } + for _, bad := range []string{"", "full avg10=1.00 avg60=0 avg300=0 total=0\n", "some avg10=x avg60=0\n"} { + if _, err := parseIOPressure([]byte(bad)); err == nil { + t.Errorf("%q was read as a pressure", bad) + } + } +} diff --git a/internal/accounts/setuid_walk.go b/internal/accounts/setuid_walk.go index 30c66f2..236ddb8 100644 --- a/internal/accounts/setuid_walk.go +++ b/internal/accounts/setuid_walk.go @@ -125,6 +125,8 @@ type walker struct { rootUID, rootGID uint32 every time.Duration mountPoints map[string]bool + // pace is asked before each directory is read (setuid_pace.go); nil never pauses. + pace *pacer } // walk carries p on to its end, calling checkpoint every w.every and after each filesystem. It ends early only @@ -232,6 +234,10 @@ func (w walker) walkMount(ctx context.Context, p *SetuidProgress, mount string, if d, ok := deviceOf(info); !ok || d != dev { return filepath.SkipDir // another filesystem, walked as its own or not at all (find's -xdev) } + // Before its entries are read: a busy disk is waited for here (novox/hq issue 433). + if err := w.pace.yield(ctx); err != nil { + return err + } case d.Type().IsRegular(): info, err := d.Info() // the entry's own, never through a link if errors.Is(err, fs.ErrNotExist) { diff --git a/internal/accounts/ways.go b/internal/accounts/ways.go index 90d68e9..372442d 100644 --- a/internal/accounts/ways.go +++ b/internal/accounts/ways.go @@ -426,7 +426,7 @@ func contains(xs []string, s string) bool { func (e Exec) setuidSearch(ctx context.Context, p *SetuidProgress, checkpoint func(), mountPoints map[string]bool) ([]string, error) { walk := e.Walk if walk == nil { - walk = walker{every: CheckpointEvery, mountPoints: mountPoints}.walk + walk = walker{every: CheckpointEvery, mountPoints: mountPoints, pace: newPacer()}.walk } if err := walk(ctx, p, checkpoint); err != nil { return nil, fmt.Errorf("the walk for setuid programs did not complete: %w", err)