libct/logs: test: make more robust

When playing with the log forwarder, I broke it, but all the units tests
were still passing. This happened because test cases were merely looking
for a word (like "kitten") in the log output, which also happened to be
there in case of an error (as a part of an error message produced by log
forwarder).

Make the test a bit more robust by
 - looking for a complete log message, not just part of it;
 - also checking that log file does NOT contain errors.

Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
This commit is contained in:
Kir Kolyshkin
2021-07-27 13:02:55 -07:00
parent 8d8415ee46
commit c4826905f1
+30 -20
View File
@@ -11,44 +11,51 @@ import (
"github.com/sirupsen/logrus"
)
const msgErr = `"level":"error"`
func TestLoggingToFile(t *testing.T) {
l := runLogForwarding(t)
logToLogWriter(t, l, `{"level": "info","msg":"kitten"}`)
msg := `"level":"info","msg":"kitten"`
logToLogWriter(t, l, msg)
finish(t, l)
check(t, l, "kitten")
check(t, l, msg, msgErr)
}
func TestLogForwardingDoesNotStopOnJsonDecodeErr(t *testing.T) {
l := runLogForwarding(t)
logToLogWriter(t, l, "invalid-json-with-kitten")
checkWait(t, l, "failed to decode")
logToLogWriter(t, l, `"invalid-json-with-kitten"`)
checkWait(t, l, msgErr, "")
truncateLogFile(t, l.file)
logToLogWriter(t, l, `{"level": "info","msg":"puppy"}`)
msg := `"level":"info","msg":"puppy"`
logToLogWriter(t, l, msg)
finish(t, l)
check(t, l, "puppy")
check(t, l, msg, msgErr)
}
func TestLogForwardingDoesNotStopOnLogLevelParsingErr(t *testing.T) {
l := runLogForwarding(t)
logToLogWriter(t, l, `{"level": "alert","msg":"puppy"}`)
checkWait(t, l, "failed to parse log level")
msg := `"level":"alert","msg":"puppy"`
logToLogWriter(t, l, msg)
checkWait(t, l, msgErr, msg)
truncateLogFile(t, l.file)
logToLogWriter(t, l, `{"level": "info","msg":"puppy"}`)
msg = `"level":"info","msg":"puppy"`
logToLogWriter(t, l, msg)
finish(t, l)
check(t, l, "puppy")
check(t, l, msg, msgErr)
}
func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) {
l := runLogForwarding(t)
logToLogWriter(t, l, `{"level": "info","msg":"sync"}`)
msg := `"level":"info","msg":"sync"`
logToLogWriter(t, l, msg)
// Do not use finish() here as we check done pipe ourselves.
l.w.Close()
@@ -58,12 +65,12 @@ func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) {
t.Fatal("log forwarding did not stop after closing the pipe")
}
check(t, l, "sync")
check(t, l, msg, msgErr)
}
func logToLogWriter(t *testing.T, l *log, message string) {
t.Helper()
_, err := l.w.Write([]byte(message + "\n"))
_, err := l.w.Write([]byte("{" + message + "}\n"))
if err != nil {
t.Fatalf("failed to write %q to log writer: %v", message, err)
}
@@ -119,21 +126,24 @@ func truncateLogFile(t *testing.T, file *os.File) {
}
}
// check checks that file contains txt
func check(t *testing.T, l *log, txt string) {
// 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 := ioutil.ReadFile(l.file.Name())
if err != nil {
t.Fatal(err)
}
if !bytes.Contains(contents, []byte(txt)) {
t.Fatalf("%q does not contain %q", string(contents), txt)
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 checks that file contains txt. If the file is empty,
// 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) {
func checkWait(t *testing.T, l *log, txt string, notxt string) {
t.Helper()
const (
delay = 100 * time.Millisecond
@@ -153,5 +163,5 @@ func checkWait(t *testing.T, l *log, txt string) {
time.Sleep(delay)
}
check(t, l, txt)
check(t, l, txt, notxt)
}