Skip to content

Commit 8a4dcf5

Browse files
vvolandvvoland
committed
test: Add tests for logging
1. Add integration tests for the ContainerLogs API call Each test handle a distinct case of ContainerLogs output. - Muxed stream, when container is started without tty - Single stream, when container is started with tty 2. Add unit test for LogReader suite that tests concurrent logging It checks that there are no race conditions when logging concurrently from multiple goroutines. Signed-off-by: Paweł Gronowski <[email protected]>
1 parent 3e32104 commit 8a4dcf5

3 files changed

Lines changed: 197 additions & 1 deletion

File tree

‎daemon/logger/jsonfilelog/read_test.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -166,7 +166,7 @@ func TestFollowLogsWithRotation(t *testing.T) {
166166
// set of logs that loggertest writes.
167167
info.Config = map[string]string{
168168
"compress": strconv.FormatBool(cmprs),
169-
"max-size": "4096b",
169+
"max-size": "512kb",
170170
"max-file": "3",
171171
}
172172
dir := t.TempDir()

‎daemon/logger/loggertest/logreader.go‎

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,10 @@
11
package loggertest // import "github.com/docker/docker/daemon/logger/loggertest"
22

33
import (
4+
"fmt"
45
"runtime"
56
"strings"
7+
"sync"
68
"testing"
79
"time"
810

@@ -381,6 +383,75 @@ func (tr Reader) TestFollow(t *testing.T) {
381383
<-doneReading
382384
assert.DeepEqual(t, logs, expected, compareLog)
383385
})
386+
387+
t.Run("Concurrent", tr.TestConcurrent)
388+
}
389+
390+
// TestConcurrent tests the Logger and its LogReader implementation for
391+
// race conditions when logging from multiple goroutines concurrently.
392+
func (tr Reader) TestConcurrent(t *testing.T) {
393+
t.Parallel()
394+
l := tr.Factory(t, logger.Info{
395+
ContainerID: "logconcurrent0",
396+
ContainerName: "logconcurrent123",
397+
})(t)
398+
399+
msgLine := func(source string, i int) []byte {
400+
return []byte(fmt.Sprintf("%s msg %d", source, i))
401+
}
402+
time0, _ := time.Parse("2006-01-02", "2000-01-01")
403+
msgTime := func(i int) time.Time {
404+
return time0.Add(time.Hour * time.Duration(i))
405+
}
406+
407+
wg := &sync.WaitGroup{}
408+
logTo := func(source string, howMany int) {
409+
defer wg.Done()
410+
for i := 0; i < howMany; i += 1 {
411+
msg := logger.NewMessage()
412+
msg.Line = msgLine(source, i)
413+
msg.Source = source
414+
msg.Timestamp = msgTime(i)
415+
l.Log(msg)
416+
}
417+
}
418+
419+
// Read all logs
420+
lw := l.(logger.LogReader).ReadLogs(logger.ReadConfig{Follow: true, Tail: -1})
421+
defer lw.ConsumerGone()
422+
423+
const messagesCount = 10000
424+
// Log concurrently from two sources
425+
wg.Add(2)
426+
go logTo("stdout", messagesCount)
427+
go logTo("stderr", messagesCount)
428+
go func() {
429+
defer l.Close()
430+
wg.Wait()
431+
}()
432+
433+
lastStdout := 0
434+
lastStderr := 0
435+
436+
// Check if the message count, order and content is equal to what was logged
437+
for l := range lw.Msg {
438+
var counter *int
439+
if l.Source == "stdout" {
440+
counter = &lastStdout
441+
} else if l.Source == "stderr" {
442+
counter = &lastStderr
443+
} else {
444+
t.Fatalf("Corrupted message.Source = %s", l.Source)
445+
}
446+
447+
assert.Equal(t, strings.TrimSpace(string(l.Line)), string(msgLine(l.Source, *counter)))
448+
assert.Equal(t, l.Timestamp.UTC(), msgTime(*counter).UTC())
449+
450+
*counter += 1
451+
}
452+
453+
assert.Equal(t, lastStdout, messagesCount)
454+
assert.Equal(t, lastStderr, messagesCount)
384455
}
385456

386457
// logMessages logs messages to l and returns a slice of messages as would be

‎integration/container/logs_test.go‎

Lines changed: 125 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,19 @@
11
package container // import "github.com/docker/docker/integration/container"
22

