Merge pull request #4682 from hashicorp/f-hc-logger

Plumb hc-logger through everything but client

client/allocrunner/taskrunner/task_runner_test.go

@@ -134,7 +134,7 @@ func testTaskRunnerFromAlloc(t *testing.T, restarts bool, alloc *structs.Allocat
 
 	vclient := vaultclient.NewMockVaultClient()
 	cclient := consul.NewMockAgent()
-	serviceClient := consul.NewServiceClient(cclient, logger, true)
+	serviceClient := consul.NewServiceClient(cclient, testlog.HCLogger(t), true)
 	go serviceClient.Run()
 	tr := NewTaskRunner(logger, conf, db, upd.Update, taskDir, alloc, task, vclient, serviceClient)
 	if !restarts {
@@ -633,7 +633,7 @@ func TestTaskRunner_UnregisterConsul_Retries(t *testing.T) {
 	ctx := testTaskRunnerFromAlloc(t, true, alloc)
 
 	// Use mockConsulServiceClient
-	consul := consulApi.NewMockConsulServiceClient(t)
+	consul := consulApi.NewMockConsulServiceClient(t, testlog.HCLogger(t))
 	ctx.tr.consul = consul
 
 	ctx.tr.MarkReceived()
@@ -1851,7 +1851,7 @@ func TestTaskRunner_CheckWatcher_Restart(t *testing.T) {
 	// backed by a mock consul whose checks are always unhealthy.
 	consulAgent := consul.NewMockAgent()
 	consulAgent.SetStatus("critical")
-	consulClient := consul.NewServiceClient(consulAgent, ctx.tr.logger, true)
+	consulClient := consul.NewServiceClient(consulAgent, testlog.HCLogger(t), true)
 	go consulClient.Run()
 	defer consulClient.Shutdown()
 

client/allocrunner/testing.go

@@ -51,7 +51,7 @@ func TestAllocRunnerFromAlloc(t *testing.T, alloc *structs.Allocation, restarts
 		alloc.Job.Type = structs.JobTypeBatch
 	}
 	vclient := vaultclient.NewMockVaultClient()
-	ar := NewAllocRunner(testlog.Logger(t), conf, db, upd.Update, alloc, vclient, consulApi.NewMockConsulServiceClient(t), NoopPrevAlloc{})
+	ar := NewAllocRunner(testlog.Logger(t), conf, db, upd.Update, alloc, vclient, consulApi.NewMockConsulServiceClient(t, testlog.HCLogger(t)), NoopPrevAlloc{})
 	return upd, ar
 }
 

client/client.go

@@ -16,28 +16,30 @@ import (
 	"time"
 
 	metrics "github.com/armon/go-metrics"
-	"github.com/boltdb/bolt"
 	consulapi "github.com/hashicorp/consul/api"
-	"github.com/hashicorp/consul/lib"
 	multierror "github.com/hashicorp/go-multierror"
+	consulApi "github.com/hashicorp/nomad/client/consul"
+	cstructs "github.com/hashicorp/nomad/client/structs"
+	hstats "github.com/hashicorp/nomad/helper/stats"
+	nconfig "github.com/hashicorp/nomad/nomad/structs/config"
+	vaultapi "github.com/hashicorp/vault/api"
+
+	"github.com/boltdb/bolt"
+	"github.com/hashicorp/consul/lib"
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/nomad/client/allocdir"
 	"github.com/hashicorp/nomad/client/allocrunner"
 	"github.com/hashicorp/nomad/client/config"
-	consulApi "github.com/hashicorp/nomad/client/consul"
 	"github.com/hashicorp/nomad/client/servers"
 	"github.com/hashicorp/nomad/client/state"
 	"github.com/hashicorp/nomad/client/stats"
-	cstructs "github.com/hashicorp/nomad/client/structs"
 	"github.com/hashicorp/nomad/client/vaultclient"
 	"github.com/hashicorp/nomad/command/agent/consul"
 	"github.com/hashicorp/nomad/helper"
 	"github.com/hashicorp/nomad/helper/pool"
-	hstats "github.com/hashicorp/nomad/helper/stats"
 	"github.com/hashicorp/nomad/helper/tlsutil"
 	"github.com/hashicorp/nomad/helper/uuid"
 	"github.com/hashicorp/nomad/nomad/structs"
-	nconfig "github.com/hashicorp/nomad/nomad/structs/config"
-	vaultapi "github.com/hashicorp/vault/api"
 	"github.com/shirou/gopsutil/host"
 )
 
@@ -196,7 +198,7 @@ var (
 )
 
 // NewClient is used to create a new client from the given configuration
-func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulService consulApi.ConsulServiceAPI, logger *log.Logger) (*Client, error) {
+func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulService consulApi.ConsulServiceAPI) (*Client, error) {
 	// Create the tls wrapper
 	var tlsWrap tlsutil.RegionWrapper
 	if cfg.TLSConfig.EnableRPC {
@@ -219,7 +221,7 @@ func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulServic
 		connPool:             pool.NewPool(cfg.LogOutput, clientRPCCache, clientMaxStreams, tlsWrap),
 		tlsWrap:              tlsWrap,
 		streamingRpcs:        structs.NewStreamingRpcRegistry(),
-		logger:               logger,
+		logger:               cfg.Logger.ResetNamed("").StandardLogger(&hclog.StandardLoggerOptions{InferLevels: true}),
 		allocs:               make(map[string]*allocrunner.AllocRunner),
 		allocUpdates:         make(chan *structs.Allocation, 64),
 		shutdownCh:           make(chan struct{}),
@@ -245,7 +247,7 @@ func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulServic
 	}
 
 	// Add the stats collector
-	statsCollector := stats.NewHostStatsCollector(logger, c.config.AllocDir)
+	statsCollector := stats.NewHostStatsCollector(c.logger, c.config.AllocDir)
 	c.hostStatsCollector = statsCollector
 
 	// Add the garbage collector
@@ -257,7 +259,7 @@ func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulServic
 		ParallelDestroys:    cfg.GCParallelDestroys,
 		ReservedDiskMB:      cfg.Node.Reserved.DiskMB,
 	}
-	c.garbageCollector = NewAllocGarbageCollector(logger, statsCollector, c, gcConfig)
+	c.garbageCollector = NewAllocGarbageCollector(c.logger, statsCollector, c, gcConfig)
 	go c.garbageCollector.Run()
 
 	// Setup the node
@@ -287,7 +289,7 @@ func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulServic
 	c.configLock.RLock()
 	if len(c.configCopy.Servers) > 0 {
 		if _, err := c.setServersImpl(c.configCopy.Servers, true); err != nil {
-			logger.Printf("[WARN] client: None of the configured servers are valid: %v", err)
+			c.logger.Printf("[WARN] client: None of the configured servers are valid: %v", err)
 		}
 	}
 	c.configLock.RUnlock()
@@ -308,13 +310,13 @@ func NewClient(cfg *config.Config, consulCatalog consul.CatalogAPI, consulServic
 
 	// Restore the state
 	if err := c.restoreState(); err != nil {
-		logger.Printf("[ERR] client: failed to restore state: %v", err)
-		logger.Printf("[ERR] client: Nomad is unable to start due to corrupt state. "+
+		c.logger.Printf("[ERR] client: failed to restore state: %v", err)
+		c.logger.Printf("[ERR] client: Nomad is unable to start due to corrupt state. "+
 			"The safest way to proceed is to manually stop running task processes "+
 			"and remove Nomad's state (%q) and alloc (%q) directories before "+
 			"restarting. Lost allocations will be rescheduled.",
 			c.config.StateDir, c.config.AllocDir)
-		logger.Printf("[ERR] client: Corrupt state is often caused by a bug. Please " +
+		c.logger.Printf("[ERR] client: Corrupt state is often caused by a bug. Please " +
 			"report as much information as possible to " +
 			"https://github.com/hashicorp/nomad/issues")
 		return nil, fmt.Errorf("failed to restore state")

client/client_test.go

@@ -602,11 +602,11 @@ func TestClient_SaveRestoreState(t *testing.T) {
 	}
 
 	// Create a new client
-	logger := testlog.Logger(t)
+	logger := testlog.HCLogger(t)
+	c1.config.Logger = logger
 	catalog := consul.NewMockCatalog(logger)
-	mockService := consulApi.NewMockConsulServiceClient(t)
-	mockService.Logger = logger
-	c2, err := NewClient(c1.config, catalog, mockService, logger)
+	mockService := consulApi.NewMockConsulServiceClient(t, logger)
+	c2, err := NewClient(c1.config, catalog, mockService)
 	if err != nil {
 		t.Fatalf("err: %v", err)
 	}

client/config/config.go

@@ -8,6 +8,8 @@ import (
 	"strings"
 	"time"
 
+	log "github.com/hashicorp/go-hclog"
+
 	"github.com/hashicorp/nomad/helper"
 	"github.com/hashicorp/nomad/nomad/structs"
 	"github.com/hashicorp/nomad/nomad/structs/config"
@@ -76,6 +78,9 @@ type Config struct {
 	// LogOutput is the destination for logs
 	LogOutput io.Writer
 
+	// Logger provides a logger to thhe client
+	Logger log.Logger
+
 	// Region is the clients region
 	Region string
 

client/consul/consul_testing.go

@@ -2,11 +2,11 @@ package consul
 
 import (
 	"fmt"
-	"log"
 	"sync"
 
+	log "github.com/hashicorp/go-hclog"
+
 	"github.com/hashicorp/nomad/command/agent/consul"
-	"github.com/hashicorp/nomad/helper/testlog"
 	"github.com/mitchellh/go-testing-interface"
 )
 
@@ -34,48 +34,49 @@ type MockConsulServiceClient struct {
 	Ops []MockConsulOp
 	mu  sync.Mutex
 
-	Logger *log.Logger
+	logger log.Logger
 
 	// AllocRegistrationsFn allows injecting return values for the
 	// AllocRegistrations function.
 	AllocRegistrationsFn func(allocID string) (*consul.AllocRegistration, error)
 }
 
-func NewMockConsulServiceClient(t testing.T) *MockConsulServiceClient {
+func NewMockConsulServiceClient(t testing.T, logger log.Logger) *MockConsulServiceClient {
+	logger = logger.Named("mock_consul")
 	m := MockConsulServiceClient{
 		Ops:    make([]MockConsulOp, 0, 20),
-		Logger: testlog.Logger(t),
+		logger: logger,
 	}
 	return &m
 }
 
 func (m *MockConsulServiceClient) UpdateTask(old, new *consul.TaskServices) error {
 	m.mu.Lock()
 	defer m.mu.Unlock()
-	m.Logger.Printf("[TEST] mock_consul: UpdateTask(alloc: %s, task: %s)", new.AllocID[:6], new.Name)
+	m.logger.Trace("UpdateTask", "alloc_id", new.AllocID, "task", new.Name)
 	m.Ops = append(m.Ops, NewMockConsulOp("update", new.AllocID, new.Name))
 	return nil
 }
 
 func (m *MockConsulServiceClient) RegisterTask(task *consul.TaskServices) error {
 	m.mu.Lock()
 	defer m.mu.Unlock()
-	m.Logger.Printf("[TEST] mock_consul: RegisterTask(alloc: %s, task: %s)", task.AllocID, task.Name)
+	m.logger.Trace("RegisterTask", "alloc_id", task.AllocID, "task", task.Name)
 	m.Ops = append(m.Ops, NewMockConsulOp("add", task.AllocID, task.Name))
 	return nil
 }
 
 func (m *MockConsulServiceClient) RemoveTask(task *consul.TaskServices) {
 	m.mu.Lock()
 	defer m.mu.Unlock()
-	m.Logger.Printf("[TEST] mock_consul: RemoveTask(%q, %q)", task.AllocID, task.Name)
+	m.logger.Trace("RemoveTask", "alloc_id", task.AllocID, "task", task.Name)
 	m.Ops = append(m.Ops, NewMockConsulOp("remove", task.AllocID, task.Name))
 }
 
 func (m *MockConsulServiceClient) AllocRegistrations(allocID string) (*consul.AllocRegistration, error) {
 	m.mu.Lock()
 	defer m.mu.Unlock()
-	m.Logger.Printf("[TEST] mock_consul: AllocRegistrations(%q)", allocID)
+	m.logger.Trace("AllocRegistrations", "alloc_id", allocID)
 	m.Ops = append(m.Ops, NewMockConsulOp("alloc_registrations", allocID, ""))
 
 	if m.AllocRegistrationsFn != nil {

client/testing.go

@@ -36,11 +36,11 @@ func TestClient(t testing.T, cb func(c *config.Config)) *Client {
 		cb(conf)
 	}
 
-	logger := testlog.Logger(t)
+	logger := testlog.HCLogger(t)
+	conf.Logger = logger
 	catalog := consul.NewMockCatalog(logger)
-	mockService := consulApi.NewMockConsulServiceClient(t)
-	mockService.Logger = logger
-	client, err := NewClient(conf, catalog, mockService, logger)
+	mockService := consulApi.NewMockConsulServiceClient(t, logger)
+	client, err := NewClient(conf, catalog, mockService)
 	if err != nil {
 		t.Fatalf("err: %v", err)
 	}