Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Implement structured logging using log/slog package #2096

Merged
merged 1 commit into from
Sep 25, 2023
Merged

Implement structured logging using log/slog package #2096

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
57 changes: 46 additions & 11 deletions internal/api/middleware.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,11 +5,11 @@ package api // import "miniflux.app/v2/internal/api"

import (
"context"
"log/slog"
"net/http"

"miniflux.app/v2/internal/http/request"
"miniflux.app/v2/internal/http/response/json"
"miniflux.app/v2/internal/logger"
"miniflux.app/v2/internal/storage"
)

Expand Down Expand Up @@ -40,25 +40,37 @@ func (m *middleware) apiKeyAuth(next http.Handler) http.Handler {
token := r.Header.Get("X-Auth-Token")

if token == "" {
logger.Debug("[API][TokenAuth] [ClientIP=%s] No API Key provided, go to the next middleware", clientIP)
slog.Debug("[API] Skipped API token authentication because no API Key has been provided",
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
)
next.ServeHTTP(w, r)
return
}

user, err := m.store.UserByAPIKey(token)
if err != nil {
logger.Error("[API][TokenAuth] %v", err)
json.ServerError(w, r, err)
return
}

if user == nil {
logger.Error("[API][TokenAuth] [ClientIP=%s] No user found with the given API key", clientIP)
slog.Warn("[API] No user found with the provided API key",
slog.Bool("authentication_failed", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
)
json.Unauthorized(w, r)
return
}

logger.Info("[API][TokenAuth] [ClientIP=%s] User authenticated: %s", clientIP, user.Username)
slog.Info("[API] User authenticated successfully with the API Token Authentication",
slog.Bool("authentication_successful", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
slog.String("username", user.Username),
)

m.store.SetLastLogin(user.ID)
m.store.SetAPIKeyUsedTimestamp(user.ID, token)

Expand All @@ -84,37 +96,60 @@ func (m *middleware) basicAuth(next http.Handler) http.Handler {
clientIP := request.ClientIP(r)
username, password, authOK := r.BasicAuth()
if !authOK {
logger.Debug("[API][BasicAuth] [ClientIP=%s] No authentication headers sent", clientIP)
slog.Warn("[API] No Basic HTTP Authentication header sent with the request",
slog.Bool("authentication_failed", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
)
json.Unauthorized(w, r)
return
}

if username == "" || password == "" {
logger.Error("[API][BasicAuth] [ClientIP=%s] Empty username or password", clientIP)
slog.Warn("[API] Empty username or password provided during Basic HTTP Authentication",
slog.Bool("authentication_failed", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
)
json.Unauthorized(w, r)
return
}

if err := m.store.CheckPassword(username, password); err != nil {
logger.Error("[API][BasicAuth] [ClientIP=%s] Invalid username or password: %s", clientIP, username)
slog.Warn("[API] Invalid username or password provided during Basic HTTP Authentication",
slog.Bool("authentication_failed", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
slog.String("username", username),
)
json.Unauthorized(w, r)
return
}

user, err := m.store.UserByUsername(username)
if err != nil {
logger.Error("[API][BasicAuth] %v", err)
json.ServerError(w, r, err)
return
}

if user == nil {
logger.Error("[API][BasicAuth] [ClientIP=%s] User not found: %s", clientIP, username)
slog.Warn("[API] User not found while using Basic HTTP Authentication",
slog.Bool("authentication_failed", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
slog.String("username", username),
)
json.Unauthorized(w, r)
return
}

logger.Info("[API][BasicAuth] [ClientIP=%s] User authenticated: %s", clientIP, username)
slog.Info("[API] User authenticated successfully with the Basic HTTP Authentication",
slog.Bool("authentication_successful", true),
slog.String("client_ip", clientIP),
slog.String("user_agent", r.UserAgent()),
slog.String("username", username),
)

m.store.SetLastLogin(user.ID)

ctx := r.Context()
Expand Down
3 changes: 1 addition & 2 deletions internal/cli/ask_credentials.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,8 +16,7 @@ func askCredentials() (string, string) {
fd := int(os.Stdin.Fd())

if !term.IsTerminal(fd) {
fmt.Fprintf(os.Stderr, "This is not a terminal, exiting.\n")
os.Exit(1)
printErrorAndExit(fmt.Errorf("this is not a terminal, exiting"))
}

fmt.Print("Enter Username: ")
Expand Down
19 changes: 13 additions & 6 deletions internal/cli/cleanup_tasks.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,10 @@
package cli // import "miniflux.app/v2/internal/cli"

import (
"log/slog"
"time"

"miniflux.app/v2/internal/config"
"miniflux.app/v2/internal/logger"
"miniflux.app/v2/internal/metric"
"miniflux.app/v2/internal/model"
"miniflux.app/v2/internal/storage"
Expand All @@ -16,13 +16,18 @@ import (
func runCleanupTasks(store *storage.Storage) {
nbSessions := store.CleanOldSessions(config.Opts.CleanupRemoveSessionsDays())
nbUserSessions := store.CleanOldUserSessions(config.Opts.CleanupRemoveSessionsDays())
logger.Info("[Sessions] Removed %d application sessions and %d user sessions", nbSessions, nbUserSessions)
slog.Info("Sessions cleanup completed",
slog.Int64("application_sessions_removed", nbSessions),
slog.Int64("user_sessions_removed", nbUserSessions),
)

startTime := time.Now()
if rowsAffected, err := store.ArchiveEntries(model.EntryStatusRead, config.Opts.CleanupArchiveReadDays(), config.Opts.CleanupArchiveBatchSize()); err != nil {
logger.Error("[ArchiveReadEntries] %v", err)
slog.Error("Unable to archive read entries", slog.Any("error", err))
} else {
logger.Info("[ArchiveReadEntries] %d entries changed", rowsAffected)
slog.Info("Archiving read entries completed",
slog.Int64("read_entries_archived", rowsAffected),
)

if config.Opts.HasMetricsCollector() {
metric.ArchiveEntriesDuration.WithLabelValues(model.EntryStatusRead).Observe(time.Since(startTime).Seconds())
Expand All @@ -31,9 +36,11 @@ func runCleanupTasks(store *storage.Storage) {

startTime = time.Now()
if rowsAffected, err := store.ArchiveEntries(model.EntryStatusUnread, config.Opts.CleanupArchiveUnreadDays(), config.Opts.CleanupArchiveBatchSize()); err != nil {
logger.Error("[ArchiveUnreadEntries] %v", err)
slog.Error("Unable to archive unread entries", slog.Any("error", err))
} else {
logger.Info("[ArchiveUnreadEntries] %d entries changed", rowsAffected)
slog.Info("Archiving unread entries completed",
slog.Int64("unread_entries_archived", rowsAffected),
)

if config.Opts.HasMetricsCollector() {
metric.ArchiveEntriesDuration.WithLabelValues(model.EntryStatusUnread).Observe(time.Since(startTime).Seconds())
Expand Down
58 changes: 39 additions & 19 deletions internal/cli/cli.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,11 +6,13 @@ package cli // import "miniflux.app/v2/internal/cli"
import (
"flag"
"fmt"
"io"
"log/slog"
"os"

"miniflux.app/v2/internal/config"
"miniflux.app/v2/internal/database"
"miniflux.app/v2/internal/locale"
"miniflux.app/v2/internal/logger"
"miniflux.app/v2/internal/storage"
"miniflux.app/v2/internal/ui/static"
"miniflux.app/v2/internal/version"
Expand Down Expand Up @@ -74,26 +76,41 @@ func Parse() {
if flagConfigFile != "" {
config.Opts, err = cfg.ParseFile(flagConfigFile)
if err != nil {
logger.Fatal("%v", err)
printErrorAndExit(err)
}
}

config.Opts, err = cfg.ParseEnvironmentVariables()
if err != nil {
logger.Fatal("%v", err)
printErrorAndExit(err)
}

if flagConfigDump {
fmt.Print(config.Opts)
return
}

if config.Opts.LogDateTime() {
logger.EnableDateTime()
if flagDebugMode {
config.Opts.SetLogLevel("debug")
}

if flagDebugMode || config.Opts.HasDebugMode() {
logger.EnableDebug()
logFile := config.Opts.LogFile()
var logFileHandler io.Writer
switch logFile {
case "stdout":
logFileHandler = os.Stdout
case "stderr":
logFileHandler = os.Stderr
default:
logFileHandler, err = os.OpenFile(logFile, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0600)
if err != nil {
printErrorAndExit(fmt.Errorf("unable to open log file: %v", err))
}
defer logFileHandler.(*os.File).Close()
}

if err := InitializeDefaultLogger(config.Opts.LogLevel(), logFileHandler, config.Opts.LogFormat(), config.Opts.LogDateTime()); err != nil {
printErrorAndExit(err)
}

if flagHealthCheck != "" {
Expand All @@ -112,25 +129,23 @@ func Parse() {
}

if config.Opts.IsDefaultDatabaseURL() {
logger.Info("The default value for DATABASE_URL is used")
slog.Info("The default value for DATABASE_URL is used")
}

logger.Debug("Loading translations...")
if err := locale.LoadCatalogMessages(); err != nil {
logger.Fatal("Unable to load translations: %v", err)
printErrorAndExit(fmt.Errorf("unable to load translations: %v", err))
}

logger.Debug("Loading static assets...")
if err := static.CalculateBinaryFileChecksums(); err != nil {
logger.Fatal("Unable to calculate binary files checksum: %v", err)
printErrorAndExit(fmt.Errorf("unable to calculate binary file checksums: %v", err))
}

if err := static.GenerateStylesheetsBundles(); err != nil {
logger.Fatal("Unable to generate Stylesheet bundles: %v", err)
printErrorAndExit(fmt.Errorf("unable to generate stylesheets bundles: %v", err))
}

if err := static.GenerateJavascriptBundles(); err != nil {
logger.Fatal("Unable to generate Javascript bundles: %v", err)
printErrorAndExit(fmt.Errorf("unable to generate javascript bundles: %v", err))
}

db, err := database.NewConnectionPool(
Expand All @@ -140,19 +155,19 @@ func Parse() {
config.Opts.DatabaseConnectionLifetime(),
)
if err != nil {
logger.Fatal("Unable to initialize database connection pool: %v", err)
printErrorAndExit(fmt.Errorf("unable to connect to database: %v", err))
}
defer db.Close()

store := storage.NewStorage(db)

if err := store.Ping(); err != nil {
logger.Fatal("Unable to connect to the database: %v", err)
printErrorAndExit(err)
}

if flagMigrate {
if err := database.Migrate(db); err != nil {
logger.Fatal(`%v`, err)
printErrorAndExit(err)
}
return
}
Expand Down Expand Up @@ -180,12 +195,12 @@ func Parse() {
// Run migrations and start the daemon.
if config.Opts.RunMigrations() {
if err := database.Migrate(db); err != nil {
logger.Fatal(`%v`, err)
printErrorAndExit(err)
}
}

if err := database.IsSchemaUpToDate(db); err != nil {
logger.Fatal(`You must run the SQL migrations, %v`, err)
printErrorAndExit(err)
}

// Create admin user and start the daemon.
Expand All @@ -205,3 +220,8 @@ func Parse() {

startDaemon(store)
}

func printErrorAndExit(err error) {
fmt.Fprintf(os.Stderr, "%v\n", err)
os.Exit(1)
}
14 changes: 6 additions & 8 deletions internal/cli/create_admin.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,9 @@
package cli // import "miniflux.app/v2/internal/cli"

import (
"fmt"
"os"
"log/slog"

"miniflux.app/v2/internal/config"
"miniflux.app/v2/internal/logger"
"miniflux.app/v2/internal/model"
"miniflux.app/v2/internal/storage"
"miniflux.app/v2/internal/validator"
Expand All @@ -26,17 +24,17 @@ func createAdmin(store *storage.Storage) {
}

if store.UserExists(userCreationRequest.Username) {
logger.Info(`User %q already exists, skipping creation`, userCreationRequest.Username)
slog.Info("Skipping admin user creation because it already exists",
slog.String("username", userCreationRequest.Username),
)
return
}

if validationErr := validator.ValidateUserCreationWithPassword(store, userCreationRequest); validationErr != nil {
fmt.Fprintf(os.Stderr, "%s\n", validationErr)
os.Exit(1)
printErrorAndExit(validationErr.Error())
}

if _, err := store.CreateUser(userCreationRequest); err != nil {
fmt.Fprintf(os.Stderr, "%v\n", err)
os.Exit(1)
printErrorAndExit(err)
}
}
Loading
Loading