add proper logging to connect service (#257)

connect/connect.go

@@ -2,7 +2,6 @@ package connect
 
 import (
 	"context"
-	"fmt"
 
 	"github.com/micromdm/mdm"
 	"github.com/pkg/errors"
@@ -39,7 +38,6 @@ func New(queue Queue, pub pubsub.Publisher) (ConnectService, error) {
 }
 
 func (svc *connectSvc) Acknowledge(ctx context.Context, req mdm.Response) (payload []byte, err error) {
-	fmt.Printf("connected udid=%s type=%s, status=%s\n", req.UDID, req.RequestType, req.Status)
 	event := NewEvent(req)
 	msg, err := MarshalEvent(event)
 	if err != nil {
@@ -48,6 +46,7 @@ func (svc *connectSvc) Acknowledge(ctx context.Context, req mdm.Response) (paylo
 	if err := svc.pub.Publish(context.TODO(), ConnectTopic, msg); err != nil {
 		return nil, errors.Wrap(err, "publish connect Response on pubsub")
 	}
+
 	cmd, err := svc.queue.Next(ctx, req)
 	if err != nil {
 		return nil, errors.Wrap(err, "calling Next with mdm response")

connect/logging.go

@@ -0,0 +1,38 @@
+package connect
+
+import (
+	"context"
+	"time"
+
+	"github.com/go-kit/kit/log"
+	"github.com/micromdm/mdm"
+)
+
+type loggingMiddleware struct {
+	logger log.Logger
+	next   ConnectService
+}
+
+func NewLoggingService(svc ConnectService, logger log.Logger) loggingMiddleware {
+	return loggingMiddleware{
+		next:   svc,
+		logger: logger,
+	}
+}
+
+func (mw loggingMiddleware) Acknowledge(ctx context.Context, req mdm.Response) (payload []byte, err error) {
+	defer func(begin time.Time) {
+		_ = mw.logger.Log(
+			"method", "Acknowledge",
+			"udid", req.UDID,
+			"command_uuid", req.CommandUUID,
+			"status", req.Status,
+			"request_type", req.RequestType,
+			"err", err,
+			"took", time.Since(begin),
+		)
+	}(time.Now())
+
+	payload, err = mw.next.Acknowledge(ctx, req)
+	return
+}

serve.go

@@ -27,6 +27,7 @@ import (
 	"github.com/boltdb/bolt"
 	"github.com/go-kit/kit/endpoint"
 	"github.com/go-kit/kit/log"
+	"github.com/go-kit/kit/log/level"
 	httptransport "github.com/go-kit/kit/transport/http"
 	"github.com/gorilla/mux"
 	"github.com/pkg/errors"
@@ -142,7 +143,7 @@ func serve(args []string) error {
 	sm.setupCheckinService()
 	sm.setupPushService()
 	sm.setupCommandService()
-	sm.setupCommandQueue()
+	sm.setupCommandQueue(logger)
 	sm.setupDEPSync()
 	if sm.err != nil {
 		stdlog.Fatal(sm.err)
@@ -489,7 +490,7 @@ func (c *config) setupCommandService() {
 	c.commandService, c.err = command.New(c.db, c.pubclient)
 }
 
-func (c *config) setupCommandQueue() {
+func (c *config) setupCommandQueue(logger log.Logger) {
 	if c.err != nil {
 		return
 	}
@@ -499,12 +500,20 @@ func (c *config) setupCommandQueue() {
 		return
 	}
 
-	connSvc, err := connect.New(q, c.pubclient)
-	if err != nil {
-		c.err = err
-		return
+	var connectService connect.ConnectService
+	{
+		svc, err := connect.New(q, c.pubclient)
+		if err != nil {
+			c.err = err
+			return
+		}
+		svc = connect.NewLoggingService(
+			svc,
+			log.With(level.Info(logger), "component", "connect"),
+		)
+		connectService = svc
 	}
-	c.connectService = connSvc
+	c.connectService = connectService
 }
 
 func (c *config) setupCheckinService() {