Skip to content

Commit

Permalink
MF-174 - Add logger interface and go-kit logger implementation (#212)
Browse files Browse the repository at this point in the history
* Add logger interface and go-kit logger implementation

Add wrapper logger interface and wrap go-kit logger in it. Add
tests for info, warn, error and log methods. Add log filtering by
level.

Signed-off-by: Aleksandar Novakovic <anovakovic01@gmail.com>

* Refactor logger and replace go-kit logger with wrapper

Replace go-kit logger from services with logger wrapper. Refactor
code in logger wrapper. Remove unnecessary subpackage, methods and
log levels.

Signed-off-by: Aleksandar Novakovic <anovakovic01@gmail.com>
  • Loading branch information
anovakovic01 authored and mijicd committed Apr 4, 2018
1 parent 301d855 commit 88b3062
Show file tree
Hide file tree
Showing 10 changed files with 298 additions and 145 deletions.
12 changes: 6 additions & 6 deletions cmd/http/main.go
Expand Up @@ -7,12 +7,12 @@ import (
"os/signal"
"syscall"

"github.com/go-kit/kit/log"
kitprometheus "github.com/go-kit/kit/metrics/prometheus"
"github.com/mainflux/mainflux"
adapter "github.com/mainflux/mainflux/http"
"github.com/mainflux/mainflux/http/api"
"github.com/mainflux/mainflux/http/nats"
log "github.com/mainflux/mainflux/logger"
manager "github.com/mainflux/mainflux/manager/client"
broker "github.com/nats-io/go-nats"
stdprometheus "github.com/prometheus/client_golang/prometheus"
Expand Down Expand Up @@ -40,12 +40,11 @@ func main() {
Port: mainflux.Env(envPort, defPort),
}

logger := log.NewJSONLogger(log.NewSyncWriter(os.Stdout))
logger = log.With(logger, "ts", log.DefaultTimestampUTC)
logger := log.New(os.Stdout)

nc, err := broker.Connect(cfg.NatsURL)
if err != nil {
logger.Log("error", err)
logger.Error(fmt.Sprintf("Failed to connect to NATS: %s", err))
os.Exit(1)
}
defer nc.Close()
Expand Down Expand Up @@ -75,7 +74,7 @@ func main() {
go func() {
p := fmt.Sprintf(":%s", cfg.Port)
mc := manager.NewClient(cfg.ManagerURL)
logger.Log("message", fmt.Sprintf("HTTP adapter service started, exposed port %s", cfg.Port))
logger.Info(fmt.Sprintf("HTTP adapter service started, exposed port %s", cfg.Port))
errs <- http.ListenAndServe(p, api.MakeHandler(svc, mc))
}()

Expand All @@ -85,5 +84,6 @@ func main() {
errs <- fmt.Errorf("%s", <-c)
}()

logger.Log("terminated", <-errs)
err = <-errs
logger.Error(fmt.Sprintf("HTTP adapter terminated: %s", err))
}
12 changes: 6 additions & 6 deletions cmd/manager/main.go
Expand Up @@ -7,9 +7,9 @@ import (
"os/signal"
"syscall"

"github.com/go-kit/kit/log"
kitprometheus "github.com/go-kit/kit/metrics/prometheus"
"github.com/mainflux/mainflux"
log "github.com/mainflux/mainflux/logger"
"github.com/mainflux/mainflux/manager"
"github.com/mainflux/mainflux/manager/api"
"github.com/mainflux/mainflux/manager/bcrypt"
Expand Down Expand Up @@ -56,12 +56,11 @@ func main() {
Secret: mainflux.Env(envSecret, defSecret),
}

logger := log.NewJSONLogger(log.NewSyncWriter(os.Stdout))
logger = log.With(logger, "ts", log.DefaultTimestampUTC)
logger := log.New(os.Stdout)

db, err := postgres.Connect(cfg.DBHost, cfg.DBPort, cfg.DBName, cfg.DBUser, cfg.DBPass)
if err != nil {
logger.Log("error", err)
logger.Error(fmt.Sprintf("Failed to connect to postgres: %s", err))
os.Exit(1)
}
defer db.Close()
Expand Down Expand Up @@ -94,7 +93,7 @@ func main() {

go func() {
p := fmt.Sprintf(":%s", cfg.Port)
logger.Log("message", fmt.Sprintf("Manager service started, exposed port %s", cfg.Port))
logger.Info(fmt.Sprintf("Manager service started, exposed port %s", cfg.Port))
errs <- http.ListenAndServe(p, api.MakeHandler(svc))
}()

Expand All @@ -104,5 +103,6 @@ func main() {
errs <- fmt.Errorf("%s", <-c)
}()

logger.Log("terminated", <-errs)
err = <-errs
logger.Error(fmt.Sprintf("Manager service terminated: %s", err))
}
13 changes: 7 additions & 6 deletions cmd/normalizer/main.go
Expand Up @@ -7,8 +7,8 @@ import (
"os/signal"
"syscall"

"github.com/go-kit/kit/log"
"github.com/mainflux/mainflux"
log "github.com/mainflux/mainflux/logger"
"github.com/mainflux/mainflux/normalizer"
nats "github.com/nats-io/go-nats"

Expand All @@ -34,12 +34,11 @@ func main() {
Port: mainflux.Env(envPort, defPort),
}

logger := log.NewJSONLogger(log.NewSyncWriter(os.Stdout))
logger = log.With(logger, "ts", log.DefaultTimestampUTC)
logger := log.New(os.Stdout)

nc, err := nats.Connect(cfg.NatsURL)
if err != nil {
logger.Log("error", fmt.Sprintf("Failed to connect: %s", err))
logger.Error(fmt.Sprintf("Failed to connect to NATS: %s", err))
os.Exit(1)
}
defer nc.Close()
Expand All @@ -48,7 +47,7 @@ func main() {

go func() {
p := fmt.Sprintf(":%s", cfg.Port)
logger.Log("message", fmt.Sprintf("Normalizer service started, exposed port %s", cfg.Port))
logger.Info(fmt.Sprintf("Normalizer service started, exposed port %s", cfg.Port))
errs <- http.ListenAndServe(p, normalizer.MakeHandler())
}()

Expand All @@ -73,5 +72,7 @@ func main() {
}, []string{"method"})

normalizer.Subscribe(nc, logger, counter, latency)
logger.Log("terminated", <-errs)

err = <-errs
logger.Error(fmt.Sprintf("Normalizer service terminated: %s", err))
}
15 changes: 9 additions & 6 deletions http/api/logging.go
@@ -1,10 +1,11 @@
package api

import (
"fmt"
"time"

"github.com/go-kit/kit/log"
"github.com/mainflux/mainflux"
log "github.com/mainflux/mainflux/logger"
)

var _ mainflux.MessagePublisher = (*loggingMiddleware)(nil)
Expand All @@ -19,12 +20,14 @@ func LoggingMiddleware(svc mainflux.MessagePublisher, logger log.Logger) mainflu
return &loggingMiddleware{logger, svc}
}

func (lm *loggingMiddleware) Publish(msg mainflux.RawMessage) error {
func (lm *loggingMiddleware) Publish(msg mainflux.RawMessage) (err error) {
defer func(begin time.Time) {
lm.logger.Log(
"method", "publish",
"took", time.Since(begin),
)
message := fmt.Sprintf("Method publish took %s to complete", time.Since(begin))
if err != nil {
lm.logger.Warn(fmt.Sprintf("%s with error: %s.", message, err))
return
}
lm.logger.Info(fmt.Sprintf("%s without errors.", message))
}(time.Now())

return lm.svc.Publish(msg)
Expand Down
3 changes: 3 additions & 0 deletions logger/doc.go
@@ -0,0 +1,3 @@
// Package logger contains logger API definition, wrapper that
// can be used around any other logger.
package logger
23 changes: 23 additions & 0 deletions logger/level.go
@@ -0,0 +1,23 @@
package logger

const (
// Error level is used when logging errors.
Error Level = iota + 1
// Warn level is used when logging warnings.
Warn
// Info level is used when logging info data.
Info
)

// Level represents severity level while logging.
type Level int

var levels = map[Level]string{
Error: "error",
Warn: "warn",
Info: "info",
}

func (lvl Level) String() string {
return levels[lvl]
}
42 changes: 42 additions & 0 deletions logger/logger.go
@@ -0,0 +1,42 @@
package logger

import (
"io"

"github.com/go-kit/kit/log"
)

// Logger specifies logging API.
type Logger interface {
// Info logs any object in JSON format on info level.
Info(string)
// Warn logs any object in JSON format on warning level.
Warn(string)
// Error logs any object in JSON format on error level.
Error(string)
}

var _ Logger = (*logger)(nil)

type logger struct {
kitLogger log.Logger
}

// New returns wrapped go kit logger.
func New(out io.Writer) Logger {
l := log.NewJSONLogger(log.NewSyncWriter(out))
l = log.With(l, "ts", log.DefaultTimestampUTC)
return &logger{l}
}

func (l logger) Info(msg string) {
l.kitLogger.Log("level", Info.String(), "message", msg)
}

func (l logger) Warn(msg string) {
l.kitLogger.Log("level", Warn.String(), "message", msg)
}

func (l logger) Error(msg string) {
l.kitLogger.Log("level", Error.String(), "message", msg)
}
93 changes: 93 additions & 0 deletions logger/logger_test.go
@@ -0,0 +1,93 @@
package logger_test

import (
"encoding/json"
"fmt"
"io"
"testing"

log "github.com/mainflux/mainflux/logger"
"github.com/stretchr/testify/assert"
)

var _ io.Writer = (*mockWriter)(nil)

type mockWriter struct {
value []byte
}

func (writer *mockWriter) Write(p []byte) (int, error) {
writer.value = p
return len(p), nil
}

func (writer *mockWriter) Read() (logMsg, error) {
var output logMsg
err := json.Unmarshal(writer.value, &output)
return output, err
}

type logMsg struct {
Level string `json:"level"`
Message string `json:"message"`
}

func TestInfo(t *testing.T) {
cases := map[string]struct {
input string
output logMsg
}{
"info log ordinary string": {"input_string", logMsg{log.Info.String(), "input_string"}},
"info log empty string": {"", logMsg{log.Info.String(), ""}},
}

writer := mockWriter{}
logger := log.New(&writer)

for desc, tc := range cases {
logger.Info(tc.input)
output, err := writer.Read()
assert.Nil(t, err, fmt.Sprintf("%s: unexpected error %s", desc, err))
assert.Equal(t, tc.output, output, fmt.Sprintf("%s: expected %s got %s", desc, tc.output, output))
}
}

func TestWarn(t *testing.T) {
cases := map[string]struct {
input string
output logMsg
}{
"warn log ordinary string": {"input_string", logMsg{log.Warn.String(), "input_string"}},
"warn log empty string": {"", logMsg{log.Warn.String(), ""}},
}

writer := mockWriter{}
logger := log.New(&writer)

for desc, tc := range cases {
logger.Warn(tc.input)
output, err := writer.Read()
assert.Nil(t, err, fmt.Sprintf("%s: unexpected error %s", desc, err))
assert.Equal(t, tc.output, output, fmt.Sprintf("%s: expected %s got %s", desc, tc.output, output))
}
}

func TestError(t *testing.T) {
cases := map[string]struct {
input string
output logMsg
}{
"error log ordinary string": {"input_string", logMsg{log.Error.String(), "input_string"}},
"error log empty string": {"", logMsg{log.Error.String(), ""}},
}

writer := mockWriter{}
logger := log.New(&writer)

for desc, tc := range cases {
logger.Error(tc.input)
output, err := writer.Read()
assert.Nil(t, err, fmt.Sprintf("%s: unexpected error %s", desc, err))
assert.Equal(t, tc.output, output, fmt.Sprintf("%s: expected %s got %s", desc, tc.output, output))
}
}

0 comments on commit 88b3062

Please sign in to comment.