From 6fa241336305c71bd7689cb16c7013ab4baf65a2 Mon Sep 17 00:00:00 2001
From: Zachary Wasserman <zachwass2000@gmail.com>
Date: Wed, 3 Aug 2016 08:01:59 -0700
Subject: [PATCH] Add logging and convenience methods (#34)

* Add request logging.
* Catch/log panic in request handlers.
* Add `mustGetDB` method that gets a DB connection or panics. This can simplify
  boilerplate in handlers.
* Consolidate `file` and `line` in logged fields to `location`.
* Set default log level to `WarnLevel`.
* Log a warning when Kolide is started with the example config.
* Turn on DB logging in debug mode.
---
 kolide.go |  6 ++++--
 models.go | 28 ++++++++++++++++++++++++++++
 server.go | 20 ++++++++++++++++++++
 3 files changed, 52 insertions(+), 2 deletions(-)

diff --git a/kolide.go b/kolide.go
index cc7505923..b93258de1 100644
--- a/kolide.go
+++ b/kolide.go
@@ -67,9 +67,8 @@ func (hook logContextHook) Fire(entry *logrus.Entry) error {
 	if pc, file, line, ok := runtime.Caller(8); ok {
 		funcName := runtime.FuncForPC(pc).Name()
 
-		entry.Data["file"] = path.Base(file)
 		entry.Data["func"] = path.Base(funcName)
-		entry.Data["line"] = line
+		entry.Data["location"] = fmt.Sprintf("%s:%d", path.Base(file), line)
 	}
 
 	return nil
@@ -87,6 +86,8 @@ func main() {
 	// configure the application based on the flags that have been set
 	if *debug {
 		logrus.SetLevel(logrus.DebugLevel)
+	} else {
+		logrus.SetLevel(logrus.WarnLevel)
 	}
 
 	if *logJson {
@@ -100,6 +101,7 @@ func main() {
 		if _, err = os.Stat("./tools/example_config.json"); err == nil {
 			*configPath = "./tools/example_config.json"
 		}
+		logrus.Warn("Using example config. These settings should be used for development only!")
 	}
 
 	// if the user has defined a config path OR the example config is found
diff --git a/models.go b/models.go
index 8c9d650d3..8d22eec32 100644
--- a/models.go
+++ b/models.go
@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"time"
 
+	"github.com/Sirupsen/logrus"
 	"github.com/jinzhu/gorm"
 
 	"github.com/gin-gonic/gin"
@@ -183,9 +184,35 @@ var tables = [...]interface{}{
 	&DistributedQueryExecution{},
 }
 
+func setDBSettings(db *gorm.DB) {
+	// Tell gorm to use the logrus logger
+	db.SetLogger(logrus.StandardLogger())
+
+	// If debug mode is enabled, tell gorm to turn on logmode (log each
+	// query as it is executed)
+	if debug != nil && *debug {
+		db.LogMode(true)
+	}
+}
+
 func openDB(user, password, address, dbName string) (*gorm.DB, error) {
 	connectionString := fmt.Sprintf("%s:%s@(%s)/%s?charset=utf8&parseTime=True&loc=Local", user, password, address, dbName)
 	return gorm.Open("mysql", connectionString)
+	db, err := gorm.Open("mysql", connectionString)
+	if err != nil {
+		return nil, err
+	}
+	setDBSettings(db)
+	return db, nil
+}
+
+/// Open a database connection, or panic
+func mustOpenDB(user, password, address, dbName string) *gorm.DB {
+	db, err := openDB(user, password, address, dbName)
+	if err != nil {
+		panic(fmt.Sprintf("Could not connect to DB: %s", err.Error()))
+	}
+	return db
 }
 
 func openTestDB() (*gorm.DB, error) {
@@ -194,6 +221,7 @@ func openTestDB() (*gorm.DB, error) {
 		return nil, err
 	}
 
+	setDBSettings(db)
 	createTables(db)
 	return db, db.Error
 }
diff --git a/server.go b/server.go
index dcd009b88..5a0daad0d 100644
--- a/server.go
+++ b/server.go
@@ -1,6 +1,10 @@
 package main
 
 import (
+	"time"
+
+	"github.com/Sirupsen/logrus"
+	"github.com/gin-gonic/contrib/ginrus"
 	"github.com/gin-gonic/gin"
 )
 
@@ -44,6 +48,22 @@ func CreateServer() *gin.Engine {
 	server := gin.New()
 	server.Use(ProductionDatabaseMiddleware)
 
+	// TODO: The following loggers are not synchronized with each other or
+	// logrus.StandardLogger() used through the rest of the codebase. As
+	// such, their output may become intermingled.
+	// See https://github.com/Sirupsen/logrus/issues/391
+
+	// Ginrus middleware logs details about incoming requests using the
+	// logrus WithFields
+	requestLogger := logrus.New()
+	server.Use(ginrus.Ginrus(requestLogger, time.RFC3339, false))
+
+	// Recovery middleware recovers from panic(), returning a 500 response
+	// code and printing the panic information to the log
+	recoveryLogger := logrus.New()
+	recoveryLogger.WriterLevel(logrus.ErrorLevel)
+	server.Use(gin.RecoveryWithWriter(recoveryLogger.Writer()))
+
 	v1 := server.Group("/api/v1")
 
 	// Kolide application API endpoints