diff --git a/cmd/build/main.go b/cmd/build/main.go index 0b9d127371..4cbdf8e9aa 100644 --- a/cmd/build/main.go +++ b/cmd/build/main.go @@ -136,10 +136,12 @@ func run() error { fmt.Printf("Building manifest: %s\n", manifestPath) jobOutput := filepath.Join(outputDir, buildName) - _, err = osbuild.RunOSBuild(mf, imgType.Exports(), checkpoints, os.Stderr, &osbuild.OSBuildOptions{ - StoreDir: osbuildStore, - OutputDir: jobOutput, - JSONOutput: false, + _, err = osbuild.RunOSBuild(mf, &osbuild.OSBuildOptions{ + StoreDir: osbuildStore, + OutputDir: jobOutput, + Exports: imgType.Exports(), + Checkpoints: checkpoints, + JSONOutput: false, }) if err != nil { return err diff --git a/cmd/osbuild-playground/playground.go b/cmd/osbuild-playground/playground.go index 6485d43a02..5fff58e115 100644 --- a/cmd/osbuild-playground/playground.go +++ b/cmd/osbuild-playground/playground.go @@ -57,10 +57,12 @@ func RunPlayground(img image.ImageKind, d distro.Distro, arch distro.Arch, repos store := path.Join(state_dir, "osbuild-store") - _, err = osbuild.RunOSBuild(bytes, manifest.GetExports(), manifest.GetCheckpoints(), os.Stdout, &osbuild.OSBuildOptions{ - StoreDir: store, - OutputDir: "./", - JSONOutput: false, + _, err = osbuild.RunOSBuild(bytes, &osbuild.OSBuildOptions{ + StoreDir: store, + OutputDir: "./", + Exports: manifest.GetExports(), + Checkpoints: manifest.GetCheckpoints(), + JSONOutput: false, }) if err != nil { fmt.Fprintf(os.Stderr, "could not run osbuild: %s", err.Error()) diff --git a/pkg/osbuild/export_test.go b/pkg/osbuild/export_test.go index 67960103ee..a9cdf18c45 100644 --- a/pkg/osbuild/export_test.go +++ b/pkg/osbuild/export_test.go @@ -4,7 +4,11 @@ type ( StatusJSON = statusJSON ) -func MockOsbuildCmd(s string) (restore func()) { +var ( + NewSyncedWriter = newSyncedWriter +) + +func MockOSBuildCmd(s string) (restore func()) { saved := osbuildCmd osbuildCmd = s return func() { diff --git a/pkg/osbuild/osbuild-exec.go b/pkg/osbuild/osbuild-exec.go index 5d3f6bd419..e21d38951b 100644 --- a/pkg/osbuild/osbuild-exec.go +++ b/pkg/osbuild/osbuild-exec.go @@ -8,6 +8,7 @@ import ( "os" "os/exec" "strings" + "sync" "github.com/hashicorp/go-version" @@ -29,17 +30,30 @@ var osbuildCmd = "osbuild" type OSBuildOptions struct { StoreDir string OutputDir string - ExtraEnv []string - Monitor MonitorType - MonitorFD uintptr + Exports []string + Checkpoints []string + ExtraEnv []string + + // If specified, the mutex is used for the syncwriter so the caller may write to the build + // log as well. Also note that in case BuildLog is specified, stderr will be combined into + // stdout. + BuildLog io.Writer + BuildLogMu *sync.Mutex + Stdout io.Writer + Stderr io.Writer + + // If MonitorFD is set, a file (MonitorW) needs to be inherited by the osbuild process. The + // caller should make sure to close it afterwards. + Monitor MonitorType + MonitorFile *os.File JSONOutput bool CacheMaxSize int64 } -func NewOSBuildCmd(manifest []byte, exports, checkpoints []string, optsPtr *OSBuildOptions) *exec.Cmd { +func NewOSBuildCmd(manifest []byte, optsPtr *OSBuildOptions) *exec.Cmd { opts := common.ValueOrEmpty(optsPtr) cacheMaxSize := int64(20 * datasizes.GiB) @@ -56,24 +70,60 @@ func NewOSBuildCmd(manifest []byte, exports, checkpoints []string, optsPtr *OSBu "-", ) - for _, export := range exports { + for _, export := range opts.Exports { cmd.Args = append(cmd.Args, "--export", export) } - for _, checkpoint := range checkpoints { + for _, checkpoint := range opts.Checkpoints { cmd.Args = append(cmd.Args, "--checkpoint", checkpoint) } if opts.Monitor != "" { cmd.Args = append(cmd.Args, fmt.Sprintf("--monitor=%s", opts.Monitor)) } - if opts.MonitorFD != 0 { - cmd.Args = append(cmd.Args, fmt.Sprintf("--monitor-fd=%d", opts.MonitorFD)) + + if opts.MonitorFile != nil { + cmd.Args = append(cmd.Args, "--monitor-fd=3") + cmd.ExtraFiles = []*os.File{opts.MonitorFile} } + if opts.JSONOutput { cmd.Args = append(cmd.Args, "--json") } + // Default to os stdout/stderr. This is for maximum compatibility with the existing + // bootc-image-builder in "verbose" mode where stdout, stderr come directly from osbuild. + var stdout, stderr io.Writer + stdout = os.Stdout + if opts.Stdout != nil { + stdout = opts.Stdout + } + cmd.Stdout = stdout + stderr = os.Stderr + if opts.Stderr != nil { + stderr = opts.Stderr + } + cmd.Stderr = stderr + + if opts.BuildLog != nil { + // There is a slight wrinkle here: when requesting a buildlog we can no longer write + // to separate stdout/stderr streams without being racy and give potential + // out-of-order output (which is very bad and confusing in a log). The reason is + // that if cmd.Std{out,err} are different "go" will start two go-routine to + // monitor/copy those are racy when both stdout,stderr output happens close together + // (TestRunOSBuildWithBuildlog demos that). We cannot have our cake and eat it so + // here we need to combine osbuilds stderr into our stdout. + // stdout → syncw → multiw → stdoutw or os stdout + // stderr ↗↗↗ → buildlog + var mw io.Writer + if opts.BuildLogMu == nil { + opts.BuildLogMu = new(sync.Mutex) + } + mw = newSyncedWriter(opts.BuildLogMu, io.MultiWriter(stdout, opts.BuildLog)) + cmd.Stdout = mw + cmd.Stderr = mw + } + cmd.Env = append(os.Environ(), opts.ExtraEnv...) cmd.Stdin = bytes.NewBuffer(manifest) return cmd @@ -84,7 +134,7 @@ func NewOSBuildCmd(manifest []byte, exports, checkpoints []string, optsPtr *OSBu // Note that osbuild returns non-zero when the pipeline fails. This function // does not return an error in this case. Instead, the failure is communicated // with its corresponding logs through osbuild.Result. -func RunOSBuild(manifest []byte, exports, checkpoints []string, errorWriter io.Writer, optsPtr *OSBuildOptions) (*Result, error) { +func RunOSBuild(manifest []byte, optsPtr *OSBuildOptions) (*Result, error) { opts := common.ValueOrEmpty(optsPtr) if err := CheckMinimumOSBuildVersion(); err != nil { @@ -93,21 +143,17 @@ func RunOSBuild(manifest []byte, exports, checkpoints []string, errorWriter io.W var stdoutBuffer bytes.Buffer var res Result - cmd := NewOSBuildCmd(manifest, exports, checkpoints, &opts) + cmd := NewOSBuildCmd(manifest, &opts) if opts.JSONOutput { cmd.Stdout = &stdoutBuffer - } else { - cmd.Stdout = os.Stdout } - cmd.Stderr = errorWriter - err := cmd.Start() if err != nil { return nil, fmt.Errorf("error starting osbuild: %v", err) } - err = cmd.Wait() + if opts.JSONOutput { // try to decode the output even though the job could have failed if stdoutBuffer.Len() == 0 { @@ -183,3 +229,19 @@ func OSBuildInspect(manifest []byte) ([]byte, error) { return out, nil } + +type syncedWriter struct { + mu *sync.Mutex + w io.Writer +} + +func newSyncedWriter(mu *sync.Mutex, w io.Writer) io.Writer { + return &syncedWriter{mu: mu, w: w} +} + +func (sw *syncedWriter) Write(p []byte) (n int, err error) { + sw.mu.Lock() + defer sw.mu.Unlock() + + return sw.w.Write(p) +} diff --git a/pkg/osbuild/osbuild-exec_test.go b/pkg/osbuild/osbuild-exec_test.go index 1a8914d081..e5f3d9ef8d 100644 --- a/pkg/osbuild/osbuild-exec_test.go +++ b/pkg/osbuild/osbuild-exec_test.go @@ -1,11 +1,16 @@ package osbuild_test import ( + "bufio" + "bytes" "fmt" "io" "os" "path/filepath" + "strings" + "sync" "testing" + "time" "github.com/stretchr/testify/assert" @@ -13,7 +18,7 @@ import ( "github.com/osbuild/images/pkg/osbuild" ) -func makeFakeOsbuild(t *testing.T, content string) string { +func makeFakeOSBuild(t *testing.T, content string) string { p := filepath.Join(t.TempDir(), "fake-osbuild") err := os.WriteFile(p, []byte("#!/bin/sh\n"+content), 0755) assert.NoError(t, err) @@ -22,7 +27,7 @@ func makeFakeOsbuild(t *testing.T, content string) string { func TestNewOSBuildCmdNilOptions(t *testing.T) { mf := []byte(`{"real": "manifest"}`) - cmd := osbuild.NewOSBuildCmd(mf, nil, nil, nil) + cmd := osbuild.NewOSBuildCmd(mf, nil) assert.NotNil(t, cmd) assert.Equal( @@ -46,22 +51,21 @@ func TestNewOSBuildCmdNilOptions(t *testing.T) { func TestNewOSBuildCmdFullOptions(t *testing.T) { mf := []byte(`{"real": "manifest"}`) + _, wp, err := os.Pipe() + assert.NoError(t, err) cmd := osbuild.NewOSBuildCmd( mf, - []string{ - "export-1", - "export-2", - }, - []string{ - "checkpoint-1", - "checkpoint-2", - }, &osbuild.OSBuildOptions{ - StoreDir: "store", - OutputDir: "output", + StoreDir: "store", + OutputDir: "output", + Exports: []string{ + "export-1", + "export-2", + }, + Checkpoints: []string{"checkpoint-1", "checkpoint-2"}, ExtraEnv: []string{"EXTRA_ENV_1=1", "EXTRA_ENV_2=2"}, Monitor: osbuild.MonitorLog, - MonitorFD: 10, + MonitorFile: wp, JSONOutput: true, CacheMaxSize: 10 * datasizes.GiB, }, @@ -87,7 +91,7 @@ func TestNewOSBuildCmdFullOptions(t *testing.T) { "--checkpoint", "checkpoint-2", "--monitor=LogMonitor", - "--monitor-fd=10", + "--monitor-fd=3", "--json", }, cmd.Args, @@ -99,24 +103,124 @@ func TestNewOSBuildCmdFullOptions(t *testing.T) { stdin, err := io.ReadAll(cmd.Stdin) assert.NoError(t, err) assert.Equal(t, mf, stdin) + + assert.Equal(t, wp, cmd.ExtraFiles[0]) } -func TestRunOSBuild(t *testing.T) { - fakeOsbuildBinary := makeFakeOsbuild(t, ` +func TestRunOSBuildJSONOutput(t *testing.T) { + fakeOSBuildBinary := makeFakeOSBuild(t, ` if [ "$1" = "--version" ]; then echo '90000.0' else echo '{"success": true}' fi `) - restore := osbuild.MockOsbuildCmd(fakeOsbuildBinary) + restore := osbuild.MockOSBuildCmd(fakeOSBuildBinary) defer restore() opts := &osbuild.OSBuildOptions{ JSONOutput: true, } - result, err := osbuild.RunOSBuild([]byte(`{"fake":"manifest"}`), nil, nil, nil, opts) + result, err := osbuild.RunOSBuild([]byte(`{"fake":"manifest"}`), opts) assert.NoError(t, err) assert.NotNil(t, result) assert.True(t, result.Success) } + +func TestRunOSBuildBuildLog(t *testing.T) { + fakeOSBuildBinary := makeFakeOSBuild(t, ` +if [ "$1" = "--version" ]; then + echo '90000.0' +else + echo osbuild-stdout-output +fi +>&2 echo osbuild-stderr-output +`) + restore := osbuild.MockOSBuildCmd(fakeOSBuildBinary) + defer restore() + + var buildLog, stdout, stderr bytes.Buffer + opts := &osbuild.OSBuildOptions{ + BuildLog: &buildLog, + Stdout: &stdout, + Stderr: &stderr, + } + + result, err := osbuild.RunOSBuild(nil, opts) + assert.NoError(t, err) + // without json output set the result should be empty + assert.Empty(t, result) + + assert.NoError(t, err) + assert.Equal(t, `osbuild-stdout-output +osbuild-stderr-output +`, buildLog.String()) + assert.Equal(t, `osbuild-stdout-output +osbuild-stderr-output +`, stdout.String()) + assert.Empty(t, stderr.Bytes()) +} + +func TestRunOSBuildMonitor(t *testing.T) { + fakeOSBuildBinary := makeFakeOSBuild(t, ` +>&3 echo -n '{"some": "monitor"}' + +if [ "$1" = "--version" ]; then + echo '90000.0' +else + echo -n osbuild-stdout-output +fi +>&2 echo -n osbuild-stderr-output +`) + restore := osbuild.MockOSBuildCmd(fakeOSBuildBinary) + defer restore() + + rp, wp, err := os.Pipe() + assert.NoError(t, err) + defer wp.Close() + + var stdout, stderr bytes.Buffer + opts := &osbuild.OSBuildOptions{ + Stdout: &stdout, + Stderr: &stderr, + Monitor: osbuild.MonitorJSONSeq, + MonitorFile: wp, + } + + // without json output set the result will be empty + _, err = osbuild.RunOSBuild(nil, opts) + assert.NoError(t, err) + assert.NoError(t, wp.Close()) + + monitorOutput, err := io.ReadAll(rp) + assert.NoError(t, err) + assert.Equal(t, `{"some": "monitor"}`, string(monitorOutput)) + assert.Equal(t, "osbuild-stdout-output", stdout.String()) + assert.Equal(t, "osbuild-stderr-output", stderr.String()) +} + +func TestSyncWriter(t *testing.T) { + var mu sync.Mutex + var buf bytes.Buffer + var wg sync.WaitGroup + + for id := 0; id < 100; id++ { + wg.Add(1) + w := osbuild.NewSyncedWriter(&mu, &buf) + go func(id int) { + defer wg.Done() + for i := 0; i < 500; i++ { + fmt.Fprintln(w, strings.Repeat(fmt.Sprintf("%v", id%10), 60)) + time.Sleep(10 * time.Nanosecond) + } + }(id) + } + wg.Wait() + + scanner := bufio.NewScanner(&buf) + for res := scanner.Scan(); res; res = scanner.Scan() { + line := scanner.Text() + assert.True(t, len(line) == 60, fmt.Sprintf("len %v: line: %v", len(line), line)) + } + assert.NoError(t, scanner.Err()) +}