Skip to content

Commit 30137d2

Browse files
Copilotlibor-m
andcommitted
Add mutex to Logger to fix race condition in parallel task execution
Co-authored-by: libor-m <1497769+libor-m@users.noreply.github.com>
1 parent 1312ee8 commit 30137d2

2 files changed

Lines changed: 175 additions & 0 deletions

File tree

internal/logger/logger.go

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ import (
66
"slices"
77
"strconv"
88
"strings"
9+
"sync"
910

1011
"github.com/Ladicle/tabwriter"
1112
"github.com/fatih/color"
@@ -137,6 +138,7 @@ type Logger struct {
137138
Color bool
138139
AssumeYes bool
139140
AssumeTerm bool // Used for testing
141+
mu sync.Mutex
140142
}
141143

142144
// Outf prints stuff to STDOUT.
@@ -153,6 +155,9 @@ func (l *Logger) FOutf(w io.Writer, color Color, s string, args ...any) {
153155
color = None
154156
}
155157
print := color()
158+
159+
l.mu.Lock()
160+
defer l.mu.Unlock()
156161
print(w, s, args...)
157162
}
158163

@@ -172,6 +177,9 @@ func (l *Logger) Errf(color Color, s string, args ...any) {
172177
color = None
173178
}
174179
print := color()
180+
181+
l.mu.Lock()
182+
defer l.mu.Unlock()
175183
print(l.Stderr, s, args...)
176184
}
177185

internal/logger/logger_test.go

Lines changed: 167 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,167 @@
1+
package logger
2+
3+
import (
4+
"bytes"
5+
"strings"
6+
"sync"
7+
"testing"
8+
)
9+
10+
// TestRaceConditionBug tests that the race condition described in the issue is fixed.
11+
// Without the mutex, ANSI escape sequences from multiple goroutines can interleave,
12+
// causing text to appear in the wrong color.
13+
// The main validation is done by running with -race flag to detect any data races.
14+
func TestRaceConditionBug(t *testing.T) {
15+
var buf bytes.Buffer
16+
logger := &Logger{
17+
Stdout: &buf,
18+
Stderr: &buf,
19+
Color: true, // Even if colors are disabled in test env, we test the sync behavior
20+
}
21+
22+
const numGoroutines = 50
23+
var wg sync.WaitGroup
24+
wg.Add(numGoroutines)
25+
26+
// Simulate the scenario: multiple goroutines writing colored output simultaneously
27+
// Goroutine 1 writes green, Goroutine 2 writes magenta
28+
// Without mutex: escape codes can interleave making text appear in wrong colors
29+
for i := 0; i < numGoroutines; i++ {
30+
go func(id int) {
31+
defer wg.Done()
32+
if id%2 == 0 {
33+
// Green output (would be ANSI: \033[32m in color-enabled terminal)
34+
logger.Outf(Green, "green message %d\n", id)
35+
} else {
36+
// Magenta output (would be ANSI: \033[35m in color-enabled terminal)
37+
logger.Outf(Magenta, "magenta message %d\n", id)
38+
}
39+
}(i)
40+
}
41+
42+
wg.Wait()
43+
44+
output := buf.String()
45+
46+
// Verify we got output
47+
if len(output) == 0 {
48+
t.Fatal("Expected output but got none")
49+
}
50+
51+
// The primary goal is to ensure no race conditions occur.
52+
// With the mutex in place, this test should pass reliably with -race flag.
53+
// We verify basic structure: output contains both green and magenta messages
54+
if !strings.Contains(output, "green message") {
55+
t.Error("Expected to find 'green message' in output")
56+
}
57+
if !strings.Contains(output, "magenta message") {
58+
t.Error("Expected to find 'magenta message' in output")
59+
}
60+
}
61+
62+
// TestConcurrentOutput tests that concurrent writes to the logger don't cause race conditions
63+
func TestConcurrentOutput(t *testing.T) {
64+
var buf bytes.Buffer
65+
logger := &Logger{
66+
Stdout: &buf,
67+
Stderr: &buf,
68+
Color: true,
69+
}
70+
71+
const numGoroutines = 100
72+
const numIterations = 10
73+
74+
var wg sync.WaitGroup
75+
wg.Add(numGoroutines * 2) // *2 because we test both Outf and Errf
76+
77+
// Test concurrent Outf calls
78+
for i := 0; i < numGoroutines; i++ {
79+
go func(id int) {
80+
defer wg.Done()
81+
for j := 0; j < numIterations; j++ {
82+
logger.Outf(Green, "goroutine %d iteration %d\n", id, j)
83+
}
84+
}(i)
85+
}
86+
87+
// Test concurrent Errf calls
88+
for i := 0; i < numGoroutines; i++ {
89+
go func(id int) {
90+
defer wg.Done()
91+
for j := 0; j < numIterations; j++ {
92+
logger.Errf(Red, "error from goroutine %d iteration %d\n", id, j)
93+
}
94+
}(i)
95+
}
96+
97+
wg.Wait()
98+
99+
// If we got here without a race condition, the test passes
100+
// We just need to verify that we got some output
101+
if buf.Len() == 0 {
102+
t.Error("Expected output but got none")
103+
}
104+
}
105+
106+
// TestConcurrentFOutf tests that concurrent writes to FOutf don't cause race conditions
107+
func TestConcurrentFOutf(t *testing.T) {
108+
var buf bytes.Buffer
109+
logger := &Logger{
110+
Stdout: &buf,
111+
Stderr: &buf,
112+
Color: true,
113+
}
114+
115+
const numGoroutines = 50
116+
const numIterations = 10
117+
118+
var wg sync.WaitGroup
119+
wg.Add(numGoroutines)
120+
121+
for i := 0; i < numGoroutines; i++ {
122+
go func(id int) {
123+
defer wg.Done()
124+
for j := 0; j < numIterations; j++ {
125+
logger.FOutf(&buf, Magenta, "FOutf from goroutine %d iteration %d\n", id, j)
126+
}
127+
}(i)
128+
}
129+
130+
wg.Wait()
131+
132+
// If we got here without a race condition, the test passes
133+
if buf.Len() == 0 {
134+
t.Error("Expected output but got none")
135+
}
136+
}
137+
138+
// TestConcurrentMixedColors tests that concurrent writes with different colors don't interleave
139+
func TestConcurrentMixedColors(t *testing.T) {
140+
var buf bytes.Buffer
141+
logger := &Logger{
142+
Stdout: &buf,
143+
Stderr: &buf,
144+
Color: true,
145+
}
146+
147+
const numGoroutines = 20
148+
colors := []Color{Green, Red, Blue, Yellow, Magenta, Cyan}
149+
150+
var wg sync.WaitGroup
151+
wg.Add(numGoroutines)
152+
153+
for i := 0; i < numGoroutines; i++ {
154+
go func(id int) {
155+
defer wg.Done()
156+
color := colors[id%len(colors)]
157+
logger.Outf(color, "message from goroutine %d\n", id)
158+
}(i)
159+
}
160+
161+
wg.Wait()
162+
163+
// The test passes if we don't have a race condition
164+
if buf.Len() == 0 {
165+
t.Error("Expected output but got none")
166+
}
167+
}

0 commit comments

Comments
 (0)