added logging library

exporter/BUILD

@@ -7,6 +7,7 @@ go_library(
     deps = [
         "//exporter/db",
         "//exporter/collectors",
+        "//exporter/logging",
         "//third_party/go:prometheus-client",
         "//third_party/go:x_sync",
     ],

exporter/collectors/BUILD

@@ -10,6 +10,7 @@ go_library(
     visibility = ["PUBLIC"],
     deps = [
         "//exporter/db",
+        "//exporter/logging",
         "//third_party/go:prometheus-client",
         "//third_party/go:x_sync",
     ],

exporter/collectors/collector.go

@@ -2,9 +2,12 @@ package collectors
 
 import (
 	"github.com/odonate/postgres-exporter/exporter/db"
+	"github.com/odonate/postgres-exporter/exporter/logging"
 	"github.com/prometheus/client_golang/prometheus"
 )
 
+var log = logging.NewLogger()
+
 const (
 	namespace   = "pg_stat"
 	namespaceIO = "pg_statio"

exporter/collectors/pg_locks.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 	"sync"
+	"time"
 
 	"github.com/odonate/postgres-exporter/exporter/db"
 	"github.com/prometheus/client_golang/prometheus"
@@ -47,6 +48,8 @@ func (c *PgLocksCollector) Collect(ch chan<- prometheus.Metric) {
 
 // Scrape implements our Scraper interface.
 func (c *PgLocksCollector) Scrape(ch chan<- prometheus.Metric) error {
+	start := time.Now()
+	defer log.Infof("lock scrape took %dms", time.Now().Sub(start).Milliseconds())
 	group := errgroup.Group{}
 	for _, dbClient := range c.dbClients {
 		dbClient := dbClient

exporter/collectors/pg_stat_activity.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 	"sync"
+	"time"
 
 	"github.com/odonate/postgres-exporter/exporter/db"
 	"github.com/prometheus/client_golang/prometheus"
@@ -55,6 +56,8 @@ func (c *PgStatActivityCollector) Collect(ch chan<- prometheus.Metric) {
 
 // Scrape implements our Scraper interfacc.
 func (c *PgStatActivityCollector) Scrape(ch chan<- prometheus.Metric) error {
+	start := time.Now()
+	defer log.Infof("activity scrape took %dms", time.Now().Sub(start).Milliseconds())
 	group := errgroup.Group{}
 	for _, dbClient := range c.dbClients {
 		dbClient := dbClient

exporter/collectors/pg_stat_statements.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"strconv"
 	"sync"
+	"time"
 
 	"github.com/odonate/postgres-exporter/exporter/db"
 	"github.com/prometheus/client_golang/prometheus"
@@ -192,6 +193,8 @@ func (c *PgStatStatementsCollector) Collect(ch chan<- prometheus.Metric) {
 
 // Scrape implements our Scraper interfacc.
 func (c *PgStatStatementsCollector) Scrape(ch chan<- prometheus.Metric) error {
+	start := time.Now()
+	defer log.Infof("statement scrape took %dms", time.Now().Sub(start).Milliseconds())
 	group := errgroup.Group{}
 	for _, dbClient := range c.dbClients {
 		dbClient := dbClient

exporter/collectors/pg_stat_user_table.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 	"sync"
+	"time"
 
 	"github.com/odonate/postgres-exporter/exporter/db"
 	"github.com/prometheus/client_golang/prometheus"
@@ -190,6 +191,8 @@ func (c *PgStatUserTableCollector) Collect(ch chan<- prometheus.Metric) {
 
 // Scrape implements our Scraper interfacc.
 func (c *PgStatUserTableCollector) Scrape(ch chan<- prometheus.Metric) error {
+	start := time.Now()
+	defer log.Infof("user table scrape took %dms", time.Now().Sub(start).Milliseconds())
 	group := errgroup.Group{}
 	for _, dbClient := range c.dbClients {
 		dbClient := dbClient

exporter/exporter.go

@@ -4,13 +4,17 @@ import (
 	"context"
 	"fmt"
 	"sync"
+	"time"
 
 	"github.com/odonate/postgres-exporter/exporter/collectors"
 	"github.com/odonate/postgres-exporter/exporter/db"
+	"github.com/odonate/postgres-exporter/exporter/logging"
 	"github.com/prometheus/client_golang/prometheus"
 	"golang.org/x/sync/errgroup"
 )
 
+var log = logging.NewLogger()
+
 const namespace = "pg_stat"
 
 // Opts for the exporter.
@@ -102,6 +106,8 @@ func (e *Exporter) Describe(ch chan<- *prometheus.Desc) {
 
 // Collect implements the promtheus.Collector.
 func (e *Exporter) Collect(ch chan<- prometheus.Metric) {
+	start := time.Now()
+	defer log.Infof("exporter collect took %dms", time.Now().Sub(start).Milliseconds())
 	e.mutex.Lock()
 	defer e.mutex.Unlock()
 

exporter/logging/BUILD

@@ -0,0 +1,11 @@
+go_library(
+    name = "logging",
+    srcs = [
+        "formatter.go",
+        "logging.go",
+    ],
+    visibility = ["PUBLIC"],
+    deps = [
+        "//third_party/go:logrus",
+    ],
+)

exporter/logging/formatter.go

@@ -0,0 +1,55 @@
+package logging
+
+import (
+	"path/filepath"
+	"strconv"
+	"strings"
+	"time"
+
+	"github.com/sirupsen/logrus"
+)
+
+const (
+	// Default log format - rich.
+	richLogFormat = "%time%:%file%:%line%# [%level%] - %message%\n"
+
+	// Raw log format - plain.
+	rawLogFormat = "%message%\n"
+
+	// Default timestamp format
+	defaultTimestampFormat = time.StampNano
+)
+
+// Formatter implements the logrus.Formatter interface.
+// It has a very nice
+type Formatter struct {
+	// Timestamp format
+	TimestampFormat string
+	// Available standard keys: time, msg, lvl
+	// Also can include custom fields but limited to strings.
+	// All of fields need to be wrapped inside %% i.e %time% %msg%
+	LogFormat string
+}
+
+// Format implements a logrus formatter's Format method.
+func (f *Formatter) Format(entry *logrus.Entry) ([]byte, error) {
+	output := f.LogFormat
+	timestampFormat := f.TimestampFormat
+	if timestampFormat == "" {
+		timestampFormat = defaultTimestampFormat
+	}
+
+	output = strings.Replace(output, "%time%", entry.Time.Format(timestampFormat), 1)
+	output = strings.Replace(output, "%file%", filepath.Base(entry.Caller.File), 1)
+	output = strings.Replace(output, "%line%", strconv.Itoa(entry.Caller.Line), 1)
+	output = strings.Replace(output, "%message%", entry.Message, 1)
+	output = strings.Replace(output, "%level%", strings.ToUpper(entry.Level.String()), 1)
+
+	for k, v := range entry.Data {
+		if s, ok := v.(string); ok {
+			output = strings.Replace(output, "%"+k+"%", s, 1)
+		}
+	}
+
+	return []byte(output), nil
+}

exporter/logging/logging.go

@@ -0,0 +1,56 @@
+package logging
+
+import (
+	"os"
+
+	"github.com/sirupsen/logrus"
+)
+
+const (
+	// PanicLevel level, highest level of severity. Logs and then calls panic with the message passed to Debug, Info, ...
+	PanicLevel Level = iota
+	// FatalLevel level. Logs and then calls `logger.Exit(1)`. It will exit even if the logging level is set to Panic.
+	FatalLevel
+	// ErrorLevel level. Logs. Used for errors that should definitely be noted.
+	// Commonly used for hooks to send errors to an error tracking service.
+	ErrorLevel
+	// WarnLevel level. Non-critical entries that deserve eyes.
+	WarnLevel
+	// InfoLevel level. General operational entries about what's going on inside the application.
+	InfoLevel
+	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
+	DebugLevel
+	// TraceLevel level. Designates finer-grained informational events than the Debug.
+	TraceLevel
+)
+
+// Level represents the logger's logging severity level.
+type Level int
+
+var levels = map[Level]logrus.Level{
+	PanicLevel: logrus.PanicLevel,
+	FatalLevel: logrus.FatalLevel,
+	ErrorLevel: logrus.ErrorLevel,
+	WarnLevel:  logrus.WarnLevel,
+	InfoLevel:  logrus.InfoLevel,
+	DebugLevel: logrus.DebugLevel,
+	TraceLevel: logrus.TraceLevel,
+}
+
+// Logger is a wrapper around logrus. It is used by all micro-services for logging purposes.
+type Logger struct {
+	*logrus.Logger
+}
+
+// NewLogger returns a new logger
+func NewLogger() *Logger {
+	logrusLogger := &logrus.Logger{
+		Out: os.Stderr,
+		Formatter: &Formatter{
+			LogFormat: richLogFormat,
+		},
+		Level:        logrus.InfoLevel,
+		ReportCaller: true,
+	}
+	return &Logger{logrusLogger}
+}