Skip to content

logutil: fix data race when Pause is called concurrently - #4007

Draft
alexey-igrychev wants to merge 1 commit into
docker:masterfrom
alexey-igrychev:fix/concurrent-log-pause
Draft

logutil: fix data race when Pause is called concurrently#4007
alexey-igrychev wants to merge 1 commit into
docker:masterfrom
alexey-igrychev:fix/concurrent-log-pause

Conversation

@alexey-igrychev

Copy link
Copy Markdown

Problem

logutil.Pause mutates the shared logger's output on every call:

func Pause(l *logrus.Logger) func() {
	l.Formatter.Format(logrus.NewEntry(l))
	bw := newBufferedWriter(l.Out)
	l.SetOutput(bw)          // write to l.Out
	return func() { bw.resume() }
}

Printer.updateDisplay calls Pause(logrus.StandardLogger()) and holds it
(via defer resumeLogs()) for the printer's entire active period. When more
than one Printer runs at the same time in a single process — e.g. a tool
that drives several concurrent build operations — each one reads l.Out
and calls l.SetOutput on the same process-wide logrus.StandardLogger()
without synchronization:

WARNING: DATA RACE
Read at ... by goroutine A:
  logutil.Pause()            pause.go  (l.Out)
Previous write by goroutine B:
  logrus.(*Logger).SetOutput()
  logutil.Pause()            pause.go  (l.SetOutput)

Fix

Install a single refcounting writer per logger instead of swapping the
logger's output on every Pause:

  • The first Pause for a logger wraps l.Out once (formatter terminal-init
    still happens while l.Out is the real terminal) and stores the wrapper in
    a small guarded map.
  • Each Pause increments a counter; each resume decrements it. Output is
    buffered while the count is > 0 and flushed, in order, when it returns to 0.
  • Pause never blocks on another active pause, so concurrent printers keep
    running in parallel — only the interleaving of logrus output with the
    progress display is serialized, not the work itself.

Test

util/logutil/pause_test.go (new) covers concurrent pause/resume, concurrent
first-time initialization (the raced path), overlapping-output buffering, and
resume idempotency. go test -race ./util/logutil fails on master and passes
with this change.

Signed-off-by: Aleksei Igrychev <aleksei.igrychev@palark.com>
@alexey-igrychev
alexey-igrychev force-pushed the fix/concurrent-log-pause branch from 8ea2e36 to 7faf88b Compare August 10, 2026 13:27
alexey-igrychev added a commit to werf/werf that referenced this pull request Aug 10, 2026
…#7803)

## Summary

Branch `3` currently serializes concurrent Dockerfile builds: the
`werf/3p-buildx`
replacement in `go.mod` fixes a data race in `docker/buildx`'s
`logutil.Pause` with a
global mutex that is held for a build's entire progress-display
lifetime, so two
Dockerfile builds in one process cannot run at the same time. This
points the
replacement at a fork commit that fixes the same race without a global
lock, restoring
concurrency.

## What

- Concurrent Dockerfile builds in a single werf process run in parallel
again; the
  previous fork serialized them.
- The `-race`-detected data race on `logrus.StandardLogger()` in
`logutil.Pause` stays
fixed: pauses are multiplexed through one refcounted per-logger writer,
and `Pause`
  never blocks on another active pause.
- Only the `go.mod`/`go.sum` `docker/buildx => werf/3p-buildx` pin
changes; no CLI,
  configuration, or persisted-data changes.

## Why

#7800 removed this replacement precisely because its global mutex
serialized concurrent
builds, and said to keep it out until an upstream-safe fix existed.
#7802 was branched
before that revert and reintroduced the old pin on merge, so `3`
regressed to the
serializing fork. The new fork commit (backport of docker/buildx#4007)
replaces the
global mutex with a per-logger refcounting writer: the first `Pause`
wraps the logger
output once, each `Pause` bumps a counter, output is buffered while any
pause is active
and flushed in order when the last one resumes. Remove this replacement
once the fix
lands in an upstream buildx release.

Fixes: f80e827 ("fix(logboek): prevent concurrent stream races
(#7802)")

Signed-off-by: Aleksei Igrychev <aleksei.igrychev@palark.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant