Good logging, graceful shutdown

.gitignore

@@ -0,0 +1 @@
+log/*

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

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

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=

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
+}

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),
+	}
+}

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}
+}

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...)
+	}
+}

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
+}

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{}{}
-}