diff --git a/agent/acl_test.go b/agent/acl_test.go index 9ae579600a..f8bfdb3d17 100644 --- a/agent/acl_test.go +++ b/agent/acl_test.go @@ -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, diff --git a/agent/ae/ae_test.go b/agent/ae/ae_test.go index 55d983e752..e26f50b1c1 100644 --- a/agent/ae/ae_test.go +++ b/agent/ae/ae_test.go @@ -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) diff --git a/agent/checks/check.go b/agent/checks/check.go index a75ee912d6..c1d3bd280b 100644 --- a/agent/checks/check.go +++ b/agent/checks/check.go @@ -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 == "" { diff --git a/agent/consul/acl_test.go b/agent/consul/acl_test.go index c99694cd9a..8e47e0032e 100644 --- a/agent/consul/acl_test.go +++ b/agent/consul/acl_test.go @@ -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, diff --git a/agent/consul/client_test.go b/agent/consul/client_test.go index 62c8264922..9adbb17fa4 100644 --- a/agent/consul/client_test.go +++ b/agent/consul/client_test.go @@ -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 } diff --git a/agent/consul/leader_test.go b/agent/consul/leader_test.go index 508509868d..365e50ec25 100644 --- a/agent/consul/leader_test.go +++ b/agent/consul/leader_test.go @@ -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{ diff --git a/agent/consul/server_test.go b/agent/consul/server_test.go index 9033a0bf39..99632a499c 100644 --- a/agent/consul/server_test.go +++ b/agent/consul/server_test.go @@ -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. diff --git a/agent/testagent.go b/agent/testagent.go index 3ddcc2de6f..1704e3a075 100644 --- a/agent/testagent.go +++ b/agent/testagent.go @@ -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{ diff --git a/api/api_test.go b/api/api_test.go index f9bf4915fc..39ae0e4c2c 100644 --- a/api/api_test.go +++ b/api/api_test.go @@ -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 { diff --git a/sdk/testutil/README.md b/sdk/testutil/README.md index 641e7f44ad..dfd57ceb8b 100644 --- a/sdk/testutil/README.md +++ b/sdk/testutil/README.md @@ -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) } diff --git a/sdk/testutil/server.go b/sdk/testutil/server.go index c3dc9e9f55..bf990795e9 100644 --- a/sdk/testutil/server.go +++ b/sdk/testutil/server.go @@ -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 } diff --git a/sdk/testutil/testlog.go b/sdk/testutil/testlog.go index 154c1fc56e..a16396cb81 100644 --- a/sdk/testutil/testlog.go +++ b/sdk/testutil/testlog.go @@ -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) }