fix: refine logging

This commit is contained in:
2024-12-04 21:49:44 +01:00
parent 5198487feb
commit 521119fc02
14 changed files with 93 additions and 70 deletions

View File

@@ -1,7 +1,6 @@
package db
import (
"log/slog"
"me-fit/log"
"me-fit/types"
@@ -116,7 +115,7 @@ func (db AuthDbSqlite) InsertUser(user *User) error {
return ErrUserExists
}
log.Error("SQL error InsertUser", err)
log.Error("SQL error InsertUser: %v", err)
return types.ErrInternal
}
@@ -131,7 +130,7 @@ func (db AuthDbSqlite) UpdateUser(user *User) error {
user.EmailVerified, user.EmailVerifiedAt, user.Password, user.Id)
if err != nil {
log.Error("SQL error UpdateUser", err)
log.Error("SQL error UpdateUser: %v", err)
return types.ErrInternal
}
@@ -157,7 +156,7 @@ func (db AuthDbSqlite) GetUserByEmail(email string) (*User, error) {
if err == sql.ErrNoRows {
return nil, ErrNotFound
} else {
log.Error("SQL error GetUser", err)
log.Error("SQL error GetUser: %v", err)
return nil, types.ErrInternal
}
}
@@ -184,7 +183,7 @@ func (db AuthDbSqlite) GetUser(userId uuid.UUID) (*User, error) {
if err == sql.ErrNoRows {
return nil, ErrNotFound
} else {
log.Error("SQL error GetUser", err)
log.Error("SQL error GetUser %v", err)
return nil, types.ErrInternal
}
}
@@ -196,41 +195,41 @@ func (db AuthDbSqlite) DeleteUser(userId uuid.UUID) error {
tx, err := db.db.Begin()
if err != nil {
log.Error("Could not start transaction", err)
log.Error("Could not start transaction: %v", err)
return types.ErrInternal
}
_, err = tx.Exec("DELETE FROM workout WHERE user_id = ?", userId)
if err != nil {
_ = tx.Rollback()
log.Error("Could not delete workouts", err)
log.Error("Could not delete workouts: %v", err)
return types.ErrInternal
}
_, err = tx.Exec("DELETE FROM user_token WHERE user_uuid = ?", userId)
if err != nil {
_ = tx.Rollback()
log.Error("Could not delete user tokens", err)
log.Error("Could not delete user tokens: %v", err)
return types.ErrInternal
}
_, err = tx.Exec("DELETE FROM session WHERE user_uuid = ?", userId)
if err != nil {
_ = tx.Rollback()
log.Error("Could not delete sessions", err)
log.Error("Could not delete sessions: %v", err)
return types.ErrInternal
}
_, err = tx.Exec("DELETE FROM user WHERE user_uuid = ?", userId)
if err != nil {
_ = tx.Rollback()
log.Error("Could not delete user", err)
log.Error("Could not delete user: %v", err)
return types.ErrInternal
}
err = tx.Commit()
if err != nil {
log.Error("Could not commit transaction", err)
log.Error("Could not commit transaction: %v", err)
return types.ErrInternal
}
@@ -243,7 +242,7 @@ func (db AuthDbSqlite) InsertToken(token *Token) error {
VALUES (?, ?, ?, ?, ?)`, token.UserId, token.Type, token.Token, token.CreatedAt, token.ExpiresAt)
if err != nil {
log.Error("Could not insert token", err)
log.Error("Could not insert token: %v", err)
return types.ErrInternal
}
@@ -268,23 +267,23 @@ func (db AuthDbSqlite) GetToken(token string) (*Token, error) {
if err != nil {
if err == sql.ErrNoRows {
slog.Info("Token '" + token + "' not found")
log.Info("Token '%v' not found", token)
return nil, ErrNotFound
} else {
log.Error("Could not get token", err)
log.Error("Could not get token: %v", err)
return nil, types.ErrInternal
}
}
createdAt, err = time.Parse(time.RFC3339, createdAtStr)
if err != nil {
log.Error("Could not parse token.created_at", err)
log.Error("Could not parse token.created_at: %v", err)
return nil, types.ErrInternal
}
expiresAt, err = time.Parse(time.RFC3339, expiresAtStr)
if err != nil {
log.Error("Could not parse token.expires_at", err)
log.Error("Could not parse token.expires_at: %v", err)
return nil, types.ErrInternal
}
@@ -300,7 +299,7 @@ func (db AuthDbSqlite) GetTokensByUserIdAndType(userId uuid.UUID, tokenType stri
AND type = ?`, userId, tokenType)
if err != nil {
log.Error("Could not get token", err)
log.Error("Could not get token: %v", err)
return nil, types.ErrInternal
}
@@ -317,19 +316,19 @@ func (db AuthDbSqlite) GetTokensByUserIdAndType(userId uuid.UUID, tokenType stri
err := query.Scan(&token, &createdAtStr, &expiresAtStr)
if err != nil {
log.Error("Could not scan token", err)
log.Error("Could not scan token: %v", err)
return nil, types.ErrInternal
}
createdAt, err = time.Parse(time.RFC3339, createdAtStr)
if err != nil {
log.Error("Could not parse token.created_at", err)
log.Error("Could not parse token.created_at: %v", err)
return nil, types.ErrInternal
}
expiresAt, err = time.Parse(time.RFC3339, expiresAtStr)
if err != nil {
log.Error("Could not parse token.expires_at", err)
log.Error("Could not parse token.expires_at: %v", err)
return nil, types.ErrInternal
}
@@ -342,7 +341,7 @@ func (db AuthDbSqlite) GetTokensByUserIdAndType(userId uuid.UUID, tokenType stri
func (db AuthDbSqlite) DeleteToken(token string) error {
_, err := db.db.Exec("DELETE FROM user_token WHERE token = ?", token)
if err != nil {
log.Error("Could not delete token", err)
log.Error("Could not delete token: %v", err)
return types.ErrInternal
}
return nil
@@ -386,7 +385,7 @@ func (db AuthDbSqlite) DeleteOldSessions(userId uuid.UUID) error {
// Delete old inactive sessions
_, err := db.db.Exec("DELETE FROM session WHERE created_at < datetime('now','-8 hours') AND user_uuid = ?", userId)
if err != nil {
log.Error("Could not delete old sessions", err)
log.Error("Could not delete old sessions: %v", err)
return types.ErrInternal
}
return nil
@@ -397,7 +396,7 @@ func (db AuthDbSqlite) DeleteSession(sessionId string) error {
_, err := db.db.Exec("DELETE FROM session WHERE session_id = ?", sessionId)
if err != nil {
log.Error("Could not delete session", err)
log.Error("Could not delete session: %v", err)
return types.ErrInternal
}
}

View File

@@ -59,7 +59,7 @@ func (db WorkoutDbSqlite) InsertWorkout(userId uuid.UUID, workout *WorkoutInsert
VALUES (?, ?, ?, ?, ?)
RETURNING rowid`, userId, workout.Date, workout.Type, workout.Sets, workout.Reps).Scan(&rowId)
if err != nil {
log.Error("Error inserting workout", err)
log.Error("Error inserting workout: %v", err)
return nil, types.ErrInternal
}
@@ -70,7 +70,7 @@ func (db WorkoutDbSqlite) GetWorkouts(userId uuid.UUID) ([]Workout, error) {
rows, err := db.db.Query("SELECT rowid, date, type, sets, reps FROM workout WHERE user_id = ? ORDER BY date desc", userId)
if err != nil {
log.Error("Could not get workouts", err)
log.Error("Could not get workouts: %v", err)
return nil, types.ErrInternal
}
@@ -83,13 +83,13 @@ func (db WorkoutDbSqlite) GetWorkouts(userId uuid.UUID) ([]Workout, error) {
err = rows.Scan(&workout.RowId, &date, &workout.Type, &workout.Sets, &workout.Reps)
if err != nil {
log.Error("Could not scan workout", err)
log.Error("Could not scan workout: %v", err)
return nil, types.ErrInternal
}
workout.Date, err = time.Parse("2006-01-02 15:04:05-07:00", date)
if err != nil {
log.Error("Could not parse date", err)
log.Error("Could not parse date: %v", err)
return nil, types.ErrInternal
}

View File

@@ -105,7 +105,7 @@ func (handler HandlerAuthImpl) handleSignIn() http.HandlerFunc {
utils.TriggerToast(w, r, "error", "Invalid email or password")
http.Error(w, "Invalid email or password", http.StatusUnauthorized)
} else {
log.Error("Error signing in", err)
log.Error("Error signing in: %v", err)
http.Error(w, "An error occurred", http.StatusInternalServerError)
}
return
@@ -305,7 +305,7 @@ func (handler HandlerAuthImpl) HandleVerifyResendComp() http.HandlerFunc {
_, err = w.Write([]byte("<p class=\"mt-8\">Verification email sent</p>"))
if err != nil {
log.Error("Could not write response", err)
log.Error("Could not write response: %v", err)
}
}
}
@@ -370,7 +370,7 @@ func (handler HandlerAuthImpl) HandleForgotPasswordResponseComp() http.HandlerFu
pageUrl, err := url.Parse(r.Header.Get("HX-Current-URL"))
if err != nil {
log.Error("Could not get current URL", err)
log.Error("Could not get current URL: %v", err)
utils.TriggerToast(w, r, "error", "Internal Server Error")
return
}

View File

@@ -25,7 +25,7 @@ func NewRender(serverSettings *types.ServerSettings) *Render {
func (render *Render) Render(r *http.Request, w http.ResponseWriter, comp templ.Component) {
err := comp.Render(r.Context(), w)
if err != nil {
log.Error("Failed to render layout", err)
log.Error("Failed to render layout: %v", err)
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
}
}

View File

@@ -1,11 +1,11 @@
package handler
import (
"me-fit/log"
"me-fit/service"
"me-fit/template/workout"
"me-fit/utils"
"log/slog"
"net/http"
"strconv"
"time"
@@ -111,7 +111,7 @@ func (handler WorkoutHandlerImpl) handleDeleteWorkout() http.HandlerFunc {
rowId := r.PathValue("id")
if rowId == "" {
http.Error(w, "Missing required fields", http.StatusBadRequest)
slog.Warn("Missing required fields for workout delete")
log.Warn("Missing required fields for workout delete")
utils.TriggerToast(w, r, "error", "Missing ID field")
return
}
@@ -119,7 +119,7 @@ func (handler WorkoutHandlerImpl) handleDeleteWorkout() http.HandlerFunc {
rowIdInt, err := strconv.Atoi(rowId)
if err != nil {
http.Error(w, "Invalid ID", http.StatusBadRequest)
slog.Warn("Invalid ID for workout delete")
log.Warn("Invalid ID for workout delete")
utils.TriggerToast(w, r, "error", "Invalid ID")
return
}
@@ -127,7 +127,7 @@ func (handler WorkoutHandlerImpl) handleDeleteWorkout() http.HandlerFunc {
err = handler.service.DeleteWorkout(user, rowIdInt)
if err != nil {
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
slog.Error("Could not delete workout: " + err.Error())
log.Error("Could not delete workout: %v", err.Error())
utils.TriggerToast(w, r, "error", "Internal Server Error")
return
}

View File

@@ -1,7 +1,10 @@
package log
import (
"fmt"
"log"
"log/slog"
"strings"
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
@@ -16,11 +19,32 @@ var (
)
)
func Error(message string, err error) {
slog.Error(message + ": " + err.Error())
func Fatal(message string, args ...interface{}) {
s := format(message, args)
log.Fatal(s)
errorMetric.Inc()
}
func ErrorMsg(message string) {
slog.Error(message)
func Error(message string, args ...interface{}) {
s := format(message, args)
slog.Error(s)
errorMetric.Inc()
}
func Warn(message string, args ...interface{}) {
s := format(message, args)
slog.Warn(s)
}
func Info(message string, args ...interface{}) {
s := format(message, args)
slog.Info(s)
}
func format(message string, args []interface{}) string {
var w strings.Builder
fmt.Fprintf(&w, message, args)
return w.String()
}

17
main.go
View File

@@ -3,6 +3,7 @@ package main
import (
"me-fit/db"
"me-fit/handler"
"me-fit/log"
"me-fit/middleware"
"me-fit/service"
"me-fit/types"
@@ -10,8 +11,6 @@ import (
"context"
"database/sql"
"log"
"log/slog"
"net/http"
"os"
"os/signal"
@@ -32,7 +31,7 @@ func main() {
db, err := sql.Open("sqlite3", "./data.db")
if err != nil {
log.Fatal("Could not open Database data.db: ", err)
log.Fatal("Could not open Database data.db: %v", err)
}
defer db.Close()
@@ -43,7 +42,7 @@ func run(ctx context.Context, db *sql.DB, env func(string) string) {
ctx, cancel := signal.NotifyContext(ctx, syscall.SIGINT, syscall.SIGTERM)
defer cancel()
slog.Info("Starting server...")
log.Info("Starting server...")
// init server settings
serverSettings := types.NewServerSettingsFromEnv(env)
@@ -51,7 +50,7 @@ func run(ctx context.Context, db *sql.DB, env func(string) string) {
// init db
err := utils.RunMigrations(db, "")
if err != nil {
slog.Error("Could not run migrations: " + err.Error())
log.Error("Could not run migrations: %v", err)
os.Exit(1)
}
@@ -80,9 +79,9 @@ func run(ctx context.Context, db *sql.DB, env func(string) string) {
}
func startServer(s *http.Server) {
slog.Info("Starting server on " + s.Addr)
log.Info("Starting server on %v", s.Addr)
if err := s.ListenAndServe(); err != nil && err != http.ErrServerClosed {
slog.Error("error listening and serving: " + err.Error())
log.Error("error listening and serving: %v", err)
}
}
@@ -97,9 +96,9 @@ func shutdownServer(s *http.Server, ctx context.Context, wg *sync.WaitGroup) {
shutdownCtx, cancel := context.WithTimeout(shutdownCtx, 10*time.Second)
defer cancel()
if err := s.Shutdown(shutdownCtx); err != nil {
slog.Error("error shutting down http server: " + err.Error())
log.Error("error shutting down http server: %v", err)
} else {
slog.Info("Gracefully stopped http server on " + s.Addr)
log.Info("Gracefully stopped http server on %v", s.Addr)
}
}

View File

@@ -1,7 +1,7 @@
package main
import (
"log/slog"
"me-fit/log"
"me-fit/service"
"me-fit/types"
"me-fit/utils"
@@ -142,17 +142,17 @@ func waitForReady(
nil,
)
if err != nil {
slog.Error("failed to create request: " + err.Error())
log.Error("failed to create request: %v", err)
return err
}
resp, err := client.Do(req)
if err != nil {
slog.Info("Error making request: " + err.Error())
log.Info("Error making request: %v", err)
continue
}
if resp.StatusCode == http.StatusOK {
slog.Info("Endpoint is ready!")
log.Info("Endpoint is ready!")
resp.Body.Close()
return nil
}
@@ -163,7 +163,7 @@ func waitForReady(
return ctx.Err()
default:
if time.Since(startTime) >= timeout {
slog.Error("timeout reached while waiting for endpoint")
log.Error("timeout reached while waiting for endpoint")
return types.ErrInternal
}
// wait a little while between checks

View File

@@ -1,7 +1,8 @@
package middleware
import (
"log/slog"
"me-fit/log"
"net/http"
"strconv"
"time"
@@ -40,7 +41,7 @@ func Log(next http.Handler) http.Handler {
}
next.ServeHTTP(wrapped, r)
slog.Info(r.RemoteAddr + " " + strconv.Itoa(wrapped.StatusCode) + " " + r.Method + " " + r.URL.Path + " " + time.Since(start).String())
log.Info(r.RemoteAddr + " " + strconv.Itoa(wrapped.StatusCode) + " " + r.Method + " " + r.URL.Path + " " + time.Since(start).String())
metrics.WithLabelValues(r.URL.Path, r.Method, http.StatusText(wrapped.StatusCode)).Inc()
})
}

View File

@@ -201,7 +201,7 @@ func (service AuthServiceImpl) SendVerificationMail(userId uuid.UUID, email stri
var w strings.Builder
err = mailTemplate.Register(service.serverSettings.BaseUrl, token.Token).Render(context.Background(), &w)
if err != nil {
log.Error("Could not render welcome email", err)
log.Error("Could not render welcome email: %v", err)
return
}
@@ -343,7 +343,7 @@ func (service AuthServiceImpl) SendForgotPasswordMail(email string) error {
var mail strings.Builder
err = mailTemplate.ResetPassword(service.serverSettings.BaseUrl, token.Token).Render(context.Background(), &mail)
if err != nil {
log.Error("Could not render reset password email", err)
log.Error("Could not render reset password email: %v", err)
return types.ErrInternal
}
go service.mailService.SendMail(email, "Reset Password", mail.String())
@@ -369,7 +369,7 @@ func (service AuthServiceImpl) ForgotPassword(tokenStr string, newPass string) e
user, err := service.dbAuth.GetUser(token.UserId)
if err != nil {
log.Error("Could not get user from token", err)
log.Error("Could not get user from token: %v", err)
return types.ErrInternal
}

View File

@@ -1,11 +1,11 @@
package service
import (
"me-fit/log"
"me-fit/types"
"crypto/rand"
"encoding/base64"
"log/slog"
"github.com/google/uuid"
)
@@ -27,7 +27,7 @@ func (r *RandomServiceImpl) Bytes(size int) ([]byte, error) {
b := make([]byte, 32)
_, err := rand.Read(b)
if err != nil {
slog.Error("Error generating random bytes: " + err.Error())
log.Error("Error generating random bytes: %v", err)
return []byte{}, types.ErrInternal
}

View File

@@ -1,8 +1,7 @@
package types
import (
"log"
"log/slog"
"me-fit/log"
)
type ServerSettings struct {
@@ -78,8 +77,8 @@ func NewServerSettingsFromEnv(env func(string) string) *ServerSettings {
log.Fatal("SMTP and Prometheus must be enabled in production")
}
slog.Info("BASE_URL is " + settings.BaseUrl)
slog.Info("ENVIRONMENT is " + settings.Environment)
log.Info("BASE_URL is %v", settings.BaseUrl)
log.Info("ENVIRONMENT is %v", settings.Environment)
return settings
}

View File

@@ -1,10 +1,11 @@
package utils
import (
"me-fit/log"
"me-fit/types"
"database/sql"
"errors"
"log/slog"
"me-fit/types"
"github.com/golang-migrate/migrate/v4"
"github.com/golang-migrate/migrate/v4/database/sqlite3"
@@ -14,7 +15,7 @@ import (
func RunMigrations(db *sql.DB, pathPrefix string) error {
driver, err := sqlite3.WithInstance(db, &sqlite3.Config{})
if err != nil {
slog.Error("Could not create Migration instance: " + err.Error())
log.Error("Could not create Migration instance: %v", err)
return types.ErrInternal
}
@@ -23,14 +24,14 @@ func RunMigrations(db *sql.DB, pathPrefix string) error {
"",
driver)
if err != nil {
slog.Error("Could not create migrations instance: " + err.Error())
log.Error("Could not create migrations instance: %v", err)
return types.ErrInternal
}
err = m.Up()
if err != nil {
if !errors.Is(err, migrate.ErrNoChange) {
slog.Error("Could not run migrations: " + err.Error())
log.Error("Could not run migrations: %v", err)
return types.ErrInternal
}
}

View File

@@ -12,7 +12,7 @@ func TriggerToast(w http.ResponseWriter, r *http.Request, class string, message
if isHtmx(r) {
w.Header().Set("HX-Trigger", fmt.Sprintf(`{"toast": "%v|%v"}`, class, message))
} else {
log.ErrorMsg("Trying to trigger toast in non-HTMX request")
log.Error("Trying to trigger toast in non-HTMX request")
}
}