Merge pull request #7948 from hashicorp/dnephin/buffer-test-logs

testutil: NewLogBuffer - buffer logs until a test fails
This commit is contained in:
Daniel Nephin 2020-07-21 15:21:52 -04:00 committed by GitHub
commit 6d3b042872
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
12 changed files with 57 additions and 116 deletions

View File

@ -59,7 +59,7 @@ func NewTestACLAgent(t *testing.T, name string, hcl string, resolveAuthz authzRe
a := &TestACLAgent{Name: name, HCL: hcl, resolveAuthzFn: resolveAuthz, resolveIdentFn: resolveIdent}
dataDir := `data_dir = "acl-agent"`
logOutput := testutil.TestWriter(t)
logOutput := testutil.NewLogBuffer(t)
logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{
Name: a.Name,
Level: hclog.Debug,

View File

@ -394,7 +394,7 @@ func (m *mock) SyncChanges() error {
func testSyncer(t *testing.T) *StateSyncer {
logger := hclog.New(&hclog.LoggerOptions{
Level: 0,
Output: testutil.TestWriter(t),
Output: testutil.NewLogBuffer(t),
})
l := NewStateSyncer(nil, time.Second, nil, logger)

View File

@ -4,6 +4,7 @@ import (
"crypto/tls"
"fmt"
"io"
"io/ioutil"
"net"
"net/http"
"os"
@ -14,7 +15,6 @@ import (
"time"
"github.com/hashicorp/consul/agent/structs"
"github.com/hashicorp/consul/sdk/testutil"
"github.com/hashicorp/go-hclog"
"github.com/armon/circbuf"
@ -613,7 +613,7 @@ func (c *CheckDocker) Start() {
}
if c.Logger == nil {
c.Logger = testutil.NewDiscardLogger()
c.Logger = hclog.New(&hclog.LoggerOptions{Output: ioutil.Discard})
}
if c.Shell == "" {

View File

@ -697,7 +697,7 @@ func newTestACLResolver(t *testing.T, delegate *ACLResolverTestDelegate, cb func
config.ACLsEnabled = delegate.enabled
rconf := &ACLResolverConfig{
Config: config,
Logger: testutil.LoggerWithName(t, t.Name()),
Logger: testutil.Logger(t),
CacheConfig: &structs.ACLCachesConfig{
Identities: 4,
Policies: 4,

View File

@ -48,7 +48,7 @@ func testClientConfig(t *testing.T) (string, *Config) {
config.SerfLANConfig.MemberlistConfig.ProbeTimeout = 200 * time.Millisecond
config.SerfLANConfig.MemberlistConfig.ProbeInterval = time.Second
config.SerfLANConfig.MemberlistConfig.GossipInterval = 100 * time.Millisecond
config.LogOutput = testutil.TestWriter(t)
config.LogOutput = testutil.NewLogBuffer(t)
return dir, config
}

View File

@ -1284,7 +1284,7 @@ func TestLeader_ConfigEntryBootstrap_Fail(t *testing.T) {
}()
dir1, s1 := testServerWithConfig(t, func(c *Config) {
c.LogOutput = io.MultiWriter(pw, testutil.TestWriter(t))
c.LogOutput = io.MultiWriter(pw, testutil.NewLogBuffer(t))
c.Build = "1.6.0"
c.ConfigEntryBootstrap = []structs.ConfigEntry{
&structs.ServiceSplitterConfigEntry{

View File

@ -146,7 +146,7 @@ func testServerConfig(t *testing.T) (string, *Config) {
config.Bootstrap = true
config.Datacenter = "dc1"
config.DataDir = dir
config.LogOutput = testutil.TestWriter(t)
config.LogOutput = testutil.NewLogBuffer(t)
// bind the rpc server to a random port. config.RPCAdvertise will be
// set to the listen address unless it was set in the configuration.

View File

@ -20,6 +20,7 @@ import (
"time"
metrics "github.com/armon/go-metrics"
"github.com/hashicorp/consul/sdk/testutil"
"github.com/hashicorp/errwrap"
"github.com/hashicorp/go-hclog"
uuid "github.com/hashicorp/go-uuid"
@ -186,7 +187,7 @@ func (a *TestAgent) Start(t *testing.T) (err error) {
logOutput := a.LogOutput
if logOutput == nil {
logOutput = os.Stderr
logOutput = testutil.NewLogBuffer(t)
}
logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{

View File

@ -62,7 +62,7 @@ func makeClientWithConfig(
retry.RunWith(retry.ThreeTimes(), t, func(r *retry.R) {
server, err = testutil.NewTestServerConfigT(t, cb2)
if err != nil {
r.Fatal(err)
r.Fatalf("Failed to start server: %v", err.Error())
}
})
if server.Config.Bootstrap {

View File

@ -27,7 +27,7 @@ import (
func TestFoo_bar(t *testing.T) {
// Create a test Consul server
srv1, err := testutil.NewTestServerT(t)
srv1, err := testutil.NewTestServerConfigT(t, nil)
if err != nil {
t.Fatal(err)
}

View File

@ -101,7 +101,8 @@ type TestServerConfig struct {
Connect map[string]interface{} `json:"connect,omitempty"`
EnableDebug bool `json:"enable_debug,omitempty"`
ReadyTimeout time.Duration `json:"-"`
Stdout, Stderr io.Writer `json:"-"`
Stdout io.Writer `json:"-"`
Stderr io.Writer `json:"-"`
Args []string `json:"-"`
ReturnPorts func() `json:"-"`
}
@ -132,13 +133,14 @@ type ServerConfigCallback func(c *TestServerConfig)
// defaultServerConfig returns a new TestServerConfig struct
// with all of the listen ports incremented by one.
func defaultServerConfig() *TestServerConfig {
func defaultServerConfig(t CleanupT) *TestServerConfig {
nodeID, err := uuid.GenerateUUID()
if err != nil {
panic(err)
}
ports := freeport.MustTake(6)
logBuffer := NewLogBuffer(t)
return &TestServerConfig{
NodeName: "node-" + nodeID,
@ -171,6 +173,8 @@ func defaultServerConfig() *TestServerConfig {
ReturnPorts: func() {
freeport.Return(ports)
},
Stdout: logBuffer,
Stderr: logBuffer,
}
}
@ -211,34 +215,11 @@ type TestServer struct {
tmpdir string
}
// Deprecated: Use NewTestServerT instead.
func NewTestServer() (*TestServer, error) {
return NewTestServerConfigT(nil, nil)
}
// NewTestServerT is an easy helper method to create a new Consul
// test server with the most basic configuration.
func NewTestServerT(t *testing.T) (*TestServer, error) {
if t == nil {
return nil, errors.New("testutil: a non-nil *testing.T is required")
}
return NewTestServerConfigT(t, nil)
}
func NewTestServerConfig(cb ServerConfigCallback) (*TestServer, error) {
return NewTestServerConfigT(nil, cb)
}
// NewTestServerConfig creates a new TestServer, and makes a call to an optional
// callback function to modify the configuration. If there is an error
// configuring or starting the server, the server will NOT be running when the
// function returns (thus you do not need to stop it).
func NewTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, error) {
return newTestServerConfigT(t, cb)
}
// newTestServerConfigT is the internal helper for NewTestServerConfigT.
func newTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, error) {
path, err := exec.LookPath("consul")
if err != nil || path == "" {
return nil, fmt.Errorf("consul not found on $PATH - download and install " +
@ -255,11 +236,7 @@ func newTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, e
return nil, errors.Wrap(err, "failed to create tempdir")
}
cfg := defaultServerConfig()
testWriter := TestWriter(t)
cfg.Stdout = testWriter
cfg.Stderr = testWriter
cfg := defaultServerConfig(t)
cfg.DataDir = filepath.Join(tmpdir, "data")
if cb != nil {
cb(cfg)
@ -272,10 +249,7 @@ func newTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, e
return nil, errors.Wrap(err, "failed marshaling json")
}
if t != nil {
// if you really want this output ensure to pass a valid t
t.Logf("CONFIG JSON: %s", string(b))
}
t.Logf("CONFIG JSON: %s", string(b))
configFile := filepath.Join(tmpdir, "config.json")
if err := ioutil.WriteFile(configFile, b, 0644); err != nil {
cfg.ReturnPorts()
@ -283,21 +257,12 @@ func newTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, e
return nil, errors.Wrap(err, "failed writing config content")
}
stdout := testWriter
if cfg.Stdout != nil {
stdout = cfg.Stdout
}
stderr := testWriter
if cfg.Stderr != nil {
stderr = cfg.Stderr
}
// Start the server
args := []string{"agent", "-config-file", configFile}
args = append(args, cfg.Args...)
cmd := exec.Command("consul", args...)
cmd.Stdout = stdout
cmd.Stderr = stderr
cmd.Stdout = cfg.Stdout
cmd.Stderr = cfg.Stderr
if err := cmd.Start(); err != nil {
cfg.ReturnPorts()
os.RemoveAll(tmpdir)
@ -331,7 +296,9 @@ func newTestServerConfigT(t testing.TB, cb ServerConfigCallback) (*TestServer, e
// Wait for the server to be ready
if err := server.waitForAPI(); err != nil {
server.Stop()
if err := server.Stop(); err != nil {
t.Logf("server stop failed with: %v", err)
}
return nil, err
}

View File

@ -1,37 +1,17 @@
package testutil
import (
"fmt"
"bytes"
"io"
"io/ioutil"
"log"
"os"
"strings"
"sync"
"testing"
"github.com/hashicorp/go-hclog"
)
var sendTestLogsToStdout bool
func init() {
sendTestLogsToStdout = os.Getenv("NOLOGBUFFER") == "1"
}
// Deprecated: use Logger(t)
func TestLogger(t testing.TB) *log.Logger {
return log.New(&testWriter{t}, t.Name()+": ", log.LstdFlags)
}
func NewDiscardLogger() hclog.Logger {
return hclog.New(&hclog.LoggerOptions{
Level: 0,
Output: ioutil.Discard,
})
}
func Logger(t testing.TB) hclog.InterceptLogger {
return LoggerWithOutput(t, &testWriter{t})
return LoggerWithOutput(t, NewLogBuffer(t))
}
func LoggerWithOutput(t testing.TB, output io.Writer) hclog.InterceptLogger {
@ -42,48 +22,41 @@ func LoggerWithOutput(t testing.TB, output io.Writer) hclog.InterceptLogger {
})
}
// Deprecated: use LoggerWithName(t)
func TestLoggerWithName(t testing.TB, name string) *log.Logger {
return log.New(&testWriter{t}, "test["+name+"]: ", log.LstdFlags)
}
var sendTestLogsToStdout = os.Getenv("NOLOGBUFFER") == "1"
func LoggerWithName(t testing.TB, name string) hclog.InterceptLogger {
return hclog.NewInterceptLogger(&hclog.LoggerOptions{
Name: "test[" + name + "]",
Level: hclog.Debug,
Output: &testWriter{t},
// NewLogBuffer returns an io.Writer which buffers all writes. When the test
// ends, t.Failed is checked. If the test has failed all log output is printed
// to stdout.
//
// Set the env var NOLOGBUFFER=1 to disable buffering, resulting in all log
// output being written immediately to stdout.
func NewLogBuffer(t CleanupT) io.Writer {
if sendTestLogsToStdout {
return os.Stdout
}
buf := &logBuffer{buf: new(bytes.Buffer)}
t.Cleanup(func() {
if t.Failed() {
buf.Lock()
defer buf.Unlock()
buf.buf.WriteTo(os.Stdout)
}
})
return buf
}
func TestWriter(t testing.TB) io.Writer {
return &testWriter{t}
type CleanupT interface {
Cleanup(f func())
Failed() bool
}
type testWriter struct {
t testing.TB
type logBuffer struct {
buf *bytes.Buffer
sync.Mutex
}
func (tw *testWriter) Write(p []byte) (n int, err error) {
if tw.t != nil {
tw.t.Helper()
}
if sendTestLogsToStdout || tw.t == nil {
fmt.Fprint(os.Stdout, strings.TrimSpace(string(p))+"\n")
} else {
defer func() {
if r := recover(); r != nil {
if sr, ok := r.(string); ok {
if strings.HasPrefix(sr, "Log in goroutine after ") {
// These sorts of panics are undesirable, but requires
// total control over goroutine lifetimes to correct.
fmt.Fprint(os.Stdout, "SUPPRESSED PANIC: "+sr+"\n")
return
}
}
panic(r)
}
}()
tw.t.Log(strings.TrimSpace(string(p)))
}
return len(p), nil
func (lb *logBuffer) Write(p []byte) (n int, err error) {
lb.Lock()
defer lb.Unlock()
return lb.buf.Write(p)
}