From f839f248b9b561cdc538ff9ee0f81f921a876078 Mon Sep 17 00:00:00 2001 From: eikendev Date: Mon, 11 Apr 2022 23:46:02 +0200 Subject: [PATCH] Use logrus for logging --- cmd/pushbits/main.go | 23 +++--- go.mod | 1 + go.sum | 3 + internal/api/application.go | 18 ++--- internal/api/application_test.go | 8 +- internal/api/notification.go | 6 +- internal/api/user.go | 8 +- .../authentication/credentials/credentials.go | 5 +- internal/authentication/credentials/hibp.go | 9 ++- .../authentication/credentials/password.go | 7 +- internal/database/database.go | 18 ++--- internal/dispatcher/application.go | 22 +++--- internal/dispatcher/dispatcher.go | 14 ++-- internal/dispatcher/notification.go | 17 ++-- internal/log/ginlogrus.go | 77 +++++++++++++++++++ internal/log/log.go | 22 ++++++ internal/model/user.go | 5 +- internal/router/router.go | 12 +-- tests/mockups/config.go | 4 +- 19 files changed, 192 insertions(+), 87 deletions(-) create mode 100644 internal/log/ginlogrus.go create mode 100644 internal/log/log.go diff --git a/cmd/pushbits/main.go b/cmd/pushbits/main.go index dc36fec..0be2d82 100644 --- a/cmd/pushbits/main.go +++ b/cmd/pushbits/main.go @@ -1,7 +1,6 @@ package main import ( - "log" "os" "os/signal" "syscall" @@ -10,6 +9,7 @@ import ( "github.com/pushbits/server/internal/configuration" "github.com/pushbits/server/internal/database" "github.com/pushbits/server/internal/dispatcher" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/router" "github.com/pushbits/server/internal/runner" ) @@ -32,45 +32,46 @@ func setupCleanup(db *database.Database, dp *dispatcher.Dispatcher) { // @version 0.7.2 // @description Documentation for the PushBits server API. -// @contact.name PushBits +// @contact.name The PushBits Developers // @contact.url https://www.pushbits.io // @license.name ISC // @license.url https://github.com/pushbits/server/blob/master/LICENSE -// @host your-domain.net // @BasePath / // @query.collection.format multi +// @schemes http https // @securityDefinitions.basic BasicAuth func main() { if len(version) == 0 { - log.Panic("Version not set") + log.L.Panic("Version not set") } else { - log.Printf("Starting PushBits %s", version) + log.L.Printf("Starting PushBits %s", version) } c := configuration.Get() if c.Debug { - log.Printf("%+v", c) + log.SetDebug() + log.L.Printf("%+v", c) } cm := credentials.CreateManager(c.Security.CheckHIBP, c.Crypto) db, err := database.Create(cm, c.Database.Dialect, c.Database.Connection) if err != nil { - log.Fatal(err) + log.L.Fatal(err) } defer db.Close() if err := db.Populate(c.Admin.Name, c.Admin.Password, c.Admin.MatrixID); err != nil { - log.Fatal(err) + log.L.Fatal(err) } dp, err := dispatcher.Create(c.Matrix.Homeserver, c.Matrix.Username, c.Matrix.Password, c.Formatting) if err != nil { - log.Fatal(err) + log.L.Fatal(err) } defer dp.Close() @@ -78,13 +79,13 @@ func main() { err = db.RepairChannels(dp) if err != nil { - log.Fatal(err) + log.L.Fatal(err) } engine := router.Create(c.Debug, cm, db, dp) err = runner.Run(engine, c.HTTP.ListenAddress, c.HTTP.Port) if err != nil { - log.Fatal(err) + log.L.Fatal(err) } } diff --git a/go.mod b/go.mod index ddd65f8..54a8d97 100644 --- a/go.mod +++ b/go.mod @@ -14,6 +14,7 @@ require ( github.com/leodido/go-urn v1.2.1 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.1 // indirect + github.com/sirupsen/logrus v1.8.1 // indirect github.com/stretchr/testify v1.7.0 github.com/ugorji/go v1.2.4 // indirect golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect diff --git a/go.sum b/go.sum index 8fa442a..f16f8a6 100644 --- a/go.sum +++ b/go.sum @@ -95,7 +95,10 @@ github.com/onsi/gomega v1.4.3/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1Cpa github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= +github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE= +github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= diff --git a/internal/api/application.go b/internal/api/application.go index 341b588..6e2f053 100644 --- a/internal/api/application.go +++ b/internal/api/application.go @@ -2,10 +2,10 @@ package api import ( "errors" - "log" "net/http" "github.com/pushbits/server/internal/authentication" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" "github.com/gin-gonic/gin" @@ -27,7 +27,7 @@ func (h *ApplicationHandler) generateToken(compat bool) string { } func (h *ApplicationHandler) registerApplication(ctx *gin.Context, a *model.Application, u *model.User) error { - log.Printf("Registering application %s.", a.Name) + log.L.Printf("Registering application %s.", a.Name) channelID, err := h.DP.RegisterApplication(a.ID, a.Name, a.Token, u.MatrixID) if success := successOrAbort(ctx, http.StatusInternalServerError, err); !success { @@ -45,7 +45,7 @@ func (h *ApplicationHandler) registerApplication(ctx *gin.Context, a *model.Appl } func (h *ApplicationHandler) createApplication(ctx *gin.Context, u *model.User, name string, compat bool) (*model.Application, error) { - log.Printf("Creating application %s.", name) + log.L.Printf("Creating application %s.", name) application := model.Application{} application.Name = name @@ -60,7 +60,7 @@ func (h *ApplicationHandler) createApplication(ctx *gin.Context, u *model.User, if err := h.registerApplication(ctx, &application, u); err != nil { err := h.DB.DeleteApplication(&application) if success := successOrAbort(ctx, http.StatusInternalServerError, err); !success { - log.Printf("Cannot delete application with ID %d.", application.ID) + log.L.Printf("Cannot delete application with ID %d.", application.ID) } return nil, err @@ -70,7 +70,7 @@ func (h *ApplicationHandler) createApplication(ctx *gin.Context, u *model.User, } func (h *ApplicationHandler) deleteApplication(ctx *gin.Context, a *model.Application, u *model.User) error { - log.Printf("Deleting application %s (ID %d).", a.Name, a.ID) + log.L.Printf("Deleting application %s (ID %d).", a.Name, a.ID) err := h.DP.DeregisterApplication(a, u) if success := successOrAbort(ctx, http.StatusInternalServerError, err); !success { @@ -86,15 +86,15 @@ func (h *ApplicationHandler) deleteApplication(ctx *gin.Context, a *model.Applic } func (h *ApplicationHandler) updateApplication(ctx *gin.Context, a *model.Application, updateApplication *model.UpdateApplication) error { - log.Printf("Updating application %s (ID %d).", a.Name, a.ID) + log.L.Printf("Updating application %s (ID %d).", a.Name, a.ID) if updateApplication.Name != nil { - log.Printf("Updating application name to '%s'.", *updateApplication.Name) + log.L.Printf("Updating application name to '%s'.", *updateApplication.Name) a.Name = *updateApplication.Name } if updateApplication.RefreshToken != nil && (*updateApplication.RefreshToken) { - log.Print("Updating application token.") + log.L.Print("Updating application token.") compat := updateApplication.StrictCompatibility != nil && (*updateApplication.StrictCompatibility) a.Token = h.generateToken(compat) } @@ -129,7 +129,7 @@ func (h *ApplicationHandler) CreateApplication(ctx *gin.Context) { var createApplication model.CreateApplication if err := ctx.Bind(&createApplication); err != nil { - log.Println(err) + log.L.Println(err) return } diff --git a/internal/api/application_test.go b/internal/api/application_test.go index c36c135..267bfd0 100644 --- a/internal/api/application_test.go +++ b/internal/api/application_test.go @@ -4,7 +4,6 @@ import ( "encoding/json" "fmt" "io/ioutil" - "log" "os" "testing" @@ -12,6 +11,7 @@ import ( "github.com/pushbits/server/internal/authentication/credentials" "github.com/pushbits/server/internal/configuration" "github.com/pushbits/server/internal/database" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" "github.com/pushbits/server/tests" "github.com/pushbits/server/tests/mockups" @@ -50,7 +50,7 @@ func TestMain(m *testing.M) { db, err := mockups.GetEmptyDatabase(config.Crypto) if err != nil { cleanUp() - log.Println("Can not set up database: ", err) + log.L.Println("Can not set up database: ", err) os.Exit(1) } TestDatabase = db @@ -58,7 +58,7 @@ func TestMain(m *testing.M) { appHandler, err := getApplicationHandler(config) if err != nil { cleanUp() - log.Println("Can not set up application handler: ", err) + log.L.Println("Can not set up application handler: ", err) os.Exit(1) } @@ -80,7 +80,7 @@ func TestMain(m *testing.M) { // Run m.Run() - log.Println("Clean up after Test") + log.L.Println("Clean up after Test") cleanUp() } diff --git a/internal/api/notification.go b/internal/api/notification.go index 4198880..2d2aaa9 100644 --- a/internal/api/notification.go +++ b/internal/api/notification.go @@ -1,12 +1,12 @@ package api import ( - "log" "net/http" "net/url" "time" "github.com/pushbits/server/internal/authentication" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" "github.com/gin-gonic/gin" @@ -45,7 +45,7 @@ type NotificationHandler struct { // @Router /message [post] func (h *NotificationHandler) CreateNotification(ctx *gin.Context) { application := authentication.GetApplication(ctx) - log.Printf("Sending notification for application %s.", application.Name) + log.L.Printf("Sending notification for application %s.", application.Name) var notification model.Notification if err := ctx.Bind(¬ification); err != nil { @@ -79,7 +79,7 @@ func (h *NotificationHandler) CreateNotification(ctx *gin.Context) { // @Router /message/{message_id} [DELETE] func (h *NotificationHandler) DeleteNotification(ctx *gin.Context) { application := authentication.GetApplication(ctx) - log.Printf("Deleting notification for application %s.", application.Name) + log.L.Printf("Deleting notification for application %s.", application.Name) id, err := getMessageID(ctx) if success := successOrAbort(ctx, http.StatusUnprocessableEntity, err); !success { diff --git a/internal/api/user.go b/internal/api/user.go index 3dca53f..f6565cc 100644 --- a/internal/api/user.go +++ b/internal/api/user.go @@ -2,10 +2,10 @@ package api import ( "errors" - "log" "net/http" "github.com/pushbits/server/internal/authentication" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" "github.com/gin-gonic/gin" @@ -90,7 +90,7 @@ func (h *UserHandler) updateUser(ctx *gin.Context, u *model.User, updateUser mod } } - log.Printf("Updating user %s.", u.Name) + log.L.Printf("Updating user %s.", u.Name) if updateUser.Name != nil { u.Name = *updateUser.Name @@ -146,7 +146,7 @@ func (h *UserHandler) CreateUser(ctx *gin.Context) { return } - log.Printf("Creating user %s.", createUser.Name) + log.L.Printf("Creating user %s.", createUser.Name) user, err := h.DB.CreateUser(createUser) @@ -232,7 +232,7 @@ func (h *UserHandler) DeleteUser(ctx *gin.Context) { } } - log.Printf("Deleting user %s.", user.Name) + log.L.Printf("Deleting user %s.", user.Name) if err := h.deleteApplications(ctx, user); err != nil { return diff --git a/internal/authentication/credentials/credentials.go b/internal/authentication/credentials/credentials.go index 1280f5b..1833054 100644 --- a/internal/authentication/credentials/credentials.go +++ b/internal/authentication/credentials/credentials.go @@ -1,9 +1,8 @@ package credentials import ( - "log" - "github.com/pushbits/server/internal/configuration" + "github.com/pushbits/server/internal/log" "github.com/alexedwards/argon2id" ) @@ -16,7 +15,7 @@ type Manager struct { // CreateManager instanciates a credential manager. func CreateManager(checkHIBP bool, c configuration.CryptoConfig) *Manager { - log.Println("Setting up credential manager.") + log.L.Println("Setting up credential manager.") argon2Params := &argon2id.Params{ Memory: c.Argon2.Memory, diff --git a/internal/authentication/credentials/hibp.go b/internal/authentication/credentials/hibp.go index 8522497..54c45c6 100644 --- a/internal/authentication/credentials/hibp.go +++ b/internal/authentication/credentials/hibp.go @@ -4,9 +4,10 @@ import ( "crypto/sha1" //#nosec G505 -- False positive, see the use below. "fmt" "io/ioutil" - "log" "net/http" "strings" + + "github.com/pushbits/server/internal/log" ) const ( @@ -27,7 +28,7 @@ func IsPasswordPwned(password string) (bool, error) { lookup := hashStr[0:5] match := hashStr[5:] - log.Printf("Checking HIBP for hashes starting with '%s'.", lookup) + log.L.Printf("Checking HIBP for hashes starting with '%s'.", lookup) resp, err := http.Get(pwnedHashesURL + lookup) if err != nil { @@ -35,13 +36,13 @@ func IsPasswordPwned(password string) (bool, error) { } if resp.StatusCode != http.StatusOK { - log.Fatalf("Request failed with HTTP %s.", resp.Status) + log.L.Fatalf("Request failed with HTTP %s.", resp.Status) } defer resp.Body.Close() bodyText, err := ioutil.ReadAll(resp.Body) if err != nil { - log.Fatal(err) + log.L.Fatal(err) } bodyStr := string(bodyText) diff --git a/internal/authentication/credentials/password.go b/internal/authentication/credentials/password.go index f5ab29c..5474e2c 100644 --- a/internal/authentication/credentials/password.go +++ b/internal/authentication/credentials/password.go @@ -2,9 +2,10 @@ package credentials import ( "errors" - "log" "github.com/alexedwards/argon2id" + + "github.com/pushbits/server/internal/log" ) // CreatePasswordHash returns a hashed version of the given password. @@ -21,7 +22,7 @@ func (m *Manager) CreatePasswordHash(password string) ([]byte, error) { hash, err := argon2id.CreateHash(password, m.argon2Params) if err != nil { - log.Fatal(err) + log.L.Fatal(err) panic(err) } @@ -33,7 +34,7 @@ func ComparePassword(hash, password []byte) bool { match, err := argon2id.ComparePasswordAndHash(string(password), string(hash)) if err != nil { - log.Fatal(err) + log.L.Fatal(err) return false } diff --git a/internal/database/database.go b/internal/database/database.go index 6ea7b81..45d4aaf 100644 --- a/internal/database/database.go +++ b/internal/database/database.go @@ -3,12 +3,12 @@ package database import ( "database/sql" "errors" - "log" "os" "path/filepath" "time" "github.com/pushbits/server/internal/authentication/credentials" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" "gorm.io/driver/mysql" @@ -36,7 +36,7 @@ func createFileDir(file string) { // Create instanciates a database connection. func Create(cm *credentials.Manager, dialect, connection string) (*Database, error) { - log.Println("Setting up database connection.") + log.L.Println("Setting up database connection.") maxOpenConns := 5 @@ -82,13 +82,13 @@ func Create(cm *credentials.Manager, dialect, connection string) (*Database, err func (d *Database) Close() { err := d.sqldb.Close() if err != nil { - log.Printf("Error while closing database: %s", err) + log.L.Printf("Error while closing database: %s", err) } } // Populate fills the database with initial information like the admin user. func (d *Database) Populate(name, password, matrixID string) error { - log.Print("Populating database.") + log.L.Print("Populating database.") var user model.User @@ -104,7 +104,7 @@ func (d *Database) Populate(name, password, matrixID string) error { return errors.New("user cannot be created") } } else { - log.Printf("Priviledged user %s already exists.", name) + log.L.Printf("Priviledged user %s already exists.", name) } return nil @@ -112,7 +112,7 @@ func (d *Database) Populate(name, password, matrixID string) error { // RepairChannels resets channels that have been modified by a user. func (d *Database) RepairChannels(dp Dispatcher) error { - log.Print("Repairing application channels.") + log.L.Print("Repairing application channels.") users, err := d.GetUsers() if err != nil { @@ -140,11 +140,11 @@ func (d *Database) RepairChannels(dp Dispatcher) error { } if orphan { - log.Printf("Found orphan channel for application %s (ID %d)", application.Name, application.ID) + log.L.Printf("Found orphan channel for application %s (ID %d)", application.Name, application.ID) if err = dp.RepairApplication(&application, &user); err != nil { - log.Printf("Unable to repair application %s (ID %d).", application.Name, application.ID) - log.Println(err) + log.L.Printf("Unable to repair application %s (ID %d).", application.Name, application.ID) + log.L.Println(err) } } } diff --git a/internal/dispatcher/application.go b/internal/dispatcher/application.go index 4e27034..4d17ee3 100644 --- a/internal/dispatcher/application.go +++ b/internal/dispatcher/application.go @@ -2,11 +2,11 @@ package dispatcher import ( "fmt" - "log" + "github.com/pushbits/server/internal/log" "github.com/pushbits/server/internal/model" - "maunium.net/go/mautrix" + "maunium.net/go/mautrix" "maunium.net/go/mautrix/event" mId "maunium.net/go/mautrix/id" ) @@ -17,7 +17,7 @@ func buildRoomTopic(id uint) string { // RegisterApplication creates a channel for an application. func (d *Dispatcher) RegisterApplication(id uint, name, token, user string) (string, error) { - log.Printf("Registering application %s, notifications will be relayed to user %s.\n", name, user) + log.L.Printf("Registering application %s, notifications will be relayed to user %s.\n", name, user) resp, err := d.mautrixClient.CreateRoom(&mautrix.ReqCreateRoom{ Visibility: "private", @@ -28,18 +28,18 @@ func (d *Dispatcher) RegisterApplication(id uint, name, token, user string) (str Topic: buildRoomTopic(id), }) if err != nil { - log.Print(err) + log.L.Print(err) return "", err } - log.Printf("Application %s is now relayed to room with ID %s.\n", name, resp.RoomID.String()) + log.L.Printf("Application %s is now relayed to room with ID %s.\n", name, resp.RoomID.String()) return resp.RoomID.String(), err } // DeregisterApplication deletes a channel for an application. func (d *Dispatcher) DeregisterApplication(a *model.Application, u *model.User) error { - log.Printf("Deregistering application %s (ID %d) with Matrix ID %s.\n", a.Name, a.ID, a.MatrixID) + log.L.Printf("Deregistering application %s (ID %d) with Matrix ID %s.\n", a.Name, a.ID, a.MatrixID) // The user might have left the channel, but we can still try to remove them. @@ -47,17 +47,17 @@ func (d *Dispatcher) DeregisterApplication(a *model.Application, u *model.User) Reason: "This application was deleted", UserID: mId.UserID(u.MatrixID), }); err != nil { - log.Print(err) + log.L.Print(err) return err } if _, err := d.mautrixClient.LeaveRoom(mId.RoomID(a.MatrixID)); err != nil { - log.Print(err) + log.L.Print(err) return err } if _, err := d.mautrixClient.ForgetRoom(mId.RoomID(a.MatrixID)); err != nil { - log.Print(err) + log.L.Print(err) return err } @@ -66,7 +66,7 @@ func (d *Dispatcher) DeregisterApplication(a *model.Application, u *model.User) func (d *Dispatcher) sendRoomEvent(roomID, eventType string, content interface{}) error { if _, err := d.mautrixClient.SendStateEvent(mId.RoomID(roomID), event.NewEventType(eventType), "", content); err != nil { - log.Print(err) + log.L.Print(err) return err } @@ -75,7 +75,7 @@ func (d *Dispatcher) sendRoomEvent(roomID, eventType string, content interface{} // UpdateApplication updates a channel for an application. func (d *Dispatcher) UpdateApplication(a *model.Application) error { - log.Printf("Updating application %s (ID %d) with Matrix ID %s.\n", a.Name, a.ID, a.MatrixID) + log.L.Printf("Updating application %s (ID %d) with Matrix ID %s.\n", a.Name, a.ID, a.MatrixID) content := map[string]interface{}{ "name": a.Name, diff --git a/internal/dispatcher/dispatcher.go b/internal/dispatcher/dispatcher.go index ec9b8c4..05d557b 100644 --- a/internal/dispatcher/dispatcher.go +++ b/internal/dispatcher/dispatcher.go @@ -1,11 +1,11 @@ package dispatcher import ( - "log" - - "github.com/pushbits/server/internal/configuration" "maunium.net/go/mautrix" "maunium.net/go/mautrix/id" + + "github.com/pushbits/server/internal/configuration" + "github.com/pushbits/server/internal/log" ) // Dispatcher holds information for sending notifications to clients. @@ -16,7 +16,7 @@ type Dispatcher struct { // Create instanciates a dispatcher connection. func Create(homeserver, username, password string, formatting configuration.Formatting) (*Dispatcher, error) { - log.Println("Setting up dispatcher.") + log.L.Println("Setting up dispatcher.") matrixClient, err := mautrix.NewClient(homeserver, "", "") if err != nil { @@ -39,14 +39,14 @@ func Create(homeserver, username, password string, formatting configuration.Form // Close closes the dispatcher connection. func (d *Dispatcher) Close() { - log.Printf("Logging out.") + log.L.Printf("Logging out.") _, err := d.mautrixClient.Logout() if err != nil { - log.Printf("Error while logging out: %s", err) + log.L.Printf("Error while logging out: %s", err) } d.mautrixClient.ClearCredentials() - log.Printf("Successfully logged out.") + log.L.Printf("Successfully logged out.") } diff --git a/internal/dispatcher/notification.go b/internal/dispatcher/notification.go index 574c995..56a0ca5 100644 --- a/internal/dispatcher/notification.go +++ b/internal/dispatcher/notification.go @@ -3,15 +3,16 @@ package dispatcher import ( "fmt" "html" - "log" "strings" "github.com/gomarkdown/markdown" - "github.com/pushbits/server/internal/model" - "github.com/pushbits/server/internal/pberrors" "maunium.net/go/mautrix" "maunium.net/go/mautrix/event" mId "maunium.net/go/mautrix/id" + + "github.com/pushbits/server/internal/log" + "github.com/pushbits/server/internal/model" + "github.com/pushbits/server/internal/pberrors" ) // MessageFormat is a matrix message format @@ -53,7 +54,7 @@ type NewContent struct { // SendNotification sends a notification to the specified user. func (d *Dispatcher) SendNotification(a *model.Application, n *model.Notification) (eventId string, err error) { - log.Printf("Sending notification to room %s.", a.MatrixID) + log.L.Printf("Sending notification to room %s.", a.MatrixID) plainMessage := strings.TrimSpace(n.Message) plainTitle := strings.TrimSpace(n.Title) @@ -77,7 +78,7 @@ func (d *Dispatcher) SendNotification(a *model.Application, n *model.Notificatio // DeleteNotification sends a notification to the specified user that another notificaion is deleted func (d *Dispatcher) DeleteNotification(a *model.Application, n *model.DeleteNotification) error { - log.Printf("Sending delete notification to room %s", a.MatrixID) + log.L.Printf("Sending delete notification to room %s", a.MatrixID) var oldFormattedBody string var oldBody string @@ -85,7 +86,7 @@ func (d *Dispatcher) DeleteNotification(a *model.Application, n *model.DeleteNot deleteMessage, err := d.getMessage(a, n.ID) if err != nil { - log.Println(err) + log.L.Println(err) return pberrors.ErrorMessageNotFound } @@ -133,7 +134,7 @@ func (d *Dispatcher) getFormattedMessage(n *model.Notification) string { if ok { if contentTypeRaw, ok := optionsDisplay["contentType"]; ok { contentType := fmt.Sprintf("%v", contentTypeRaw) - log.Printf("Message content type: %s", contentType) + log.L.Printf("Message content type: %s", contentType) switch contentType { case "html", "text/html": @@ -220,7 +221,7 @@ func (d *Dispatcher) replaceMessage(a *model.Application, newBody, newFormattedB sendEvent, err := d.mautrixClient.SendMessageEvent(mId.RoomID(a.MatrixID), event.EventMessage, &replaceEvent) if err != nil { - log.Println(err) + log.L.Println(err) return nil, err } diff --git a/internal/log/ginlogrus.go b/internal/log/ginlogrus.go new file mode 100644 index 0000000..ace201b --- /dev/null +++ b/internal/log/ginlogrus.go @@ -0,0 +1,77 @@ +// Source: https://github.com/toorop/gin-logrus + +package log + +import ( + "fmt" + "math" + "net/http" + "os" + "time" + + "github.com/gin-gonic/gin" + "github.com/sirupsen/logrus" +) + +// GinLogger integrates logrus with gin +func GinLogger(logger logrus.FieldLogger, notLogged ...string) gin.HandlerFunc { + hostname, err := os.Hostname() + if err != nil { + hostname = "unknow" + } + + var skip map[string]struct{} + + if length := len(notLogged); length > 0 { + skip = make(map[string]struct{}, length) + + for _, p := range notLogged { + skip[p] = struct{}{} + } + } + + return func(c *gin.Context) { + path := c.Request.URL.Path + 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 + } + + if _, ok := skip[path]; ok { + return + } + + entry := logger.WithFields(logrus.Fields{ + "hostname": hostname, + "statusCode": statusCode, + "latency": latency, + "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 [%d] %s %s", clientIP, statusCode, c.Request.Method, path) + if statusCode >= http.StatusInternalServerError { + entry.Error(msg) + } else if statusCode >= http.StatusBadRequest { + entry.Warn(msg) + } else { + entry.Info(msg) + } + } + } +} diff --git a/internal/log/log.go b/internal/log/log.go new file mode 100644 index 0000000..322b18d --- /dev/null +++ b/internal/log/log.go @@ -0,0 +1,22 @@ +package log + +import ( + "os" + + log "github.com/sirupsen/logrus" +) + +var L *log.Logger + +func init() { + L = log.New() + L.SetOutput(os.Stderr) + L.SetLevel(log.InfoLevel) + L.SetFormatter(&log.TextFormatter{ + DisableTimestamp: true, + }) +} + +func SetDebug() { + L.SetLevel(log.DebugLevel) +} diff --git a/internal/model/user.go b/internal/model/user.go index 16d6a08..2d5afda 100644 --- a/internal/model/user.go +++ b/internal/model/user.go @@ -1,9 +1,8 @@ package model import ( - "log" - "github.com/pushbits/server/internal/authentication/credentials" + "github.com/pushbits/server/internal/log" ) // User holds information like the name, the secret, and the applications of a user. @@ -37,7 +36,7 @@ type CreateUser struct { // NewUser creates a new user. func NewUser(cm *credentials.Manager, name, password string, isAdmin bool, matrixID string) (*User, error) { - log.Printf("Creating user %s.", name) + log.L.Printf("Creating user %s.", name) passwordHash, err := cm.CreatePasswordHash(password) if err != nil { diff --git a/internal/router/router.go b/internal/router/router.go index 68f61ca..29a156c 100644 --- a/internal/router/router.go +++ b/internal/router/router.go @@ -1,21 +1,20 @@ package router import ( - "log" + "github.com/gin-contrib/location" + "github.com/gin-gonic/gin" "github.com/pushbits/server/internal/api" "github.com/pushbits/server/internal/authentication" "github.com/pushbits/server/internal/authentication/credentials" "github.com/pushbits/server/internal/database" "github.com/pushbits/server/internal/dispatcher" - - "github.com/gin-contrib/location" - "github.com/gin-gonic/gin" + "github.com/pushbits/server/internal/log" ) // Create a Gin engine and setup all routes. func Create(debug bool, cm *credentials.Manager, db *database.Database, dp *dispatcher.Dispatcher) *gin.Engine { - log.Println("Setting up HTTP routes.") + log.L.Println("Setting up HTTP routes.") if !debug { gin.SetMode(gin.ReleaseMode) @@ -28,7 +27,8 @@ func Create(debug bool, cm *credentials.Manager, db *database.Database, dp *disp notificationHandler := api.NotificationHandler{DB: db, DP: dp} userHandler := api.UserHandler{AH: &applicationHandler, CM: cm, DB: db, DP: dp} - r := gin.Default() + r := gin.New() + r.Use(log.GinLogger(log.L), gin.Recovery()) r.Use(location.Default()) diff --git a/tests/mockups/config.go b/tests/mockups/config.go index d87ea65..8aad161 100644 --- a/tests/mockups/config.go +++ b/tests/mockups/config.go @@ -3,17 +3,17 @@ package mockups import ( "errors" "io/ioutil" - "log" "os" "github.com/pushbits/server/internal/configuration" + "github.com/pushbits/server/internal/log" ) // ReadConfig copies the given filename to the current folder and parses it as a config file. RemoveFile indicates whether to remove the copied file or not func ReadConfig(filename string, removeFile bool) (config *configuration.Configuration, err error) { defer func() { if r := recover(); r != nil { - log.Println(r) + log.L.Println(r) err = errors.New("paniced while reading config") } }()