logging

Fixes #6.

game.go

@@ -3,6 +3,7 @@ package main
 import (
 	"context"
 	"errors"
+	"log/slog"
 	"time"
 
 	"nhooyr.io/websocket"
@@ -31,11 +32,13 @@ func gameActor(ctx context.Context, g *game.Game, dealer, chall person, join <-c
 	go playerActor(ctx, dealer, actions)
 	go playerActor(ctx, chall, actions)
 	// TODO(zeph): send round start info
+	slog.InfoContext(ctx, "start game", "dealer", dealer.id, "challenger", chall.id)
 	for {
 		select {
 		case <-ctx.Done():
 			return
 		case p := <-join:
+			slog.DebugContext(ctx, "observer", "id", p.id)
 			// Deliver the game state just to the new observer.
 			if err := wsjson.Write(ctx, p.conn, g.DTO(p.id)); err != nil {
 				// We don't need to track them as an observer. Just close their
@@ -49,7 +52,7 @@ func gameActor(ctx context.Context, g *game.Game, dealer, chall person, join <-c
 			p.conn.CloseRead(ctx)
 		case a := <-actions:
 			// TODO(zeph): transform the action into a game state change
-			_ = a
+			slog.DebugContext(ctx, "got action", "from", a.Player, "action", a)
 			broadcast(ctx, g, dealer, chall, obs)
 		}
 	}
@@ -64,6 +67,7 @@ func playerActor(ctx context.Context, p person, actions chan<- action) {
 			select {
 			case <-ctx.Done():
 			case actions <- a:
+				slog.DebugContext(ctx, "lost connection", "player", p.id, "err", err.Error())
 			}
 			return
 		}
@@ -71,6 +75,7 @@ func playerActor(ctx context.Context, p person, actions chan<- action) {
 		case <-ctx.Done():
 			return
 		case actions <- a:
+			slog.DebugContext(ctx, "action", "action", a)
 		}
 	}
 }
@@ -80,15 +85,15 @@ func broadcast(ctx context.Context, g *game.Game, dealer, chall person, obs []pe
 	// if a player drops so that the actor knows to quit
 	if err := wsjson.Write(ctx, dealer.conn, g.DTO(dealer.id)); err != nil {
 		// TODO(zeph): concede, but we need to be careful not to recurse
-		// TODO(zeph): log
+		slog.DebugContext(ctx, "lost dealer", "player", dealer.id, "err", err.Error())
 	}
 	if err := wsjson.Write(ctx, chall.conn, g.DTO(chall.id)); err != nil {
 		// TODO(zeph): concede, but we need to be careful not to recurse
-		// TODO(zeph): log
+		slog.DebugContext(ctx, "lost challenger", "player", chall.id, "err", err.Error())
 	}
 	for _, p := range obs {
 		if err := wsjson.Write(ctx, p.conn, g.DTO(p.id)); err != nil {
-			// TODO(zeph): log
+			slog.DebugContext(ctx, "lost observer", "player", p.id, "err", err.Error())
 		}
 	}
 }

player/player.go

@@ -1,6 +1,12 @@
 // Package player implements data about players outside games.
 package player
 
+import "encoding/hex"
+
 // ID is a unique ID for a player.
 // May just be IPv6 (or IPv4-in-6) of their connection, or a UUID.
 type ID [16]byte
+
+func (id ID) String() string {
+	return hex.EncodeToString(id[:])
+}

server.go

@@ -3,6 +3,7 @@ package main
 import (
 	"context"
 	"errors"
+	"log/slog"
 	"net/http"
 	"sync"
 	"time"
@@ -39,6 +40,7 @@ func (s *Server) accept(w http.ResponseWriter, r *http.Request, p player.ID) (pe
 	if err != nil {
 		return person{}, err
 	}
+	slog.Debug("upgraded", "player", p)
 	s.mu.Lock()
 	defer s.mu.Unlock()
 	s.pp[p] = conn
@@ -55,6 +57,7 @@ func (s *Server) left(p player.ID) {
 	if c != nil {
 		// We don't care about the error here since the connection is leaving.
 		// It's probably already closed anyway.
+		slog.Debug("leaving", "player", p)
 		c.Close(websocket.StatusNormalClosure, "bye")
 	}
 }
@@ -75,6 +78,7 @@ func (s *Server) Queue(w http.ResponseWriter, r *http.Request) {
 }
 
 func (s *Server) joinAndServe(p person) {
+	slog.Debug("joining", "player", p.id)
 	ctx, stop := context.WithTimeoutCause(context.Background(), 10*time.Minute, errQueueEmpty)
 	id, chall, deal := s.l.Queue(ctx, p.id)
 	stop()
@@ -96,7 +100,7 @@ func (s *Server) joinAndServe(p person) {
 		Game: id,
 	}
 	if err := wsjson.Write(context.TODO(), p.conn, r); err != nil {
-		// TODO(zeph): log
+		slog.WarnContext(ctx, "got a game but player dropped", "game", id, "player", p.id)
 		s.left(p.id)
 		return
 	}