Skip to content

Revert mettle temp debug logs #354

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
olha-ctrl merged 4 commits into from
Jun 16, 2026
Merged

Revert mettle temp debug logs #354

Changes from 1 commit
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
ade1b93
Revert mettle temp debug logs
olha-ctrl Jun 1, 2026
876c8ff
Fix linter
olha-ctrl Jun 12, 2026
1ff97dc
Bump version
olha-ctrl Jun 12, 2026
bdc1c39
Remove process snapshot go routine
olha-ctrl Jun 15, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
204 changes: 0 additions & 204 deletions mettle/worker/worker.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@
"path"
"path/filepath"
"runtime"
"strconv"

Check failure on line 17 in mettle/worker/worker.go

View workflow job for this annotation

GitHub Actions / lint 

"strconv" imported and not used (typecheck)

@toastwaffle toastwaffle Jun 8, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

plz fix lint

@olha-ctrl olha-ctrl Jun 15, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed the linter. I had a chat with Hamish and we decided to remove it as it's ~300lines on code; if we need it one day, we can revert this change

"strings"
"syscall"
"time"
Expand Down Expand Up @@ -974,9 +974,6 @@
if !errors.Is(ctx.Err(), context.DeadlineExceeded) {
return
}
// # TODO(INFRA-130229): Revert this temporary change mettle timeouts investigations are completed
w.logProcOnTimeout(pid)
w.logProcChain(pid)
}(pid)

err := cmd.Wait()
Expand Down Expand Up @@ -1030,207 +1027,6 @@
return err
}

// logProcOnTimeout logs /proc diagnostics for the timed-out pid and its process group.
// It does not rely on `ps` existing in the container.
func (w *worker) logProcOnTimeout(pid int) {
const maxFDs = 200
const maxTargetLen = 256
p := strconv.Itoa(pid)
base := filepath.Join("/proc", p)
var errs []error

cmdlineBytes, err := os.ReadFile(filepath.Join(base, "cmdline"))
cmdline := ""
if err != nil {
errs = append(errs, fmt.Errorf("cmdline: %v", err))
} else if len(cmdlineBytes) > 0 {
cmdline = strings.TrimSpace(strings.ReplaceAll(string(cmdlineBytes), "\x00", " "))
}

wchanBytes, err := os.ReadFile(filepath.Join(base, "wchan"))
wchan := ""
if err != nil {
errs = append(errs, fmt.Errorf("wchan: %v", err))
} else if len(wchanBytes) > 0 {
wchan = strings.TrimSpace(string(wchanBytes))
}

var fds []string
entries, err := os.ReadDir(filepath.Join(base, "fd"))
if err != nil {
errs = append(errs, fmt.Errorf("fd: %v", err))
} else {
for i, e := range entries {
if i >= maxFDs {
fds = append(fds, "...truncated")
break
}
target, err := os.Readlink(filepath.Join(base, "fd", e.Name()))
if err != nil {
continue
}
if len(target) > maxTargetLen {
target = target[:maxTargetLen] + "…"
}
fds = append(fds, e.Name()+" -> "+target)
}
}

var errSummary string
if len(errs) > 0 {
s := make([]string, len(errs))
for i, e := range errs {
s[i] = e.Error()
}
errSummary = strings.Join(s, ", ")
}

logr.WithFields(logrus.Fields{
"hash": w.actionDigest.Hash,
"pid": pid,
"cmdline": cmdline,
"wchan": wchan,
"fds": fds,
"proc_err": errSummary,
}).Debug("Deadline exceeded: /proc snapshot")
}

// logProcTree logs a bounded process subtree starting from pid.
// Example:
//
// 24877:bash[S - sleeping/waiting]{do_wait} -> 24890:test_binary[D - io_wait)]{tcp_recvmsg}
// 24877:bash[S - sleeping/waiting]{do_wait} -> 24891:tee[S - sleeping/waitin]{pipe_read}
func (w *worker) logProcChain(pid int) {
const (
maxDepth = 6
maxNodes = 40
)
lines := make([]string, 0, maxNodes)
nodes := 0
var walk func(pid, depth int, path []string)
walk = func(pid, depth int, path []string) {
if depth > maxDepth || nodes >= maxNodes {
return
}

current := formatProc(pid)
path = append(path, current)

children := childPIDs(pid)
if len(children) == 0 {
lines = append(lines, strings.Join(path, " -> "))
nodes++
return
}
for _, c := range children {
if nodes >= maxNodes {
return
}
walk(c, depth+1, path)
}
}

walk(pid, 0, nil)

logr.WithFields(logrus.Fields{
"hash": w.actionDigest.Hash,
"pid": pid,
"tree": strings.Join(lines, "\n"),
}).Debug("Deadline exceeded: /proc process tree")
}

// formatProc creates formatted log line
func formatProc(pid int) string {
state := procState(pid)
wchan := readTrim(filepath.Join(procBase(pid), "wchan"))

return fmt.Sprintf(
"%d:%s[%s - %s]{%s}",
pid,
procName(pid),
state,
stateComment(state),
wchan,
)
}

// procBase returns the /proc path for a pid
func procBase(pid int) string {
return filepath.Join("/proc", strconv.Itoa(pid))
}

// readTrim reads a file and returns trimmed content, or "" on error/empty content
func readTrim(path string) string {
b, err := os.ReadFile(path)
if err != nil || len(b) == 0 {
return ""
}
return strings.TrimSpace(string(b))
}

// procName returns the process name from /proc/<pid>/comm, or "?" if unavailable
func procName(pid int) string {
name := readTrim(filepath.Join(procBase(pid), "comm"))
if name == "" {
return "?"
}
return name
}

// procState returns the Linux process state code from /proc/<pid>/status
func procState(pid int) string {
b, err := os.ReadFile(filepath.Join(procBase(pid), "status"))
if err != nil {
return ""
}
for _, ln := range strings.Split(string(b), "\n") {
k, v, ok := strings.Cut(ln, ":")
if !ok || strings.TrimSpace(k) != "State" {
continue
}
if f := strings.Fields(strings.TrimSpace(v)); len(f) > 0 {
return f[0]
}
return ""
}
return ""
}

// childPIDs returns direct children of pid from /proc/<pid>/task/<pid>/children
func childPIDs(pid int) []int {
b, err := os.ReadFile(filepath.Join(procBase(pid), "task", strconv.Itoa(pid), "children"))
if err != nil || len(b) == 0 {
return nil
}
var out []int
for _, s := range strings.Fields(string(b)) {
if n, err := strconv.Atoi(s); err == nil && n > 0 {
out = append(out, n)
}
}
return out
}

// stateComment is a helper to translate tail_state code into text
func stateComment(s string) string {
switch s {
case "R":
return "running"
case "S":
return "sleeping/waiting"
case "D":
return "io_wait"
case "I":
return "idle"
case "T":
return "stopped"
case "Z":
return "zombie"
default:
return "unknown"
}
}

// writeUncachedResult attempts to write an uncached action result proto.
// This is an extension for buildbarn-browser that lets it display results of a failed build.
// It returns a string that, on success, contains an appropriate message about it (they are
Expand Down
Loading