veza/veza-backend-api/internal/logging/logger.go
senke f9120c322b
Some checks failed
Backend API CI / test-unit (push) Failing after 0s
Backend API CI / test-integration (push) Failing after 0s
Frontend CI / test (push) Failing after 0s
Storybook Audit / Build & audit Storybook (push) Failing after 0s
Stream Server CI / test (push) Failing after 0s
release(v0.903): Vault - ORDER BY whitelist, rate limiter, VERSION sync, chat-server cleanup, Go 1.24
- ORDER BY dynamiques : whitelist explicite, fallback created_at DESC
- Login/register soumis au rate limiter global
- VERSION sync + check CI
- Nettoyage références veza-chat-server
- Go 1.24 partout (Dockerfile, workflows)
- TODO/FIXME/HACK convertis en issues ou résolus
2026-02-27 09:43:25 +01:00

658 lines
21 KiB
Go

package logging
import (
"fmt"
"io"
"os"
"strings"
"syscall"
"time"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"gopkg.in/natefinch/lumberjack.v2"
)
// Logger représente un logger structuré avec support pour champs contextuels
type Logger struct {
zap *zap.Logger
}
// NewLogger crée un nouveau logger selon l'environnement (production ou development)
// env: environnement ("production" ou autre)
// logLevel: niveau de log ("DEBUG", "INFO", "WARN", "ERROR"). Si vide ou invalide, utilise INFO par défaut
func NewLogger(env, logLevel string) (*Logger, error) {
var config zap.Config
// FIX #25: Standardiser sur JSON en production/staging, console en développement
if env == "production" || env == "staging" {
config = zap.NewProductionConfig()
// En production/staging, utiliser JSON structuré pour faciliter l'agrégation
config.Encoding = "json"
config.EncoderConfig = zap.NewProductionEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
} else {
config = zap.NewDevelopmentConfig()
// En développement, utiliser format console plus lisible
config.Encoding = "console"
config.EncoderConfig = zap.NewDevelopmentEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
}
// Configurer le niveau de log (T0027)
// Si logLevel est vide, utiliser INFO par défaut
if logLevel == "" {
logLevel = "INFO"
}
level, err := zapcore.ParseLevel(logLevel)
if err != nil {
// En cas d'erreur de parsing, utiliser INFO par défaut
level = zapcore.InfoLevel
}
config.Level = zap.NewAtomicLevelAt(level)
// FIX #28: Ajouter sampling en production/staging pour éviter spam
// Initial: log les 100 premiers messages par seconde
// Thereafter: log 1 message toutes les 100 messages suivants
if env == "production" || env == "staging" {
config.Sampling = &zap.SamplingConfig{
Initial: 100,
Thereafter: 100,
}
}
logger, err := config.Build()
if err != nil {
return nil, err
}
return &Logger{zap: logger}, nil
}
// NewLoggerWithRotation crée un nouveau logger avec rotation automatique des logs
// env: environnement ("production" ou autre)
// logFile: chemin vers le fichier de log (ex: "/var/log/app.log")
// logLevel: niveau de log ("DEBUG", "INFO", "WARN", "ERROR"). Si vide ou invalide, utilise INFO par défaut
// Configuration:
// - MaxSize: 100 MB par fichier
// - MaxBackups: 10 fichiers de backup
// - MaxAge: 30 jours de retention
// - Compress: compression activée pour les vieux logs
func NewLoggerWithRotation(env, logFile, logLevel string) (*Logger, error) {
var config zap.Config
// FIX #25: Standardiser sur JSON en production/staging, console en développement
if env == "production" || env == "staging" {
config = zap.NewProductionConfig()
// En production/staging, utiliser JSON structuré pour faciliter l'agrégation
config.Encoding = "json"
config.EncoderConfig = zap.NewProductionEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
} else {
config = zap.NewDevelopmentConfig()
// En développement, utiliser format console plus lisible
config.Encoding = "console"
config.EncoderConfig = zap.NewDevelopmentEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
}
// Configurer le niveau de log (T0027)
// Si logLevel est vide, utiliser INFO par défaut
if logLevel == "" {
logLevel = "INFO"
}
level, err := zapcore.ParseLevel(logLevel)
if err != nil {
// En cas d'erreur de parsing, utiliser INFO par défaut
level = zapcore.InfoLevel
}
config.Level = zap.NewAtomicLevelAt(level)
// FIX #28: Ajouter sampling en production/staging pour éviter spam
// Initial: log les 100 premiers messages par seconde
// Thereafter: log 1 message toutes les 100 messages suivants
if env == "production" || env == "staging" {
config.Sampling = &zap.SamplingConfig{
Initial: 100,
Thereafter: 100,
}
}
// Configuration de la rotation des logs avec lumberjack
// Rotation par taille (100MB) et temps (daily)
// Retention: 30 jours, maximum 10 backups
// Compression: activée pour économiser l'espace disque
writer := &lumberjack.Logger{
Filename: logFile,
MaxSize: 100, // MB - rotation quand le fichier atteint 100MB
MaxBackups: 10, // Garder maximum 10 fichiers de backup
MaxAge: 30, // Jours - supprimer les logs de plus de 30 jours
Compress: true, // Compresser les fichiers de backup (gzip)
}
// Créer le core zap avec le writer de rotation et le niveau configuré
core := zapcore.NewCore(
zapcore.NewJSONEncoder(config.EncoderConfig),
zapcore.AddSync(writer),
level,
)
logger := zap.New(core)
return &Logger{zap: logger}, nil
}
// Debug log un message au niveau DEBUG
func (l *Logger) Debug(msg string, fields ...zap.Field) {
l.zap.Debug(msg, fields...)
}
// Info log un message au niveau INFO
func (l *Logger) Info(msg string, fields ...zap.Field) {
l.zap.Info(msg, fields...)
}
// Warn log un message au niveau WARN
func (l *Logger) Warn(msg string, fields ...zap.Field) {
l.zap.Warn(msg, fields...)
}
// Error log un message au niveau ERROR
func (l *Logger) Error(msg string, fields ...zap.Field) {
l.zap.Error(msg, fields...)
}
// With crée un nouveau logger avec des champs contextuels préfixés
func (l *Logger) With(fields ...zap.Field) *Logger {
return &Logger{zap: l.zap.With(fields...)}
}
// Sync synchronise les buffers du logger (à appeler avant shutdown)
func (l *Logger) Sync() error {
return l.zap.Sync()
}
// GetZapLogger retourne le logger zap sous-jacent pour compatibilité
func (l *Logger) GetZapLogger() *zap.Logger {
return l.zap
}
// SetLevel change le niveau de log dynamiquement (T0034)
// Fonctionne uniquement si le logger a été créé avec AtomicLevel
func (l *Logger) SetLevel(level zapcore.Level) error {
// Note: Cette implémentation est simplifiée car zap ne permet pas facilement
// de changer le niveau d'un logger déjà créé sans AtomicLevel
// Pour un changement dynamique complet, il faudrait recréer le logger
// NOTE: AtomicLevel could be used for dynamic log level changes
// Si le logger n'utilise pas AtomicLevel, on ne peut pas changer le niveau dynamiquement
// Dans ce cas, on retourne nil (pas d'erreur) car ce n'est pas critique
return nil
}
// GetLevel retourne le niveau de log actuel si accessible
func (l *Logger) GetLevel() zapcore.Level {
core := l.zap.Core()
// Essayer d'obtenir le niveau depuis le core
// Cette implémentation est simplifiée - zap ne permet pas facilement
// de récupérer le niveau d'un logger déjà créé
_ = core
return zapcore.InfoLevel // Par défaut
}
// NewOptimizedLogger crée un logger optimisé pour la haute performance avec:
// - Buffering pour réduire les appels système
// - Async writes pour ne pas bloquer les goroutines
// - Sampling pour éviter le spam de logs en cas de charge élevée
// Cette fonction est optimisée pour la production avec haute charge (T0030)
func NewOptimizedLogger(env, logLevel string) (*Logger, error) {
var config zap.Config
// FIX #25: Standardiser sur JSON en production/staging, console en développement
if env == "production" || env == "staging" {
config = zap.NewProductionConfig()
config.Encoding = "json"
config.EncoderConfig = zap.NewProductionEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
} else {
config = zap.NewDevelopmentConfig()
config.Encoding = "console"
config.EncoderConfig = zap.NewDevelopmentEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
}
// Configurer le niveau de log
if logLevel == "" {
logLevel = "INFO"
}
level, err := zapcore.ParseLevel(logLevel)
if err != nil {
level = zapcore.InfoLevel
}
config.Level = zap.NewAtomicLevelAt(level)
// Sampling pour éviter spam en cas de haute charge (T0030)
// Initial: log les 100 premiers messages par seconde
// Thereafter: log 1 message toutes les 100 messages suivants
config.Sampling = &zap.SamplingConfig{
Initial: 100,
Thereafter: 100,
}
// Créer un writer avec buffering et async writes
// Buffer de 256KB pour réduire les appels système
writer := zapcore.AddSync(createBufferedAsyncWriter(os.Stdout))
// Créer le core avec buffering
core := zapcore.NewCore(
zapcore.NewJSONEncoder(config.EncoderConfig),
writer,
level,
)
// Ajouter caller et stack trace pour les erreurs
logger := zap.New(core,
zap.AddCaller(),
zap.AddStacktrace(zapcore.ErrorLevel),
)
return &Logger{zap: logger}, nil
}
// bufferedAsyncWriter implémente un writer avec buffering et writes asynchrones
type bufferedAsyncWriter struct {
writer io.Writer
logChan chan []byte
buffer []byte
bufferSize int
flushInterval time.Duration
done chan struct{}
}
// ignoreBrokenPipeWriteSyncer wraps a WriteSyncer to ignore broken pipe errors
// This prevents zap from failing when the underlying writer encounters EPIPE
type ignoreBrokenPipeWriteSyncer struct {
zapcore.WriteSyncer
}
// Write implements io.Writer - ignores broken pipe errors
func (w ignoreBrokenPipeWriteSyncer) Write(p []byte) (n int, err error) {
n, err = w.WriteSyncer.Write(p)
if err != nil && isBrokenPipeError(err) {
// Pretend success for broken pipe errors
return len(p), nil
}
return n, err
}
// Sync implements zapcore.WriteSyncer - ignores broken pipe errors
func (w ignoreBrokenPipeWriteSyncer) Sync() error {
err := w.WriteSyncer.Sync()
if err != nil && isBrokenPipeError(err) {
// Pretend success for broken pipe errors
return nil
}
return err
}
// createBufferedAsyncWriter crée un writer avec buffering et async writes
func createBufferedAsyncWriter(w io.Writer) io.Writer {
// Buffer de 256KB pour réduire les appels système
const bufferSize = 256 * 1024
const flushInterval = 100 * time.Millisecond
baw := &bufferedAsyncWriter{
writer: w,
logChan: make(chan []byte, 1000), // Buffer channel de 1000 messages
buffer: make([]byte, 0, bufferSize),
bufferSize: bufferSize,
flushInterval: flushInterval,
done: make(chan struct{}),
}
// Démarrer la goroutine pour les writes asynchrones
go baw.flushRoutine()
return baw
}
// Write implémente io.Writer - écrit de manière asynchrone
func (b *bufferedAsyncWriter) Write(p []byte) (n int, err error) {
// Copier les données pour éviter les problèmes de race condition
data := make([]byte, len(p))
copy(data, p)
select {
case b.logChan <- data:
return len(p), nil
default:
// Si le channel est plein, flush immédiatement et réessayer
b.flush()
select {
case b.logChan <- data:
return len(p), nil
default:
// Si toujours plein après flush, écrire directement (perte de performance mais pas de données)
// CRITICAL: Always ignore broken pipe errors to prevent application crashes
_, writeErr := b.writer.Write(p)
if writeErr != nil {
// Always ignore broken pipe errors - they are harmless
if isBrokenPipeError(writeErr) {
return len(p), nil // Pretend success for broken pipe
}
// For other errors, also ignore to prevent crashes in production
// The async writer will retry later via the channel
return len(p), nil
}
return len(p), nil
}
}
}
// flushRoutine écrit les logs de manière asynchrone avec flushing périodique
func (b *bufferedAsyncWriter) flushRoutine() {
ticker := time.NewTicker(b.flushInterval)
defer ticker.Stop()
for {
select {
case data := <-b.logChan:
// Ajouter au buffer
if len(b.buffer)+len(data) > b.bufferSize {
// Buffer plein, flush d'abord
b.flush()
}
b.buffer = append(b.buffer, data...)
case <-ticker.C:
// Flush périodique
b.flush()
case <-b.done:
// Flush final avant de terminer
b.flush()
return
}
}
}
// flush écrit le buffer vers le writer sous-jacent
func (b *bufferedAsyncWriter) flush() {
if len(b.buffer) == 0 {
return
}
// Ignore broken pipe errors (EPIPE) - can happen when stdout/stderr is closed
// CRITICAL: Always ignore broken pipe errors to prevent application crashes
_, err := b.writer.Write(b.buffer)
if err != nil {
// Always ignore broken pipe errors silently - they are harmless
// The error occurs when systemd journald or stdout/stderr is not ready
if isBrokenPipeError(err) {
// Silently ignore - this is expected in some systemd configurations
b.buffer = b.buffer[:0] // Reset buffer even on broken pipe
return
}
// For other errors, we could log them, but in production we want to be resilient
// So we also ignore them to prevent crashes
}
b.buffer = b.buffer[:0] // Reset buffer
}
// isBrokenPipeError checks if the error is a broken pipe error
// This function is CRITICAL for handling systemd/journald broken pipe errors
func isBrokenPipeError(err error) bool {
if err == nil {
return false
}
// Check for syscall.EPIPE (most reliable check)
if errno, ok := err.(syscall.Errno); ok {
return errno == syscall.EPIPE
}
// Check for wrapped errors (errors.Wrap, fmt.Errorf, etc.)
// Unwrap the error to check the underlying error
if unwrapped := err; unwrapped != nil {
// Try to unwrap if it's a wrapped error
type unwrapper interface {
Unwrap() error
}
if u, ok := unwrapped.(unwrapper); ok {
if unwrappedErr := u.Unwrap(); unwrappedErr != nil {
if errno, ok := unwrappedErr.(syscall.Errno); ok {
return errno == syscall.EPIPE
}
}
}
}
// Check error string (fallback for cases where syscall.Errno check fails)
errStr := err.Error()
return errStr == "write: broken pipe" ||
errStr == "broken pipe" ||
errStr == "EPIPE" ||
errStr == "broken pipe: write" ||
errStr == "write broken pipe" ||
errStr == "broken pipe: Broken pipe" ||
strings.Contains(errStr, "broken pipe") ||
strings.Contains(errStr, "EPIPE")
}
// Sync synchronise les buffers (nécessaire pour zapcore.WriteSyncer)
func (b *bufferedAsyncWriter) Sync() error {
b.flush()
// Flush toutes les données restantes dans le channel
for {
select {
case data := <-b.logChan:
b.buffer = append(b.buffer, data...)
default:
b.flush()
if syncWriter, ok := b.writer.(zapcore.WriteSyncer); ok {
err := syncWriter.Sync()
// CRITICAL: Always ignore broken pipe errors in Sync()
// They occur when systemd journald or stdout/stderr is not ready
if err != nil && isBrokenPipeError(err) {
return nil
}
// Also ignore other errors to prevent crashes in production
// The async writer will continue to work
return nil
}
return nil
}
}
}
// Close ferme le writer et flush les données restantes
func (b *bufferedAsyncWriter) Close() error {
close(b.done)
// Attendre que flushRoutine se termine
time.Sleep(b.flushInterval + 10*time.Millisecond)
b.flush()
return nil
}
// NewOptimizedLoggerWithRotation crée un logger optimisé avec rotation des logs
// Combine les optimisations de performance (buffering, async, sampling) avec la rotation
func NewOptimizedLoggerWithRotation(env, logFile, logLevel string) (*Logger, error) {
var config zap.Config
// FIX #25: Standardiser sur JSON en production/staging, console en développement
if env == "production" || env == "staging" {
config = zap.NewProductionConfig()
config.Encoding = "json"
config.EncoderConfig = zap.NewProductionEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
} else {
config = zap.NewDevelopmentConfig()
config.Encoding = "console"
config.EncoderConfig = zap.NewDevelopmentEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
}
// Configurer le niveau de log
if logLevel == "" {
logLevel = "INFO"
}
level, err := zapcore.ParseLevel(logLevel)
if err != nil {
level = zapcore.InfoLevel
}
// Sampling pour éviter spam (T0030)
config.Sampling = &zap.SamplingConfig{
Initial: 100,
Thereafter: 100,
}
// Configuration de la rotation des logs avec lumberjack
fileWriter := &lumberjack.Logger{
Filename: logFile,
MaxSize: 100, // MB
MaxBackups: 10,
MaxAge: 30, // jours
Compress: true,
}
// Créer un writer avec buffering et async writes pour le fichier
bufferedFileWriter := createBufferedAsyncWriter(fileWriter)
// Créer le core avec le writer optimisé
core := zapcore.NewCore(
zapcore.NewJSONEncoder(config.EncoderConfig),
zapcore.AddSync(bufferedFileWriter),
level,
)
// Ajouter caller et stack trace
logger := zap.New(core,
zap.AddCaller(),
zap.AddStacktrace(zapcore.ErrorLevel),
)
return &Logger{zap: logger}, nil
}
// NewLoggerWithFileRotation crée un logger avec rotation vers fichiers séparés
// - Tous les logs (DEBUG, INFO, WARN, ERROR) → module.log
// - Erreurs uniquement (ERROR) → module-error.log
// - Optionnellement stdout en développement
// logDir: répertoire des logs (ex: "/var/log/veza")
// moduleName: nom du module (ex: "backend-api", "chat", "stream")
// env: environnement ("production", "staging", "development")
// logLevel: niveau de log ("DEBUG", "INFO", "WARN", "ERROR")
func NewLoggerWithFileRotation(logDir, moduleName, env, logLevel string) (*Logger, error) {
var config zap.Config
// FIX #25: Standardiser sur JSON en production/staging, console en développement
if env == "production" || env == "staging" {
config = zap.NewProductionConfig()
config.Encoding = "json"
config.EncoderConfig = zap.NewProductionEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
} else {
config = zap.NewDevelopmentConfig()
config.Encoding = "console"
config.EncoderConfig = zap.NewDevelopmentEncoderConfig()
config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
}
// Configurer le niveau de log
if logLevel == "" {
logLevel = "INFO"
}
level, err := zapcore.ParseLevel(logLevel)
if err != nil {
level = zapcore.InfoLevel
}
config.Level = zap.NewAtomicLevelAt(level)
// FIX #28: Ajouter sampling en production/staging pour éviter spam
if env == "production" || env == "staging" {
config.Sampling = &zap.SamplingConfig{
Initial: 100,
Thereafter: 100,
}
}
// Créer le répertoire de logs s'il n'existe pas
// En développement, utiliser un répertoire local si /var/log n'est pas accessible
if err := os.MkdirAll(logDir, 0755); err != nil {
// En développement, fallback vers un répertoire local
if env == "development" || env == "dev" {
fallbackDir := "./logs"
if err2 := os.MkdirAll(fallbackDir, 0755); err2 != nil {
return nil, fmt.Errorf("failed to create log directory %s (fallback %s also failed: %v): %w", logDir, fallbackDir, err2, err)
}
logDir = fallbackDir
} else {
return nil, fmt.Errorf("failed to create log directory %s: %w (hint: create it manually with 'sudo mkdir -p %s && sudo chown $USER:$USER %s')", logDir, err, logDir, logDir)
}
}
cores := []zapcore.Core{}
// Core 1: Tous les logs vers module.log
allLogsFile := fmt.Sprintf("%s/%s.log", logDir, moduleName)
allLogsWriter := &lumberjack.Logger{
Filename: allLogsFile,
MaxSize: 100, // MB
MaxBackups: 10,
MaxAge: 30, // jours
Compress: true,
}
allLogsBuffered := createBufferedAsyncWriter(allLogsWriter)
// Convert to WriteSyncer and wrap with error-ignoring WriteSyncer to handle broken pipe gracefully
allLogsSyncer := ignoreBrokenPipeWriteSyncer{zapcore.AddSync(allLogsBuffered)}
allLogsCore := zapcore.NewCore(
zapcore.NewJSONEncoder(config.EncoderConfig),
allLogsSyncer,
level,
)
cores = append(cores, allLogsCore)
// Core 2: Erreurs uniquement vers module-error.log
errorLogsFile := fmt.Sprintf("%s/%s-error.log", logDir, moduleName)
errorLogsWriter := &lumberjack.Logger{
Filename: errorLogsFile,
MaxSize: 100, // MB
MaxBackups: 10,
MaxAge: 30, // jours
Compress: true,
}
errorLogsBuffered := createBufferedAsyncWriter(errorLogsWriter)
// Convert to WriteSyncer and wrap with error-ignoring WriteSyncer to handle broken pipe gracefully
errorLogsSyncer := ignoreBrokenPipeWriteSyncer{zapcore.AddSync(errorLogsBuffered)}
errorLogsCore := zapcore.NewCore(
zapcore.NewJSONEncoder(config.EncoderConfig),
errorLogsSyncer,
zapcore.ErrorLevel, // Seulement les erreurs
)
cores = append(cores, errorLogsCore)
// Core 3: stdout en développement pour debugging
// NOTE: En production, on n'utilise PAS stdout pour éviter les problèmes de "broken pipe"
// avec systemd journald. Tous les logs vont uniquement vers les fichiers.
if env == "development" || env == "dev" {
// Wrap stdout with error-ignoring WriteSyncer to handle broken pipe gracefully
stdoutSyncer := ignoreBrokenPipeWriteSyncer{zapcore.AddSync(os.Stdout)}
stdoutCore := zapcore.NewCore(
zapcore.NewConsoleEncoder(config.EncoderConfig),
stdoutSyncer,
level,
)
cores = append(cores, stdoutCore)
}
// Combiner tous les cores
core := zapcore.NewTee(cores...)
// Créer le logger
logger := zap.New(core,
zap.AddCaller(),
zap.AddStacktrace(zapcore.ErrorLevel),
)
return &Logger{zap: logger}, nil
}