From 5a33dd3135f2ea802024eeda0c2fa4e17106eb62 Mon Sep 17 00:00:00 2001 From: Miroslav Vasilev Date: Fri, 20 Jun 2025 16:26:39 +0300 Subject: [PATCH] Good logging, graceful shutdown --- .gitignore | 1 + cmd/lastmudserver/main.go | 50 ++++++--- go.mod | 5 + go.sum | 4 + internal/game/game.go | 75 ++++++++++++++ internal/game/player.go | 19 ++++ internal/game/traits.go | 45 ++++++++ internal/logging/logging.go | 188 ++++++++++++++++++++++++++++++++++ internal/server/connection.go | 88 ++++++++++++---- internal/server/server.go | 68 ++++++++---- 10 files changed, 488 insertions(+), 55 deletions(-) create mode 100644 .gitignore create mode 100644 internal/game/game.go create mode 100644 internal/game/player.go create mode 100644 internal/game/traits.go create mode 100644 internal/logging/logging.go diff --git a/.gitignore b/.gitignore new file mode 100644 index 0000000..87afabb --- /dev/null +++ b/.gitignore @@ -0,0 +1 @@ +log/* \ No newline at end of file diff --git a/cmd/lastmudserver/main.go b/cmd/lastmudserver/main.go index edd31f5..e904555 100644 --- a/cmd/lastmudserver/main.go +++ b/cmd/lastmudserver/main.go @@ -1,36 +1,60 @@ package main import ( - "bufio" - "fmt" + "context" "log" "os" - "strings" + "os/signal" + "sync" + "syscall" "code.haedhutner.dev/mvv/LastMUD/internal/server" + + "golang.org/x/term" ) func main() { - fmt.Println(`\\\\---------------------////`) - fmt.Println(`|||| LastMUD Server ||||`) - fmt.Println(`////---------------------\\\\`) + ctx, cancel := context.WithCancel(context.Background()) + wg := sync.WaitGroup{} - lastMudServer, err := server.CreateServer(":8000") + defer wg.Wait() + defer cancel() + + _, err := server.CreateServer(ctx, &wg, ":8000") if err != nil { log.Fatal(err) } - go lastMudServer.Listen() + processInput() +} - reader := bufio.NewReader(os.Stdin) +func processInput() { + oldState, err := term.MakeRaw(int(os.Stdin.Fd())) + + if err != nil { + panic(err) + } + + defer term.Restore(int(os.Stdin.Fd()), oldState) + + sigChan := make(chan os.Signal, 1) + signal.Notify(sigChan, syscall.SIGINT, syscall.SIGTERM) + + buf := make([]byte, 1) for { - text, _ := reader.ReadString('\n') - text = strings.ReplaceAll(text, "\n", "") + // If interrupt received, stop + select { + case <-sigChan: + return + default: + } - if strings.Compare("exit", text) == 0 { - lastMudServer.Stop() + // TODO: Proper TUI for the server + os.Stdin.Read(buf) + + if buf[0] == 'q' { return } } diff --git a/go.mod b/go.mod index 4890150..b6b4d65 100644 --- a/go.mod +++ b/go.mod @@ -3,3 +3,8 @@ module code.haedhutner.dev/mvv/LastMUD go 1.24.4 require github.com/google/uuid v1.6.0 + +require ( + golang.org/x/sys v0.33.0 // indirect + golang.org/x/term v0.32.0 // indirect +) diff --git a/go.sum b/go.sum index 7790d7c..c67480a 100644 --- a/go.sum +++ b/go.sum @@ -1,2 +1,6 @@ github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +golang.org/x/sys v0.33.0 h1:q3i8TbbEz+JRD9ywIRlyRAQbM0qF7hu24q3teo2hbuw= +golang.org/x/sys v0.33.0/go.mod h1:BJP2sWEmIv4KK5OTEluFJCKSidICx8ciO85XgH3Ak8k= +golang.org/x/term v0.32.0 h1:DR4lr0TjUs3epypdhTOkMmuF5CDFJ/8pOnbzMZPQ7bg= +golang.org/x/term v0.32.0/go.mod h1:uZG1FhGx848Sqfsq4/DlJr3xGGsYMu/L5GW4abiaEPQ= diff --git a/internal/game/game.go b/internal/game/game.go new file mode 100644 index 0000000..6d2388b --- /dev/null +++ b/internal/game/game.go @@ -0,0 +1,75 @@ +package game + +import ( + "context" + "sync" + "time" + + "code.haedhutner.dev/mvv/LastMUD/internal/logging" +) + +const TickRate = time.Duration(50 * time.Millisecond) + +type GameSignal struct { +} + +type LastMUDGame struct { + ctx context.Context + wg *sync.WaitGroup +} + +func CreateGame(ctx context.Context, wg *sync.WaitGroup) (game *LastMUDGame) { + game = &LastMUDGame{ + wg: wg, + ctx: ctx, + } + + wg.Add(1) + go game.start() + + return +} + +func (game *LastMUDGame) start() { + defer game.wg.Done() + defer game.shutdown() + + logging.Info("Starting LastMUD...") + + lastTick := time.Now() + + for { + now := time.Now() + + if game.shouldStop() { + break + } + + game.tick(now.Sub(lastTick)) + + // Tick at regular intervals + if time.Since(lastTick) < TickRate { + time.Sleep(TickRate - time.Since(lastTick)) + } + + lastTick = now + } +} + +func (game *LastMUDGame) shutdown() { + logging.Info("Stopping LastMUD...") +} + +func (game *LastMUDGame) shouldStop() bool { + select { + case <-game.ctx.Done(): + return true + default: + return false + } +} + +func (g *LastMUDGame) tick(delta time.Duration) { + // logging.Debug("Tick") + // TODO +} diff --git a/internal/game/player.go b/internal/game/player.go new file mode 100644 index 0000000..bdae4a3 --- /dev/null +++ b/internal/game/player.go @@ -0,0 +1,19 @@ +package game + +type Player struct { + GameObject + Name + Description + Position + Velocity +} + +func CreatePlayer(name, description string, x, y int) *Player { + return &Player{ + GameObject: CreateGameObject(), + Name: WithName(name), + Description: WithDescription(description), + Position: WithPosition(x, y), + Velocity: WithVelocity(0, 0), + } +} diff --git a/internal/game/traits.go b/internal/game/traits.go new file mode 100644 index 0000000..c4a7f92 --- /dev/null +++ b/internal/game/traits.go @@ -0,0 +1,45 @@ +package game + +import "github.com/google/uuid" + +type GameObject struct { + uuid uuid.UUID +} + +func CreateGameObject() GameObject { + return GameObject{ + uuid: uuid.New(), + } +} + +type Position struct { + x, y int +} + +func WithPosition(x, y int) Position { + return Position{x, y} +} + +type Velocity struct { + velX, velY int +} + +func WithVelocity(velX, velY int) Velocity { + return Velocity{velX, velY} +} + +type Name struct { + name string +} + +func WithName(name string) Name { + return Name{name} +} + +type Description struct { + description string +} + +func WithDescription(description string) Description { + return Description{description} +} diff --git a/internal/logging/logging.go b/internal/logging/logging.go new file mode 100644 index 0000000..c165158 --- /dev/null +++ b/internal/logging/logging.go @@ -0,0 +1,188 @@ +package logging + +import ( + "bufio" + "fmt" + "os" + "path/filepath" + "regexp" + "strconv" + "strings" + "time" +) + +type LogLevel byte + +const ( + DBG LogLevel = iota + INF + WRN + ERR +) + +func (ll LogLevel) String() string { + switch ll { + case DBG: + return "DBG" + case INF: + return "INF" + case WRN: + return "WRN" + case ERR: + return "ERR" + default: + return strconv.FormatInt(int64(ll), 10) + } +} + +const DefaultLogFilePath = "./log/lastmud.log" +const DefaultTimeFormat = "2006-01-02 15:04:05.000" +const DefaultLogFileTimeFormat = "2006-01-02_15-04-05" + +var DefaultLogger = CreateLogger(DBG, DBG, DefaultLogFilePath, DefaultTimeFormat, DefaultLogFileTimeFormat) + +// Regex for color codes +var ansiRegex = regexp.MustCompile(`\x1b\[[0-9;]*m`) + +const ( + ColorReset = "\033[0m" + ColorRed = "\033[31m" + ColorGreen = "\033[32m" + ColorYellow = "\033[33m" + ColorBlue = "\033[34m" + ColorPurple = "\033[35m" + ColorCyan = "\033[36m" + ColorWhite = "\033[37m" +) + +type Logger struct { + file *os.File + timestampFormat string + maxFileLevel LogLevel + maxDisplayedLevel LogLevel +} + +// Create a [Logger] +// +// Parameters: +// - maxFileLevel: The maximum level to log ( in file ) +// - maxDisplayedLevel: The maximum level to display in the stdout ( can be different from [maxLevel] ) +// - filePath: The file to log to. Can be empty string if no file logging is desired. +func CreateLogger(maxFileLevel LogLevel, maxDisplayedLevel LogLevel, filePath string, timestampFormat string, fileTimestampFormat string) (logger *Logger) { + logger = &Logger{} + + if filePath != "" { + timestamp := time.Now().Format(fileTimestampFormat) + + ext := filepath.Ext(filePath) // ".txt" + base := strings.TrimSuffix(filePath, ext) // "./base/dir/log" + + logFilePath := fmt.Sprintf("%s-%s%s", base, timestamp, ext) // "./base/dir/log-2006-01-02_15-04-05.txt" + + file, fileErr := os.OpenFile(logFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + + if fileErr != nil { + err(os.Stdout, false, "Logging: Unable to write to file", filePath, fileErr) + } else { + logger.file = file + } + } + + logger.timestampFormat = timestampFormat + logger.maxFileLevel = maxFileLevel + logger.maxDisplayedLevel = maxDisplayedLevel + + return +} + +func (l *Logger) Debug(v ...any) { + l.Log(DBG, v...) +} + +func (l *Logger) Info(v ...any) { + l.Log(INF, v...) +} + +func (l *Logger) Warn(v ...any) { + l.Log(WRN, v...) +} + +func (l *Logger) Error(v ...any) { + l.Log(ERR, v...) +} + +func (l *Logger) Log(level LogLevel, v ...any) { + if level >= l.maxDisplayedLevel { + log(os.Stdout, level, false, l.timestampFormat, v...) + } + + if level >= l.maxFileLevel { + log(l.file, level, true, l.timestampFormat, v...) + } +} + +func Debug(v ...any) { + DefaultLogger.Log(DBG, v...) +} + +func Info(v ...any) { + DefaultLogger.Log(INF, v...) +} + +func Warn(v ...any) { + DefaultLogger.Log(WRN, v...) +} + +func Error(v ...any) { + DefaultLogger.Log(ERR, v...) +} + +func Log(level LogLevel, v ...any) { + DefaultLogger.Log(level, v...) +} + +func dbg(file *os.File, stripColor bool, timestampFormat string, v ...any) { + custom(file, ColorWhite+DBG.String()+ColorReset, stripColor, timestampFormat, v...) +} + +func inf(file *os.File, stripColor bool, timestampFormat string, v ...any) { + custom(file, ColorCyan+INF.String()+ColorReset, stripColor, timestampFormat, v...) +} + +func wrn(file *os.File, stripColor bool, timestampFormat string, v ...any) { + custom(file, ColorYellow+WRN.String()+ColorReset, stripColor, timestampFormat, v...) +} + +func err(file *os.File, stripColor bool, timestampFormat string, v ...any) { + custom(file, ColorRed+ERR.String()+ColorReset, stripColor, timestampFormat, v...) +} + +func custom(file *os.File, prefix string, stripColor bool, timestampFormat string, v ...any) { + w := bufio.NewWriter(file) + + msg := fmt.Sprint(v...) + + if stripColor { + msg = ansiRegex.ReplaceAllString(msg, "") + prefix = ansiRegex.ReplaceAllString(prefix, "") + } + + fmt.Fprintf(w, "%s | %s | %s\r\n", time.Now().Format(timestampFormat), prefix, msg) + + w.Flush() +} + +func log(file *os.File, level LogLevel, stripColor bool, timestampFormat string, v ...any) { + switch level { + case DBG: + dbg(file, stripColor, timestampFormat, v...) + case INF: + inf(file, stripColor, timestampFormat, v...) + case WRN: + wrn(file, stripColor, timestampFormat, v...) + case ERR: + err(file, stripColor, timestampFormat, v...) + default: + custom(file, level.String(), stripColor, timestampFormat, v...) + } +} diff --git a/internal/server/connection.go b/internal/server/connection.go index 3266898..2a884e3 100644 --- a/internal/server/connection.go +++ b/internal/server/connection.go @@ -2,70 +2,113 @@ package server import ( "bufio" - "fmt" + "context" "net" + "sync" "time" + "code.haedhutner.dev/mvv/LastMUD/internal/logging" "github.com/google/uuid" ) +const MaxLastSeenTime = 120 * time.Second + type Connection struct { + ctx context.Context + wg *sync.WaitGroup + identity uuid.UUID - conn net.Conn + conn *net.TCPConn + lastSeen time.Time inputChannel chan string - closeChannel chan struct{} } -func CreateConnection(conn net.Conn) *Connection { - return &Connection{ +func CreateConnection(conn *net.TCPConn, ctx context.Context, wg *sync.WaitGroup) (c *Connection) { + logging.Info("Connect: ", conn.RemoteAddr()) + + conn.SetKeepAlive(true) + conn.SetKeepAlivePeriod(1 * time.Second) + + c = &Connection{ + ctx: ctx, + wg: wg, identity: uuid.New(), conn: conn, inputChannel: make(chan string), - closeChannel: make(chan struct{}), + lastSeen: time.Now(), } + + c.wg.Add(2) + go c.listen() + go c.checkAlive() + + return } -func (c *Connection) listen() (err error) { - defer c.conn.Close() +func (c *Connection) listen() { + defer c.wg.Done() - c.conn.SetReadDeadline(time.Time{}) + logging.Info("Listening on connection ", c.conn.RemoteAddr()) for { - if c.shouldClose() { - break - } + c.conn.SetReadDeadline(time.Time{}) message, err := bufio.NewReader(c.conn).ReadString('\n') if err != nil { - fmt.Println(err) - return err + logging.Warn(err) + break } c.inputChannel <- message c.conn.Write([]byte(message)) - } - return + c.lastSeen = time.Now() + } +} + +func (c *Connection) checkAlive() { + defer c.wg.Done() + defer c.closeConnection() + + for { + if c.shouldClose() { + c.Write("Server shutting down, bye bye!\r\n") + break + } + + if time.Since(c.lastSeen) > MaxLastSeenTime { + c.Write("You have been away for too long, bye bye!\r\n") + break + } + + _, err := c.conn.Write([]byte{0x00}) + + if err != nil { + break + } + } } func (c *Connection) shouldClose() bool { select { - case <-c.closeChannel: + case <-c.ctx.Done(): return true default: return false } } -func (c *Connection) Close() { - c.closeChannel <- struct{}{} +func (c *Connection) closeConnection() { + c.conn.Close() + + logging.Info("Disconnected: ", c.conn.RemoteAddr()) } -func (c *Connection) NextInput() (next string, err error) { +func (c *Connection) NextInput() (input string, err error) { select { case val := <-c.inputChannel: return val, nil @@ -73,3 +116,8 @@ func (c *Connection) NextInput() (next string, err error) { return "", newInputEmptyError() } } + +func (c *Connection) Write(output string) (err error) { + _, err = c.conn.Write([]byte(output)) + return +} diff --git a/internal/server/server.go b/internal/server/server.go index eca8399..4ed2281 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -1,50 +1,73 @@ package server import ( - "fmt" + "context" "net" + "sync" "time" + + "code.haedhutner.dev/mvv/LastMUD/internal/game" + "code.haedhutner.dev/mvv/LastMUD/internal/logging" ) type Server struct { + ctx context.Context + wg *sync.WaitGroup + listener *net.TCPListener connections []*Connection - stopChannel chan struct{} + game *game.LastMUDGame } -func CreateServer(port string) (srv *Server, err error) { +func CreateServer(ctx context.Context, wg *sync.WaitGroup, port string) (srv *Server, err error) { + + logging.Info(" _ _ __ __ _ _ ____ ") + logging.Info(" | | __ _ ___| |_| \\/ | | | | _ \\ ") + logging.Info(" | | / _` / __| __| |\\/| | | | | | | | ") + logging.Info(" | |__| (_| \\__ \\ |_| | | | |_| | |_| | ") + logging.Info(" |_____\\__,_|___/\\__|_| |_|\\___/|____/ ") + logging.Info(" ") + addr, err := net.ResolveTCPAddr("tcp", port) if err != nil { - fmt.Println(err) + logging.Error(err) return nil, err } ln, err := net.ListenTCP("tcp", addr) if err != nil { - fmt.Println(err) + logging.Error(err) return nil, err } - fmt.Println("Listening on port", port) + logging.Info("Starting server, listening on port ", port) srv = &Server{ + ctx: ctx, + wg: wg, listener: ln, connections: []*Connection{}, - stopChannel: make(chan struct{}), } + srv.game = game.CreateGame(ctx, srv.wg) + + srv.wg.Add(1) + go srv.listen() + return } -func (srv *Server) Listen() { - // Wait for 200 millis for a new connection, and loop if none found in that time - srv.listener.SetDeadline(time.Now().Add(1 * time.Second)) +func (srv *Server) listen() { + defer srv.wg.Done() + defer srv.shutdown() for { + srv.listener.SetDeadline(time.Now().Add(1 * time.Second)) + if srv.shouldStop() { break } @@ -55,32 +78,33 @@ func (srv *Server) Listen() { continue } - c := CreateConnection(conn) + tcpConn, ok := conn.(*net.TCPConn) + + if !ok { + logging.Warn("Attempted invalid connection from", conn.RemoteAddr()) + continue + } + + c := CreateConnection(tcpConn, srv.ctx, srv.wg) srv.connections = append(srv.connections, c) - - go c.listen() } +} - for _, v := range srv.connections { - v.Close() - } +func (srv *Server) shutdown() { + logging.Info("Stopping Server...") err := srv.listener.Close() if err != nil { - fmt.Println(err) + logging.Error(err) } } func (srv *Server) shouldStop() bool { select { - case <-srv.stopChannel: + case <-srv.ctx.Done(): return true default: return false } } - -func (srv *Server) Stop() { - srv.stopChannel <- struct{}{} -}