33
import (
4+
"bytes"
45
"context"
56
"io"
67
"testing"
8+
"time"
79

810
"github.com/docker/docker/api/types"
11+
"github.com/docker/docker/daemon/logger/jsonfilelog"
12+
"github.com/docker/docker/daemon/logger/local"
913
"github.com/docker/docker/integration/internal/container"
1014
"github.com/docker/docker/pkg/stdcopy"
1115
"gotest.tools/v3/assert"
16+
"gotest.tools/v3/poll"
1217
"gotest.tools/v3/skip"
1318
)
1419

@@ -32,3 +37,123 @@ func TestLogsFollowTailEmpty(t *testing.T) {
3237
_, err = stdcopy.StdCopy(io.Discard, io.Discard, logs)
3338
assert.Check(t, err)
3439
}
40+
41+
func TestLogs(t *testing.T) {
42+
drivers := []string{local.Name, jsonfilelog.Name}
43+
44+
for _, logDriver := range drivers {
45+
t.Run("driver "+logDriver, func(t *testing.T) {
46+
testLogs(t, logDriver)
47+
})
48+
}
49+
}
50+
51+
func testLogs(t *testing.T, logDriver string) {
52+
defer setupTest(t)()
53+
client := testEnv.APIClient()
54+
ctx := context.Background()
55+
56+
testCases := []struct {
57+
desc string
58+
logOps types.ContainerLogsOptions
59+
expectedOut string
60+
expectedErr string
61+
tty bool
62+
}{
63+
// TTY, only one output streamś
64+
{
65+
desc: "tty/stdout and stderr",
66+
tty: true,
67+
logOps: types.ContainerLogsOptions{
68+
ShowStdout: true,
69+
ShowStderr: true,
70+
},
71+
expectedOut: "this is fineaccidents happen",
72+
},
73+
{
74+
desc: "tty/only stdout",
75+
tty: true,
76+
logOps: types.ContainerLogsOptions{
77+
ShowStdout: true,
78+
ShowStderr: false,
79+
},
80+
expectedOut: "this is fineaccidents happen",
81+
},
82+
{
83+
desc: "tty/only stderr",
84+
tty: true,
85+
logOps: types.ContainerLogsOptions{
86+
ShowStdout: false,
87+
ShowStderr: true,
88+
},
89+
expectedOut: "",
90+
},
91+
// Without TTY, both stdout and stderrś
92+
{
93+
desc: "without tty/stdout and stderr",
94+
tty: false,
95+
logOps: types.ContainerLogsOptions{
96+
ShowStdout: true,
97+
ShowStderr: true,
98+
},
99+
expectedOut: "this is fine",
100+
expectedErr: "accidents happen",
101+
},
102+
{
103+
desc: "without tty/only stdout",
104+
tty: false,
105+
logOps: types.ContainerLogsOptions{
106+
ShowStdout: true,
107+
ShowStderr: false,
108+
},
109+
expectedOut: "this is fine",
110+
expectedErr: "",
111+
},
112+
{
113+
desc: "without tty/only stderr",
114+
tty: false,
115+
logOps: types.ContainerLogsOptions{
116+
ShowStdout: false,
117+
ShowStderr: true,
118+
},
119+
expectedOut: "",
120+
expectedErr: "accidents happen",
121+
},
122+
}
123+
124+
for _, tC := range testCases {
125+
t.Run(tC.desc, func(t *testing.T) {
126+
t.Parallel()
127+
tty := tC.tty
128+
id := container.Run(ctx, t, client,
129+
container.WithCmd("sh", "-c", "echo -n this is fine; echo -n accidents happen >&2"),
130+
container.WithTty(tty),
131+
container.WithLogDriver(logDriver),
132+
)
133+
defer client.ContainerRemove(ctx, id, types.ContainerRemoveOptions{Force: true})
134+
135+
poll.WaitOn(t, container.IsStopped(ctx, client, id), poll.WithDelay(time.Millisecond*100))
136+
137+
logs, err := client.ContainerLogs(ctx, id, tC.logOps)
138+
assert.NilError(t, err)
139+
defer logs.Close()
140+
141+
// TTY, only one output stream
142+
if tty {
143+
out := new(bytes.Buffer)
144+
145+
_, err = io.Copy(out, logs)
146+
assert.NilError(t, err)
147+
assert.DeepEqual(t, out.String(), tC.expectedOut)
148+
} else {
149+
stdout := new(bytes.Buffer)
150+
stderr := new(bytes.Buffer)
151+
152+
_, err = stdcopy.StdCopy(stdout, stderr, logs)
153+
assert.NilError(t, err)
154+
assert.DeepEqual(t, stdout.String(), tC.expectedOut)
155+
assert.DeepEqual(t, stderr.String(), tC.expectedErr)
156+
}
157+
})
158+
}
159+
}

0 commit comments

Comments
 (0)