use structured logging

cmd/openldap_exporter/main.go

@@ -2,14 +2,14 @@ package main
 
 import (
 	"context"
-	"log"
 	"os"
 	"os/signal"
 	"syscall"
 	"time"
 
 	exporter "github.com/tomcz/openldap_exporter"
 
+	log "github.com/sirupsen/logrus"
 	"github.com/urfave/cli/v2"
 	"github.com/urfave/cli/v2/altsrc"
 	"golang.org/x/sync/errgroup"
@@ -88,9 +88,11 @@ func main() {
 		Flags:           flags,
 		Action:          runMain,
 	}
+	log.Info("service starting")
 	if err := app.Run(os.Args); err != nil {
-		log.Fatalln(err)
+		log.WithError(err).Fatal("service failed")
 	}
+	log.Info("service stopped")
 }
 
 func optionalYamlSourceFunc(flagFileName string) func(context *cli.Context) (altsrc.InputSourceContext, error) {
@@ -118,12 +120,10 @@ func runMain(c *cli.Context) error {
 	var group errgroup.Group
 	group.Go(func() error {
 		defer cancel()
-		log.Printf("starting Prometheus HTTP metrics server on %s\n", c.String(promAddr))
 		return server.Start()
 	})
 	group.Go(func() error {
 		defer cancel()
-		log.Printf("starting OpenLDAP scraper for %s://%s\n", scraper.Net, scraper.Addr)
 		return scraper.Start(ctx)
 	})
 	group.Go(func() error {
@@ -135,7 +135,7 @@ func runMain(c *cli.Context) error {
 		signal.Notify(signalChan, syscall.SIGINT, syscall.SIGTERM)
 		select {
 		case <-signalChan:
-			log.Println("shutdown received")
+			log.Info("shutdown received")
 			return nil
 		case <-ctx.Done():
 			return nil

go.mod

@@ -6,6 +6,7 @@ require (
 	github.com/go-kit/kit v0.10.0
 	github.com/prometheus/client_golang v1.7.1
 	github.com/prometheus/exporter-toolkit v0.5.1
+	github.com/sirupsen/logrus v1.6.0
 	github.com/urfave/cli/v2 v2.2.0
 	golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e
 	gopkg.in/asn1-ber.v1 v1.0.0-20181015200546-f715ec2f112d // indirect

go.sum

@@ -144,6 +144,7 @@ github.com/julienschmidt/httprouter v1.3.0/go.mod h1:JR6WtHb+2LUe8TCKY3cZOxFyyO8
 github.com/kisielk/errcheck v1.1.0/go.mod h1:EZBBE59ingxPouuu3KfxchcWSUPOHkagtvWXihfKN4Q=
 github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck=
 github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
+github.com/konsorten/go-windows-terminal-sequences v1.0.3 h1:CE8S1cTafDpPvMhIxNJKvHsGVBgn1xWYf1NbHQhywc8=
 github.com/konsorten/go-windows-terminal-sequences v1.0.3/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
 github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc=
 github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI=
@@ -250,6 +251,7 @@ github.com/shurcooL/sanitized_anchor_name v1.0.0 h1:PdmoCO6wvbs+7yrJyMORt4/BmY5I
 github.com/shurcooL/sanitized_anchor_name v1.0.0/go.mod h1:1NzhyTcUVG4SuEtjjoZeVRXNmyL/1OwPU0+IJeTBvfc=
 github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
 github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
+github.com/sirupsen/logrus v1.6.0 h1:UBcNElsrwanuuMsnGSlYmtmgbb23qDR5dG+6X6Oo89I=
 github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88=
 github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=
 github.com/smartystreets/goconvey v1.6.4/go.mod h1:syvi0/a8iFYH4r/RixwvyeAJjdLS9QV7WQ/tjFTllLA=

scraper.go

@@ -3,12 +3,12 @@ package openldap_exporter
 import (
 	"context"
 	"fmt"
-	"log"
 	"strconv"
 	"strings"
 	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
+	log "github.com/sirupsen/logrus"
 	"gopkg.in/ldap.v2"
 )
 
@@ -111,9 +111,13 @@ type Scraper struct {
 	User string
 	Pass string
 	Tick time.Duration
+	log  log.FieldLogger
 }
 
 func (s *Scraper) Start(ctx context.Context) error {
+	s.log = log.WithField("component", "scraper")
+	address := fmt.Sprintf("%s://%s", s.Net, s.Addr)
+	s.log.WithField("addr", address).Info("starting monitor loop")
 	ticker := time.NewTicker(s.Tick)
 	for {
 		select {
@@ -136,23 +140,23 @@ func (s *Scraper) runOnce() {
 func (s *Scraper) scrape() bool {
 	l, err := ldap.Dial(s.Net, s.Addr)
 	if err != nil {
-		log.Printf("dial failed: %v\n", err)
+		s.log.WithError(err).Error("dial failed")
 		return false
 	}
 	defer l.Close()
 
 	if s.User != "" && s.Pass != "" {
 		err = l.Bind(s.User, s.Pass)
 		if err != nil {
-			log.Printf("bind failed: %v\n", err)
+			s.log.WithError(err).Error("bind failed")
 			return false
 		}
 	}
 
 	ret := true
 	for _, q := range queries {
 		if err := scrapeQuery(l, q); err != nil {
-			log.Printf("query failed: %v\n", err)
+			s.log.WithError(err).Warn("query failed")
 			ret = false
 		}
 	}

server.go

@@ -4,14 +4,13 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"log"
 	"net/http"
-	"strings"
 	"time"
 
 	kitlog "github.com/go-kit/kit/log"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"github.com/prometheus/exporter-toolkit/web"
+	log "github.com/sirupsen/logrus"
 )
 
 var commit string
@@ -23,29 +22,17 @@ func GetVersion() string {
 
 type Server struct {
 	server  *http.Server
+	logger  log.FieldLogger
 	cfgPath string
 }
 
-func (s *Server) Start() error {
-	err := web.ListenAndServe(s.server, s.cfgPath, kitlog.LoggerFunc(logger))
-	if errors.Is(err, http.ErrServerClosed) {
-		return nil
-	}
-	return err
-}
-
-func (s *Server) Stop() {
-	ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond)
-	s.server.Shutdown(ctx)
-	cancel()
-}
-
 func NewMetricsServer(bindAddr, metricsPath, tlsConfigPath string) *Server {
 	mux := http.NewServeMux()
 	mux.Handle(metricsPath, promhttp.Handler())
 	mux.HandleFunc("/version", showVersion)
 	return &Server{
 		server:  &http.Server{Addr: bindAddr, Handler: mux},
+		logger:  log.WithField("component", "server"),
 		cfgPath: tlsConfigPath,
 	}
 }
@@ -59,20 +46,53 @@ func showVersion(w http.ResponseWriter, r *http.Request) {
 	fmt.Fprintln(w, GetVersion())
 }
 
-func logger(kvs ...interface{}) error {
+func (s *Server) Start() error {
+	s.logger.WithField("addr", s.server.Addr).Info("starting http listener")
+	err := web.ListenAndServe(s.server, s.cfgPath, kitlog.LoggerFunc(s.adaptor))
+	if errors.Is(err, http.ErrServerClosed) {
+		return nil
+	}
+	return err
+}
+
+func (s *Server) Stop() {
+	ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond)
+	s.server.Shutdown(ctx)
+	cancel()
+}
+
+func (s *Server) adaptor(kvs ...interface{}) error {
 	if len(kvs) == 0 {
 		return nil
 	}
 	if len(kvs)%2 != 0 {
 		kvs = append(kvs, nil)
 	}
-	var buf strings.Builder
+	fields := log.Fields{}
 	for i := 0; i < len(kvs); i += 2 {
-		if i > 0 {
-			buf.WriteString(" ")
-		}
-		fmt.Fprintf(&buf, "%v=%v", kvs[i], kvs[i+1])
+		key := fmt.Sprint(kvs[i])
+		fields[key] = kvs[i+1]
+	}
+	msg := ""
+	if val, ok := fields["msg"]; ok {
+		delete(fields, "msg")
+		msg = fmt.Sprint(val)
+	}
+	level := "info"
+	if val, ok := fields["level"]; ok {
+		delete(fields, "level")
+		level = fmt.Sprint(val)
+	}
+	ll := s.logger.WithFields(fields)
+	switch level {
+	case "error":
+		ll.Error(msg)
+	case "warn":
+		ll.Warn(msg)
+	case "debug":
+		ll.Debug(msg)
+	default:
+		ll.Info(msg)
 	}
-	log.Println(buf.String())
 	return nil
 }