adding new environmental variables for added debugging: COLLECTOR_LOG_FILE, COLLECTOR_DEBUG, DEBUG, SCRUTINY_LOG_FILE, SCRUTINY_DEBUG

webapp/backend/pkg/web/middleware/logger.go

@@ -0,0 +1,93 @@
+package middleware
+
+import (
+	"bytes"
+	"fmt"
+	"github.com/gin-gonic/gin"
+	"github.com/sirupsen/logrus"
+	"math"
+	"net/http"
+	"os"
+	"strings"
+	"time"
+)
+
+// Middleware based on https://github.com/toorop/gin-logrus/blob/master/logger.go
+// Body recording based on
+// - https://github.com/gin-gonic/gin/issues/1363
+// - https://stackoverflow.com/questions/38501325/how-to-log-response-body-in-gin
+
+// 2016-09-27 09:38:21.541541811 +0200 CEST
+// 127.0.0.1 - frank [10/Oct/2000:13:55:36 -0700]
+// "GET /apache_pb.gif HTTP/1.0" 200 2326
+// "http://www.example.com/start.html"
+// "Mozilla/4.08 [en] (Win98; I ;Nav)"
+
+var timeFormat = "02/Jan/2006:15:04:05 -0700"
+
+// Logger is the logrus logger handler
+func LoggerMiddleware(logger logrus.FieldLogger) gin.HandlerFunc {
+
+	hostname, err := os.Hostname()
+	if err != nil {
+		hostname = "unknow"
+	}
+
+	return func(c *gin.Context) {
+		// other handler can change c.Path so:
+		path := c.Request.URL.Path
+		blw := &bodyLogWriter{body: &bytes.Buffer{}, ResponseWriter: c.Writer}
+		c.Writer = blw
+		start := time.Now()
+		c.Next()
+		stop := time.Since(start)
+		latency := int(math.Ceil(float64(stop.Nanoseconds()) / 1000000.0))
+		statusCode := c.Writer.Status()
+		clientIP := c.ClientIP()
+		clientUserAgent := c.Request.UserAgent()
+		referer := c.Request.Referer()
+		dataLength := c.Writer.Size()
+		if dataLength < 0 {
+			dataLength = 0
+		}
+
+		entry := logger.WithFields(logrus.Fields{
+			"hostname":   hostname,
+			"statusCode": statusCode,
+			"latency":    latency, // time to process
+			"clientIP":   clientIP,
+			"method":     c.Request.Method,
+			"path":       path,
+			"referer":    referer,
+			"dataLength": dataLength,
+			"userAgent":  clientUserAgent,
+		})
+
+		if len(c.Errors) > 0 {
+			entry.Error(c.Errors.ByType(gin.ErrorTypePrivate).String())
+		} else {
+			msg := fmt.Sprintf("%s - %s [%s] \"%s %s\" %d %d \"%s\" \"%s\" (%dms)", clientIP, hostname, time.Now().Format(timeFormat), c.Request.Method, path, statusCode, dataLength, referer, clientUserAgent, latency)
+			if statusCode >= http.StatusInternalServerError {
+				entry.Error(msg)
+			} else if statusCode >= http.StatusBadRequest {
+				entry.Warn(msg)
+			} else {
+				entry.Info(msg)
+			}
+		}
+		if strings.HasPrefix(path, "/api/") {
+			//only debug log request/response from api endpoint.
+			entry.Debugln(blw.body.String())
+		}
+	}
+}
+
+type bodyLogWriter struct {
+	gin.ResponseWriter
+	body *bytes.Buffer
+}
+
+func (w bodyLogWriter) Write(b []byte) (int, error) {
+	w.body.Write(b)
+	return w.ResponseWriter.Write(b)
+}

webapp/backend/pkg/web/middleware/sqlite3.go

@@ -2,21 +2,23 @@ package middleware
 
 import (
 	"fmt"
+	"github.com/analogj/scrutiny/webapp/backend/pkg/config"
 	"github.com/analogj/scrutiny/webapp/backend/pkg/models/db"
 	"github.com/gin-gonic/gin"
 	"github.com/jinzhu/gorm"
 	_ "github.com/jinzhu/gorm/dialects/sqlite"
+	"github.com/sirupsen/logrus"
 )
 
-func DatabaseMiddleware(dbPath string) gin.HandlerFunc {
+func DatabaseMiddleware(appConfig config.Interface, logger logrus.FieldLogger) gin.HandlerFunc {
 	//var database *gorm.DB
-	fmt.Printf("Trying to connect to database stored: %s", dbPath)
-	database, err := gorm.Open("sqlite3", dbPath)
-
+	fmt.Printf("Trying to connect to database stored: %s\n", appConfig.GetString("web.database.location"))
+	database, err := gorm.Open("sqlite3", appConfig.GetString("web.database.location"))
 	if err != nil {
 		panic("Failed to connect to database!")
 	}
 
+	database.SetLogger(&GormLogger{Logger: logger})
 	database.AutoMigrate(&db.Device{})
 	database.AutoMigrate(&db.SelfTest{})
 	database.AutoMigrate(&db.Smart{})
@@ -30,3 +32,24 @@ func DatabaseMiddleware(dbPath string) gin.HandlerFunc {
 		c.Next()
 	}
 }
+
+// GormLogger is a custom logger for Gorm, making it use logrus.
+type GormLogger struct{ Logger logrus.FieldLogger }
+
+// Print handles log events from Gorm for the custom logger.
+func (gl *GormLogger) Print(v ...interface{}) {
+	switch v[0] {
+	case "sql":
+		gl.Logger.WithFields(
+			logrus.Fields{
+				"module":  "gorm",
+				"type":    "sql",
+				"rows":    v[5],
+				"src_ref": v[1],
+				"values":  v[4],
+			},
+		).Debug(v[3])
+	case "log":
+		gl.Logger.WithFields(logrus.Fields{"module": "gorm", "type": "log"}).Print(v[2])
+	}
+}