feat(logging): error logging improvements

pkg/api/common.go

@@ -4,7 +4,6 @@ import (
 	"encoding/json"
 	"net/http"
 
-	"github.com/grafana/grafana/pkg/log"
 	"github.com/grafana/grafana/pkg/metrics"
 	"github.com/grafana/grafana/pkg/middleware"
 	"github.com/grafana/grafana/pkg/setting"
@@ -21,13 +20,15 @@ var (
 )
 
 type Response interface {
-	WriteTo(out http.ResponseWriter)
+	WriteTo(ctx *middleware.Context)
 }
 
 type NormalResponse struct {
 	status     int
 	body       []byte
 	header     http.Header
+	errMessage string
+	err        error
 }
 
 func wrap(action interface{}) macaron.Handler {
@@ -41,17 +42,21 @@ func wrap(action interface{}) macaron.Handler {
 			res = ServerError(err)
 		}
 
-		res.WriteTo(c.Resp)
+		res.WriteTo(c)
 	}
 }
 
-func (r *NormalResponse) WriteTo(out http.ResponseWriter) {
-	header := out.Header()
+func (r *NormalResponse) WriteTo(ctx *middleware.Context) {
+	if r.err != nil {
+		ctx.Logger.Error(r.errMessage, "error", r.err)
+	}
+
+	header := ctx.Resp.Header()
 	for k, v := range r.header {
 		header[k] = v
 	}
-	out.WriteHeader(r.status)
-	out.Write(r.body)
+	ctx.Resp.WriteHeader(r.status)
+	ctx.Resp.Write(r.body)
 }
 
 func (r *NormalResponse) Cache(ttl string) *NormalResponse {
@@ -64,7 +69,6 @@ func (r *NormalResponse) Header(key, value string) *NormalResponse {
 }
 
 // functions to create responses
-
 func Empty(status int) *NormalResponse {
 	return Respond(status, nil)
 }
@@ -80,29 +84,35 @@ func ApiSuccess(message string) *NormalResponse {
 }
 
 func ApiError(status int, message string, err error) *NormalResponse {
-	resp := make(map[string]interface{})
-
-	if err != nil {
-		log.Error(4, "%s: %v", message, err)
-		if setting.Env != setting.PROD {
-			resp["error"] = err.Error()
-		}
-	}
+	data := make(map[string]interface{})
 
 	switch status {
 	case 404:
 		metrics.M_Api_Status_404.Inc(1)
-		resp["message"] = "Not Found"
+		data["message"] = "Not Found"
 	case 500:
 		metrics.M_Api_Status_500.Inc(1)
-		resp["message"] = "Internal Server Error"
+		data["message"] = "Internal Server Error"
 	}
 
 	if message != "" {
-		resp["message"] = message
+		data["message"] = message
+	}
+
+	if err != nil {
+		if setting.Env != setting.PROD {
+			data["error"] = err.Error()
+		}
+	}
+
+	resp := Json(status, data)
+
+	if err != nil {
+		resp.errMessage = message
+		resp.err = err
 	}
 
-	return Json(status, resp)
+	return resp
 }
 
 func Respond(status int, body interface{}) *NormalResponse {

pkg/middleware/logger.go

@@ -48,7 +48,11 @@ func Logger() macaron.Handler {
 
 		if ctx, ok := c.Data["ctx"]; ok {
 			ctxTyped := ctx.(*Context)
+			if status == 500 {
+				ctxTyped.Logger.Error("Request Completed", "method", req.Method, "path", req.URL.Path, "status", status, "remote_addr", c.RemoteAddr(), "time_ns", timeTakenMs, "size", rw.Size())
+			} else {
 				ctxTyped.Logger.Info("Request Completed", "method", req.Method, "path", req.URL.Path, "status", status, "remote_addr", c.RemoteAddr(), "time_ns", timeTakenMs, "size", rw.Size())
 			}
 		}
+	}
 }

pkg/middleware/middleware.go

@@ -80,7 +80,7 @@ func initContextWithAnonymousUser(ctx *Context) bool {
 func initContextWithUserSessionCookie(ctx *Context) bool {
 	// initialize session
 	if err := ctx.Session.Start(ctx); err != nil {
-		log.Error(3, "Failed to start session", err)
+		ctx.Logger.Error("Failed to start session", "error", err)
 		return false
 	}
 
@@ -91,7 +91,7 @@ func initContextWithUserSessionCookie(ctx *Context) bool {
 
 	query := m.GetSignedInUserQuery{UserId: userId}
 	if err := bus.Dispatch(&query); err != nil {
-		log.Error(3, "Failed to get user with id %v", userId)
+		ctx.Logger.Error("Failed to get user with id", "userId", userId)
 		return false
 	} else {
 		ctx.SignedInUser = query.Result
@@ -185,7 +185,7 @@ func initContextWithApiKeyFromSession(ctx *Context) bool {
 
 	keyQuery := m.GetApiKeyByIdQuery{ApiKeyId: keyId.(int64)}
 	if err := bus.Dispatch(&keyQuery); err != nil {
-		log.Error(3, "Failed to get api key by id", err)
+		ctx.Logger.Error("Failed to get api key by id", "id", keyId, "error", err)
 		return false
 	} else {
 		apikey := keyQuery.Result
@@ -202,7 +202,7 @@ func initContextWithApiKeyFromSession(ctx *Context) bool {
 // Handle handles and logs error by given status.
 func (ctx *Context) Handle(status int, title string, err error) {
 	if err != nil {
-		log.Error(4, "%s: %v", title, err)
+		ctx.Logger.Error(title, "error", err)
 		if setting.Env != setting.PROD {
 			ctx.Data["ErrorMsg"] = err
 		}
@@ -223,9 +223,7 @@ func (ctx *Context) Handle(status int, title string, err error) {
 
 func (ctx *Context) JsonOK(message string) {
 	resp := make(map[string]interface{})
-
 	resp["message"] = message
-
 	ctx.JSON(200, resp)
 }
 
@@ -237,7 +235,7 @@ func (ctx *Context) JsonApiErr(status int, message string, err error) {
 	resp := make(map[string]interface{})
 
 	if err != nil {
-		log.Error(4, "%s: %v", message, err)
+		ctx.Logger.Error(message, "error", err)
 		if setting.Env != setting.PROD {
 			resp["error"] = err.Error()
 		}