Improve logging

This commit is contained in:
Torjus Håkestad 2022-09-28 12:28:15 +02:00
parent 837f89e5d3
commit 8084362d22
No known key found for this signature in database
GPG Key ID: C6FD38B820D295FC

View File

@ -57,17 +57,17 @@ func ActionServe(c *cli.Context) error {
// Setup logging // Setup logging
loggers := setupLoggers(cfg) loggers := setupLoggers(cfg)
loggers.rootLogger.Infow("Starting apiary", "version", apiary.FullVersion()) loggers.rootLogger.Infow("Starting apiary.", "version", apiary.FullVersion())
// Setup store // Setup store
var s store.LoginAttemptStore var s store.LoginAttemptStore
switch cfg.Store.Type { switch cfg.Store.Type {
case "MEMORY", "memory": case "MEMORY", "memory":
loggers.rootLogger.Infow("Initialized store", "store_type", "memory") loggers.rootLogger.Infow("Initialized store.", "store_type", "memory")
s = &store.MemoryStore{} s = &store.MemoryStore{}
case "POSTGRES", "postgres": case "POSTGRES", "postgres":
pgStartTime := time.Now() pgStartTime := time.Now()
loggers.rootLogger.Debugw("Initializing store", "store_type", "postgres") loggers.rootLogger.Debugw("Initializing store.", "store_type", "postgres")
pgStore, err := store.NewPostgresStore(cfg.Store.Postgres.DSN) pgStore, err := store.NewPostgresStore(cfg.Store.Postgres.DSN)
if err != nil { if err != nil {
return err return err
@ -75,33 +75,33 @@ func ActionServe(c *cli.Context) error {
if err := pgStore.InitDB(); err != nil { if err := pgStore.InitDB(); err != nil {
return err return err
} }
loggers.rootLogger.Infow("Initialized store", "store_type", "postgres", "init_time", time.Since(pgStartTime)) loggers.rootLogger.Infow("Initialized store.", "store_type", "postgres", "init_time", time.Since(pgStartTime))
if cfg.Store.EnableCache { if cfg.Store.EnableCache {
loggers.rootLogger.Debugw("Initializing store", "store_type", "cache-postgres") loggers.rootLogger.Debugw("Initializing store.", "store_type", "cache-postgres")
startTime := time.Now() startTime := time.Now()
cachingStore := store.NewCachingStore(pgStore) cachingStore := store.NewCachingStore(pgStore)
s = cachingStore s = cachingStore
loggers.rootLogger.Infow("Initialized store", "store_type", "cache-postgres", "init_time", time.Since(startTime)) loggers.rootLogger.Infow("Initialized store.", "store_type", "cache-postgres", "init_time", time.Since(startTime))
} else { } else {
s = pgStore s = pgStore
} }
case "bolt", "BOLT": case "bolt", "BOLT":
boltStartTime := time.Now() boltStartTime := time.Now()
loggers.rootLogger.Debugw("Initializing store", "store_type", "bolt") loggers.rootLogger.Debugw("Initializing store.", "store_type", "bolt")
boltStore, err := store.NewBBoltStore(cfg.Store.Bolt.DBPath) boltStore, err := store.NewBBoltStore(cfg.Store.Bolt.DBPath)
if err != nil { if err != nil {
return err return err
} }
defer boltStore.Close() defer boltStore.Close()
loggers.rootLogger.Infow("Initialized store", "store_type", "bolt", "init_time", time.Since(boltStartTime)) loggers.rootLogger.Infow("Initialized store.", "store_type", "bolt", "init_time", time.Since(boltStartTime))
if cfg.Store.EnableCache { if cfg.Store.EnableCache {
loggers.rootLogger.Debugw("Initializing store", "store_type", "cache-bolt") loggers.rootLogger.Debugw("Initializing store.", "store_type", "cache-bolt")
startTime := time.Now() startTime := time.Now()
cachingStore := store.NewCachingStore(boltStore) cachingStore := store.NewCachingStore(boltStore)
s = cachingStore s = cachingStore
loggers.rootLogger.Infow("Initialized store", "store_type", "cache-bolt", "init_time", time.Since(startTime)) loggers.rootLogger.Infow("Initialized store.", "store_type", "cache-bolt", "init_time", time.Since(startTime))
} else { } else {
s = boltStore s = boltStore
} }
@ -160,9 +160,9 @@ func ActionServe(c *cli.Context) error {
} }
go func() { go func() {
loggers.rootLogger.Info("Starting ports server") loggers.rootLogger.Info("Starting ports server.")
if err := portsServer.Start(portsCtx); err != nil { if err := portsServer.Start(portsCtx); err != nil {
loggers.rootLogger.Warnw("Ports server returned error", "err", err) loggers.rootLogger.Warnw("Ports server returned error.", "err", err)
} }
}() }()
} }
@ -171,7 +171,7 @@ func ActionServe(c *cli.Context) error {
if cfg.SMTP.Enable { if cfg.SMTP.Enable {
honeypot, err := smtp.NewSMTPHoneypot() honeypot, err := smtp.NewSMTPHoneypot()
if err != nil { if err != nil {
loggers.rootLogger.Warnw("Error seting up SMTP honeypot", "error", err) loggers.rootLogger.Warnw("Error seting up SMTP honeypot.", "error", err)
} }
honeypot.Addr = cfg.SMTP.Addr honeypot.Addr = cfg.SMTP.Addr
honeypot.Logger = loggers.smtpLogger honeypot.Logger = loggers.smtpLogger
@ -183,43 +183,44 @@ func ActionServe(c *cli.Context) error {
// Start smtp honeypot // Start smtp honeypot
go func() { go func() {
loggers.rootLogger.Info("Starting SMTP server") loggers.rootLogger.Info("Starting SMTP server.")
if err := honeypot.ListenAndServe(); err != nil { if err := honeypot.ListenAndServe(); err != nil {
loggers.rootLogger.Warnw("SMTP server returned error", "error", err) loggers.rootLogger.Warnw("SMTP server returned error.", "error", err)
} }
}() }()
// Wait for smtp shutdown // Wait for smtp shutdown
go func() { go func() {
<-serversCtx.Done() <-serversCtx.Done()
loggers.rootLogger.Info("SMTP server shutdown started") loggers.rootLogger.Info("SMTP server shutdown started.")
if err := honeypot.Shutdown(); err != nil { if err := honeypot.Shutdown(); err != nil {
loggers.rootLogger.Errorw("Error shutting down SMTP server", "error", err) loggers.rootLogger.Errorw("Error shutting down SMTP server.", "error", err)
} }
loggers.rootLogger.Info("SMTP server shutdown complete") loggers.rootLogger.Info("SMTP server shutdown complete.")
}() }()
} }
// Handle interrupt // Handle interrupt
go func() { go func() {
<-interruptChan <-interruptChan
loggers.rootLogger.Info("Interrupt received, shutting down") loggers.rootLogger.Info("Interrupt received, shutting down.")
serversCancel() serversCancel()
}() }()
// Start ssh server // Start ssh server
go func() { go func() {
loggers.rootLogger.Info("Starting SSH server") loggers.rootLogger.Info("Starting SSH server.")
if err := hs.ListenAndServe(); err != nil && err != sshlib.ErrServerClosed { if err := hs.ListenAndServe(); err != nil && err != sshlib.ErrServerClosed {
loggers.rootLogger.Warnw("SSH server returned error", "error", err) loggers.rootLogger.Warnw("SSH server returned error.", "error", err)
} }
loggers.rootLogger.Infow("SSH server stopped.")
}() }()
// Start web server // Start web server
go func() { go func() {
loggers.rootLogger.Info("Starting web server") loggers.rootLogger.Info("Starting web server.")
if err := web.StartServe(); err != nil && err != http.ErrServerClosed { if err := web.StartServe(); err != nil && err != http.ErrServerClosed {
loggers.rootLogger.Warnw("Web server returned error", "error", err) loggers.rootLogger.Warnw("Web server returned error.", "error", err)
} }
}() }()
@ -283,21 +284,21 @@ func ActionServe(c *cli.Context) error {
// Stop SSH server // Stop SSH server
sshShutdownCtx, sshShutdownCancel := context.WithTimeout(context.Background(), 10*time.Second) sshShutdownCtx, sshShutdownCancel := context.WithTimeout(context.Background(), 10*time.Second)
defer sshShutdownCancel() defer sshShutdownCancel()
loggers.rootLogger.Info("SSH server shutdown started") loggers.rootLogger.Info("SSH server shutdown started.")
if err := hs.Shutdown(sshShutdownCtx); err != nil { if err := hs.Shutdown(sshShutdownCtx); err != nil {
loggers.rootLogger.Infow("Error shutting down SSH server", "error", err) loggers.rootLogger.Infow("Error shutting down SSH server.", "error", err)
} }
loggers.rootLogger.Info("SSH server shutdown complete") loggers.rootLogger.Info("SSH server shutdown complete.")
// Stop Web server // Stop Web server
webShutdownCtx, webShutdownCancel := context.WithTimeout(context.Background(), 10*time.Second) webShutdownCtx, webShutdownCancel := context.WithTimeout(context.Background(), 10*time.Second)
defer webShutdownCancel() defer webShutdownCancel()
loggers.rootLogger.Info("Web server shutdown started") loggers.rootLogger.Info("Web server shutdown started.")
if err := web.Shutdown(webShutdownCtx); err != nil { if err := web.Shutdown(webShutdownCtx); err != nil {
loggers.rootLogger.Infow("Error shutting down web server", "error", err) loggers.rootLogger.Infow("Error shutting down web server.", "error", err)
} }
loggers.rootLogger.Info("Web server shutdown complete") loggers.rootLogger.Info("Web server shutdown complete.")
rootCancel() rootCancel()
}() }()