Skip to content

Commit

Permalink
improve watcher logs and TestWatcher_AgentErrorQuick logs
Browse files Browse the repository at this point in the history
add PrettyPrintf method to ObservedLogs to logger.NewTesting

ObservedLogs.PrettyPrintf is a helper function to pretty print the logs in the observedLogs
  • Loading branch information
AndersonQ committed Sep 3, 2024
1 parent d8bdd71 commit 0f8abc5
Show file tree
Hide file tree
Showing 4 changed files with 79 additions and 14 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -182,10 +182,10 @@ func TestDownloadLogProgressWithLength(t *testing.T) {
)

// Consider only progress logs
obs = obs.Filter(func(entry observer.LoggedEntry) bool {
obs = &logger.ObservedLogs{ObservedLogs: obs.Filter(func(entry observer.LoggedEntry) bool {
return expectedProgressRegexp.MatchString(entry.Message) ||
expectedCompletedRegexp.MatchString(entry.Message)
})
})}

// Two files are downloaded. Each file is being downloaded in 100 chunks with a delay of 10ms between chunks. The
// expected time to download is, therefore, 100 * 10ms = 1000ms. In reality, the actual download time will be a bit
Expand Down Expand Up @@ -265,10 +265,10 @@ func TestDownloadLogProgressWithoutLength(t *testing.T) {
)

// Consider only progress logs
obs = obs.Filter(func(entry observer.LoggedEntry) bool {
obs = &logger.ObservedLogs{ObservedLogs: obs.Filter(func(entry observer.LoggedEntry) bool {
return expectedProgressRegexp.MatchString(entry.Message) ||
expectedCompletedRegexp.MatchString(entry.Message)
})
})}

// Two files are downloaded. Each file is being downloaded in 100 chunks with a delay of 10ms between chunks. The
// expected time to download is, therefore, 100 * 10ms = 1000ms. In reality, the actual download time will be a bit
Expand Down
9 changes: 1 addition & 8 deletions internal/pkg/agent/application/upgrade/watcher_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -278,14 +278,7 @@ func TestWatcher_AgentErrorQuick(t *testing.T) {
log, obs := logger.NewTesting("watcher")
defer func() {
if t.Failed() {
rawLogs := obs.All()
for _, rawLog := range rawLogs {
msg := fmt.Sprintf("[%s] %s", rawLog.Level, rawLog.Message)
for k, v := range rawLog.ContextMap() {
msg += fmt.Sprintf("%s=%v", k, v)
}
t.Log(msg)
}
obs.TakeAndPrettyPrint(t.Log)
}
}()
w := NewAgentWatcher(errCh, log, 100*time.Millisecond)
Expand Down
26 changes: 24 additions & 2 deletions pkg/core/logger/testing.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,22 +5,44 @@
package logger

import (
"fmt"

"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"

"github.com/elastic/elastic-agent-libs/logp"
)

type ObservedLogs struct {
*observer.ObservedLogs
}

// NewTesting creates a testing logger that buffers the logs in memory and
// logs in debug level. Check observer.ObservedLogs for more details.
func NewTesting(name string) (*Logger, *observer.ObservedLogs) {
func NewTesting(name string) (*Logger, *ObservedLogs) {
core, obs := observer.New(zapcore.DebugLevel)

logger := logp.NewLogger(
name,
zap.WrapCore(func(in zapcore.Core) zapcore.Core {
return zapcore.NewTee(in, core)
}))
return logger, obs

return logger, &ObservedLogs{ObservedLogs: obs}
}

// TakeAndPrettyPrint consumes, formats and prints all captured log messages,
// one at a time, using the provided print function. It used the underlying
// `observer.ObservedLogs.TakeAll`, therefore, after calling it,
// the ObservedLogs will be empty.
func (obs *ObservedLogs) TakeAndPrettyPrint(print func(a ...any)) {
rawLogs := obs.TakeAll()
for _, rawLog := range rawLogs {
msg := fmt.Sprintf("[%s] %s", rawLog.Level, rawLog.Message)
for k, v := range rawLog.ContextMap() {
msg += fmt.Sprintf(" %s=%v", k, v)
}
print(msg)
}
}
50 changes: 50 additions & 0 deletions pkg/core/logger/testing_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
// Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
// or more contributor license agreements. Licensed under the Elastic License;
// you may not use this file except in compliance with the Elastic License.

package logger

import (
"fmt"
"strings"
"testing"

"github.com/stretchr/testify/assert"
)

func TestObservedLogs_PrettyPrintf(t *testing.T) {
want := `
[debug] a debug message
[debug] a debug message with keys key2=42
[info] an info message
[info] an info message with keys key1=value1
[warn] a warn message
[warn] a warn message with keys key2=42
[error] an error message
[error] an error message with keys key1=value1
`

logger, obs := NewTesting("testLogger")

logger.Debug("a debug message")
logger.Debugw("a debug message with keys", "key2", 42)
logger.Infow("an info message")
logger.Infow("an info message with keys", "key1", "value1")
logger.Warn("a warn message")
logger.Warnw("a warn message with keys", "key2", 42)
logger.Error("an error message")
logger.Errorw("an error message with keys", "key1", "value1")

var got strings.Builder
printFn := func(a ...any) {
_, _ = fmt.Fprintln(&got, a...)
}

obs.TakeAndPrettyPrint(printFn)
assert.Equal(t, want[1:], got.String())

// second call should be empty because PrettyPrintf should consume all logs
got.Reset()
obs.TakeAndPrettyPrint(printFn)
assert.Empty(t, got.String())
}

0 comments on commit 0f8abc5

Please sign in to comment.