diff --git a/cmd/shell.go b/cmd/shell.go index 779c20130..04deabcc7 100644 --- a/cmd/shell.go +++ b/cmd/shell.go @@ -138,7 +138,8 @@ type logWriter struct { } func (lw logWriter) Write(p []byte) (n int, err error) { - lw.Logger.Info(string(p)) + // Lines received by logWriter will always have a trailing newline. + lw.Logger.Info(strings.Trim(string(p), "\n")) return } diff --git a/cmd/shell_test.go b/cmd/shell_test.go index d6e0ee459..134e5290f 100644 --- a/cmd/shell_test.go +++ b/cmd/shell_test.go @@ -194,3 +194,12 @@ func TestReadConfigFile(t *testing.T) { test.AssertNotError(t, err, "ReadConfigFile(../test/config/notify-mailer.json) errored") test.AssertEquals(t, c.NotifyMailer.SMTPConfig.Server, "localhost") } + +func TestLogWriter(t *testing.T) { + mock := blog.UseMock() + lw := logWriter{mock} + _, _ = lw.Write([]byte("hi\n")) + lines := mock.GetAllMatching(".*") + test.AssertEquals(t, len(lines), 1) + test.AssertEquals(t, lines[0], "INFO: hi") +} diff --git a/log/log.go b/log/log.go index e77845509..562be917a 100644 --- a/log/log.go +++ b/log/log.go @@ -7,6 +7,7 @@ import ( "errors" "fmt" "hash/crc32" + "io" "log/syslog" "os" "path" @@ -60,7 +61,7 @@ func New(log *syslog.Writer, stdoutLogLevel int, syslogLogLevel int) (Logger, er return nil, errors.New("Attempted to use a nil System Logger.") } return &impl{ - &bothWriter{log, stdoutLogLevel, syslogLogLevel, clock.New()}, + &bothWriter{log, stdoutLogLevel, syslogLogLevel, clock.New(), os.Stdout}, }, nil } @@ -118,6 +119,7 @@ type bothWriter struct { stdoutLevel int syslogLevel int clk clock.Clock + stdout io.Writer } func LogLineChecksum(line string) string { @@ -138,6 +140,9 @@ func (w *bothWriter) logAtLevel(level syslog.Priority, msg string) { const red = "\033[31m\033[1m" const yellow = "\033[33m" + // Since messages are delimited by newlines, we have to escape any internal or + // trailing newlines before generating the checksum or outputting the message. + msg = strings.Replace(msg, "\n", "\\n", -1) msg = fmt.Sprintf("%s %s", LogLineChecksum(msg), msg) switch syslogAllowed := int(level) <= w.syslogLevel; level { @@ -175,7 +180,7 @@ func (w *bothWriter) logAtLevel(level syslog.Priority, msg string) { } if int(level) <= w.stdoutLevel { - if _, err := fmt.Printf("%s%s %s %s%s\n", + if _, err := fmt.Fprintf(w.stdout, "%s%s %s %s%s\n", prefix, w.clk.Now().Format("150405"), path.Base(os.Args[0]), diff --git a/log/log_test.go b/log/log_test.go index ee1cf8af9..6ba6e9d6c 100644 --- a/log/log_test.go +++ b/log/log_test.go @@ -1,6 +1,7 @@ package log import ( + "bytes" "fmt" "log" "log/syslog" @@ -340,3 +341,11 @@ func TestStdoutFailure(t *testing.T) { // Try to audit log something log.AuditInfo("This should cause a panic, stdout is closed!") } + +func TestLogAtLevelEscapesNewlines(t *testing.T) { + var buf bytes.Buffer + w := &bothWriter{nil, 6, 0, clock.New(), &buf} + w.logAtLevel(6, "foo\nbar") + + test.Assert(t, strings.Contains(buf.String(), "foo\\nbar"), "failed to escape newline") +}