From da64d6200099f070dc61ea0df7b405d71309d489 Mon Sep 17 00:00:00 2001 From: Boris Korzun Date: Fri, 15 Apr 2022 01:51:00 +0300 Subject: [PATCH] Fix incorrect severity syslog messages (#12079) Co-authored-by: Evan Culver --- .changelog/12079.txt | 3 ++ .circleci/config.yml | 2 + logging/logger.go | 2 +- logging/syslog.go | 4 +- logging/syslog_test.go | 77 ++++++++++++++++++++++++++++++ logging/syslog_unsupported_test.go | 20 ++++++++ 6 files changed, 105 insertions(+), 3 deletions(-) create mode 100644 .changelog/12079.txt create mode 100644 logging/syslog_test.go create mode 100644 logging/syslog_unsupported_test.go diff --git a/.changelog/12079.txt b/.changelog/12079.txt new file mode 100644 index 000000000..aa5dabb38 --- /dev/null +++ b/.changelog/12079.txt @@ -0,0 +1,3 @@ +```release-note:bug +logging: fix a bug with incorrect severity syslog messages (all messages were sent with NOTICE severity). +``` diff --git a/.circleci/config.yml b/.circleci/config.yml index f5b25f359..005deefb1 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -225,6 +225,8 @@ jobs: - image: *GOLANG_IMAGE environment: <<: *ENVIRONMENT + # tput complains if this isn't set to something. + TERM: ansi steps: - checkout - run: diff --git a/logging/logger.go b/logging/logger.go index 9d6cff74f..39b538336 100644 --- a/logging/logger.go +++ b/logging/logger.go @@ -77,7 +77,7 @@ func Setup(config Config, out io.Writer) (hclog.InterceptLogger, error) { for i := 0; i <= retries; i++ { syslog, err := gsyslog.NewLogger(gsyslog.LOG_NOTICE, config.SyslogFacility, "consul") if err == nil { - writers = append(writers, syslog) + writers = append(writers, &SyslogWrapper{l: syslog}) break } diff --git a/logging/syslog.go b/logging/syslog.go index 7115d0354..6e2c71e26 100644 --- a/logging/syslog.go +++ b/logging/syslog.go @@ -3,7 +3,7 @@ package logging import ( "bytes" - "github.com/hashicorp/go-syslog" + gsyslog "github.com/hashicorp/go-syslog" ) // levelPriority is used to map a log level to a @@ -34,7 +34,7 @@ func (s *SyslogWrapper) Write(p []byte) (int, error) { y := bytes.IndexByte(p[x:], ']') if y >= 0 { level = string(p[x+1 : x+y]) - afterLevel = p[x+y+2:] + afterLevel = bytes.TrimLeft(p[x+y+2:], " ") } } diff --git a/logging/syslog_test.go b/logging/syslog_test.go new file mode 100644 index 000000000..19931e346 --- /dev/null +++ b/logging/syslog_test.go @@ -0,0 +1,77 @@ +//go:build linux || darwin || dragonfly || freebsd || netbsd || openbsd || solaris +// +build linux darwin dragonfly freebsd netbsd openbsd solaris + +package logging + +import ( + "testing" + + gsyslog "github.com/hashicorp/go-syslog" + "github.com/stretchr/testify/require" +) + +// testSyslogFunc is a wrapper for injecting WriteLevel functionality into a Syslogger +// implementation; it gives us a way to inject test assertions into a SyslogWrapper. +type testSyslogWriteLevelFunc func(p gsyslog.Priority, m []byte) error + +// Write is a no-op +func (f testSyslogWriteLevelFunc) Write(p []byte) (int, error) { + return 0, nil +} + +// WriteLevel is a wrapper for the identity to be called +func (f testSyslogWriteLevelFunc) WriteLevel(p gsyslog.Priority, m []byte) error { + return f(p, m) +} + +// Close is a no-op +func (f testSyslogWriteLevelFunc) Close() error { + return nil +} + +func TestSyslog_Wrapper(t *testing.T) { + expectedMsg := []byte("test message") + + // generator for a writer that expects to be written with expectedPriority + writerForPriority := func(expectedPriority gsyslog.Priority) testSyslogWriteLevelFunc { + return func(p gsyslog.Priority, m []byte) error { + require.Equal(t, expectedPriority, p) + require.Equal(t, expectedMsg, m) + return nil + } + } + // [TRACE] is mapped to the LOG_DEBUG priority + debugw := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_DEBUG)} + _, err := debugw.Write([]byte("[TRACE] " + string(expectedMsg))) + require.NoError(t, err) + + // [DEBUG] is mapped to the LOG_INFO priority + infow := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_INFO)} + _, err = infow.Write([]byte("[DEBUG] " + string(expectedMsg))) + require.NoError(t, err) + + // [INFO] is mapped to the LOG_NOTICE priority + noticew := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_NOTICE)} + _, err = noticew.Write([]byte("[INFO] " + string(expectedMsg))) + require.NoError(t, err) + + // [WARN] is mapped to the LOG_WARNING priority + warnw := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_WARNING)} + _, err = warnw.Write([]byte("[WARN] " + string(expectedMsg))) + require.NoError(t, err) + + // [ERROR] is mapped to the LOG_ERR priority + errorw := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_ERR)} + _, err = errorw.Write([]byte("[ERROR] " + string(expectedMsg))) + require.NoError(t, err) + + // [CRIT] is mapped to the LOG_CRIT priority + critw := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_CRIT)} + _, err = critw.Write([]byte("[CRIT] " + string(expectedMsg))) + require.NoError(t, err) + + // unknown levels are written with LOG_NOTICE priority + defaultw := &SyslogWrapper{l: writerForPriority(gsyslog.LOG_NOTICE)} + _, err = defaultw.Write([]byte("[INVALID] " + string(expectedMsg))) + require.NoError(t, err) +} diff --git a/logging/syslog_unsupported_test.go b/logging/syslog_unsupported_test.go new file mode 100644 index 000000000..5a3f4886d --- /dev/null +++ b/logging/syslog_unsupported_test.go @@ -0,0 +1,20 @@ +//go:build windows || plan9 || nacl +// +build windows plan9 nacl + +package logging + +import ( + "testing" + + gsyslog "github.com/hashicorp/go-syslog" + "github.com/stretchr/testify/require" +) + +func TestSyslog_Unsupported(t *testing.T) { + // the role of the underlying go-syslog library is primarily to wrap the + // default log/syslog package such that when running against an unsupported + // OS, a meaningful error is returned, so that's what we'll test here by default. + s, err := gsyslog.NewLogger(gsyslog.LOG_NOTICE, "USER", "consul") + require.Error(t, err) + require.Nil(t, s) +}