From 668d10d1dab18cde6b759136057400cc4fd39489 Mon Sep 17 00:00:00 2001 From: sunby Date: Tue, 7 Sep 2021 16:07:58 +0800 Subject: [PATCH] Add log unit tests (#7524) issue: #7491 Signed-off-by: sunby --- internal/log/log.go | 12 +++ internal/log/log_test.go | 39 ++++++++++ internal/log/zap_log_test.go | 122 ++++++++++++++++++------------- internal/log/zap_text_encoder.go | 3 +- 4 files changed, 125 insertions(+), 51 deletions(-) diff --git a/internal/log/log.go b/internal/log/log.go index b20e437190..face2ac80e 100644 --- a/internal/log/log.go +++ b/internal/log/log.go @@ -1,3 +1,14 @@ +// Copyright (C) 2019-2020 Zilliz. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software distributed under the License +// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express +// or implied. See the License for the specific language governing permissions and limitations under the License. + // Copyright 2019 PingCAP, Inc. // // Licensed under the Apache License, Version 2.0 (the "License"); @@ -56,6 +67,7 @@ func InitLogger(cfg *Config, opts ...zap.Option) (*zap.Logger, *ZapProperties, e return InitLoggerWithWriteSyncer(cfg, output, opts...) } +// InitTestLogger initializes a logger for unit tests func InitTestLogger(t zaptest.TestingT, cfg *Config, opts ...zap.Option) (*zap.Logger, *ZapProperties, error) { writer := newTestingWriter(t) zapOptions := []zap.Option{ diff --git a/internal/log/log_test.go b/internal/log/log_test.go index d3ad1f4722..2d273022cb 100644 --- a/internal/log/log_test.go +++ b/internal/log/log_test.go @@ -1,3 +1,14 @@ +// Copyright (C) 2019-2020 Zilliz. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software distributed under the License +// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express +// or implied. See the License for the specific language governing permissions and limitations under the License. + // Copyright 2019 PingCAP, Inc. // // Licensed under the Apache License, Version 2.0 (the "License"); @@ -17,6 +28,8 @@ package log import ( "bufio" "bytes" + "io/ioutil" + "os" "testing" "github.com/stretchr/testify/assert" @@ -34,6 +47,7 @@ func TestExport(t *testing.T) { Debug("Testing") Warn("Testing") Error("Testing") + Sync() ts.assertMessagesContains("log_test.go:") ts = newTestLogSpy(t) @@ -43,6 +57,7 @@ func TestExport(t *testing.T) { newLogger := With(zap.String("name", "tester"), zap.Int64("age", 42)) newLogger.Info("hello") newLogger.Debug("world") + Sync() ts.assertMessagesContains(`name=tester`) ts.assertMessagesContains(`age=42`) } @@ -59,3 +74,27 @@ func TestZapTextEncoder(t *testing.T) { _ = writer.Flush() assert.Equal(t, `[INFO] ["this is a message from zap"]`+"\n", buffer.String()) } + +func TestInvalidFileConfig(t *testing.T) { + tmpDir, _ := ioutil.TempDir("/tmp", "invalid-log-test") + defer os.RemoveAll(tmpDir) + + invalidFileConf := FileLogConfig{ + Filename: tmpDir, + } + conf := &Config{Level: "debug", File: invalidFileConf, DisableTimestamp: true} + + _, _, err := InitLogger(conf) + assert.Equal(t, "can't use directory as log file name", err.Error()) +} + +func TestLevelGetterAndSetter(t *testing.T) { + conf := &Config{Level: "debug", File: FileLogConfig{}, DisableTimestamp: true} + logger, p, _ := InitLogger(conf) + ReplaceGlobals(logger, p) + + assert.Equal(t, zap.DebugLevel, GetLevel()) + + SetLevel(zap.ErrorLevel) + assert.Equal(t, zap.ErrorLevel, GetLevel()) +} diff --git a/internal/log/zap_log_test.go b/internal/log/zap_log_test.go index 99f1cf25b1..8b0699c841 100644 --- a/internal/log/zap_log_test.go +++ b/internal/log/zap_log_test.go @@ -1,3 +1,14 @@ +// Copyright (C) 2019-2020 Zilliz. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software distributed under the License +// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express +// or implied. See the License for the specific language governing permissions and limitations under the License. + // Copyright 2019 PingCAP, Inc. // // Licensed under the Apache License, Version 2.0 (the "License"); @@ -98,14 +109,14 @@ func TestLog(t *testing.T) { zap.Duration("duration", 10*time.Second), ) ts.assertMessages( - `[INFO] [zap_log_test.go:50] ["failed to fetch URL"] [url=http://example.com] [attempt=3] [backoff=1s]`, - `[INFO] [zap_log_test.go:55] ["failed to \"fetch\" [URL]: http://example.com"]`, - `[DEBUG] [zap_log_test.go:56] ["Slow query"] [sql="SELECT * FROM TABLE\n\tWHERE ID=\"abc\""] [duration=1.3s] ["process keys"=1500]`, - `[INFO] [zap_log_test.go:62] [Welcome]`, - `[INFO] [zap_log_test.go:63] [欢迎]`, - `[WARN] [zap_log_test.go:64] [Type] [Counter=NaN] [Score=+Inf]`, - `[INFO] [zap_log_test.go:69] ["new connection"] [connID=1] [traceID=dse1121]`, - `[INFO] [zap_log_test.go:70] ["Testing typs"] [filed1=noquote] `+ + `[INFO] [zap_log_test.go:61] ["failed to fetch URL"] [url=http://example.com] [attempt=3] [backoff=1s]`, + `[INFO] [zap_log_test.go:66] ["failed to \"fetch\" [URL]: http://example.com"]`, + `[DEBUG] [zap_log_test.go:67] ["Slow query"] [sql="SELECT * FROM TABLE\n\tWHERE ID=\"abc\""] [duration=1.3s] ["process keys"=1500]`, + `[INFO] [zap_log_test.go:73] [Welcome]`, + `[INFO] [zap_log_test.go:74] [欢迎]`, + `[WARN] [zap_log_test.go:75] [Type] [Counter=NaN] [Score=+Inf]`, + `[INFO] [zap_log_test.go:80] ["new connection"] [connID=1] [traceID=dse1121]`, + `[INFO] [zap_log_test.go:81] ["Testing typs"] [filed1=noquote] `+ `[filed2="in quote"] [urls="[http://mock1.com:2347,http://mock2.com:2432]"] `+ `[urls-peer="[t1,\"t2 fine\"]"] ["store ids"="[1,4,5]"] [object="{username=user1}"] `+ `[object2="{username=\"user 2\"}"] [binary="YWIxMjM="] ["is processed"=true] `+ @@ -163,45 +174,6 @@ func TestZapCaller(t *testing.T) { } } -func TestRotateLog(t *testing.T) { - tempDir, _ := ioutil.TempDir("/tmp", "pd-test-log") - conf := &Config{ - Level: "info", - File: FileLogConfig{ - Filename: tempDir + "/test.log", - MaxSize: 1, - }, - } - logger, _, err := InitLogger(conf) - assert.Nil(t, err) - - var data []byte - for i := 1; i <= 1*1024*1024; i++ { - if i%1000 != 0 { - data = append(data, 'd') - continue - } - logger.Info(string(data)) - data = data[:0] - } - files, _ := ioutil.ReadDir(tempDir) - assert.Len(t, files, 2) - _ = os.RemoveAll(tempDir) -} - -func TestWithOptions(t *testing.T) { - ts := newTestLogSpy(t) - conf := &Config{ - Level: "debug", - DisableTimestamp: true, - DisableErrorVerbose: true, - } - logger, _, _ := InitTestLogger(ts, conf, zap.AddStacktrace(zapcore.FatalLevel)) - logger.Error("Testing", zap.Error(errors.New("log-with-option"))) - ts.assertMessagesNotContains("errorVerbose") - ts.assertMessagesNotContains("stack") -} - func TestLogJSON(t *testing.T) { ts := newTestLogSpy(t) conf := &Config{Level: "debug", DisableTimestamp: true, Format: "json"} @@ -215,8 +187,60 @@ func TestLogJSON(t *testing.T) { "backoff", time.Second, ) logger.With(zap.String("connID", "1"), zap.String("traceID", "dse1121")).Info("new connection") - ts.assertMessages("{\"level\":\"INFO\",\"caller\":\"zap_log_test.go:212\",\"message\":\"failed to fetch URL\",\"url\":\"http://example.com\",\"attempt\":3,\"backoff\":\"1s\"}", - "{\"level\":\"INFO\",\"caller\":\"zap_log_test.go:217\",\"message\":\"new connection\",\"connID\":\"1\",\"traceID\":\"dse1121\"}") + ts.assertMessages("{\"level\":\"INFO\",\"caller\":\"zap_log_test.go:184\",\"message\":\"failed to fetch URL\",\"url\":\"http://example.com\",\"attempt\":3,\"backoff\":\"1s\"}", + "{\"level\":\"INFO\",\"caller\":\"zap_log_test.go:189\",\"message\":\"new connection\",\"connID\":\"1\",\"traceID\":\"dse1121\"}") +} + +func TestRotateLog(t *testing.T) { + cases := []struct { + desc string + maxSize int + writeSize int + expectedFileNum int + }{ + {"test default max size", 0, defaultLogMaxSize * 1024 * 1024, 2}, + {"test limited max size", 1, 1 * 1024 * 1024, 2}, + } + for _, c := range cases { + t.Run(c.desc, func(t *testing.T) { + tempDir, _ := ioutil.TempDir("/tmp", "pd-test-log") + conf := &Config{ + Level: "info", + File: FileLogConfig{ + Filename: tempDir + "/test.log", + MaxSize: c.maxSize, + }, + } + logger, _, err := InitLogger(conf) + assert.Nil(t, err) + + var data []byte + for i := 1; i <= c.writeSize; i++ { + if i%1000 != 0 { + data = append(data, 'd') + continue + } + logger.Info(string(data)) + data = data[:0] + } + files, _ := ioutil.ReadDir(tempDir) + assert.Len(t, files, c.expectedFileNum) + _ = os.RemoveAll(tempDir) + }) + } +} + +func TestWithOptions(t *testing.T) { + ts := newTestLogSpy(t) + conf := &Config{ + Level: "debug", + DisableTimestamp: true, + DisableErrorVerbose: true, + } + logger, _, _ := InitTestLogger(ts, conf, zap.AddStacktrace(zapcore.FatalLevel)) + logger.Error("Testing", zap.Error(errors.New("log-with-option"))) + ts.assertMessagesNotContains("errorVerbose") + ts.assertMessagesNotContains("stack") } // testLogSpy is a testing.TB that captures logged messages. diff --git a/internal/log/zap_text_encoder.go b/internal/log/zap_text_encoder.go index 0ceab556bb..28031c6725 100644 --- a/internal/log/zap_text_encoder.go +++ b/internal/log/zap_text_encoder.go @@ -650,8 +650,7 @@ func (enc *textEncoder) encodeError(f zapcore.Field) { if enc.disableErrorVerbose { return } - e, isFormatter := err.(fmt.Formatter) - if isFormatter { + if e, isFormatter := err.(fmt.Formatter); isFormatter { verbose := fmt.Sprintf("%+v", e) if verbose != basic { // This is a rich error type, like those produced by