[chore] use our own logging implementation (#716)

* first commit

Signed-off-by: kim <grufwub@gmail.com>

* replace logging with our own log library

Signed-off-by: kim <grufwub@gmail.com>

* fix imports

Signed-off-by: kim <grufwub@gmail.com>

* fix log imports

Signed-off-by: kim <grufwub@gmail.com>

* add license text

Signed-off-by: kim <grufwub@gmail.com>

* fix package import cycle between config and log package

Signed-off-by: kim <grufwub@gmail.com>

* fix empty kv.Fields{} being passed to WithFields()

Signed-off-by: kim <grufwub@gmail.com>

* fix uses of log.WithFields() with whitespace issues and empty slices

Signed-off-by: kim <grufwub@gmail.com>

* *linter related grumbling*

Signed-off-by: kim <grufwub@gmail.com>

* gofmt the codebase! also fix more log.WithFields() formatting issues

Signed-off-by: kim <grufwub@gmail.com>

* update testrig code to match new changes

Signed-off-by: kim <grufwub@gmail.com>

* fix error wrapping in non fmt.Errorf function

Signed-off-by: kim <grufwub@gmail.com>

* add benchmarking of log.Caller() vs non-cached

Signed-off-by: kim <grufwub@gmail.com>

* fix syslog tests, add standard build tags to test runner to ensure consistency

Signed-off-by: kim <grufwub@gmail.com>

* make syslog tests more robust

Signed-off-by: kim <grufwub@gmail.com>

* fix caller depth arithmatic (is that how you spell it?)

Signed-off-by: kim <grufwub@gmail.com>

* update to use unkeyed fields in kv.Field{} instances

Signed-off-by: kim <grufwub@gmail.com>

* update go-kv library

Signed-off-by: kim <grufwub@gmail.com>

* update libraries list

Signed-off-by: kim <grufwub@gmail.com>

* fuck you linter get nerfed

Signed-off-by: kim <grufwub@gmail.com>

Co-authored-by: tobi <31960611+tsmethurst@users.noreply.github.com>

internal/router/logger.go

@@ -21,19 +21,20 @@ package router
 import (
 	"fmt"
 	"net/http"
-	"os"
 	"time"
 
 	"codeberg.org/gruf/go-bytesize"
 	"codeberg.org/gruf/go-errors/v2"
+	"codeberg.org/gruf/go-kv"
+	"codeberg.org/gruf/go-logger/v2/level"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 )
 
 // loggingMiddleware provides a request logging and panic recovery gin handler.
 func loggingMiddleware(c *gin.Context) {
 	// Initialize the logging fields
-	fields := make(logrus.Fields, 7)
+	fields := make(kv.Fields, 6, 7)
 
 	// Determine pre-handler time
 	before := time.Now()
@@ -49,11 +50,12 @@ func loggingMiddleware(c *gin.Context) {
 			}
 
 			// Append panic information to the request ctx
-			_ = c.Error(fmt.Errorf("recovered panic: %v", r))
+			err := fmt.Errorf("recovered panic: %v", r)
+			_ = c.Error(err)
 
-			// Dump a stacktrace to stderr
+			// Dump a stacktrace to error log
 			callers := errors.GetCallers(3, 10)
-			fmt.Fprintf(os.Stderr, "recovered panic: %v\n%s", r, callers)
+			log.WithField("stacktrace", callers).Error(err)
 		}
 
 		// NOTE:
@@ -63,32 +65,38 @@ func loggingMiddleware(c *gin.Context) {
 		// and could lead to storing plaintext API keys in logs
 
 		// Set request logging fields
-		fields["latency"] = time.Since(before)
-		fields["clientIP"] = c.ClientIP()
-		fields["userAgent"] = c.Request.UserAgent()
-		fields["method"] = c.Request.Method
-		fields["statusCode"] = code
-		fields["path"] = path
+		fields[0] = kv.Field{"latency", time.Since(before)}
+		fields[1] = kv.Field{"clientIP", c.ClientIP()}
+		fields[2] = kv.Field{"userAgent", c.Request.UserAgent()}
+		fields[3] = kv.Field{"method", c.Request.Method}
+		fields[4] = kv.Field{"statusCode", code}
+		fields[5] = kv.Field{"path", path}
 
-		// Create a log entry with fields
-		l := logrus.WithFields(fields)
-		l.Level = logrus.InfoLevel
+		var lvl level.LEVEL
+
+		// Default is info
+		lvl = level.INFO
 
 		if code >= 500 {
 			// This is a server error
-			l.Level = logrus.ErrorLevel
+			lvl = level.ERROR
 
 			if len(c.Errors) > 0 {
 				// Add an error string log field
-				fields["error"] = c.Errors.String()
+				fields = append(fields, kv.Field{
+					"error", c.Errors.String(),
+				})
 			}
 		}
 
 		// Generate a nicer looking bytecount
 		size := bytesize.Size(c.Writer.Size())
 
+		// Create log entry with fields
+		l := log.WithFields(fields...)
+
 		// Finally, write log entry with status text body size
-		l.Logf(l.Level, "%s: wrote %s", http.StatusText(code), size)
+		l.Logf(lvl, "%s: wrote %s", http.StatusText(code), size)
 	}()
 
 	// Process request

internal/router/router.go

@@ -26,9 +26,9 @@ import (
 
 	"codeberg.org/gruf/go-debug"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/config"
 	"github.com/superseriousbusiness/gotosocial/internal/db"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"golang.org/x/crypto/acme/autocert"
 )
 
@@ -94,10 +94,10 @@ func (r *router) Start() {
 			)
 
 			// Start the LetsEncrypt autocert manager HTTP server.
-			logrus.Infof("letsencrypt listening on %s", srv.Addr)
+			log.Infof("letsencrypt listening on %s", srv.Addr)
 			if err := srv.ListenAndServe(); err != nil &&
 				err != http.ErrServerClosed {
-				logrus.Fatalf("letsencrypt: listen: %s", err)
+				log.Fatalf("letsencrypt: listen: %s", err)
 			}
 		}()
 
