Merge pull request 'Image builds run their RUN steps on pasta, and every build failure keeps its real error (issue 1703)' (#502) from fix/1703-image-error-shown into main

This commit was merged in pull request #502.
This commit is contained in:
2026-10-26 14:48:17 +00:00
10 changed files with 230 additions and 40 deletions
@@ -332,10 +332,11 @@ func (m *Module) clock() time.Time {
func (m *Module) now() time.Time { return m.clock() }
// causeLine is the first line of a go command's output that says something other than Go's own progress: `go:
// downloading ...` comes first when Go fetches a module, and the cause of a failure on a later line.
// downloading ...` comes first when Go fetches a module, and `# <package>` heads a compile error of go build or go vet
// (issue 1703: the reason said only the package), and the cause of a failure on a later line.
func causeLine(s string) string {
for _, l := range strings.Split(s, "\n") {
if l = strings.TrimSpace(l); l != "" && !strings.HasPrefix(l, "go: downloading ") {
if l = strings.TrimSpace(l); l != "" && !strings.HasPrefix(l, "go: downloading ") && !strings.HasPrefix(l, "# ") {
return l
}
}
@@ -302,3 +302,16 @@ func TestWorkAndCacheAreTheDirectoriesTheManifestPlacesOutsideTheHome(t *testing
}
}
}
// issue 1703: a go command's reason is its cause, not Go's progress nor go build's `# <package>` heading.
func TestCauseLineSkipsProgressAndThePackageHeading(t *testing.T) {
for in, want := range map[string]string{
"go: downloading x v1\n# git.example/m/cmd\n./main.go:3:2: undefined: y\n": "./main.go:3:2: undefined: y",
"\ngo: example.com/x@v1: reading: 404\n": "go: example.com/x@v1: reading: 404",
"go: downloading x v1\n": "go: downloading x v1",
} {
if got := causeLine(in); got != want {
t.Errorf("causeLine(%q) = %q, want %q", in, got, want)
}
}
}
@@ -155,14 +155,18 @@ func (m *Module) build(ctx context.Context, args map[string]any) (any, error) {
}
local := localName(workspace, manifest.Module, art.Name)
argv := append(m.storeFlags(), "bud", "--isolation", "oci", "--tag", local, "--file", dockerfile)
// --network pasta: a RUN step's network is pasta's, in user space. buildah's default for a rootless RUN is a
// netavark bridge whose nftables rules cannot be applied for an account without a user session, so every RUN
// failed before it started ("setup network: netavark: nftables error"; issue 1703, reproduced with buildah 1.45.2).
argv := append(m.storeFlags(), "bud", "--isolation", "oci", "--network", "pasta", "--tag", local, "--file", dockerfile)
if art.Target != "" {
argv = append(argv, "--target", art.Target)
}
argv = append(argv, imageArgs(manifest)...)
argv = append(argv, contextDir)
if r := m.Run(ctx, m.env(), "buildah", argv...); r.Status != 0 || r.Err != "" {
return nil, fmt.Errorf("buildah bud of %s: %s", art.Name, lastLine(r.Err+"\n"+r.Stderr+"\n"+r.Stdout))
m.sayFailure("buildah bud of "+art.Name+" of "+manifest.Module, r)
return nil, fmt.Errorf("buildah bud of %s: %s", art.Name, cause(r))
}
defer m.remove(local)
digest, err := m.localDigest(ctx, local)
@@ -204,8 +208,11 @@ func localName(workspace, module, artifact string) string {
func (m *Module) localDigest(ctx context.Context, name string) (string, error) {
r := m.Run(ctx, m.env(), "buildah", append(m.storeFlags(), "images", "--no-trunc", "--format", "{{.Digest}}", name)...)
digest := strings.TrimSpace(r.Stdout)
if r.Status != 0 || r.Err != "" || !digestOK.MatchString(digest) {
return "", fmt.Errorf("the digest of the image %s could not be read: %s", name, lastLine(r.Err+"\n"+r.Stderr+"\n"+r.Stdout))
if r.Status != 0 || r.Err != "" {
return "", fmt.Errorf("the digest of the image %s could not be read: %s", name, cause(r))
}
if !digestOK.MatchString(digest) {
return "", fmt.Errorf("the digest of the image %s could not be read: buildah images answered %q, not a digest", name, cutFront(digest, CauseBytes))
}
return digest, nil
}
@@ -216,17 +223,6 @@ var digestOK = regexp.MustCompile(`^sha256:[0-9a-f]{64}$`)
func (m *Module) remove(name string) {
r := m.Run(m.Ctx, m.env(), "buildah", append(m.storeFlags(), "rmi", "--force", name)...)
if (r.Status != 0 || r.Err != "") && m.Say != nil {
m.Say("the image %s could not be removed from the store: %s", name, lastLine(r.Err+"\n"+r.Stderr))
m.Say("the image %s could not be removed from the store: %s", name, cause(r))
}
}
// lastLine is the last line of a command's output that says something: buildah's error is its last line.
func lastLine(s string) string {
lines := strings.Split(s, "\n")
for i := len(lines) - 1; i >= 0; i-- {
if l := strings.TrimSpace(lines[i]); l != "" {
return l
}
}
return ""
}
@@ -2,6 +2,7 @@ package main
import (
"encoding/json"
"git.novox.be/novox/mesh-sdk/go/forgekey"
"os"
"path/filepath"
"strings"
@@ -84,7 +85,7 @@ func TestBuildRunsBuildahRootlessAndAnswersTheDigest(t *testing.T) {
}
dir := filepath.Join(m.Work, "ws1", "tree", "modules", "demo")
for _, want := range []string{
"--root " + m.Store + "/root", "--runroot " + m.Store + "/run", "--isolation oci",
"--root " + m.Store + "/root", "--runroot " + m.Store + "/run", "--isolation oci", "--network pasta",
"--file " + dir + "/Dockerfile", "--target final",
"--build-arg DEMO_BASE=docker.io/library/busybox@sha256:0000000000000000000000000000000000000000000000000000000000000001",
} {
@@ -121,16 +122,50 @@ func TestBuildRunsBuildahRootlessAndAnswersTheDigest(t *testing.T) {
}
}
// 1703c: a failing Dockerfile step fails the step, saying buildah's last line.
func TestBuildFailsWithBuildahsLastLine(t *testing.T) {
m, f, states := setup(t, same)
f.failBud = "Error: building at STEP \"RUN false\": exit status 1"
_, st := runBuild(t, m, states, nil)
if st.State != delivery.StepFailed || !strings.Contains(st.Reason, `STEP "RUN false"`) {
t.Errorf("step = %+v", st)
// 1703c, issue 1703: a failing Dockerfile step fails the step, its reason saying buildah's error from stderr, never the
// last STEP line buildah writes on stdout; nothing is pushed.
func TestBuildFailsWithBuildahsError(t *testing.T) {
steps := "STEP 1/3: FROM docker.io/library/alpine\nSTEP 2/3: RUN apk add --no-cache ca-certificates\nfetch https://dl-cdn.alpinelinux.org/x\n"
long := strings.Repeat("x", 2*CauseBytes)
cases := map[string]struct {
ran forgekey.Ran
want []string
wantNot []string
}{
"buildah's RUN failure": {forgekey.Ran{Status: 1, Stdout: steps + "STEP 3/3: COPY . /app\n",
Stderr: "error running container: from /usr/bin/crun creating container for [/bin/sh -c apk add]: sd-bus call: Interactive authentication required.\nError: building at STEP \"RUN apk add --no-cache ca-certificates\": while running runtime: exit status 1\n"},
[]string{"exit status 1", "Interactive authentication required", `building at STEP "RUN apk add`}, []string{"STEP 3/3", "COPY"}},
"a failed RUN": {forgekey.Ran{Status: 1, Stdout: steps, Stderr: "Error: building at STEP \"RUN false\": exit status 1\n"},
[]string{`STEP "RUN false"`}, []string{"dl-cdn"}},
"a long stderr is bounded, its end kept": {forgekey.Ran{Status: 125, Stdout: steps, Stderr: "early noise\n" + long + "\nError: the end\n"},
[]string{"Error: the end"}, []string{"early noise", long}},
"nothing on stderr": {forgekey.Ran{Status: 2, Stdout: steps}, []string{"exit status 2", "nothing on stderr", "dl-cdn"}, nil},
"never ran": {forgekey.Ran{Err: "ENOENT"}, []string{"ENOENT", "wrote nothing"}, nil},
}
if len(f.called("push")) != 0 {
t.Error("a failed build pushed")
for name, c := range cases {
m, f, states := setup(t, same)
f.failBud = c.ran
_, st := runBuild(t, m, states, nil)
if st.State != delivery.StepFailed {
t.Errorf("%s: step = %+v, want failed", name, st)
continue
}
for _, w := range c.want {
if !strings.Contains(st.Reason, w) {
t.Errorf("%s: the reason %q lacks %q", name, st.Reason, w)
}
}
for _, w := range c.wantNot {
if strings.Contains(st.Reason, w) {
t.Errorf("%s: the reason %q carries %q", name, st.Reason, w)
}
}
if len(st.Reason) > CauseBytes+200 {
t.Errorf("%s: the reason is %d bytes, more than its bound", name, len(st.Reason))
}
if len(f.called("push")) != 0 {
t.Errorf("%s: a failed build pushed", name)
}
}
}
@@ -0,0 +1,90 @@
package main
// Why a command failed, as the command said it (issue 1703). buildah writes its progress (STEP n/m, the RUN's own
// output) on stdout and its error on stderr, so the last line of both together is a STEP line and hides the error:
// a failure's reason is stderr's last lines, never stdout's, and the whole tail of stderr is said in the journal.
import (
"fmt"
"strings"
"unicode/utf8"
"git.novox.be/novox/mesh-sdk/go/forgekey"
)
// CauseBytes bounds what a failure's reason carries of the command's output; TailBytes bounds what the journal gets.
const (
CauseBytes = 600
TailBytes = 4096
)
// cause says why a command failed: its exit status (or why it never ran to one) and the last lines it wrote on stderr,
// at most CauseBytes of them, joined with " | ". Only when stderr is empty does stdout's tail stand in, said as such.
func cause(r forgekey.Ran) string {
head := exitOf(r)
if said := tailLines(r.Stderr, CauseBytes, " | "); said != "" {
return head + ": " + said
}
if said := tailLines(r.Stdout, CauseBytes, " | "); said != "" {
return head + ", nothing on stderr; stdout ends: " + said
}
return head + ", and it wrote nothing"
}
// exitOf is how a command ended: why it never ran to an exit status, or the status.
func exitOf(r forgekey.Ran) string {
if r.Err != "" {
return r.Err
}
return fmt.Sprintf("exit status %d", r.Status)
}
// tailLines is the last non-empty lines of s, trimmed, joined with sep, at most max bytes: the lines are taken whole
// from the end while they fit, and when even the last one does not, its end is kept behind "…".
func tailLines(s string, max int, sep string) string {
var lines []string
for _, l := range strings.Split(s, "\n") {
if l = strings.TrimSpace(l); l != "" {
lines = append(lines, l)
}
}
var keep []string
n := 0
for i := len(lines) - 1; i >= 0; i-- {
add := len(lines[i])
if len(keep) > 0 {
add += len(sep)
}
if n+add > max {
if len(keep) == 0 {
keep = append(keep, "…"+cutFront(lines[i], max-len("…")))
}
break
}
keep = append([]string{lines[i]}, keep...)
n += add
}
return strings.Join(keep, sep)
}
// cutFront is the last at most max bytes of s, starting on a whole character.
func cutFront(s string, max int) string {
if max <= 0 {
return ""
}
if len(s) <= max {
return s
}
s = s[len(s)-max:]
for len(s) > 0 && !utf8.RuneStart(s[0]) {
s = s[1:]
}
return s
}
// sayFailure writes the tail of a failed command's stderr (and of its stdout, where buildah's RUN output goes) to the
// journal, so what the reason had to leave out can still be read there.
func (m *Module) sayFailure(what string, r forgekey.Ran) {
m.say("%s failed (%s); stderr ends:\n%s\nstdout ends:\n%s", what, exitOf(r),
tailLines(r.Stderr, TailBytes, "\n"), tailLines(r.Stdout, TailBytes, "\n"))
}
@@ -70,8 +70,8 @@ type fake struct {
calls []cmdRecord
digest string // what `buildah images` prints
pushes int
refuse int // the first n pushes answer "connection refused"
failBud string
refuse int // the first n pushes answer "connection refused"
failBud forgekey.Ran // what a failing buildah bud answers; a zero Status is a passing bud
// digestFile: "" writes the digest, "none" writes no file, "empty" writes an empty one.
digestFile string
// registry: repository:tag -> digest
@@ -116,8 +116,8 @@ func (f *fake) run(ctx context.Context, env []string, name string, args ...strin
case name == "buildah" && strings.Contains(line, "--version"):
return forgekey.Ran{Stdout: "buildah version 1.45.1 (image-spec 1.1.0, runtime-spec 1.1.0)\n"}
case name == "buildah" && strings.Contains(line, " bud "):
if f.failBud != "" {
return forgekey.Ran{Status: 1, Stderr: "STEP 1/2: FROM x\n" + f.failBud + "\n"}
if f.failBud.Status != 0 || f.failBud.Err != "" {
return f.failBud
}
case name == "buildah" && strings.Contains(line, " images "):
return forgekey.Ran{Stdout: f.digest + "\n"}
@@ -203,6 +203,8 @@ func TestARealBuildIsRootlessWithNoSocketAndNoWayOut(t *testing.T) {
imageModule(t, m, "FROM "+base+"\nRUN echo b > /proc/sysrq-trigger\n", nil)
if _, st := buildReal(t, m, states); st.State != delivery.StepFailed {
t.Errorf("a write to the host's /proc/sysrq-trigger passed: %+v", st)
} else if strings.Contains(st.Reason, "setup network") {
t.Errorf("the RUN never started, so the write was not what failed (issue 1703): %s", st.Reason)
}
}
@@ -15,6 +15,8 @@ import (
"strings"
"syscall"
"time"
"git.novox.be/novox/mesh-sdk/go/forgekey"
)
// RegistryWait is how long a call waits for a registry that refuses connections, longer than the nightly collection
@@ -47,13 +49,15 @@ func (m *Module) push(ctx context.Context, workspace, module, local string, res
dest := addr + "/" + repository + ":" + tag
digestFile := filepath.Join(m.Work, workspace, "pushed."+tag)
argv := append(m.storeFlags(), "push", "--tls-verify=false", "--digestfile", digestFile, local, "docker://"+dest)
var last forgekey.Ran
if err := m.waitForRegistry(ctx, addr, "buildah push "+dest, func() error {
r := m.Run(ctx, m.env(), "buildah", argv...)
if r.Status != 0 || r.Err != "" {
return errors.New(lastLine(r.Err + "\n" + r.Stderr + "\n" + r.Stdout))
last = m.Run(ctx, m.env(), "buildah", argv...)
if last.Status != 0 || last.Err != "" {
return errors.New(cause(last))
}
return nil
}); err != nil {
m.sayFailure("buildah push "+dest, last)
return nil, fmt.Errorf("pushing %s: %w", dest, err)
}
var served string
@@ -267,3 +267,38 @@ func TestTheLaunchersAreTheSDKsRule(t *testing.T) {
t.Errorf("launchers %v, mesh-sdk's rule %v", got, want)
}
}
// issue 1703: a failed command's reason keeps stderr's end and stdout's start, each bounded, so a long stdout (npm's
// progress) never pushes npm's error out, and tsc's first error on stdout stays in.
func TestRanFailedKeepsTheError(t *testing.T) {
noise := strings.Repeat("npm progress line\n", 200)
cases := map[string]struct {
ran forgekey.Ran
want []string
wantNot []string
}{
"passed": {forgekey.Ran{Stdout: "ok"}, nil, nil},
"npm, long stdout": {forgekey.Ran{Status: 1, Stdout: noise, Stderr: "npm ERR! early\n" + noise + "npm ERR! code E404\n"}, []string{"status 1", "npm ERR! code E404"}, []string{"npm ERR! early"}},
"tsc on stdout": {forgekey.Ran{Status: 2, Stdout: "src/a.ts(1,7): error TS2322: wrong\n" + noise}, []string{"error TS2322"}, nil},
"never ran": {forgekey.Ran{Err: "ENOENT"}, []string{"ENOENT"}, nil},
}
for name, c := range cases {
got := ranFailed(c.ran)
if c.want == nil && got != "" {
t.Errorf("%s: %q, want none", name, got)
}
for _, w := range c.want {
if !strings.Contains(got, w) {
t.Errorf("%s: %q lacks %q", name, got, w)
}
}
for _, w := range c.wantNot {
if strings.Contains(got, w) {
t.Errorf("%s: %q carries %q", name, got, w)
}
}
if len(got) > failedBytes+100 {
t.Errorf("%s: %d bytes, past its bound", name, len(got))
}
}
}
@@ -180,14 +180,28 @@ func (m *Module) runIn(ctx context.Context, root string, write bool, dir string,
return run(ctx, extra, "env", append([]string{"-C", dir, name}, args...)...)
}
// ranFailed says why a command did not pass, or "" when it did.
// ranFailed says why a command did not pass, or "" when it did (issue 1703): its exit status, the end of what it wrote
// on stderr (npm's error is its last lines) and the start of what it wrote on stdout (tsc writes its errors there,
// first first), each bounded, so a long stdout never pushes stderr's error out of the reason.
func ranFailed(r forgekey.Ran) string {
if r.Status == 0 && r.Err == "" {
return ""
}
out := strings.TrimSpace(r.Stdout + "\n" + r.Stderr)
if len(out) > 1500 {
out = out[:1500] + " ..."
why := fmt.Sprintf("status %d %s", r.Status, r.Err)
if e := strings.TrimSpace(r.Stderr); e != "" {
if len(e) > failedBytes/2 {
e = "... " + e[len(e)-failedBytes/2:]
}
why += ": stderr: " + e
}
return fmt.Sprintf("status %d %s: %s", r.Status, r.Err, out)
if o := strings.TrimSpace(r.Stdout); o != "" {
if len(o) > failedBytes/2 {
o = o[:failedBytes/2] + " ..."
}
why += ": stdout: " + o
}
return why
}
// failedBytes bounds what ranFailed carries of a command's output, stderr and stdout half each.
const failedBytes = 1500