File: logs_linux_test.go

package info (click to toggle)
runc 1.3.3%2Bds1-2
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 3,000 kB
  • sloc: sh: 2,298; ansic: 1,125; makefile: 229
file content (166 lines) | stat: -rw-r--r-- 3,380 bytes parent folder | download | duplicates (5)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
package logs

import (
	"bytes"
	"io"
	"os"
	"testing"
	"time"

	"github.com/sirupsen/logrus"
)

const msgErr = `"level":"error"`

func TestLoggingToFile(t *testing.T) {
	l := runLogForwarding(t)

	msg := `"level":"info","msg":"kitten"`
	logToLogWriter(t, l, msg)
	finish(t, l)
	check(t, l, msg, msgErr)
}

func TestLogForwardingDoesNotStopOnJsonDecodeErr(t *testing.T) {
	l := runLogForwarding(t)

	logToLogWriter(t, l, `"invalid-json-with-kitten"`)
	checkWait(t, l, msgErr, "")

	truncateLogFile(t, l.file)

	msg := `"level":"info","msg":"puppy"`
	logToLogWriter(t, l, msg)
	finish(t, l)
	check(t, l, msg, msgErr)
}

func TestLogForwardingDoesNotStopOnLogLevelParsingErr(t *testing.T) {
	l := runLogForwarding(t)

	msg := `"level":"alert","msg":"puppy"`
	logToLogWriter(t, l, msg)
	checkWait(t, l, msgErr, msg)

	truncateLogFile(t, l.file)

	msg = `"level":"info","msg":"puppy"`
	logToLogWriter(t, l, msg)
	finish(t, l)
	check(t, l, msg, msgErr)
}

func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) {
	l := runLogForwarding(t)

	msg := `"level":"info","msg":"sync"`
	logToLogWriter(t, l, msg)

	// Do not use finish() here as we check done pipe ourselves.
	l.w.Close()
	select {
	case <-l.done:
	case <-time.After(10 * time.Second):
		t.Fatal("log forwarding did not stop after closing the pipe")
	}

	check(t, l, msg, msgErr)
}

func logToLogWriter(t *testing.T, l *log, message string) {
	t.Helper()
	_, err := l.w.Write([]byte("{" + message + "}\n"))
	if err != nil {
		t.Fatalf("failed to write %q to log writer: %v", message, err)
	}
}

type log struct {
	w    io.WriteCloser
	file *os.File
	done chan error
}

func runLogForwarding(t *testing.T) *log {
	t.Helper()
	logR, logW, err := os.Pipe()
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(func() {
		logR.Close()
		logW.Close()
	})

	tempFile, err := os.CreateTemp("", "")
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(func() {
		tempFile.Close()
		os.Remove(tempFile.Name())
	})

	logrus.SetOutput(tempFile)
	logrus.SetFormatter(&logrus.JSONFormatter{})
	doneForwarding := ForwardLogs(logR)

	return &log{w: logW, done: doneForwarding, file: tempFile}
}

func finish(t *testing.T, l *log) {
	t.Helper()
	l.w.Close()
	if err := <-l.done; err != nil {
		t.Fatalf("ForwardLogs: %v", err)
	}
}

func truncateLogFile(t *testing.T, file *os.File) {
	t.Helper()

	err := file.Truncate(0)
	if err != nil {
		t.Fatalf("failed to truncate log file: %v", err)
	}
}

// check checks that the file contains txt and does not contain notxt.
func check(t *testing.T, l *log, txt, notxt string) {
	t.Helper()
	contents, err := os.ReadFile(l.file.Name())
	if err != nil {
		t.Fatal(err)
	}
	if txt != "" && !bytes.Contains(contents, []byte(txt)) {
		t.Fatalf("%s does not contain %s", contents, txt)
	}
	if notxt != "" && bytes.Contains(contents, []byte(notxt)) {
		t.Fatalf("%s does contain %s", contents, notxt)
	}
}

// checkWait is like check, but if the file is empty,
// it waits until it's not.
func checkWait(t *testing.T, l *log, txt string, notxt string) {
	t.Helper()
	const (
		delay = 100 * time.Millisecond
		iter  = 3
	)
	for i := 0; ; i++ {
		st, err := l.file.Stat()
		if err != nil {
			t.Fatal(err)
		}
		if st.Size() > 0 {
			break
		}
		if i == iter {
			t.Fatalf("waited %s for file %s to be non-empty but it still is", iter*delay, l.file.Name())
		}
		time.Sleep(delay)
	}

	check(t, l, txt, notxt)
}