@@ -112,16 +112,16 @@ func (r *router) Start() {
 	r.srv.Handler = debug.WithPprof(r.srv.Handler)
 	if debug.DEBUG() {
 		// Profiling requires timeouts longer than 30s, so reset these.
-		logrus.Warn("resetting http.Server{} timeout to support profiling")
+		log.Warn("resetting http.Server{} timeout to support profiling")
 		r.srv.ReadTimeout = 0
 		r.srv.WriteTimeout = 0
 	}
 
 	// Start the main listener.
 	go func() {
-		logrus.Infof("listening on %s", r.srv.Addr)
+		log.Infof("listening on %s", r.srv.Addr)
 		if err := listen(); err != nil && err != http.ErrServerClosed {
-			logrus.Fatalf("listen: %s", err)
+			log.Fatalf("listen: %s", err)
 		}
 	}()
 }

internal/router/session.go

@@ -29,9 +29,9 @@ import (
 	"github.com/gin-contrib/sessions"
 	"github.com/gin-contrib/sessions/memstore"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/config"
 	"github.com/superseriousbusiness/gotosocial/internal/db"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"golang.org/x/net/idna"
 )
 
@@ -44,7 +44,7 @@ func SessionOptions() sessions.Options {
 	case "strict":
 		samesite = http.SameSiteStrictMode
 	default:
-		logrus.Warnf("%s set to %s which is not recognized, defaulting to 'lax'", config.AdvancedCookiesSamesiteFlag(), config.GetAdvancedCookiesSamesite())
+		log.Warnf("%s set to %s which is not recognized, defaulting to 'lax'", config.AdvancedCookiesSamesiteFlag(), config.GetAdvancedCookiesSamesite())
 		samesite = http.SameSiteLaxMode
 	}