The second review of #147 found three blockers before the home server. 1. ${setting:} was not filled in a unit's name, so the distribution timers would have reached the machine as "zfs-scrub-weekly@${setting:scrub-pool}.timer". mesh-controller #171 fills it and refuses any value that is not a unit-name part. The module's own schedule needs no setting in a name now: the node-engine's timer for the scheduled process zfs-mesh-scrub fires `zfs-tools scrub-run` every quarter of an hour, and the run reads the pool, cadence, day and time from the configuration file. 2. The run does what upstream's zfs-scrub@.service does: if a scrub is running it waits for it with zpool wait -t scrub, otherwise it starts one and waits. It never pauses or stops a scrub, and the unit has no ExecStop. A resilver defers the scrub. The served slot is kept in /var/lib/zfs-tools. 3. Unassigning left the pool with no schedule. mesh-host #66 (hq ADR 0269, proposed) gives the distribution timer back running and enabled. The README says not to unassign before it is merged. Also: the run comes before the distribution timers in the declaration; the day and time are checked against fixed sets and reach no unit file (an invalid value runs nothing); a due scrub not started an hour after its time is a warning; the error counts outlive a restart in a small state file.
286 lines
9.1 KiB
Go
286 lines
9.1 KiB
Go
package main
|
|
|
|
import (
|
|
"context"
|
|
"fmt"
|
|
"regexp"
|
|
"strconv"
|
|
"strings"
|
|
"time"
|
|
)
|
|
|
|
// ScrubWarnAfter is how long after the last completed scrub the module warns: a month and a few days, so
|
|
// a monthly scrub that ran late is not yet a warning.
|
|
const ScrubWarnAfter = 35 * 24 * time.Hour
|
|
|
|
// HistoryTimeout bounds reading a pool's history, which grows with the pool's life.
|
|
const HistoryTimeout = 60 * time.Second
|
|
|
|
// HistoryArgv is one pool's history with ZFS's internal events, where each scan's start and end are.
|
|
func HistoryArgv(pool string) []string { return []string{"history", "-i", pool} }
|
|
|
|
// Pass is one scan the history records: when it started and how it ended.
|
|
type Pass struct {
|
|
Kind string `json:"kind"`
|
|
Started *time.Time `json:"started,omitempty"`
|
|
Ended *time.Time `json:"ended,omitempty"`
|
|
// Outcome is finished or canceled.
|
|
Outcome string `json:"outcome"`
|
|
Errors *int `json:"errors,omitempty"`
|
|
}
|
|
|
|
var historyScan = regexp.MustCompile(`^(\d{4}-\d{2}-\d{2}\.\d{2}:\d{2}:\d{2}) \[txg:\d+\] scan (setup|done|cancelled|canceled|aborted)\b(.*)$`)
|
|
var historyFunc = regexp.MustCompile(`\bfunc=(\d+)`)
|
|
var historyErrors = regexp.MustCompile(`\berrors=(\d+)`)
|
|
|
|
// ParseHistory reads `zpool history -i` for the last finished scrub and the last finished resilver. ZFS
|
|
// writes `scan setup … func=1` for a scrub and `func=2` for a resilver, then `scan done … errors=N` or
|
|
// `scan cancelled`.
|
|
func ParseHistory(out string) (scrub, resilver *Pass) {
|
|
var open *Pass
|
|
for _, line := range lines(out) {
|
|
m := historyScan.FindStringSubmatch(strings.TrimSpace(line))
|
|
if m == nil {
|
|
continue
|
|
}
|
|
t, err := time.ParseInLocation("2006-01-02.15:04:05", m[1], time.Local)
|
|
if err != nil {
|
|
continue
|
|
}
|
|
switch m[2] {
|
|
case "setup":
|
|
kind := "scan"
|
|
if f := historyFunc.FindStringSubmatch(m[3]); f != nil {
|
|
switch f[1] {
|
|
case "1":
|
|
kind = "scrub"
|
|
case "2":
|
|
kind = "resilver"
|
|
}
|
|
}
|
|
open = &Pass{Kind: kind, Started: &t}
|
|
default:
|
|
if open == nil {
|
|
continue
|
|
}
|
|
open.Ended = &t
|
|
open.Outcome = "finished"
|
|
if m[2] != "done" {
|
|
open.Outcome = "canceled"
|
|
}
|
|
if e := historyErrors.FindStringSubmatch(m[3]); e != nil {
|
|
n, _ := strconv.Atoi(e[1])
|
|
open.Errors = &n
|
|
}
|
|
if open.Outcome == "finished" {
|
|
switch open.Kind {
|
|
case "scrub":
|
|
scrub = open
|
|
case "resilver":
|
|
resilver = open
|
|
}
|
|
}
|
|
open = nil
|
|
}
|
|
}
|
|
return scrub, resilver
|
|
}
|
|
|
|
// ScrubRow is one pool's scans.
|
|
type ScrubRow struct {
|
|
Pool string `json:"pool"`
|
|
// Scans are the pool's scan lines as status gives them: its scrub or error scrub, then its resilver.
|
|
Scans []Scan `json:"scans"`
|
|
// LastScrub and LastResilver are the last finished of each, from status, or from the history when it
|
|
// was read and status no longer shows it.
|
|
LastScrub *Pass `json:"last_scrub,omitempty"`
|
|
LastResilver *Pass `json:"last_resilver,omitempty"`
|
|
DaysSince *float64 `json:"days_since_last_scrub,omitempty"`
|
|
Warning string `json:"warning,omitempty"`
|
|
Note string `json:"note,omitempty"`
|
|
Said []string `json:"said"`
|
|
}
|
|
|
|
// ScrubAnswer is what zfs_scrub answers.
|
|
type ScrubAnswer struct {
|
|
Applicable bool `json:"applicable"`
|
|
Pools []ScrubRow `json:"pools"`
|
|
Schedule *Schedule `json:"schedule,omitempty"`
|
|
Said []string `json:"said"`
|
|
}
|
|
|
|
// LastScrubEnded is when the pool's last scrub finished, as status shows it; nil when status shows no
|
|
// finished scrub.
|
|
func LastScrubEnded(p PoolStatus) *time.Time {
|
|
if s := p.Scrub(); s != nil && s.State == "finished" {
|
|
return s.Ended
|
|
}
|
|
return nil
|
|
}
|
|
|
|
// ScrubLate is how long after its last finished scrub a pool is late: its schedule's cadence and margin,
|
|
// or ScrubWarnAfter where the module has no schedule for it.
|
|
func ScrubLate(pool string, s *Schedule) (time.Duration, string) {
|
|
if s != nil && s.Pool == pool {
|
|
return cadenceAllows[s.Cadence], "its " + s.Cadence + " schedule allows"
|
|
}
|
|
return ScrubWarnAfter, "the module's line for a pool without a schedule"
|
|
}
|
|
|
|
// Scrubs are every pool's scans, its schedule and when it fires next. With history, each pool's history
|
|
// is read too (as root), for the scrub and the resilver status no longer shows.
|
|
func (m *Machine) Scrubs(ctx context.Context, history bool) (any, error) {
|
|
st, err := m.Status(ctx)
|
|
if err != nil {
|
|
return notHere(err)
|
|
}
|
|
now := m.Now()
|
|
a := ScrubAnswer{Applicable: true, Pools: []ScrubRow{}, Said: []string{}}
|
|
sched, serr := m.ScheduleNow(ctx)
|
|
switch {
|
|
case serr != nil:
|
|
a.Said = append(a.Said, "The scrub schedule's settings are not valid: "+serr.Error()+".")
|
|
case sched == nil:
|
|
a.Said = append(a.Said, "The module has no scrub schedule on this machine (no "+ScrubConfig+").")
|
|
default:
|
|
a.Schedule = sched
|
|
line := fmt.Sprintf("%s scrub of %s, %s at %s (monthly: the first %s of the month), decided by the run %s fires "+
|
|
"every quarter of an hour (%s, %s)", sched.Cadence, sched.Pool, sched.Day, sched.Time, sched.Day,
|
|
sched.Timer, orUnknown(sched.TimerState), orUnknown(sched.Enabled))
|
|
if sched.Cadence == "weekly" {
|
|
line = fmt.Sprintf("weekly scrub of %s, %s at %s, decided by the run %s fires every quarter of an hour (%s, %s)",
|
|
sched.Pool, sched.Day, sched.Time, sched.Timer, orUnknown(sched.TimerState), orUnknown(sched.Enabled))
|
|
}
|
|
if sched.Next != nil {
|
|
line += "; next scheduled scrub of " + sched.Pool + ": " + sched.Next.Local().Format("2006-01-02 15:04")
|
|
}
|
|
if sched.LastResult != "" {
|
|
line += "; last run: " + sched.LastResult
|
|
}
|
|
a.Said = append(a.Said, line)
|
|
if sched.Note != "" {
|
|
a.Said = append(a.Said, sched.Note)
|
|
}
|
|
}
|
|
for _, p := range st {
|
|
r := ScrubRow{Pool: p.Name, Scans: p.Scans, Said: []string{}}
|
|
if ended := LastScrubEnded(p); ended != nil {
|
|
sc := p.Scrub()
|
|
r.LastScrub = &Pass{Kind: "scrub", Started: sc.Started, Ended: ended, Outcome: "finished", Errors: sc.Errors}
|
|
}
|
|
for _, rs := range p.Resilvers() {
|
|
if rs.State == "finished" && rs.Ended != nil && (r.LastResilver == nil || rs.Ended.After(*r.LastResilver.Ended)) {
|
|
r.LastResilver = &Pass{Kind: "resilver", Started: rs.Started, Ended: rs.Ended, Outcome: "finished", Errors: rs.Errors}
|
|
}
|
|
}
|
|
if history {
|
|
hctx, cancel := context.WithTimeout(ctx, HistoryTimeout)
|
|
out, err := m.AsRoot(hctx, "zpool", HistoryArgv(p.Name)...)
|
|
cancel()
|
|
if err != nil {
|
|
r.Note = "the history could not be read: " + err.Error()
|
|
} else {
|
|
scrub, resilver := ParseHistory(out.Out)
|
|
if scrub != nil && (r.LastScrub == nil || scrub.Ended.After(*r.LastScrub.Ended)) {
|
|
r.LastScrub = scrub
|
|
}
|
|
if resilver != nil && (r.LastResilver == nil || resilver.Ended.After(*r.LastResilver.Ended)) {
|
|
r.LastResilver = resilver
|
|
}
|
|
}
|
|
} else if r.LastScrub == nil {
|
|
r.Note = "status shows no finished scrub of this pool; ask with history=true for the last one the pool's history records"
|
|
}
|
|
late, by := ScrubLate(p.Name, sched)
|
|
if r.LastScrub != nil && r.LastScrub.Ended != nil {
|
|
d := round1(now.Sub(*r.LastScrub.Ended).Hours() / 24)
|
|
r.DaysSince = &d
|
|
if now.Sub(*r.LastScrub.Ended) > late {
|
|
r.Warning = fmt.Sprintf("the last scrub of %s finished %.0f days ago, more than %s (%d days)", p.Name, d, by, int(late.Hours()/24))
|
|
}
|
|
} else if history {
|
|
r.Warning = fmt.Sprintf("no finished scrub of %s is on record", p.Name)
|
|
}
|
|
for _, sc := range p.Scans {
|
|
r.Said = append(r.Said, p.Name+": "+scanSaid(sc))
|
|
}
|
|
if len(p.Scans) == 0 {
|
|
r.Said = append(r.Said, p.Name+": no scan was ever asked")
|
|
}
|
|
if r.DaysSince != nil {
|
|
r.Said = append(r.Said, fmt.Sprintf("%s: last finished scrub %.1f days ago", p.Name, *r.DaysSince))
|
|
}
|
|
if r.Warning != "" {
|
|
r.Said = append(r.Said, p.Name+": WARNING: "+r.Warning)
|
|
}
|
|
if r.Note != "" {
|
|
r.Said = append(r.Said, p.Name+": "+r.Note)
|
|
}
|
|
a.Pools = append(a.Pools, r)
|
|
a.Said = append(a.Said, r.Said...)
|
|
}
|
|
return a, nil
|
|
}
|
|
|
|
// scanSaid says one scan in a line: a running one with its progress and the time to go.
|
|
func scanSaid(s Scan) string {
|
|
what := s.Kind
|
|
if s.Vdev != "" {
|
|
what += " of " + s.Vdev
|
|
}
|
|
switch s.State {
|
|
case "running", "paused":
|
|
line := fmt.Sprintf("a %s is %s", what, s.State)
|
|
if s.Started != nil {
|
|
line += " (started " + s.Started.Local().Format("2006-01-02 15:04") + ")"
|
|
}
|
|
if s.Done != nil {
|
|
line += fmt.Sprintf(", %.2f %% done", *s.Done)
|
|
}
|
|
switch {
|
|
case s.ToGo != "":
|
|
line += ", " + s.ToGo + " to go"
|
|
case s.NoEstimate:
|
|
line += ", no estimate of the time to go yet"
|
|
}
|
|
return line
|
|
case "finished":
|
|
line := fmt.Sprintf("the last %s finished %s after %s, %s", what, stamp(s.Ended), s.Took, s.Repaired)
|
|
if s.Kind == "scrub" {
|
|
line += " repaired"
|
|
} else if s.Kind == "resilver" {
|
|
line += " resilvered"
|
|
}
|
|
if s.Errors != nil {
|
|
line += fmt.Sprintf(", %d errors", *s.Errors)
|
|
}
|
|
return line
|
|
case "canceled":
|
|
return fmt.Sprintf("the last %s was canceled %s", what, stamp(s.Ended))
|
|
case "none":
|
|
return "no scan was ever asked"
|
|
}
|
|
return "scan: " + firstLine(s.Said)
|
|
}
|
|
|
|
func orUnknown(s string) string {
|
|
if s == "" {
|
|
return "not known"
|
|
}
|
|
return s
|
|
}
|
|
|
|
func stamp(t *time.Time) string {
|
|
if t == nil {
|
|
return "at a time status did not say"
|
|
}
|
|
return t.Local().Format("2006-01-02 15:04")
|
|
}
|
|
|
|
func deref(n *int) int {
|
|
if n == nil {
|
|
return 0
|
|
}
|
|
return *n
|
|
}
|