Merge branch 'remove-zap'

This commit is contained in:
Torjus Håkestad 2025-03-19 23:18:06 +01:00
commit cdbcf0e03b
Signed by: torjus
SSH Key Fingerprint: SHA256:KjAds8wHfD2mBYK2H815s/+ABcSdcIHUndwHEdSxml4
9 changed files with 70 additions and 91 deletions

View File

@ -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"),
}
}

View File

@ -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"

2
go.mod
View File

@ -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

6
go.sum
View File

@ -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=

View File

@ -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" {

View File

@ -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)

View File

@ -6,7 +6,7 @@ import (
)
var (
Version = "v0.2.1"
Version = "v0.2.2"
Build string
)

View File

@ -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(),

View File

@ -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)
}
}