remove logrus dependency (#134)

This PR removes logrus as a dependency, and makes the built-in
default logger work more like Zap than it does Logrus.

In the future, users of gostats should bring their own
logger. Zap is fairly popular, so I expect many folks to conform to
Zap like logging, so the default logger now logs in JSON formatted
lines like zap.NewProduction, though not exactly.

If the built-in default logger is not suitable for a user's needs,
they can use a zap sugared logger, logrus, or conform to the interface
with their own logger.

go.mod

@@ -2,12 +2,4 @@ module github.com/lyft/gostats
 
 go 1.17
 
-require (
-	github.com/kelseyhightower/envconfig v1.4.0
-	github.com/sirupsen/logrus v1.8.1
-)
-
-require (
-	github.com/stretchr/testify v1.6.1 // indirect
-	golang.org/x/sys v0.0.0-20200519105757-fe76b779f299 // indirect
-)
+require github.com/kelseyhightower/envconfig v1.4.0

go.sum

@@ -1,19 +1,2 @@
-github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
-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/kelseyhightower/envconfig v1.4.0 h1:Im6hONhd3pLkfDFsbRgu68RDNkGF1r3dvMUtDTo2cv8=
 github.com/kelseyhightower/envconfig v1.4.0/go.mod h1:cccZRl6mQpaq41TPp5QxidR+Sa3axMbJDNb//FQX6Gg=
-github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
-github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
-github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE=
-github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
-github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
-github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
-github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0=
-github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
-golang.org/x/sys v0.0.0-20200519105757-fe76b779f299 h1:DYfZAGf2WMFjMxbgTjaC+2HC7NkNAQs+6Q8b9WEB/F4=
-golang.org/x/sys v0.0.0-20200519105757-fe76b779f299/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
-gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
-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=

logging_sink.go

@@ -1,26 +1,105 @@
 package stats
 
-import logger "github.com/sirupsen/logrus"
+import (
+	"encoding/json"
+	"fmt"
+	"io"
+	"os"
+	"strconv"
+	"time"
+)
 
-type loggingSink struct{}
+type loggingSink struct {
+	writer io.Writer
+	now    func() time.Time
+}
+
+type logLine struct {
+	Level     string                `json:"level"`
+	Timestamp sixDecimalPlacesFloat `json:"ts"`
+	Logger    string                `json:"logger"`
+	Message   string                `json:"msg"`
+	JSON      map[string]string     `json:"json"`
+}
+
+type sixDecimalPlacesFloat float64
+
+func (f sixDecimalPlacesFloat) MarshalJSON() ([]byte, error) {
+	var ret []byte
+	ret = strconv.AppendFloat(ret, float64(f), 'f', 6, 64)
+	return ret, nil
+}
 
-// NewLoggingSink returns a Sink that flushes stats to os.StdErr.
+// NewLoggingSink returns a "default" logging Sink that flushes stats
+// to os.StdErr. This sink is not fast, or flexible, it doesn't
+// buffer, it exists merely to be convenient to use by default, with
+// no configuration.
+//
+// The format of this logger is similar to Zap, but not explicitly
+// importing Zap to avoid the dependency. The format is as if you used
+// a zap.NewProduction-generated logger, but also added a
+// log.With(zap.Namespace("json")). This does not include any
+// stacktrace for errors at the moment.
+//
+// If these defaults do not work for you, users should provide their
+// own logger, conforming to FlushableSink, instead.
 func NewLoggingSink() FlushableSink {
-	return &loggingSink{}
+	return &loggingSink{writer: os.Stderr, now: time.Now}
 }
 
-func (s *loggingSink) FlushCounter(name string, value uint64) {
-	logger.Debugf("[gostats] flushing counter %s: %d", name, value)
+// this is allocated outside of logMessage, even though its only used
+// there, to avoid allocing a map every time we log.
+var emptyMap = map[string]string{}
+
+func (s *loggingSink) logMessage(level string, msg string) {
+	nanos := s.now().UnixNano()
+	sec := sixDecimalPlacesFloat(float64(nanos) / float64(time.Second))
+	enc := json.NewEncoder(s.writer)
+	enc.Encode(logLine{
+		Message:   msg,
+		Level:     level,
+		Timestamp: sec,
+		Logger:    "gostats.loggingsink",
+		// intentional empty map used to avoid any null parsing issues
+		// on the log collection side
+		JSON: emptyMap,
+	})
 }
 
-func (s *loggingSink) FlushGauge(name string, value uint64) {
-	logger.Debugf("[gostats] flushing gauge %s: %d", name, value)
+func (s *loggingSink) log(name, typ string, value float64) {
+	nanos := s.now().UnixNano()
+	sec := sixDecimalPlacesFloat(float64(nanos) / float64(time.Second))
+	enc := json.NewEncoder(s.writer)
+	kv := map[string]string{
+		"type":  typ,
+		"value": fmt.Sprintf("%f", value),
+	}
+	if name != "" {
+		kv["name"] = name
+	}
+	enc.Encode(logLine{
+		Message:   fmt.Sprintf("flushing %s", typ),
+		Level:     "info",
+		Timestamp: sec,
+		Logger:    "gostats.loggingsink",
+		JSON:      kv,
+	})
 }
 
-func (s *loggingSink) FlushTimer(name string, value float64) {
-	logger.Debugf("[gostats] flushing time %s: %f", name, value)
+func (s *loggingSink) FlushCounter(name string, value uint64) { s.log(name, "counter", float64(value)) }
+
+func (s *loggingSink) FlushGauge(name string, value uint64) { s.log(name, "gauge", float64(value)) }
+
+func (s *loggingSink) FlushTimer(name string, value float64) { s.log(name, "timer", value) }
+
+func (s *loggingSink) Flush() { s.log("", "all stats", 0) }
+
+// Logger
+
+func (s *loggingSink) Errorf(msg string, args ...interface{}) {
+	s.logMessage("error", fmt.Sprintf(msg, args...))
 }
 
-func (s *loggingSink) Flush() {
-	logger.Debugf("[gostats] Flush() called, all stats would be flushed")
+func (s *loggingSink) Warnf(msg string, args ...interface{}) {
+	s.logMessage("warn", fmt.Sprintf(msg, args...))
 }

logging_sink_test.go

@@ -0,0 +1,12 @@
+package stats
+
+import (
+	"os"
+)
+
+func Example_flushCounter() {
+	l := &loggingSink{writer: os.Stdout, now: foreverNow}
+	l.FlushCounter("counterName", 420)
+	// Output:
+	// {"level":"info","ts":1640995200.000000,"logger":"gostats.loggingsink","msg":"flushing counter","json":{"name":"counterName","type":"counter","value":"420.000000"}}
+}

net_sink.go

@@ -6,13 +6,22 @@ import (
 	"fmt"
 	"math"
 	"net"
+	"os"
 	"strconv"
 	"sync"
 	"time"
-
-	logger "github.com/sirupsen/logrus"
 )
 
+// Logger is used to log errors and other important operational
+// information while using gostats.
+//
+// For convenience of transitioning from logrus to zap, this interface
+// conforms BOTH to logrus.Logger as well as the Zap's Sugared logger.
+type Logger interface {
+	Errorf(msg string, args ...interface{})
+	Warnf(msg string, args ...interface{})
+}
+
 const (
 	defaultRetryInterval = time.Second * 3
 	defaultDialTimeout   = defaultRetryInterval / 2
@@ -67,9 +76,8 @@ func WithStatsdPort(port int) SinkOption {
 }
 
 // WithLogger configures the sink to use the provided logger otherwise
-// the standard logrus logger is used.
-func WithLogger(log *logger.Logger) SinkOption {
-	// TODO (CEV): use the zap.Logger
+// the built-in zap-like logger is used.
+func WithLogger(log Logger) SinkOption {
 	return sinkOptionFunc(func(sink *netSink) {
 		sink.log = log
 	})
@@ -89,8 +97,9 @@ func NewNetSink(opts ...SinkOption) FlushableSink {
 		// arbitrarily buffered
 		doFlush: make(chan chan struct{}, 8),
 
-		// CEV: default to the standard logger to match the legacy implementation.
-		log: logger.StandardLogger(),
+		// default logging sink mimics the previously-used logrus
+		// logger by logging to stderr
+		log: &loggingSink{writer: os.Stderr, now: time.Now},
 
 		// TODO (CEV): auto loading from the env is bad and should be removed.
 		conf: GetSettings(),
@@ -127,7 +136,7 @@ type netSink struct {
 	bufWriter    *bufio.Writer
 	doFlush      chan chan struct{}
 	droppedBytes uint64
-	log          *logger.Logger
+	log          Logger
 	conf         Settings
 }
 
@@ -185,9 +194,7 @@ func (s *netSink) drainFlushQueue() {
 func (s *netSink) handleFlushErrorSize(err error, dropped int) {
 	d := uint64(dropped)
 	if (s.droppedBytes+d)%logOnEveryNDroppedBytes > s.droppedBytes%logOnEveryNDroppedBytes {
-		s.log.WithField("total_dropped_bytes", s.droppedBytes+d).
-			WithField("dropped_bytes", d).
-			Error(err)
+		s.log.Errorf("dropped %d bytes: %s", s.droppedBytes+d, err)
 	}
 	s.droppedBytes += d
 
@@ -275,7 +282,7 @@ func (s *netSink) run() {
 	for {
 		if s.conn == nil {
 			if err := s.connect(addr); err != nil {
-				s.log.Warnf("statsd connection error: %s", err)
+				s.log.Warnf("connection error: %s", err)
 
 				// If the previous reconnect attempt failed, drain the flush
 				// queue to prevent Flush() from blocking indefinitely.
@@ -400,7 +407,7 @@ func (b *buffer) WriteString(s string) {
 // This is named WriteChar instead of WriteByte because the 'stdmethods' check
 // of 'go vet' wants WriteByte to have the signature:
 //
-// 	func (b *buffer) WriteByte(c byte) error { ... }
+//	func (b *buffer) WriteByte(c byte) error { ... }
 //
 func (b *buffer) WriteChar(c byte) {
 	*b = append(*b, c)

net_sink_test.go

@@ -17,10 +17,12 @@ import (
 	"sync/atomic"
 	"testing"
 	"time"
-
-	logger "github.com/sirupsen/logrus"
 )
 
+func foreverNow() time.Time {
+	return time.Date(2022, 1, 1, 0, 0, 0, 0, time.UTC)
+}
+
 type testStatSink struct {
 	sync.Mutex
 	record string
@@ -542,10 +544,8 @@ func TestNetSink_DrainFlushQueue(t *testing.T) {
 	}
 }
 
-func discardLogger() *logger.Logger {
-	log := logger.New()
-	log.Out = ioutil.Discard
-	return log
+func discardLogger() *loggingSink {
+	return &loggingSink{writer: ioutil.Discard, now: foreverNow}
 }
 
 func setupTestNetSink(t *testing.T, protocol string, stop bool) (*netTestSink, *netSink) {

stats.go

@@ -7,7 +7,6 @@ import (
 	"time"
 
 	tagspkg "github.com/lyft/gostats/internal/tags"
-	logger "github.com/sirupsen/logrus"
 )
 
 // A Store holds statistics.
@@ -200,7 +199,6 @@ func NewDefaultStore() Store {
 	var newStore Store
 	settings := GetSettings()
 	if !settings.UseStatsd {
-		logger.Warn("statsd is not in use")
 		if settings.LoggingSinkDisabled {
 			newStore = NewStore(NewNullSink(), false)
 		} else {