diff --git a/go.mod b/go.mod index 458403775..e55a91bb3 100644 --- a/go.mod +++ b/go.mod @@ -6,7 +6,7 @@ require ( github.com/armon/circbuf v0.0.0-20150827004946-bbbad097214e github.com/armon/go-metrics v0.4.1 github.com/armon/go-radix v1.0.0 // indirect - github.com/fatih/color v1.9.0 // indirect + github.com/hashicorp/go-hclog v1.5.0 github.com/hashicorp/go-msgpack v0.5.3 github.com/hashicorp/go-multierror v1.1.0 // indirect github.com/hashicorp/go-syslog v1.0.0 @@ -14,7 +14,6 @@ require ( github.com/hashicorp/logutils v1.0.0 github.com/hashicorp/mdns v1.0.4 github.com/hashicorp/memberlist v0.5.0 - github.com/mattn/go-colorable v0.1.6 // indirect github.com/mitchellh/cli v1.1.5 github.com/mitchellh/mapstructure v1.5.0 github.com/posener/complete v1.2.3 // indirect diff --git a/go.sum b/go.sum index eb8f9ef7b..fb1544c77 100644 --- a/go.sum +++ b/go.sum @@ -29,8 +29,8 @@ github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4= -github.com/fatih/color v1.9.0 h1:8xPHl4/q1VyqGIPif1F+1V3Y3lSmrq01EabUW3CoW5s= -github.com/fatih/color v1.9.0/go.mod h1:eQcE1qtQxscV5RaZvpXrrb8Drkc3/DdQ+uUYCNjL+zU= +github.com/fatih/color v1.13.0 h1:8LOYc1KYPPmyKMuN8QV2DNRWNbLo6LZ0iLs8+mlH53w= +github.com/fatih/color v1.13.0/go.mod h1:kLAiJbzzSOZDVNGyDpeOxJ47H46qBXwg5ILebYFFOfk= github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= github.com/go-kit/kit v0.9.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE= @@ -51,6 +51,8 @@ github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+ github.com/hashicorp/errwrap v1.0.0 h1:hLrqtEDnRye3+sgx6z4qVLNuviH3MR5aQ0ykNJa/UYA= github.com/hashicorp/errwrap v1.0.0/go.mod h1:YH+1FKiLXxHSkmPseP+kNlulaMuP3n2brvKWEqk/Jc4= github.com/hashicorp/go-cleanhttp v0.5.0/go.mod h1:JpRdi6/HCYpAwUzNwuwqhbovhLtngrth3wmdIIUrZ80= +github.com/hashicorp/go-hclog v1.5.0 h1:bI2ocEMgcVlz55Oj1xZNBsVi900c7II+fWDyV9o+13c= +github.com/hashicorp/go-hclog v1.5.0/go.mod h1:W4Qnvbt70Wk/zYJryRzDRU/4r0kIg0PVHBcfoyhpF5M= github.com/hashicorp/go-immutable-radix v1.0.0 h1:AKDB1HM5PWEA7i4nhcpwOrO2byshxBjXVn/J/3+z5/0= github.com/hashicorp/go-immutable-radix v1.0.0/go.mod h1:0y9vanUI8NX6FsYoO3zeMjhV/C5i9g4Q3DwcSNZ4P60= github.com/hashicorp/go-msgpack v0.5.3 h1:zKjpN5BK/P5lMYrLmBHdBULWbJ0XpYR+7NGzqkZzoD4= @@ -90,14 +92,13 @@ github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= github.com/mattn/go-colorable v0.0.9/go.mod h1:9vuHe8Xs5qXnSaW/c/ABM9alt+Vo+STaOChaDxuIBZU= -github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE= -github.com/mattn/go-colorable v0.1.6 h1:6Su7aK7lXmJ/U79bYtBjLNaha4Fs1Rg9plHpcH+vvnE= -github.com/mattn/go-colorable v0.1.6/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc= +github.com/mattn/go-colorable v0.1.9/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= github.com/mattn/go-isatty v0.0.3/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4= -github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= -github.com/mattn/go-isatty v0.0.11/go.mod h1:PhnuNfih5lzO57/f3n+odYbM4JtupLOxQOAqxQCu2WE= -github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY= github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= github.com/miekg/dns v1.1.26/go.mod h1:bPDLeHnStXmXAq1m/Ch/hvfNHr14JKNPMBo3VZKjuso= github.com/miekg/dns v1.1.41 h1:WMszZWJG0XmzbK9FEmzH2TVcqYzFesusSIB41b8KHxY= @@ -152,8 +153,9 @@ github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXf github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= -github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0= github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.2 h1:4jaiDzPyXQvSd7D0EjG45355tLlV3VOECpq10pLC+8s= +github.com/stretchr/testify v1.7.2/go.mod h1:R6va5+xMeoiuVRoj+gSkQ7d3FALtqAAGI1FQKckRals= github.com/tv42/httpunix v0.0.0-20150427012821-b75d8614f926/go.mod h1:9ESjWnEqriFuLhtthL60Sar/7RFoluCcXsuvEwTV5KM= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= @@ -178,18 +180,19 @@ golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20181116152217-5ac8a444bdc5/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190922100055-0a153f010e69/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190924154521-2837fb4f24fe/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200122134326-e047566fdf82/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200223170610-d5e6a3e2c0ae/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210303074136-134d130e1a04/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220503163025-988cb79eb6c6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220728004956-3c1f35247d10 h1:WIoqL4EROvwiPdUtaip4VcDdpZ4kha7wBWZrbVKCIZg= golang.org/x/sys v0.0.0-20220728004956-3c1f35247d10/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= @@ -211,5 +214,6 @@ gopkg.in/yaml.v2 v2.2.4/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.2.5/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.3.0 h1:clyUAQHOM3G0M3f5vQj7LuJrETvjVot3Z5el9nffUtU= gopkg.in/yaml.v2 v2.3.0/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= -gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/serf/config.go b/serf/config.go index 2a4fb7649..fc38bdc92 100644 --- a/serf/config.go +++ b/serf/config.go @@ -5,11 +5,11 @@ package serf import ( "io" - "log" "os" "time" "github.com/armon/go-metrics" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/memberlist" ) @@ -209,7 +209,7 @@ type Config struct { // this for the internal logger. If Logger is not set, it will fall back to the // behavior for using LogOutput. You cannot specify both LogOutput and Logger // at the same time. - Logger *log.Logger + Logger hclog.Logger // SnapshotPath if provided is used to snapshot live nodes as well // as lamport clock values. When Serf is started with a snapshot, diff --git a/serf/delegate.go b/serf/delegate.go index 6555f5a26..132d94531 100644 --- a/serf/delegate.go +++ b/serf/delegate.go @@ -47,53 +47,53 @@ func (d *delegate) NotifyMsg(buf []byte) { case messageLeaveType: var leave messageLeave if err := decodeMessage(buf[1:], &leave); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding leave message: %s", err) + d.serf.logger.Error("serf: Error decoding leave message: %s", err) break } - d.serf.logger.Printf("[DEBUG] serf: messageLeaveType: %s", leave.Node) + d.serf.logger.Debug("serf: messageLeaveType: %s", leave.Node) rebroadcast = d.serf.handleNodeLeaveIntent(&leave) case messageJoinType: var join messageJoin if err := decodeMessage(buf[1:], &join); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding join message: %s", err) + d.serf.logger.Error("serf: Error decoding join message: %s", err) break } - d.serf.logger.Printf("[DEBUG] serf: messageJoinType: %s", join.Node) + d.serf.logger.Debug("serf: messageJoinType: %s", join.Node) rebroadcast = d.serf.handleNodeJoinIntent(&join) case messageUserEventType: var event messageUserEvent if err := decodeMessage(buf[1:], &event); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding user event message: %s", err) + d.serf.logger.Error("serf: Error decoding user event message: %s", err) break } - d.serf.logger.Printf("[DEBUG] serf: messageUserEventType: %s", event.Name) + d.serf.logger.Debug("serf: messageUserEventType: %s", event.Name) rebroadcast = d.serf.handleUserEvent(&event) rebroadcastQueue = d.serf.eventBroadcasts case messageQueryType: var query messageQuery if err := decodeMessage(buf[1:], &query); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding query message: %s", err) + d.serf.logger.Error("serf: Error decoding query message: %s", err) break } - d.serf.logger.Printf("[DEBUG] serf: messageQueryType: %s", query.Name) + d.serf.logger.Debug("serf: messageQueryType: %s", query.Name) rebroadcast = d.serf.handleQuery(&query) rebroadcastQueue = d.serf.queryBroadcasts case messageQueryResponseType: var resp messageQueryResponse if err := decodeMessage(buf[1:], &resp); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding query response message: %s", err) + d.serf.logger.Error("serf: Error decoding query response message: %s", err) break } - d.serf.logger.Printf("[DEBUG] serf: messageQueryResponseType: %v", resp.From) + d.serf.logger.Debug("serf: messageQueryResponseType: %v", resp.From) d.serf.handleQueryResponse(&resp) case messageRelayType: @@ -102,7 +102,7 @@ func (d *delegate) NotifyMsg(buf []byte) { reader := bytes.NewReader(buf[1:]) decoder := codec.NewDecoder(reader, &handle) if err := decoder.Decode(&header); err != nil { - d.serf.logger.Printf("[ERR] serf: Error decoding relay header: %s", err) + d.serf.logger.Error("serf: Error decoding relay header: %s", err) break } @@ -115,14 +115,14 @@ func (d *delegate) NotifyMsg(buf []byte) { Name: header.DestName, } - d.serf.logger.Printf("[DEBUG] serf: Relaying response to addr: %s", header.DestAddr.String()) + d.serf.logger.Debug("serf: Relaying response to addr: %s", header.DestAddr.String()) if err := d.serf.memberlist.SendToAddress(addr, raw); err != nil { - d.serf.logger.Printf("[ERR] serf: Error forwarding message to %s: %s", header.DestAddr.String(), err) + d.serf.logger.Error("serf: Error forwarding message to %s: %s", header.DestAddr.String(), err) break } default: - d.serf.logger.Printf("[WARN] serf: Received message of unknown type: %d", t) + d.serf.logger.Warn("serf: Received message of unknown type: %d", t) } if rebroadcast { @@ -202,7 +202,7 @@ func (d *delegate) LocalState(join bool) []byte { // Encode the push pull state buf, err := encodeMessage(messagePushPullType, &pp) if err != nil { - d.serf.logger.Printf("[ERR] serf: Failed to encode local state: %v", err) + d.serf.logger.Error("serf: Failed to encode local state: %v", err) return nil } return buf @@ -211,13 +211,13 @@ func (d *delegate) LocalState(join bool) []byte { func (d *delegate) MergeRemoteState(buf []byte, isJoin bool) { // Ensure we have a message if len(buf) == 0 { - d.serf.logger.Printf("[ERR] serf: Remote state is zero bytes") + d.serf.logger.Error("serf: Remote state is zero bytes") return } // Check the message type if messageType(buf[0]) != messagePushPullType { - d.serf.logger.Printf("[ERR] serf: Remote state has bad type prefix: %v", buf[0]) + d.serf.logger.Error("serf: Remote state has bad type prefix: %v", buf[0]) return } @@ -228,7 +228,7 @@ func (d *delegate) MergeRemoteState(buf []byte, isJoin bool) { // Attempt a decode pp := messagePushPull{} if err := decodeMessage(buf[1:], &pp); err != nil { - d.serf.logger.Printf("[ERR] serf: Failed to decode remote state: %v", err) + d.serf.logger.Error("serf: Failed to decode remote state: %v", err) return } diff --git a/serf/internal_query.go b/serf/internal_query.go index cac3340cf..c2e8bda4d 100644 --- a/serf/internal_query.go +++ b/serf/internal_query.go @@ -6,8 +6,9 @@ package serf import ( "encoding/base64" "fmt" - "log" "strings" + + "github.com/hashicorp/go-hclog" ) const ( @@ -50,7 +51,7 @@ func internalQueryName(name string) string { // _serf and respond to them as appropriate. type serfQueries struct { inCh chan Event - logger *log.Logger + logger hclog.Logger outCh chan<- Event serf *Serf shutdownCh <-chan struct{} @@ -75,7 +76,7 @@ type nodeKeyResponse struct { // newSerfQueries is used to create a new serfQueries. We return an event // channel that is ingested and forwarded to an outCh. Any Queries that // have the InternalQueryPrefix are handled instead of forwarded. -func newSerfQueries(serf *Serf, logger *log.Logger, outCh chan<- Event, shutdownCh <-chan struct{}) (chan<- Event, error) { +func newSerfQueries(serf *Serf, logger hclog.Logger, outCh chan<- Event, shutdownCh <-chan struct{}) (chan<- Event, error) { inCh := make(chan Event, 1024) q := &serfQueries{ inCh: inCh, @@ -125,7 +126,7 @@ func (s *serfQueries) handleQuery(q *Query) { case listKeysQuery: s.handleListKeys(q) default: - s.logger.Printf("[WARN] serf: Unhandled internal query '%s'", queryName) + s.logger.Warn("serf: Unhandled internal query '%s'", queryName) } } @@ -140,7 +141,7 @@ func (s *serfQueries) handleConflict(q *Query) { if node == s.serf.config.NodeName { return } - s.logger.Printf("[DEBUG] serf: Got conflict resolution query for '%s'", node) + s.logger.Debug("serf: Got conflict resolution query for '%s'", node) // Look for the member info var out *Member @@ -153,13 +154,13 @@ func (s *serfQueries) handleConflict(q *Query) { // Encode the response buf, err := encodeMessage(messageConflictResponseType, out) if err != nil { - s.logger.Printf("[ERR] serf: Failed to encode conflict query response: %v", err) + s.logger.Error("serf: Failed to encode conflict query response: %v", err) return } // Send our answer if err := q.Respond(buf); err != nil { - s.logger.Printf("[ERR] serf: Failed to respond to conflict query: %v", err) + s.logger.Error("serf: Failed to respond to conflict query: %v", err) } } @@ -196,7 +197,7 @@ func (s *serfQueries) keyListResponseWithCorrectSize(q *Query, resp *nodeKeyResp } if actual > i { - s.logger.Printf("[WARN] serf: %s", resp.Message) + s.logger.Warn("serf: %s", resp.Message) } return raw, qresp, nil } @@ -209,21 +210,21 @@ func (s *serfQueries) sendKeyResponse(q *Query, resp *nodeKeyResponse) { case internalQueryName(listKeysQuery): raw, qresp, err := s.keyListResponseWithCorrectSize(q, resp) if err != nil { - s.logger.Printf("[ERR] serf: %v", err) + s.logger.Error("serf: %v", err) return } if err := q.respondWithMessageAndResponse(raw, qresp); err != nil { - s.logger.Printf("[ERR] serf: Failed to respond to key query: %v", err) + s.logger.Error("serf: Failed to respond to key query: %v", err) return } default: buf, err := encodeMessage(messageKeyResponseType, resp) if err != nil { - s.logger.Printf("[ERR] serf: Failed to encode key response: %v", err) + s.logger.Error("serf: Failed to encode key response: %v", err) return } if err := q.Respond(buf); err != nil { - s.logger.Printf("[ERR] serf: Failed to respond to key query: %v", err) + s.logger.Error("serf: Failed to respond to key query: %v", err) return } } @@ -241,27 +242,27 @@ func (s *serfQueries) handleInstallKey(q *Query) { err := decodeMessage(q.Payload[1:], &req) if err != nil { - s.logger.Printf("[ERR] serf: Failed to decode key request: %v", err) + s.logger.Error("serf: Failed to decode key request: %v", err) goto SEND } if !s.serf.EncryptionEnabled() { response.Message = "No keyring to modify (encryption not enabled)" - s.logger.Printf("[ERR] serf: No keyring to modify (encryption not enabled)") + s.logger.Error("serf: No keyring to modify (encryption not enabled)") goto SEND } - s.logger.Printf("[INFO] serf: Received install-key query") + s.logger.Info("serf: Received install-key query") if err := keyring.AddKey(req.Key); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to install key: %s", err) + s.logger.Error("serf: Failed to install key: %s", err) goto SEND } if s.serf.config.KeyringFile != "" { if err := s.serf.writeKeyringFile(); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to write keyring file: %s", err) + s.logger.Error("serf: Failed to write keyring file: %s", err) goto SEND } } @@ -283,26 +284,26 @@ func (s *serfQueries) handleUseKey(q *Query) { err := decodeMessage(q.Payload[1:], &req) if err != nil { - s.logger.Printf("[ERR] serf: Failed to decode key request: %v", err) + s.logger.Error("serf: Failed to decode key request: %v", err) goto SEND } if !s.serf.EncryptionEnabled() { response.Message = "No keyring to modify (encryption not enabled)" - s.logger.Printf("[ERR] serf: No keyring to modify (encryption not enabled)") + s.logger.Error("serf: No keyring to modify (encryption not enabled)") goto SEND } - s.logger.Printf("[INFO] serf: Received use-key query") + s.logger.Info("serf: Received use-key query") if err := keyring.UseKey(req.Key); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to change primary key: %s", err) + s.logger.Error("serf: Failed to change primary key: %s", err) goto SEND } if err := s.serf.writeKeyringFile(); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to write keyring file: %s", err) + s.logger.Error("serf: Failed to write keyring file: %s", err) goto SEND } @@ -323,26 +324,26 @@ func (s *serfQueries) handleRemoveKey(q *Query) { err := decodeMessage(q.Payload[1:], &req) if err != nil { - s.logger.Printf("[ERR] serf: Failed to decode key request: %v", err) + s.logger.Error("serf: Failed to decode key request: %v", err) goto SEND } if !s.serf.EncryptionEnabled() { response.Message = "No keyring to modify (encryption not enabled)" - s.logger.Printf("[ERR] serf: No keyring to modify (encryption not enabled)") + s.logger.Error("serf: No keyring to modify (encryption not enabled)") goto SEND } - s.logger.Printf("[INFO] serf: Received remove-key query") + s.logger.Info("serf: Received remove-key query") if err := keyring.RemoveKey(req.Key); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to remove key: %s", err) + s.logger.Error("serf: Failed to remove key: %s", err) goto SEND } if err := s.serf.writeKeyringFile(); err != nil { response.Message = err.Error() - s.logger.Printf("[ERR] serf: Failed to write keyring file: %s", err) + s.logger.Error("serf: Failed to write keyring file: %s", err) goto SEND } @@ -362,11 +363,11 @@ func (s *serfQueries) handleListKeys(q *Query) { var primaryKeyBytes []byte if !s.serf.EncryptionEnabled() { response.Message = "Keyring is empty (encryption not enabled)" - s.logger.Printf("[ERR] serf: Keyring is empty (encryption not enabled)") + s.logger.Error("serf: Keyring is empty (encryption not enabled)") goto SEND } - s.logger.Printf("[INFO] serf: Received list-keys query") + s.logger.Info("serf: Received list-keys query") for _, keyBytes := range keyring.GetKeys() { // Encode the keys before sending the response. This should help take // some the burden of doing this off of the asking member. diff --git a/serf/internal_query_test.go b/serf/internal_query_test.go index 470e9e7f5..b449215b9 100644 --- a/serf/internal_query_test.go +++ b/serf/internal_query_test.go @@ -4,11 +4,11 @@ package serf import ( - "log" - "os" "strings" "testing" "time" + + "github.com/hashicorp/go-hclog" ) func TestInternalQueryName(t *testing.T) { @@ -20,7 +20,7 @@ func TestInternalQueryName(t *testing.T) { func TestSerfQueries_Passthrough(t *testing.T) { serf := &Serf{} - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() outCh := make(chan Event, 4) shutdown := make(chan struct{}) defer close(shutdown) @@ -50,7 +50,7 @@ func TestSerfQueries_Passthrough(t *testing.T) { func TestSerfQueries_Ping(t *testing.T) { serf := &Serf{} - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() outCh := make(chan Event, 4) shutdown := make(chan struct{}) defer close(shutdown) @@ -72,7 +72,7 @@ func TestSerfQueries_Ping(t *testing.T) { func TestSerfQueries_Conflict_SameName(t *testing.T) { serf := &Serf{config: &Config{NodeName: "foo"}} - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() outCh := make(chan Event, 4) shutdown := make(chan struct{}) defer close(shutdown) @@ -124,7 +124,7 @@ func TestSerfQueries_estimateMaxKeysInListKeyResponseFactor(t *testing.T) { } func TestSerfQueries_keyListResponseWithCorrectSize(t *testing.T) { - s := serfQueries{logger: log.New(os.Stderr, "", log.LstdFlags)} + s := serfQueries{logger: hclog.Default()} q := Query{id: 0, serf: &Serf{config: &Config{NodeName: "", QueryResponseSizeLimit: 1024}}} cases := []struct { resp nodeKeyResponse diff --git a/serf/keymanager.go b/serf/keymanager.go index 5ce8fbf8d..893ef2479 100644 --- a/serf/keymanager.go +++ b/serf/keymanager.go @@ -77,7 +77,7 @@ func (k *KeyManager) streamKeyResp(resp *KeyResponse, ch <-chan NodeResponse) { if nodeResponse.Result && len(nodeResponse.Message) > 0 { resp.Messages[r.From] = nodeResponse.Message - k.serf.logger.Println("[WARN] serf:", nodeResponse.Message) + k.serf.logger.Warn("serf:", nodeResponse.Message) } // Currently only used for key list queries, this adds keys to a counter diff --git a/serf/ping_delegate.go b/serf/ping_delegate.go index 78a34f742..0c90d7a86 100644 --- a/serf/ping_delegate.go +++ b/serf/ping_delegate.go @@ -39,7 +39,7 @@ func (p *pingDelegate) AckPayload() []byte { // The rest of the message is the serialized coordinate. enc := codec.NewEncoder(&buf, &codec.MsgpackHandle{}) if err := enc.Encode(p.serf.coordClient.GetCoordinate()); err != nil { - p.serf.logger.Printf("[ERR] serf: Failed to encode coordinate: %v\n", err) + p.serf.logger.Error("serf: Failed to encode coordinate: %v\n", err) } return buf.Bytes() } @@ -54,7 +54,7 @@ func (p *pingDelegate) NotifyPingComplete(other *memberlist.Node, rtt time.Durat // Verify ping version in the header. version := payload[0] if version != PingVersion { - p.serf.logger.Printf("[ERR] serf: Unsupported ping version: %v", version) + p.serf.logger.Error("serf: Unsupported ping version: %v", version) return } @@ -63,7 +63,7 @@ func (p *pingDelegate) NotifyPingComplete(other *memberlist.Node, rtt time.Durat dec := codec.NewDecoder(r, &codec.MsgpackHandle{}) var coord coordinate.Coordinate if err := dec.Decode(&coord); err != nil { - p.serf.logger.Printf("[ERR] serf: Failed to decode coordinate from ping: %v", err) + p.serf.logger.Error("serf: Failed to decode coordinate from ping: %v", err) return } @@ -72,7 +72,7 @@ func (p *pingDelegate) NotifyPingComplete(other *memberlist.Node, rtt time.Durat after, err := p.serf.coordClient.Update(other.Name, &coord, rtt) if err != nil { metrics.IncrCounterWithLabels([]string{"serf", "coordinate", "rejected"}, 1, p.serf.metricLabels) - p.serf.logger.Printf("[TRACE] serf: Rejected coordinate from %s: %v\n", + p.serf.logger.Trace("serf: Rejected coordinate from %s: %v\n", other.Name, err) return } diff --git a/serf/query.go b/serf/query.go index 2c04a9078..115c3af38 100644 --- a/serf/query.go +++ b/serf/query.go @@ -219,7 +219,7 @@ func (s *Serf) shouldProcessQuery(filters [][]byte) bool { // Decode the filter var nodes filterNode if err := decodeMessage(filter[1:], &nodes); err != nil { - s.logger.Printf("[WARN] serf: failed to decode filterNodeType: %v", err) + s.logger.Warn("serf: failed to decode filterNodeType: %v", err) return false } @@ -239,7 +239,7 @@ func (s *Serf) shouldProcessQuery(filters [][]byte) bool { // Decode the filter var filt filterTag if err := decodeMessage(filter[1:], &filt); err != nil { - s.logger.Printf("[WARN] serf: failed to decode filterTagType: %v", err) + s.logger.Warn("serf: failed to decode filterTagType: %v", err) return false } @@ -247,7 +247,7 @@ func (s *Serf) shouldProcessQuery(filters [][]byte) bool { tags := s.config.Tags matched, err := regexp.MatchString(filt.Expr, tags[filt.Tag]) if err != nil { - s.logger.Printf("[WARN] serf: failed to compile filter regex (%s): %v", filt.Expr, err) + s.logger.Warn("serf: failed to compile filter regex (%s): %v", filt.Expr, err) return false } if !matched { @@ -255,7 +255,7 @@ func (s *Serf) shouldProcessQuery(filters [][]byte) bool { } default: - s.logger.Printf("[WARN] serf: query has unrecognized filter type: %d", filter[0]) + s.logger.Warn("serf: query has unrecognized filter type: %d", filter[0]) return false } } diff --git a/serf/serf.go b/serf/serf.go index 96f1d0a09..b1a7eb9a2 100644 --- a/serf/serf.go +++ b/serf/serf.go @@ -9,7 +9,6 @@ import ( "encoding/json" "fmt" "io/ioutil" - "log" "math/rand" "net" "os" @@ -20,6 +19,7 @@ import ( "time" "github.com/armon/go-metrics" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/go-msgpack/codec" "github.com/hashicorp/memberlist" "github.com/hashicorp/serf/coordinate" @@ -96,7 +96,7 @@ type Serf struct { queryResponse map[LamportTime]*QueryResponse queryLock sync.RWMutex - logger *log.Logger + logger hclog.Logger joinLock sync.Mutex stateLock sync.Mutex state SerfState @@ -266,7 +266,10 @@ func Create(conf *Config) (*Serf, error) { if logOutput == nil { logOutput = os.Stderr } - logger = log.New(logOutput, "", log.LstdFlags) + + logger = hclog.New(&hclog.LoggerOptions{ + Output: logOutput, + }) } serf := &Serf{ @@ -688,7 +691,7 @@ func (s *Serf) broadcastJoin(ltime LamportTime) error { // Start broadcasting the update if err := s.broadcast(messageJoinType, &msg, nil); err != nil { - s.logger.Printf("[WARN] serf: Failed to broadcast join intent: %v", err) + s.logger.Warn("serf: Failed to broadcast join intent: %v", err) return err } return nil @@ -739,14 +742,14 @@ func (s *Serf) Leave() error { select { case <-notifyCh: case <-time.After(s.config.BroadcastTimeout): - s.logger.Printf("[WARN] serf: timeout while waiting for graceful leave") + s.logger.Warn("serf: timeout while waiting for graceful leave") } } // Attempt the memberlist leave err := s.memberlist.Leave(s.config.BroadcastTimeout) if err != nil { - s.logger.Printf("[WARN] serf: timeout waiting for leave broadcast: %s", err.Error()) + s.logger.Warn("serf: timeout waiting for leave broadcast: %s", err.Error()) } // Wait for the leave to propagate through the cluster. The broadcast @@ -870,7 +873,7 @@ func (s *Serf) Shutdown() error { } if s.state != SerfLeft { - s.logger.Printf("[WARN] serf: Shutdown without a Leave") + s.logger.Warn("serf: Shutdown without a Leave") } // Wait to close the shutdown channel until after we've shut down the @@ -995,7 +998,7 @@ func (s *Serf) handleNodeJoin(n *memberlist.Node) { metrics.IncrCounterWithLabels([]string{"serf", "member", "join"}, 1, s.metricLabels) // Send an event along - s.logger.Printf("[INFO] serf: EventMemberJoin: %s %s", + s.logger.Info("serf: EventMemberJoin: %s %s", member.Member.Name, member.Member.Addr) if s.config.EventCh != nil { s.config.EventCh <- MemberEvent{ @@ -1029,7 +1032,7 @@ func (s *Serf) handleNodeLeave(n *memberlist.Node) { s.failedMembers = append(s.failedMembers, member) default: // Unknown state that it was in? Just don't do anything - s.logger.Printf("[WARN] serf: Bad state when leave: %d", member.Status) + s.logger.Warn("serf: Bad state when leave: %d", member.Status) return } @@ -1044,7 +1047,7 @@ func (s *Serf) handleNodeLeave(n *memberlist.Node) { // Update some metrics metrics.IncrCounterWithLabels([]string{"serf", "member", member.Status.String()}, 1, s.metricLabels) - s.logger.Printf("[INFO] serf: %s: %s %s", + s.logger.Info("serf: %s: %s %s", eventStr, member.Member.Name, member.Member.Addr) if s.config.EventCh != nil { s.config.EventCh <- MemberEvent{ @@ -1089,7 +1092,7 @@ func (s *Serf) handleNodeUpdate(n *memberlist.Node) { metrics.IncrCounterWithLabels([]string{"serf", "member", "update"}, 1, s.metricLabels) // Send an event along - s.logger.Printf("[INFO] serf: EventMemberUpdate: %s", member.Member.Name) + s.logger.Info("serf: EventMemberUpdate: %s", member.Member.Name) if s.config.EventCh != nil { s.config.EventCh <- MemberEvent{ Type: EventMemberUpdate, @@ -1122,7 +1125,7 @@ func (s *Serf) handleNodeLeaveIntent(leaveMsg *messageLeave) bool { // Refute us leaving if we are in the alive state // Must be done in another goroutine since we have the memberLock if leaveMsg.Node == s.config.NodeName && state == SerfAlive { - s.logger.Printf("[DEBUG] serf: Refuting an older leave intent") + s.logger.Debug("serf: Refuting an older leave intent") go s.broadcastJoin(s.clock.Time()) return false } @@ -1166,7 +1169,7 @@ func (s *Serf) handleNodeLeaveIntent(leaveMsg *messageLeave) bool { // We must push a message indicating the node has now // left to allow higher-level applications to handle the // graceful leave. - s.logger.Printf("[INFO] serf: EventMemberLeave (forced): %s %s", + s.logger.Info("serf: EventMemberLeave (forced): %s %s", member.Member.Name, member.Member.Addr) if s.config.EventCh != nil { s.config.EventCh <- MemberEvent{ @@ -1198,7 +1201,7 @@ func (s *Serf) handlePrune(member *memberState) { time.Sleep(s.config.BroadcastTimeout + s.config.LeavePropagateDelay) } - s.logger.Printf("[INFO] serf: EventMemberReap (forced): %s %s", member.Name, member.Member.Addr) + s.logger.Info("serf: EventMemberReap (forced): %s %s", member.Name, member.Member.Addr) //If we are leaving or left we may be in that list of members if member.Status == StatusLeaving || member.Status == StatusLeft { @@ -1257,8 +1260,8 @@ func (s *Serf) handleUserEvent(eventMsg *messageUserEvent) bool { curTime := s.eventClock.Time() if curTime > LamportTime(len(s.eventBuffer)) && eventMsg.LTime < curTime-LamportTime(len(s.eventBuffer)) { - s.logger.Printf( - "[WARN] serf: received old event %s from time %d (current: %d)", + s.logger.Warn( + "serf: received old event %s from time %d (current: %d)", eventMsg.Name, eventMsg.LTime, s.eventClock.Time()) @@ -1316,8 +1319,8 @@ func (s *Serf) handleQuery(query *messageQuery) bool { curTime := s.queryClock.Time() if curTime > LamportTime(len(s.queryBuffer)) && query.LTime < curTime-LamportTime(len(s.queryBuffer)) { - s.logger.Printf( - "[WARN] serf: received old query %s from time %d (current: %d)", + s.logger.Warn( + "serf: received old query %s from time %d (current: %d)", query.Name, query.LTime, s.queryClock.Time()) @@ -1369,7 +1372,7 @@ func (s *Serf) handleQuery(query *messageQuery) bool { } raw, err := encodeMessage(messageQueryResponseType, &ack) if err != nil { - s.logger.Printf("[ERR] serf: failed to format ack: %v", err) + s.logger.Error("serf: failed to format ack: %v", err) } else { udpAddr := net.UDPAddr{IP: query.Addr, Port: int(query.Port)} addr := memberlist.Address{ @@ -1377,10 +1380,10 @@ func (s *Serf) handleQuery(query *messageQuery) bool { Name: query.SourceNode, } if err := s.memberlist.SendToAddress(addr, raw); err != nil { - s.logger.Printf("[ERR] serf: failed to send ack: %v", err) + s.logger.Error("serf: failed to send ack: %v", err) } if err := s.relayResponse(query.RelayFactor, udpAddr, query.SourceNode, &ack); err != nil { - s.logger.Printf("[ERR] serf: failed to relay ack: %v", err) + s.logger.Error("serf: failed to relay ack: %v", err) } } } @@ -1410,14 +1413,14 @@ func (s *Serf) handleQueryResponse(resp *messageQueryResponse) { query, ok := s.queryResponse[resp.LTime] s.queryLock.RUnlock() if !ok { - s.logger.Printf("[WARN] serf: reply for non-running query (LTime: %d, ID: %d) From: %s", + s.logger.Warn("serf: reply for non-running query (LTime: %d, ID: %d) From: %s", resp.LTime, resp.ID, resp.From) return } // Verify the ID matches if query.id != resp.ID { - s.logger.Printf("[WARN] serf: query reply ID mismatch (Local: %d, Response: %d)", + s.logger.Warn("serf: query reply ID mismatch (Local: %d, Response: %d)", query.id, resp.ID) return } @@ -1438,7 +1441,7 @@ func (s *Serf) handleQueryResponse(resp *messageQueryResponse) { metrics.IncrCounterWithLabels([]string{"serf", "query_acks"}, 1, s.metricLabels) err := query.sendAck(resp) if err != nil { - s.logger.Printf("[WARN] %v", err) + s.logger.Warn("%v", err) } } else { // Exit early if this is a duplicate response @@ -1450,7 +1453,7 @@ func (s *Serf) handleQueryResponse(resp *messageQueryResponse) { metrics.IncrCounterWithLabels([]string{"serf", "query_responses"}, 1, s.metricLabels) err := query.sendResponse(NodeResponse{From: resp.From, Payload: resp.Payload}) if err != nil { - s.logger.Printf("[WARN] %v", err) + s.logger.Warn("%v", err) } } } @@ -1461,13 +1464,13 @@ func (s *Serf) handleQueryResponse(resp *messageQueryResponse) { func (s *Serf) handleNodeConflict(existing, other *memberlist.Node) { // Log a basic warning if the node is not us... if existing.Name != s.config.NodeName { - s.logger.Printf("[WARN] serf: Name conflict for '%s' both %s:%d and %s:%d are claiming", + s.logger.Warn("serf: Name conflict for '%s' both %s:%d and %s:%d are claiming", existing.Name, existing.Addr, existing.Port, other.Addr, other.Port) return } // The current node is conflicting! This is an error - s.logger.Printf("[ERR] serf: Node name conflicts with another node at %s:%d. Names must be unique! (Resolution enabled: %v)", + s.logger.Error("serf: Node name conflicts with another node at %s:%d. Names must be unique! (Resolution enabled: %v)", other.Addr, other.Port, s.config.EnableNameConflictResolution) // If automatic resolution is enabled, kick off the resolution @@ -1487,7 +1490,7 @@ func (s *Serf) resolveNodeConflict() { payload := []byte(s.config.NodeName) resp, err := s.Query(qName, payload, nil) if err != nil { - s.logger.Printf("[ERR] serf: Failed to start name resolution query: %v", err) + s.logger.Error("serf: Failed to start name resolution query: %v", err) return } @@ -1499,12 +1502,12 @@ func (s *Serf) resolveNodeConflict() { for r := range respCh { // Decode the response if len(r.Payload) < 1 || messageType(r.Payload[0]) != messageConflictResponseType { - s.logger.Printf("[ERR] serf: Invalid conflict query response type: %v", r.Payload) + s.logger.Error("serf: Invalid conflict query response type: %v", r.Payload) continue } var member Member if err := decodeMessage(r.Payload[1:], &member); err != nil { - s.logger.Printf("[ERR] serf: Failed to decode conflict query response: %v", err) + s.logger.Error("serf: Failed to decode conflict query response: %v", err) continue } @@ -1518,20 +1521,20 @@ func (s *Serf) resolveNodeConflict() { // Query over, determine if we should live majority := (responses / 2) + 1 if matching >= majority { - s.logger.Printf("[INFO] serf: majority in name conflict resolution [%d / %d]", + s.logger.Info("serf: majority in name conflict resolution [%d / %d]", matching, responses) return } // Since we lost the vote, we need to exit - s.logger.Printf("[WARN] serf: minority in name conflict resolution, quiting [%d / %d]", + s.logger.Warn("serf: minority in name conflict resolution, quiting [%d / %d]", matching, responses) if err := s.Shutdown(); err != nil { - s.logger.Printf("[ERR] serf: Failed to shutdown: %v", err) + s.logger.Error("serf: Failed to shutdown: %v", err) } } -//eraseNode takes a node completely out of the member list +// eraseNode takes a node completely out of the member list func (s *Serf) eraseNode(m *memberState) { // Delete from members delete(s.members, m.Name) @@ -1611,7 +1614,7 @@ func (s *Serf) reap(old []*memberState, now time.Time, timeout time.Duration) [] i-- // Delete from members and send out event - s.logger.Printf("[INFO] serf: EventMemberReap: %s", m.Name) + s.logger.Info("serf: EventMemberReap: %s", m.Name) s.eraseNode(m) } @@ -1643,7 +1646,7 @@ func (s *Serf) reconnect() { prob := numFailed / numAlive if rand.Float32() > prob { s.memberLock.RUnlock() - s.logger.Printf("[DEBUG] serf: forgoing reconnect for random throttling") + s.logger.Debug("serf: forgoing reconnect for random throttling") return } @@ -1653,7 +1656,7 @@ func (s *Serf) reconnect() { // Format the addr addr := net.UDPAddr{IP: mem.Addr, Port: int(mem.Port)} - s.logger.Printf("[INFO] serf: attempting reconnect to %v %s", mem.Name, addr.String()) + s.logger.Info("serf: attempting reconnect to %v %s", mem.Name, addr.String()) joinAddr := addr.String() if mem.Name != "" { @@ -1690,10 +1693,10 @@ func (s *Serf) checkQueueDepth(name string, queue *memberlist.TransmitLimitedQue numq := queue.NumQueued() metrics.AddSampleWithLabels([]string{"serf", "queue", name}, float32(numq), s.metricLabels) if numq >= s.config.QueueDepthWarning { - s.logger.Printf("[WARN] serf: %s queue depth: %d", name, numq) + s.logger.Warn("serf: %s queue depth: %d", name, numq) } if max := s.getQueueMax(); numq > max { - s.logger.Printf("[WARN] serf: %s queue depth (%d) exceeds limit (%d), dropping messages!", + s.logger.Warn("serf: %s queue depth (%d) exceeds limit (%d), dropping messages!", name, numq, max) queue.Prune(max) } @@ -1772,14 +1775,14 @@ func (s *Serf) handleRejoin(previous []*PreviousNode) { joinAddr = prev.Name + "/" + prev.Addr } - s.logger.Printf("[INFO] serf: Attempting re-join to previously known node: %s", prev) + s.logger.Info("serf: Attempting re-join to previously known node: %s", prev) _, err := s.memberlist.Join([]string{joinAddr}) if err == nil { - s.logger.Printf("[INFO] serf: Re-joined to previously known node: %s", prev) + s.logger.Info("serf: Re-joined to previously known node: %s", prev) return } } - s.logger.Printf("[WARN] serf: Failed to re-join any previously known node") + s.logger.Warn("serf: Failed to re-join any previously known node") } // encodeTags is used to encode a tag map @@ -1814,7 +1817,7 @@ func (s *Serf) decodeTags(buf []byte) map[string]string { r := bytes.NewReader(buf[1:]) dec := codec.NewDecoder(r, &codec.MsgpackHandle{}) if err := dec.Decode(&tags); err != nil { - s.logger.Printf("[ERR] serf: Failed to decode tags: %v", err) + s.logger.Error("serf: Failed to decode tags: %v", err) } return tags } diff --git a/serf/serf_test.go b/serf/serf_test.go index 0dada60fb..9662ce88e 100644 --- a/serf/serf_test.go +++ b/serf/serf_test.go @@ -9,7 +9,6 @@ import ( "encoding/base64" "fmt" "io/ioutil" - "log" "net" "os" "path/filepath" @@ -21,6 +20,7 @@ import ( "testing" "time" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/go-msgpack/codec" "github.com/hashicorp/memberlist" "github.com/hashicorp/serf/coordinate" @@ -59,8 +59,10 @@ func testConfig(t *testing.T, ip net.IP) *Config { config.TombstoneTimeout = 1 * time.Microsecond if t != nil { - config.Logger = log.New(os.Stderr, "test["+t.Name()+"]: ", log.LstdFlags) - config.MemberlistConfig.Logger = config.Logger + config.Logger = hclog.Default().Named("test[" + t.Name() + "]: ") + config.MemberlistConfig.Logger = config.Logger.StandardLogger(&hclog.StandardLoggerOptions{ + InferLevels: true, + }) } return config diff --git a/serf/snapshot.go b/serf/snapshot.go index 28bb668e6..f40e1cc0c 100644 --- a/serf/snapshot.go +++ b/serf/snapshot.go @@ -6,7 +6,6 @@ package serf import ( "bufio" "fmt" - "log" "math/rand" "net" "os" @@ -15,6 +14,7 @@ import ( "time" "github.com/armon/go-metrics" + "github.com/hashicorp/go-hclog" ) /* @@ -72,7 +72,7 @@ type Snapshotter struct { lastQueryClock LamportTime leaveCh chan struct{} leaving bool - logger *log.Logger + logger hclog.Logger minCompactSize int64 path string offset int64 @@ -103,7 +103,7 @@ func (p PreviousNode) String() string { func NewSnapshotter(path string, minCompactSize int, rejoinAfterLeave bool, - logger *log.Logger, + logger hclog.Logger, clock *LamportClock, outCh chan<- Event, shutdownCh <-chan struct{}) (chan<- Event, *Snapshotter, error) { @@ -262,7 +262,7 @@ func (s *Snapshotter) stream() { case *Query: s.processQuery(typed) default: - s.logger.Printf("[ERR] serf: Unknown event to snapshot: %#v", e) + s.logger.Error("serf: Unknown event to snapshot: %#v", e) } } @@ -277,10 +277,10 @@ func (s *Snapshotter) stream() { } s.tryAppend("leave\n") if err := s.buffered.Flush(); err != nil { - s.logger.Printf("[ERR] serf: failed to flush leave to snapshot: %v", err) + s.logger.Error("serf: failed to flush leave to snapshot: %v", err) } if err := s.fh.Sync(); err != nil { - s.logger.Printf("[ERR] serf: failed to sync leave to snapshot: %v", err) + s.logger.Error("serf: failed to sync leave to snapshot: %v", err) } case e := <-s.streamCh: @@ -310,10 +310,10 @@ func (s *Snapshotter) stream() { } if err := s.buffered.Flush(); err != nil { - s.logger.Printf("[ERR] serf: failed to flush snapshot: %v", err) + s.logger.Error("serf: failed to flush snapshot: %v", err) } if err := s.fh.Sync(); err != nil { - s.logger.Printf("[ERR] serf: failed to sync snapshot: %v", err) + s.logger.Error("serf: failed to sync snapshot: %v", err) } s.fh.Close() close(s.waitCh) @@ -377,16 +377,16 @@ func (s *Snapshotter) processQuery(q *Query) { // tryAppend will invoke append line but will not return an error func (s *Snapshotter) tryAppend(l string) { if err := s.appendLine(l); err != nil { - s.logger.Printf("[ERR] serf: Failed to update snapshot: %v", err) + s.logger.Error("serf: Failed to update snapshot: %v", err) now := time.Now() if now.Sub(s.lastAttemptedCompaction) > snapshotErrorRecoveryInterval { s.lastAttemptedCompaction = now - s.logger.Printf("[INFO] serf: Attempting compaction to recover from error...") + s.logger.Info("serf: Attempting compaction to recover from error...") err = s.compact() if err != nil { - s.logger.Printf("[ERR] serf: Compaction failed, will reattempt after %v: %v", snapshotErrorRecoveryInterval, err) + s.logger.Error("serf: Compaction failed, will reattempt after %v: %v", snapshotErrorRecoveryInterval, err) } else { - s.logger.Printf("[INFO] serf: Finished compaction, successfully recovered from error state") + s.logger.Info("serf: Finished compaction, successfully recovered from error state") } } } @@ -564,7 +564,7 @@ func (s *Snapshotter) replay() error { info := strings.TrimPrefix(line, "alive: ") addrIdx := strings.LastIndex(info, " ") if addrIdx == -1 { - s.logger.Printf("[WARN] serf: Failed to parse address: %v", line) + s.logger.Warn("serf: Failed to parse address: %v", line) continue } addr := info[addrIdx+1:] @@ -579,7 +579,7 @@ func (s *Snapshotter) replay() error { timeStr := strings.TrimPrefix(line, "clock: ") timeInt, err := strconv.ParseUint(timeStr, 10, 64) if err != nil { - s.logger.Printf("[WARN] serf: Failed to convert clock time: %v", err) + s.logger.Warn("serf: Failed to convert clock time: %v", err) continue } s.lastClock = LamportTime(timeInt) @@ -588,7 +588,7 @@ func (s *Snapshotter) replay() error { timeStr := strings.TrimPrefix(line, "event-clock: ") timeInt, err := strconv.ParseUint(timeStr, 10, 64) if err != nil { - s.logger.Printf("[WARN] serf: Failed to convert event clock time: %v", err) + s.logger.Warn("serf: Failed to convert event clock time: %v", err) continue } s.lastEventClock = LamportTime(timeInt) @@ -597,7 +597,7 @@ func (s *Snapshotter) replay() error { timeStr := strings.TrimPrefix(line, "query-clock: ") timeInt, err := strconv.ParseUint(timeStr, 10, 64) if err != nil { - s.logger.Printf("[WARN] serf: Failed to convert query clock time: %v", err) + s.logger.Warn("serf: Failed to convert query clock time: %v", err) continue } s.lastQueryClock = LamportTime(timeInt) @@ -607,7 +607,7 @@ func (s *Snapshotter) replay() error { } else if line == "leave" { // Ignore a leave if we plan on re-joining if s.rejoinAfterLeave { - s.logger.Printf("[INFO] serf: Ignoring previous leave in snapshot") + s.logger.Info("serf: Ignoring previous leave in snapshot") continue } s.aliveNodes = make(map[string]string) @@ -619,7 +619,7 @@ func (s *Snapshotter) replay() error { // Skip comment lines } else { - s.logger.Printf("[WARN] serf: Unrecognized snapshot line: %v", line) + s.logger.Warn("serf: Unrecognized snapshot line: %v", line) } } diff --git a/serf/snapshot_test.go b/serf/snapshot_test.go index bab5bc76e..854a3f6ef 100644 --- a/serf/snapshot_test.go +++ b/serf/snapshot_test.go @@ -6,11 +6,12 @@ package serf import ( "fmt" "io/ioutil" - "log" "os" "reflect" "testing" "time" + + "github.com/hashicorp/go-hclog" ) func TestSnapshotter(t *testing.T) { @@ -23,7 +24,7 @@ func TestSnapshotter(t *testing.T) { clock := new(LamportClock) outCh := make(chan Event, 64) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() inCh, snap, err := NewSnapshotter(td+"snap", snapshotSizeLimit, false, logger, clock, outCh, stopCh) if err != nil { @@ -176,7 +177,7 @@ func TestSnapshotter_forceCompact(t *testing.T) { clock := new(LamportClock) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() // Create a very low limit inCh, snap, err := NewSnapshotter(td+"snap", 1024, false, @@ -240,7 +241,7 @@ func TestSnapshotter_leave(t *testing.T) { clock := new(LamportClock) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() inCh, snap, err := NewSnapshotter(td+"snap", snapshotSizeLimit, false, logger, clock, nil, stopCh) if err != nil { @@ -321,7 +322,7 @@ func TestSnapshotter_leave_rejoin(t *testing.T) { clock := new(LamportClock) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() inCh, snap, err := NewSnapshotter(td+"snap", snapshotSizeLimit, true, logger, clock, nil, stopCh) if err != nil { @@ -404,7 +405,7 @@ func TestSnapshotter_slowDiskNotBlockingEventCh(t *testing.T) { clock := new(LamportClock) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() outCh := make(chan Event, 1024) inCh, snap, err := NewSnapshotter(td+"snap", snapshotSizeLimit, true, @@ -490,7 +491,7 @@ func TestSnapshotter_blockedUpstreamNotBlockingMemberlist(t *testing.T) { clock := new(LamportClock) stopCh := make(chan struct{}) - logger := log.New(os.Stderr, "", log.LstdFlags) + logger := hclog.Default() // OutCh is unbuffered simulating a slow upstream outCh := make(chan Event)