Rework progress

[croissanne]

Opened in conjunction with osbuild/images#1966, to see if ppl think this is a good approach.

[lzap]

...

[croissanne]

As this is still draft, this is just to show what it would look like with osbuild/images#1966. Not actually intending to merge this.

[lzap]

Sure was just highlighting it, I guess we have a linter for that. Or not, depends on the repo :-)

[lzap]

This should not have been in this commit, there is a separate one I guess you accidentally squashed it in.

[lzap]

Using defer does not seem correct there is a double lock if both variables are not empty.

[lzap]

Can someone explain why newSyncedWriter was written in a way it accepts a mutex? I do not understand why a mutex could be shared for this decorator design pattern. It should have been:

type SyncedWriter struct {
	mu sync.Mutex
	w  io.Writer
}

func NewSyncedWriter(w io.Writer) *SyncedWriter {
	return &SyncedWriter{w: w}
}

func (sw *SyncedWriter) Write(p []byte) (n int, err error) {
	sw.mu.Lock()
	defer sw.mu.Unlock()

	return sw.w.Write(p)
}

Than we could drop this passing of mutex, it is created on stack either way.

[croissanne]

2 reasons:

1. ibcli needs to write to the buildlog itself, it needs access to the mutex. So passing the mutex to the synced writer is needed, or we need to retrieve the mutex from the writer. It's ugly, but I can't think of an alternative.

2. 2 separate instances of synced writer need to share this mutex

mw = newSyncedWriter(&writeMu, io.MultiWriter(&stdio, opts.BuildLog))
buildLog = newSyncedWriter(&writeMu, opts.BuildLog)

[croissanne]

The 2nd reason is actually no longer the case with osbuild/images#1966 ; but we still need to pass along the mutex, unless we don't care about the ordering for these extra statements ibcli adds to the buildlog.

[lzap]

Hmmm, right. Well, how about to tee before sync so each writer has its individual mutex that can be shared? Something like:

syncedStdio := newSyncedWriter(&stdio)
syncedBuildLog := newSyncedWriter(opts.BuildLog)
io.MultiWriter(syncedStdio, syncedBuildLog)

Then use syncedBuildLog to write separately only to the build log independent of stdio. The example assumes newSyncedWriter no longer takes a shared mutex.

[croissanne]

So the flow should be

stdout → syncw → multiw → stdoutw or os stdout     
stderr ↗↗↗              → buildlog

If we create the syncw after the mw we get

stdout → multiw → syncw
stderr ↗↗↗      → syncw

I think by having both stdout and stderr go via the multiw into syncw we're already out of order? Unsure.

[croissanne]

Oh actually this works in images, I guess io.MultiWriter isn't racy?

	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
		//
		//
		// stdout → syncw → multiw → stdoutw or os stdout
		// stderr ↗↗↗             → buildlog
		// mu := common.ValueOrEmpty(opts.BuildLogMu)
		var mu1 sync.Mutex
		var mu2 sync.Mutex
		mw := io.MultiWriter(newSyncedWriter(&mu1, stdout), newSyncedWriter(&mu2, opts.BuildLog))
		cmd.Stdout = mw
		cmd.Stderr = mw
	}

The only problem is still writing the the buildlog from ibcli if we actually wanna move the synced writer over to images.

[croissanne]

Reversing multiwriter and syncedwriter can work, test pass with go test -race iwth this in images:

		if opts.BuildLogMu == nil {
			var mu sync.Mutex
			opts.BuildLogMu = &mu
		}

		var syncedStdio, syncedBuildlog io.Writer
		syncedStdio = newSyncedWriter(opts.BuildLogMu, stdout)
		syncedBuildlog = newSyncedWriter(opts.BuildLogMu, opts.BuildLog)
		mw := io.MultiWriter(syncedStdio, syncedBuildlog)
		cmd.Stdout = mw
		cmd.Stderr = mw

But this doesn't solve problem 2 :/

[croissanne]

maybe helpful