diff --git a/cmd/apiary/apiary.go b/cmd/apiary/apiary.go index ec68d5b..e5c8ab3 100644 --- a/cmd/apiary/apiary.go +++ b/cmd/apiary/apiary.go @@ -3,6 +3,7 @@ package main import ( "context" "fmt" + "log/slog" "net/http" "os" "os/signal" @@ -17,8 +18,6 @@ import ( "github.com/coreos/go-systemd/daemon" sshlib "github.com/gliderlabs/ssh" "github.com/urfave/cli/v2" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" "golang.org/x/crypto/acme/autocert" ) @@ -55,17 +54,17 @@ func ActionServe(c *cli.Context) error { // Setup logging loggers := setupLoggers(cfg) - loggers.rootLogger.Infow("Starting apiary.", "version", apiary.FullVersion()) + loggers.rootLogger.Info("Starting apiary.", "version", apiary.FullVersion()) // Setup store var s store.LoginAttemptStore switch cfg.Store.Type { case "MEMORY", "memory": - loggers.rootLogger.Infow("Initialized store.", "store_type", "memory") + loggers.rootLogger.Info("Initialized store.", "store_type", "memory") s = &store.MemoryStore{} case "POSTGRES", "postgres": pgStartTime := time.Now() - loggers.rootLogger.Debugw("Initializing store.", "store_type", "postgres") + loggers.rootLogger.Debug("Initializing store.", "store_type", "postgres") pgStore, err := store.NewPostgresStore(cfg.Store.Postgres.DSN) if err != nil { return err @@ -73,33 +72,33 @@ func ActionServe(c *cli.Context) error { if err := pgStore.InitDB(); err != nil { return err } - loggers.rootLogger.Infow("Initialized store.", "store_type", "postgres", "init_time", time.Since(pgStartTime)) + loggers.rootLogger.Info("Initialized store.", "store_type", "postgres", "init_time", time.Since(pgStartTime)) if cfg.Store.EnableCache { - loggers.rootLogger.Debugw("Initializing store.", "store_type", "cache-postgres") + loggers.rootLogger.Debug("Initializing store.", "store_type", "cache-postgres") startTime := time.Now() cachingStore := store.NewCachingStore(pgStore) s = cachingStore - loggers.rootLogger.Infow("Initialized store.", "store_type", "cache-postgres", "init_time", time.Since(startTime)) + loggers.rootLogger.Info("Initialized store.", "store_type", "cache-postgres", "init_time", time.Since(startTime)) } else { s = pgStore } case "bolt", "BOLT": boltStartTime := time.Now() - loggers.rootLogger.Debugw("Initializing store.", "store_type", "bolt") + loggers.rootLogger.Debug("Initializing store.", "store_type", "bolt") boltStore, err := store.NewBBoltStore(cfg.Store.Bolt.DBPath) if err != nil { return err } defer boltStore.Close() - loggers.rootLogger.Infow("Initialized store.", "store_type", "bolt", "init_time", time.Since(boltStartTime)) + loggers.rootLogger.Info("Initialized store.", "store_type", "bolt", "init_time", time.Since(boltStartTime)) if cfg.Store.EnableCache { - loggers.rootLogger.Debugw("Initializing store.", "store_type", "cache-bolt") + loggers.rootLogger.Debug("Initializing store.", "store_type", "cache-bolt") startTime := time.Now() cachingStore := store.NewCachingStore(boltStore) s = cachingStore - loggers.rootLogger.Infow("Initialized store.", "store_type", "cache-bolt", "init_time", time.Since(startTime)) + loggers.rootLogger.Info("Initialized store.", "store_type", "cache-bolt", "init_time", time.Since(startTime)) } else { s = boltStore } @@ -153,18 +152,18 @@ func ActionServe(c *cli.Context) error { // Start ssh server go func() { - loggers.rootLogger.Infow("Starting SSH server.", "addr", cfg.Honeypot.ListenAddr) + loggers.rootLogger.Info("Starting SSH server.", "addr", cfg.Honeypot.ListenAddr) if err := hs.ListenAndServe(); err != nil && err != sshlib.ErrServerClosed { - loggers.rootLogger.Warnw("SSH server returned error.", "error", err) + loggers.rootLogger.Warn("SSH server returned error.", "error", err) } - loggers.rootLogger.Infow("SSH server stopped.") + loggers.rootLogger.Info("SSH server stopped.") }() // Start web server go func() { - loggers.rootLogger.Infow("Starting web server.", "addr", cfg.Frontend.ListenAddr) + loggers.rootLogger.Info("Starting web server.", "addr", cfg.Frontend.ListenAddr) if err := web.StartServe(); err != nil && err != http.ErrServerClosed { - loggers.rootLogger.Warnw("Web server returned error.", "error", err) + loggers.rootLogger.Warn("Web server returned error.", "error", err) } }() @@ -184,7 +183,7 @@ func ActionServe(c *cli.Context) error { return } if err != nil { - loggers.rootLogger.Warnw("Unable to connect to NOTIFY_SOCKET.", "error", err) + loggers.rootLogger.Warn("Unable to connect to NOTIFY_SOCKET.", "error", err) return } loggers.rootLogger.Debug("Sent READY=1 to NOTIFY_SOCKET.") @@ -192,11 +191,11 @@ func ActionServe(c *cli.Context) error { // Setup timer timeout, err := daemon.SdWatchdogEnabled(false) if err != nil { - loggers.rootLogger.Warnw("Unable to get watchdog timeout.", "error", err) + loggers.rootLogger.Warn("Unable to get watchdog timeout.", "error", err) return } if timeout == 0 { - loggers.rootLogger.Infow("Systemd watchdog not enabled.") + loggers.rootLogger.Info("Systemd watchdog not enabled.") return } @@ -209,14 +208,14 @@ func ActionServe(c *cli.Context) error { case <-ticker.C: if healthy == nil { if _, err := daemon.SdNotify(false, daemon.SdNotifyWatchdog); err != nil { - loggers.rootLogger.Warnw("Error notifying watchdog.", "err", err) + loggers.rootLogger.Warn("Error notifying watchdog.", "err", err) } continue } // TODO: If unhealthy, should we retry healthcheck immediately, otherwise service will most likely get killed by watchdog. - loggers.rootLogger.Errorw("Store reported not healthy, might get killed by watchdog.", "err", healthy) + loggers.rootLogger.Error("Store reported not healthy, might get killed by watchdog.", "err", healthy) case <-notifyCtx.Done(): - loggers.rootLogger.Debugw("Notify context cancelled.") + loggers.rootLogger.Debug("Notify context cancelled.") return } } @@ -230,7 +229,7 @@ func ActionServe(c *cli.Context) error { defer sshShutdownCancel() loggers.rootLogger.Info("SSH server shutdown started.") if err := hs.Shutdown(sshShutdownCtx); err != nil { - loggers.rootLogger.Infow("Error shutting down SSH server.", "error", err) + loggers.rootLogger.Info("Error shutting down SSH server.", "error", err) } loggers.rootLogger.Info("SSH server shutdown complete.") @@ -240,7 +239,7 @@ func ActionServe(c *cli.Context) error { loggers.rootLogger.Info("Web server shutdown started.") if err := web.Shutdown(webShutdownCtx); err != nil { - loggers.rootLogger.Infow("Error shutting down web server.", "error", err) + loggers.rootLogger.Info("Error shutting down web server.", "error", err) } loggers.rootLogger.Info("Web server shutdown complete.") rootCancel() @@ -252,49 +251,36 @@ func ActionServe(c *cli.Context) error { } type loggerCollection struct { - rootLogger *zap.SugaredLogger - honeypotLogger *zap.SugaredLogger - webAccessLogger *zap.SugaredLogger - webServerLogger *zap.SugaredLogger + rootLogger *slog.Logger + honeypotLogger *slog.Logger + webAccessLogger *slog.Logger + webServerLogger *slog.Logger } func setupLoggers(cfg config.Config) *loggerCollection { - logEncoderCfg := zap.NewProductionEncoderConfig() - logEncoderCfg.EncodeCaller = func(caller zapcore.EntryCaller, enc zapcore.PrimitiveArrayEncoder) {} - - var level zap.AtomicLevel + opts := &slog.HandlerOptions{} switch strings.ToUpper(cfg.Honeypot.LogLevel) { case "INFO": - level = zap.NewAtomicLevelAt(zap.InfoLevel) + opts.Level = slog.LevelInfo case "DEBUG": - level = zap.NewAtomicLevelAt(zap.DebugLevel) + opts.Level = slog.LevelDebug + opts.AddSource = true case "WARN", "WARNING": - level = zap.NewAtomicLevelAt(zap.WarnLevel) + opts.Level = slog.LevelWarn case "ERR", "ERROR": - level = zap.NewAtomicLevelAt(zap.WarnLevel) + opts.Level = slog.LevelError default: - level = zap.NewAtomicLevelAt(zap.InfoLevel) - } - logEncoderCfg.EncodeLevel = zapcore.CapitalColorLevelEncoder - logEncoderCfg.EncodeTime = zapcore.ISO8601TimeEncoder - logEncoderCfg.EncodeDuration = zapcore.StringDurationEncoder - rootLoggerCfg := &zap.Config{ - Level: level, - OutputPaths: []string{"stdout"}, - ErrorOutputPaths: []string{"stderr"}, - Encoding: "console", - EncoderConfig: logEncoderCfg, - } - rootLogger, err := rootLoggerCfg.Build() - if err != nil { - panic(err) + opts.Level = slog.LevelInfo } + handler := slog.NewTextHandler(os.Stdout, opts) + rootLogger := slog.New(handler) + return &loggerCollection{ - rootLogger: rootLogger.Named("APP").Sugar(), - honeypotLogger: rootLogger.Named("HON").Sugar(), - webAccessLogger: rootLogger.Named("ACC").Sugar(), - webServerLogger: rootLogger.Named("WEB").Sugar(), + rootLogger: rootLogger.With("module", "application"), + honeypotLogger: rootLogger.With("module", "honeypot"), + webAccessLogger: rootLogger.With("module", "web-access-log"), + webServerLogger: rootLogger.With("module", "web-server"), } } diff --git a/flake.nix b/flake.nix index 65d8d90..044ac3d 100644 --- a/flake.nix +++ b/flake.nix @@ -75,7 +75,7 @@ mkdir -p web/frontend/dist cp -r ${frontend}/* web/frontend/dist ''; - vendorHash = "sha256-j3NT1caRun3sLXti1Whrljz8gW8GmALJXqWWJFGD+Ko="; + vendorHash = "sha256-fJnln143V5ajZgEEgVZN2y3dIz9/L9w6ZBLZk/eX61M="; ldflags = [ "-X git.t-juice.club/torjus/apiary.Build=${rev}" ]; tags = [ "embed" diff --git a/go.mod b/go.mod index 5653da6..71b29c6 100644 --- a/go.mod +++ b/go.mod @@ -16,7 +16,6 @@ require ( github.com/prometheus/client_golang v1.21.1 github.com/urfave/cli/v2 v2.27.6 go.etcd.io/bbolt v1.4.0 - go.uber.org/zap v1.27.0 golang.org/x/crypto v0.36.0 ) @@ -39,7 +38,6 @@ require ( github.com/prometheus/procfs v0.16.0 // indirect github.com/russross/blackfriday/v2 v2.1.0 // indirect github.com/xrash/smetrics v0.0.0-20240521201337-686a1a2994c1 // indirect - go.uber.org/multierr v1.11.0 // indirect golang.org/x/net v0.37.0 // indirect golang.org/x/sys v0.31.0 // indirect golang.org/x/text v0.23.0 // indirect diff --git a/go.sum b/go.sum index 751ce6e..3467883 100644 --- a/go.sum +++ b/go.sum @@ -166,19 +166,13 @@ go.uber.org/atomic v1.3.2/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.5.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ= go.uber.org/atomic v1.6.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ= -go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= -go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0= go.uber.org/multierr v1.3.0/go.mod h1:VgVr7evmIr6uPjLBxg28wmKNXyqE9akIJ5XnfpiKl+4= go.uber.org/multierr v1.5.0/go.mod h1:FeouvMocqHpRaaGuG9EjoKcStLC43Zu/fmqdUMPcKYU= -go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= -go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= go.uber.org/tools v0.0.0-20190618225709-2cfd321de3ee/go.mod h1:vJERXedbb3MVM5f9Ejo0C68/HhF8uaILCdgjnY+goOA= go.uber.org/zap v1.9.1/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.13.0/go.mod h1:zwrFLgMcdUuIBviXEYEH1YKNaOBnKXsx2IPda5bBwHM= -go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= -go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= golang.org/x/crypto v0.0.0-20190411191339-88737f569e3a/go.mod h1:WFFai1msRO1wXaEeE5yQxYXgSfI8pQAWXbQop6sCtWE= golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= diff --git a/honeypot/ssh/geolocate.go b/honeypot/ssh/geolocate.go index 8c0736e..51b7f08 100644 --- a/honeypot/ssh/geolocate.go +++ b/honeypot/ssh/geolocate.go @@ -13,7 +13,7 @@ var mmdb []byte func (s *HoneypotServer) LookupCountry(ip net.IP) string { db, err := maxminddb.FromBytes(mmdb) if err != nil { - s.Logger.Warnw("Error opening geoip database", "error", err) + s.Logger.Warn("Error opening geoip database", "error", err) return "??" } @@ -25,7 +25,7 @@ func (s *HoneypotServer) LookupCountry(ip net.IP) string { err = db.Lookup(ip, &record) if err != nil { - s.Logger.Warnw("Error doing geoip lookup", "error", err) + s.Logger.Warn("Error doing geoip lookup", "error", err) return "??" } if record.Country.ISOCode == "None" { diff --git a/honeypot/ssh/server.go b/honeypot/ssh/server.go index 9d1c801..27bcdd6 100644 --- a/honeypot/ssh/server.go +++ b/honeypot/ssh/server.go @@ -3,6 +3,7 @@ package ssh import ( "context" "io" + "log/slog" "net" "os" "time" @@ -16,11 +17,10 @@ import ( "git.t-juice.club/torjus/apiary/models" sshlib "github.com/gliderlabs/ssh" "github.com/google/uuid" - "go.uber.org/zap" ) type HoneypotServer struct { - Logger *zap.SugaredLogger + Logger *slog.Logger sshServer *sshlib.Server @@ -33,7 +33,7 @@ type HoneypotServer struct { func NewHoneypotServer(cfg config.HoneypotConfig, store store.LoginAttemptStore) (*HoneypotServer, error) { var hs HoneypotServer hs.attemptStore = store - hs.Logger = zap.NewNop().Sugar() + hs.Logger = slog.New(slog.NewTextHandler(io.Discard, nil)) hs.sshServer = &sshlib.Server{ Addr: cfg.ListenAddr, @@ -94,19 +94,19 @@ func (hs *HoneypotServer) passwordHandler(ctx sshlib.Context, password string) b } country := hs.LookupCountry(la.RemoteIP) if utf8.RuneCountInString(country) > 2 { - hs.Logger.Warnw("Too many characters in country", "country", country, "runecount", utf8.RuneCountInString(country)) + hs.Logger.Warn("Too many characters in country", "country", country, "runecount", utf8.RuneCountInString(country)) country = "??" } la.Country = country - hs.Logger.Infow("Login attempt", + hs.Logger.Info("Login attempt", "remote_ip", la.RemoteIP.String(), "username", la.Username, "password", la.Password, "country", la.Country) if err := hs.attemptStore.AddAttempt(&la); err != nil { - hs.Logger.Warnw("Error adding attempt to store", "error", err) + hs.Logger.Warn("Error adding attempt to store", "error", err) } for _, cFunc := range hs.attemptsCallbacks { @@ -117,7 +117,7 @@ func (hs *HoneypotServer) passwordHandler(ctx sshlib.Context, password string) b } func (s *HoneypotServer) connCallback(ctx sshlib.Context, conn net.Conn) net.Conn { - s.Logger.Debugw("Connection received.", "remote_addr", conn.RemoteAddr()) + s.Logger.Debug("Connection received.", "remote_addr", conn.RemoteAddr()) throttledConn := newThrottledConn(conn) throttledConn.SetSpeed(s.throttleSpeed) diff --git a/version.go b/version.go index 5452ff0..c7daf67 100644 --- a/version.go +++ b/version.go @@ -6,7 +6,7 @@ import ( ) var ( - Version = "v0.2.1" + Version = "v0.2.2" Build string ) diff --git a/web/middleware.go b/web/middleware.go index c990eb8..e036ca0 100644 --- a/web/middleware.go +++ b/web/middleware.go @@ -21,7 +21,7 @@ func (s *Server) LoggingMiddleware(next http.Handler) http.Handler { if s.cfg.AccessLogIgnoreMetrics && r.URL.Path == "/metrics" && ww.Status() == http.StatusOK { return } - s.AccessLogger.Infow(r.Method, + s.AccessLogger.Info(r.Method, "path", r.URL.Path, "status", ww.Status(), "written", ww.BytesWritten(), diff --git a/web/server.go b/web/server.go index db69bac..e38057e 100644 --- a/web/server.go +++ b/web/server.go @@ -6,6 +6,7 @@ import ( "encoding/json" "fmt" "io" + "log/slog" "net/http" "strconv" "sync" @@ -20,7 +21,6 @@ import ( "github.com/go-chi/chi/v5/middleware" "github.com/google/uuid" "github.com/prometheus/client_golang/prometheus/promhttp" - "go.uber.org/zap" "golang.org/x/crypto/acme/autocert" ) @@ -35,8 +35,8 @@ type Server struct { honeypotServer *ssh.HoneypotServer store store.LoginAttemptStore - ServerLogger *zap.SugaredLogger - AccessLogger *zap.SugaredLogger + ServerLogger *slog.Logger + AccessLogger *slog.Logger attemptListenersLock sync.RWMutex attemptListeners map[string]chan models.LoginAttempt @@ -44,9 +44,10 @@ type Server struct { } func NewServer(cfg config.FrontendConfig, hs *ssh.HoneypotServer, store store.LoginAttemptStore) *Server { + discardLogger := slog.New(slog.NewTextHandler(io.Discard, nil)) s := &Server{ - ServerLogger: zap.NewNop().Sugar(), - AccessLogger: zap.NewNop().Sugar(), + ServerLogger: discardLogger, + AccessLogger: discardLogger, store: store, cfg: cfg, } @@ -125,7 +126,7 @@ func (s *Server) StartServe() error { s.ServerLogger.Debug("Starting HTTP redirect server") go func() { if err := s.httpRedirectServer.ListenAndServe(); err != nil && err != http.ErrServerClosed { - s.ServerLogger.Warnw("HTTP redirect server returned error", "error", err) + s.ServerLogger.Warn("HTTP redirect server returned error", "error", err) } }() } @@ -174,7 +175,7 @@ func (s *Server) HandlerAttemptStream(w http.ResponseWriter, r *http.Request) { } _, err = io.WriteString(w, fmt.Sprintf("data: %s\n\n", string(data))) if err != nil { - s.ServerLogger.Warnw("Error writing event", "error", err) + s.ServerLogger.Warn("Error writing event", "error", err) } flusher.Flush() ticker.Reset(streamKeepAliveDuration) @@ -184,7 +185,7 @@ func (s *Server) HandlerAttemptStream(w http.ResponseWriter, r *http.Request) { return case <-ticker.C: if _, err := io.WriteString(w, ": keep-alive\n\n"); err != nil { - s.ServerLogger.Warnw("Error writing event", "error", err) + s.ServerLogger.Warn("Error writing event", "error", err) } flusher.Flush() } @@ -207,14 +208,14 @@ func (s *Server) HandlerStats(w http.ResponseWriter, r *http.Request) { stats, err := s.store.Stats(statType, limit) if err != nil { - s.ServerLogger.Warnw("Error fetching stats", "error", err) + s.ServerLogger.Warn("Error fetching stats", "error", err) s.WriteAPIError(w, r, http.StatusInternalServerError, "Error fetching stats") return } encoder := json.NewEncoder(w) if err := encoder.Encode(stats); err != nil { - s.ServerLogger.Debugf("Error encoding or writing response", "remote_ip", r.RemoteAddr, "error", err) + s.ServerLogger.Debug("Error encoding or writing response", "remote_ip", r.RemoteAddr, "error", err) } } @@ -241,13 +242,13 @@ func (s *Server) HandlerQuery(w http.ResponseWriter, r *http.Request) { userResults, err := s.store.Query(uq) if err != nil { s.WriteAPIError(w, r, http.StatusInternalServerError, "Unable to perform query") - s.ServerLogger.Warnw("Error performing query", "error", err) + s.ServerLogger.Warn("Error performing query", "error", err) return } passwordResults, err := s.store.Query(pq) if err != nil { s.WriteAPIError(w, r, http.StatusInternalServerError, "Unable to perform query") - s.ServerLogger.Warnw("Error performing query", "error", err) + s.ServerLogger.Warn("Error performing query", "error", err) return } @@ -263,7 +264,7 @@ func (s *Server) HandlerQuery(w http.ResponseWriter, r *http.Request) { queryResults, err := s.store.Query(aq) if err != nil { s.WriteAPIError(w, r, http.StatusInternalServerError, "Unable to perform query") - s.ServerLogger.Warnw("Error performing query", "error", err) + s.ServerLogger.Warn("Error performing query", "error", err) return } @@ -272,7 +273,7 @@ func (s *Server) HandlerQuery(w http.ResponseWriter, r *http.Request) { encoder := json.NewEncoder(w) if err := encoder.Encode(&results); err != nil { - s.ServerLogger.Warnw("Error writing query results", "error", err) + s.ServerLogger.Warn("Error writing query results", "error", err) } } @@ -294,6 +295,6 @@ func (s *Server) WriteAPIError(w http.ResponseWriter, r *http.Request, status in apiErr := APIErrorResponse{Error: message} w.WriteHeader(status) if err := encoder.Encode(&apiErr); err != nil { - s.ServerLogger.Debugf("Error encoding or writing error response", "remote_ip", r.RemoteAddr, "error", err) + s.ServerLogger.Debug("Error encoding or writing error response", "remote_ip", r.RemoteAddr, "error", err) } }