[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>

11 files changed, 55 insertions, 56 deletions

diff --git a/internal/api/client/fileserver/servefile.go b/internal/api/client/fileserver/servefile.go
index ac2fa7bc2..fffa15a1c 100644
--- a/internal/api/client/fileserver/servefile.go
+++ b/internal/api/client/fileserver/servefile.go
@@ -24,10 +24,10 @@ import (
 	"net/http"
 
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/api"
 	"github.com/superseriousbusiness/gotosocial/internal/api/model"
 	"github.com/superseriousbusiness/gotosocial/internal/gtserror"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
 )
 
@@ -93,7 +93,7 @@ func (m *FileServer) ServeFile(c *gin.Context) {
 		// if the content is a ReadCloser, close it when we're done
 		if closer, ok := content.Content.(io.ReadCloser); ok {
 			if err := closer.Close(); err != nil {
-				logrus.Errorf("ServeFile: error closing readcloser: %s", err)
+				log.Errorf("ServeFile: error closing readcloser: %s", err)
 			}
 		}
 	}()
diff --git a/internal/api/client/fileserver/servefile_test.go b/internal/api/client/fileserver/servefile_test.go
index e918a9026..8e9cbe548 100644
--- a/internal/api/client/fileserver/servefile_test.go
+++ b/internal/api/client/fileserver/servefile_test.go
@@ -27,7 +27,6 @@ import (
 	"testing"
 
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/suite"
 	"github.com/superseriousbusiness/gotosocial/internal/api/client/fileserver"
 	"github.com/superseriousbusiness/gotosocial/internal/concurrency"
@@ -35,6 +34,7 @@ import (
 	"github.com/superseriousbusiness/gotosocial/internal/email"
 	"github.com/superseriousbusiness/gotosocial/internal/federation"
 	"github.com/superseriousbusiness/gotosocial/internal/gtsmodel"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/media"
 	"github.com/superseriousbusiness/gotosocial/internal/messages"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
@@ -96,7 +96,7 @@ func (suite *ServeFileTestSuite) SetupSuite() {
 
 func (suite *ServeFileTestSuite) TearDownSuite() {
 	if err := suite.db.Stop(context.Background()); err != nil {
-		logrus.Panicf("error closing db connection: %s", err)
+		log.Panicf("error closing db connection: %s", err)
 	}
 }
 
diff --git a/internal/api/client/media/mediacreate_test.go b/internal/api/client/media/mediacreate_test.go
index 935fc2970..595edb73d 100644
--- a/internal/api/client/media/mediacreate_test.go
+++ b/internal/api/client/media/mediacreate_test.go
@@ -30,7 +30,6 @@ import (
 	"net/http/httptest"
 	"testing"
 
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/suite"
 	mediamodule "github.com/superseriousbusiness/gotosocial/internal/api/client/media"
 	"github.com/superseriousbusiness/gotosocial/internal/api/model"
@@ -40,6 +39,7 @@ import (
 	"github.com/superseriousbusiness/gotosocial/internal/email"
 	"github.com/superseriousbusiness/gotosocial/internal/federation"
 	"github.com/superseriousbusiness/gotosocial/internal/gtsmodel"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/media"
 	"github.com/superseriousbusiness/gotosocial/internal/messages"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
@@ -100,7 +100,7 @@ func (suite *MediaCreateTestSuite) SetupSuite() {
 
 func (suite *MediaCreateTestSuite) TearDownSuite() {
 	if err := suite.db.Stop(context.Background()); err != nil {
-		logrus.Panicf("error closing db connection: %s", err)
+		log.Panicf("error closing db connection: %s", err)
 	}
 }
 
diff --git a/internal/api/client/media/mediaupdate_test.go b/internal/api/client/media/mediaupdate_test.go
index deb93d83c..8081a5c15 100644
--- a/internal/api/client/media/mediaupdate_test.go
+++ b/internal/api/client/media/mediaupdate_test.go
@@ -29,7 +29,6 @@ import (
 	"testing"
 
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/suite"
 	mediamodule "github.com/superseriousbusiness/gotosocial/internal/api/client/media"
 	"github.com/superseriousbusiness/gotosocial/internal/api/model"
@@ -39,6 +38,7 @@ import (
 	"github.com/superseriousbusiness/gotosocial/internal/email"
 	"github.com/superseriousbusiness/gotosocial/internal/federation"
 	"github.com/superseriousbusiness/gotosocial/internal/gtsmodel"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/media"
 	"github.com/superseriousbusiness/gotosocial/internal/messages"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
@@ -99,7 +99,7 @@ func (suite *MediaUpdateTestSuite) SetupSuite() {
 
 func (suite *MediaUpdateTestSuite) TearDownSuite() {
 	if err := suite.db.Stop(context.Background()); err != nil {
-		logrus.Panicf("error closing db connection: %s", err)
+		log.Panicf("error closing db connection: %s", err)
 	}
 }
 
diff --git a/internal/api/client/status/status.go b/internal/api/client/status/status.go
index abb23f1ca..67f046abd 100644
--- a/internal/api/client/status/status.go
+++ b/internal/api/client/status/status.go
@@ -22,10 +22,9 @@ import (
 	"net/http"
 	"strings"
 
-	"github.com/sirupsen/logrus"
-
 	"github.com/gin-gonic/gin"
 	"github.com/superseriousbusiness/gotosocial/internal/api"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/processing"
 	"github.com/superseriousbusiness/gotosocial/internal/router"
 )
@@ -105,7 +104,7 @@ func (m *Module) Route(r router.Router) error {
 
 // muxHandler is a little workaround to overcome the limitations of Gin
 func (m *Module) muxHandler(c *gin.Context) {
-	logrus.Debug("entering mux handler")
+	log.Debug("entering mux handler")
 	ru := c.Request.RequestURI
 
 	if c.Request.Method == http.MethodGet {
diff --git a/internal/api/client/status/statusboostedby.go b/internal/api/client/status/statusboostedby.go
index 382b38f7b..fbe447bf4 100644
--- a/internal/api/client/status/statusboostedby.go
+++ b/internal/api/client/status/statusboostedby.go
@@ -21,9 +21,10 @@ package status
 import (
 	"net/http"
 
+	"codeberg.org/gruf/go-kv"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/api"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
 )
 
@@ -64,12 +65,12 @@ import (
 //   '404':
 //      description: not found
 func (m *Module) StatusBoostedByGETHandler(c *gin.Context) {
-	l := logrus.WithFields(logrus.Fields{
-		"func":        "StatusBoostedByGETHandler",
-		"request_uri": c.Request.RequestURI,
-		"user_agent":  c.Request.UserAgent(),
-		"origin_ip":   c.ClientIP(),
-	})
+	l := log.WithFields(kv.Fields{
+
+		{"request_uri", c.Request.RequestURI},
+		{"user_agent", c.Request.UserAgent()},
+		{"origin_ip", c.ClientIP()},
+	}...)
 	l.Debugf("entering function")
 
 	authed, err := oauth.Authed(c, true, true, true, true) // we don't really need an app here but we want everything else
diff --git a/internal/api/client/streaming/stream.go b/internal/api/client/streaming/stream.go
index 2c18e4e41..7e2922acf 100644
--- a/internal/api/client/streaming/stream.go
+++ b/internal/api/client/streaming/stream.go
@@ -5,9 +5,10 @@ import (
 	"net/http"
 	"time"
 
-	"github.com/sirupsen/logrus"
+	"codeberg.org/gruf/go-kv"
 	"github.com/superseriousbusiness/gotosocial/internal/api"
 	"github.com/superseriousbusiness/gotosocial/internal/gtserror"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 
 	"github.com/gin-gonic/gin"
 	"github.com/gorilla/websocket"
@@ -144,12 +145,12 @@ func (m *Module) StreamGETHandler(c *gin.Context) {
 		return
 	}
 
-	l := logrus.WithFields(logrus.Fields{
-		"account":    account.Username,
-		"path":       BasePath,
-		"streamID":   stream.ID,
-		"streamType": streamType,
-	})
+	l := log.WithFields(kv.Fields{
+		{"account", account.Username},
+		{"path", BasePath},
+		{"streamID", stream.ID},
+		{"streamType", streamType},
+	}...)
 
 	wsConn, err := wsUpgrader.Upgrade(c.Writer, c.Request, nil)
 	if err != nil {
diff --git a/internal/api/errorhandling.go b/internal/api/errorhandling.go
index 32699fe36..346841f3f 100644
--- a/internal/api/errorhandling.go
+++ b/internal/api/errorhandling.go
@@ -22,11 +22,12 @@ import (
 	"context"
 	"net/http"
 
+	"codeberg.org/gruf/go-kv"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	apimodel "github.com/superseriousbusiness/gotosocial/internal/api/model"
 	"github.com/superseriousbusiness/gotosocial/internal/config"
 	"github.com/superseriousbusiness/gotosocial/internal/gtserror"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 )
 
 // TODO: add more templated html pages here for different error types
@@ -106,11 +107,11 @@ func ErrorHandler(c *gin.Context, errWithCode gtserror.WithCode, instanceGet fun
 // to pass any detailed errors (that might contain sensitive information) into the
 // errWithCode.Error() field, since the client will see this. Use your noggin!
 func OAuthErrorHandler(c *gin.Context, errWithCode gtserror.WithCode) {
-	l := logrus.WithFields(logrus.Fields{
-		"path":  c.Request.URL.Path,
-		"error": errWithCode.Error(),
-		"help":  errWithCode.Safe(),
-	})
+	l := log.WithFields(kv.Fields{
+		{"path", c.Request.URL.Path},
+		{"error", errWithCode.Error()},
+		{"help", errWithCode.Safe()},
+	}...)
 
 	statusCode := errWithCode.Code()
 
diff --git a/internal/api/s2s/webfinger/webfingerget.go b/internal/api/s2s/webfinger/webfingerget.go
index 6d4764ce5..68ea760bd 100644
--- a/internal/api/s2s/webfinger/webfingerget.go
+++ b/internal/api/s2s/webfinger/webfingerget.go
@@ -23,11 +23,12 @@ import (
 	"fmt"
 	"net/http"
 
+	"codeberg.org/gruf/go-kv"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/ap"
 	"github.com/superseriousbusiness/gotosocial/internal/api"
 	"github.com/superseriousbusiness/gotosocial/internal/config"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/util"
 )
 
@@ -55,10 +56,9 @@ import (
 //     schema:
 //       "$ref": "#/definitions/wellKnownResponse"
 func (m *Module) WebfingerGETRequest(c *gin.Context) {
-	l := logrus.WithFields(logrus.Fields{
-		"func":       "WebfingerGETRequest",
-		"user-agent": c.Request.UserAgent(),
-	})
+	l := log.WithFields(kv.Fields{
+		{K: "user-agent", V: c.Request.UserAgent()},
+	}...)
 
 	resourceQuery, set := c.GetQuery("resource")
 	if !set || resourceQuery == "" {
diff --git a/internal/api/security/signaturecheck.go b/internal/api/security/signaturecheck.go
index 1dd6b5f79..1c117cd1b 100644
--- a/internal/api/security/signaturecheck.go
+++ b/internal/api/security/signaturecheck.go
@@ -4,8 +4,8 @@ import (
 	"net/http"
 	"net/url"
 
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/ap"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 
 	"github.com/gin-gonic/gin"
 	"github.com/go-fed/httpsig"
@@ -15,8 +15,6 @@ import (
 // that signed the request is permitted to access the server. If it is permitted, the handler will set the key
 // verifier and the signature in the gin context for use down the line.
 func (m *Module) SignatureCheck(c *gin.Context) {
-	l := logrus.WithField("func", "DomainBlockChecker")
-
 	// create the verifier from the request
 	// if the request is signed, it will have a signature header
 	verifier, err := httpsig.NewVerifier(c.Request)
@@ -32,12 +30,12 @@ func (m *Module) SignatureCheck(c *gin.Context) {
 			// if the domain is blocked we want to bail as early as possible
 			blocked, err := m.db.IsURIBlocked(c.Request.Context(), requestingPublicKeyID)
 			if err != nil {
-				l.Errorf("could not tell if domain %s was blocked or not: %s", requestingPublicKeyID.Host, err)
+				log.Errorf("could not tell if domain %s was blocked or not: %s", requestingPublicKeyID.Host, err)
 				c.AbortWithStatus(http.StatusInternalServerError)
 				return
 			}
 			if blocked {
-				l.Infof("domain %s is blocked", requestingPublicKeyID.Host)
+				log.Infof("domain %s is blocked", requestingPublicKeyID.Host)
 				c.AbortWithStatus(http.StatusForbidden)
 				return
 			}
diff --git a/internal/api/security/tokencheck.go b/internal/api/security/tokencheck.go
index e366af2ea..0e9e7bde2 100644
--- a/internal/api/security/tokencheck.go
+++ b/internal/api/security/tokencheck.go
@@ -20,9 +20,9 @@ package security
 
 import (
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 	"github.com/superseriousbusiness/gotosocial/internal/db"
 	"github.com/superseriousbusiness/gotosocial/internal/gtsmodel"
+	"github.com/superseriousbusiness/gotosocial/internal/log"
 	"github.com/superseriousbusiness/gotosocial/internal/oauth"
 )
 
@@ -32,7 +32,6 @@ import (
 // If user or account can't be found, then the handler won't *fail*, in case the server wants to allow
 // public requests that don't have a Bearer token set (eg., for public instance information and so on).
 func (m *Module) TokenCheck(c *gin.Context) {
-	l := logrus.WithField("func", "OauthTokenMiddleware")
 	ctx := c.Request.Context()
 	defer c.Next()
 
@@ -43,38 +42,38 @@ func (m *Module) TokenCheck(c *gin.Context) {
 
 	ti, err := m.server.ValidationBearerToken(c.Copy().Request)
 	if err != nil {
-		l.Infof("token was passed in Authorization header but we could not validate it: %s", err)
+		log.Infof("token was passed in Authorization header but we could not validate it: %s", err)
 		return
 	}
 	c.Set(oauth.SessionAuthorizedToken, ti)
 
 	// check for user-level token
 	if userID := ti.GetUserID(); userID != "" {
-		l.Tracef("authenticated user %s with bearer token, scope is %s", userID, ti.GetScope())
+		log.Tracef("authenticated user %s with bearer token, scope is %s", userID, ti.GetScope())
 
 		// fetch user for this token
 		user := &gtsmodel.User{}
 		if err := m.db.GetByID(ctx, userID, user); err != nil {
 			if err != db.ErrNoEntries {
-				l.Errorf("database error looking for user with id %s: %s", userID, err)
+				log.Errorf("database error looking for user with id %s: %s", userID, err)
 				return
 			}
-			l.Warnf("no user found for userID %s", userID)
+			log.Warnf("no user found for userID %s", userID)
 			return
 		}
 
 		if user.ConfirmedAt.IsZero() {
-			l.Warnf("authenticated user %s has never confirmed thier email address", userID)
+			log.Warnf("authenticated user %s has never confirmed thier email address", userID)
 			return
 		}
 
 		if !user.Approved {
-			l.Warnf("authenticated user %s's account was never approved by an admin", userID)
+			log.Warnf("authenticated user %s's account was never approved by an admin", userID)
 			return
 		}
 
 		if user.Disabled {
-			l.Warnf("authenticated user %s's account was disabled'", userID)
+			log.Warnf("authenticated user %s's account was disabled'", userID)
 			return
 		}
 
@@ -84,15 +83,15 @@ func (m *Module) TokenCheck(c *gin.Context) {
 		acct, err := m.db.GetAccountByID(ctx, user.AccountID)
 		if err != nil {
 			if err != db.ErrNoEntries {
-				l.Errorf("database error looking for account with id %s: %s", user.AccountID, err)
+				log.Errorf("database error looking for account with id %s: %s", user.AccountID, err)
 				return
 			}
-			l.Warnf("no account found for userID %s", userID)
+			log.Warnf("no account found for userID %s", userID)
 			return
 		}
 
 		if !acct.SuspendedAt.IsZero() {
-			l.Warnf("authenticated user %s's account (accountId=%s) has been suspended", userID, user.AccountID)
+			log.Warnf("authenticated user %s's account (accountId=%s) has been suspended", userID, user.AccountID)
 			return
 		}
 
@@ -101,16 +100,16 @@ func (m *Module) TokenCheck(c *gin.Context) {
 
 	// check for application token
 	if clientID := ti.GetClientID(); clientID != "" {
-		l.Tracef("authenticated client %s with bearer token, scope is %s", clientID, ti.GetScope())
+		log.Tracef("authenticated client %s with bearer token, scope is %s", clientID, ti.GetScope())
 
 		// fetch app for this token
 		app := &gtsmodel.Application{}
 		if err := m.db.GetWhere(ctx, []db.Where{{Key: "client_id", Value: clientID}}, app); err != nil {
 			if err != db.ErrNoEntries {
-				l.Errorf("database error looking for application with clientID %s: %s", clientID, err)
+				log.Errorf("database error looking for application with clientID %s: %s", clientID, err)
 				return
 			}
-			l.Warnf("no app found for client %s", clientID)
+			log.Warnf("no app found for client %s", clientID)
 			return
 		}
 		c.Set(oauth.SessionAuthorizedApplication, app)