From b05884511095f8ff25b6f5cf227375473a67f1bf Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Thu, 3 Feb 2022 13:40:19 -0500 Subject: [PATCH 1/2] sdk: add TestLogLevel for setting log level in tests And default log level to WARN. --- agent/acl_test.go | 2 +- agent/ae/ae_test.go | 6 +++--- agent/consul/client_test.go | 2 +- agent/consul/leader_test.go | 2 +- agent/consul/prepared_query_endpoint_test.go | 3 ++- agent/router/manager_internal_test.go | 5 +---- agent/testagent.go | 2 +- sdk/testutil/testlog.go | 14 ++++++++++++++ 8 files changed, 24 insertions(+), 12 deletions(-) diff --git a/agent/acl_test.go b/agent/acl_test.go index ad7e8cebbb..539cf5c074 100644 --- a/agent/acl_test.go +++ b/agent/acl_test.go @@ -67,7 +67,7 @@ func NewTestACLAgent(t *testing.T, name string, hcl string, resolveAuthz authzRe bd.Logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{ Name: name, - Level: hclog.Debug, + Level: testutil.TestLogLevel, Output: logBuffer, TimeFormat: "04:05.000", }) diff --git a/agent/ae/ae_test.go b/agent/ae/ae_test.go index dd88b52bfc..c719f1951c 100644 --- a/agent/ae/ae_test.go +++ b/agent/ae/ae_test.go @@ -8,10 +8,11 @@ import ( "testing" "time" - "github.com/hashicorp/consul/lib" - "github.com/hashicorp/consul/sdk/testutil" "github.com/hashicorp/go-hclog" "github.com/stretchr/testify/assert" + + "github.com/hashicorp/consul/lib" + "github.com/hashicorp/consul/sdk/testutil" ) func TestAE_scaleFactor(t *testing.T) { @@ -401,7 +402,6 @@ func (m *mock) SyncChanges() error { func testSyncer(t *testing.T) *StateSyncer { logger := hclog.New(&hclog.LoggerOptions{ - Level: 0, Output: testutil.NewLogBuffer(t), }) diff --git a/agent/consul/client_test.go b/agent/consul/client_test.go index 79c3f1a7b5..9eb45aa8d5 100644 --- a/agent/consul/client_test.go +++ b/agent/consul/client_test.go @@ -507,7 +507,7 @@ func newDefaultDeps(t *testing.T, c *Config) Deps { logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{ Name: c.NodeName, - Level: hclog.Debug, + Level: testutil.TestLogLevel, Output: testutil.NewLogBuffer(t), }) diff --git a/agent/consul/leader_test.go b/agent/consul/leader_test.go index aeaf70f22d..5106651b32 100644 --- a/agent/consul/leader_test.go +++ b/agent/consul/leader_test.go @@ -1445,7 +1445,7 @@ func TestLeader_ConfigEntryBootstrap_Fail(t *testing.T) { logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{ Name: config.NodeName, - Level: hclog.Debug, + Level: testutil.TestLogLevel, Output: io.MultiWriter(pw, testutil.NewLogBuffer(t)), }) diff --git a/agent/consul/prepared_query_endpoint_test.go b/agent/consul/prepared_query_endpoint_test.go index 8f0e7ca318..7e64b8603f 100644 --- a/agent/consul/prepared_query_endpoint_test.go +++ b/agent/consul/prepared_query_endpoint_test.go @@ -21,6 +21,7 @@ import ( "github.com/hashicorp/consul/agent/structs" tokenStore "github.com/hashicorp/consul/agent/token" "github.com/hashicorp/consul/api" + "github.com/hashicorp/consul/sdk/testutil" "github.com/hashicorp/consul/sdk/testutil/retry" "github.com/hashicorp/consul/testrpc" "github.com/hashicorp/consul/types" @@ -2760,7 +2761,7 @@ func (m *mockQueryServer) GetLogger() hclog.Logger { m.Logger = hclog.New(&hclog.LoggerOptions{ Name: "mock_query", Output: m.LogBuffer, - Level: hclog.Debug, + Level: testutil.TestLogLevel, }) } return m.Logger diff --git a/agent/router/manager_internal_test.go b/agent/router/manager_internal_test.go index 92714a0155..640e96a062 100644 --- a/agent/router/manager_internal_test.go +++ b/agent/router/manager_internal_test.go @@ -25,10 +25,7 @@ func init() { func GetBufferedLogger() hclog.Logger { localLogBuffer = new(bytes.Buffer) - return hclog.New(&hclog.LoggerOptions{ - Level: 0, - Output: localLogBuffer, - }) + return hclog.New(&hclog.LoggerOptions{Output: localLogBuffer}) } type fauxConnPool struct { diff --git a/agent/testagent.go b/agent/testagent.go index 0119a612e9..84618f9afb 100644 --- a/agent/testagent.go +++ b/agent/testagent.go @@ -159,7 +159,7 @@ func (a *TestAgent) Start(t *testing.T) error { } logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{ - Level: hclog.Debug, + Level: testutil.TestLogLevel, Output: logOutput, TimeFormat: "04:05.000", Name: name, diff --git a/sdk/testutil/testlog.go b/sdk/testutil/testlog.go index fa0bd93dbb..bb41c4b55a 100644 --- a/sdk/testutil/testlog.go +++ b/sdk/testutil/testlog.go @@ -10,6 +10,20 @@ import ( "github.com/hashicorp/go-hclog" ) +// TestLogLevel is set from the TEST_LOG_LEVEL environment variable. It can +// be used by tests to set the log level of a hclog.Logger. Defaults to +// hclog.Warn if the environment variable is unset, or if the value of the +// environment variable can not be matched to a log level. +var TestLogLevel = testLogLevel() + +func testLogLevel() hclog.Level { + level := hclog.LevelFromString(os.Getenv("TEST_LOG_LEVEL")) + if level != hclog.NoLevel { + return level + } + return hclog.Warn +} + func Logger(t TestingTB) hclog.InterceptLogger { return LoggerWithOutput(t, NewLogBuffer(t)) } From 3f590bb8a1485497572b75eb1fd43651238e71d8 Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Thu, 3 Feb 2022 17:07:39 -0500 Subject: [PATCH 2/2] testing: fix test failures caused by new log level These two tests require debug logging enabled, because they look for log lines. Also switched to testify assertions because the previous errors were not clear. --- agent/consul/prepared_query_endpoint_test.go | 7 ++----- agent/http_test.go | 10 ++++++---- agent/testagent.go | 7 ++++++- 3 files changed, 14 insertions(+), 10 deletions(-) diff --git a/agent/consul/prepared_query_endpoint_test.go b/agent/consul/prepared_query_endpoint_test.go index 7e64b8603f..c77a0d40c4 100644 --- a/agent/consul/prepared_query_endpoint_test.go +++ b/agent/consul/prepared_query_endpoint_test.go @@ -21,7 +21,6 @@ import ( "github.com/hashicorp/consul/agent/structs" tokenStore "github.com/hashicorp/consul/agent/token" "github.com/hashicorp/consul/api" - "github.com/hashicorp/consul/sdk/testutil" "github.com/hashicorp/consul/sdk/testutil/retry" "github.com/hashicorp/consul/testrpc" "github.com/hashicorp/consul/types" @@ -2761,7 +2760,7 @@ func (m *mockQueryServer) GetLogger() hclog.Logger { m.Logger = hclog.New(&hclog.LoggerOptions{ Name: "mock_query", Output: m.LogBuffer, - Level: testutil.TestLogLevel, + Level: hclog.Debug, }) } return m.Logger @@ -3018,9 +3017,7 @@ func TestPreparedQuery_queryFailover(t *testing.T) { if queries := mock.JoinQueryLog(); queries != "dc1:PreparedQuery.ExecuteRemote|dc2:PreparedQuery.ExecuteRemote|dc4:PreparedQuery.ExecuteRemote" { t.Fatalf("bad: %s", queries) } - if !strings.Contains(mock.LogBuffer.String(), "Skipping unknown datacenter") { - t.Fatalf("bad: %s", mock.LogBuffer.String()) - } + require.Contains(t, mock.LogBuffer.String(), "Skipping unknown datacenter") } // Same setup as before but dc1 is going to return an error and should diff --git a/agent/http_test.go b/agent/http_test.go index ebeb18b732..e63849b151 100644 --- a/agent/http_test.go +++ b/agent/http_test.go @@ -21,6 +21,7 @@ import ( "github.com/NYTimes/gziphandler" cleanhttp "github.com/hashicorp/go-cleanhttp" + "github.com/hashicorp/go-hclog" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "golang.org/x/net/http2" @@ -651,7 +652,10 @@ func TestHTTP_wrap_obfuscateLog(t *testing.T) { t.Parallel() buf := &syncBuffer{b: new(bytes.Buffer)} - a := StartTestAgent(t, TestAgent{LogOutput: buf}) + a := StartTestAgent(t, TestAgent{ + LogOutput: buf, + LogLevel: hclog.Debug, + }) defer a.Shutdown() handler := func(resp http.ResponseWriter, req *http.Request) (interface{}, error) { @@ -694,9 +698,7 @@ func TestHTTP_wrap_obfuscateLog(t *testing.T) { req, _ := http.NewRequest("GET", url, nil) a.srv.wrap(handler, []string{"GET"})(resp, req) bufout := buf.String() - if !strings.Contains(bufout, want) { - t.Fatalf("got %s want %s", bufout, want) - } + require.Contains(t, bufout, want) }) } } diff --git a/agent/testagent.go b/agent/testagent.go index 84618f9afb..fd35eb7127 100644 --- a/agent/testagent.go +++ b/agent/testagent.go @@ -56,6 +56,7 @@ type TestAgent struct { // The io.Writer must allow concurrent reads and writes. Note that // bytes.Buffer is not safe for concurrent reads and writes. LogOutput io.Writer + LogLevel hclog.Level // DataDir may be set to a directory which exists. If is it not set, // TestAgent.Start will create one and set DataDir to the directory path. @@ -158,8 +159,12 @@ func (a *TestAgent) Start(t *testing.T) error { logOutput = testutil.NewLogBuffer(t) } + if a.LogLevel == 0 { + a.LogLevel = testutil.TestLogLevel + } + logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{ - Level: testutil.TestLogLevel, + Level: a.LogLevel, Output: logOutput, TimeFormat: "04:05.000", Name: name,