From 09aea9c49d33758660f73f11931489e38d597c63 Mon Sep 17 00:00:00 2001 From: Rob O'Dwyer Date: Fri, 2 Sep 2022 14:35:55 -0700 Subject: [PATCH] DEV 1666: Fix /end requests and clean up logging (#109) * ensure /end request is always called, and refactor win/draw logic * clean up logging and error handling during initialization * automatically generate friendly snake names * title-case snake names * print out list of alive snake names instead of count * log snake names, IDs, and URLs at startup * print out state for turn zero --- board/server.go | 26 ++-- cli/commands/info.go | 9 +- cli/commands/map.go | 5 +- cli/commands/names.go | 153 ++++++++++++++++++++++++ cli/commands/output.go | 7 +- cli/commands/play.go | 244 +++++++++++++++++++------------------- cli/commands/play_test.go | 1 - cli/commands/root.go | 14 ++- go.mod | 2 +- go.sum | 3 +- 10 files changed, 315 insertions(+), 149 deletions(-) create mode 100644 cli/commands/names.go diff --git a/board/server.go b/board/server.go index 685a03e..dd93d0e 100644 --- a/board/server.go +++ b/board/server.go @@ -3,12 +3,12 @@ package board import ( "context" "encoding/json" - "log" "net" "net/http" "github.com/gorilla/websocket" "github.com/rs/cors" + log "github.com/spf13/jwalterweatherman" ) // A minimal server capable of handling the requests from a single browser client running the board viewer. @@ -51,7 +51,7 @@ func (server *BoardServer) handleGame(w http.ResponseWriter, r *http.Request) { Game Game }{server.game}) if err != nil { - log.Printf("Unable to serialize game: %v", err) + log.ERROR.Printf("Unable to serialize game: %v", err) w.WriteHeader(http.StatusInternalServerError) return } @@ -61,37 +61,37 @@ func (server *BoardServer) handleGame(w http.ResponseWriter, r *http.Request) { func (server *BoardServer) handleWebsocket(w http.ResponseWriter, r *http.Request) { ws, err := upgrader.Upgrade(w, r, nil) if err != nil { - log.Printf("Unable to upgrade connection: %v", err) + log.ERROR.Printf("Unable to upgrade connection: %v", err) return } defer func() { err = ws.Close() if err != nil { - log.Printf("Unable to close websocket stream") + log.ERROR.Printf("Unable to close websocket stream") } }() for event := range server.events { jsonStr, err := json.Marshal(event) if err != nil { - log.Printf("Unable to serialize event for websocket: %v", err) + log.ERROR.Printf("Unable to serialize event for websocket: %v", err) } err = ws.WriteMessage(websocket.TextMessage, jsonStr) if err != nil { - log.Printf("Unable to write to websocket: %v", err) + log.ERROR.Printf("Unable to write to websocket: %v", err) break } } - log.Printf("Finished writing all game events, signalling game server to stop") + log.DEBUG.Printf("Finished writing all game events, signalling game server to stop") close(server.done) - log.Printf("Sending websocket close message") + log.DEBUG.Printf("Sending websocket close message") err = ws.WriteMessage(websocket.CloseMessage, websocket.FormatCloseMessage(websocket.CloseNormalClosure, "")) if err != nil { - log.Printf("Problem closing websocket: %v", err) + log.ERROR.Printf("Problem closing websocket: %v", err) } } @@ -103,7 +103,7 @@ func (server *BoardServer) Listen() (string, error) { go func() { err = server.httpServer.Serve(listener) if err != http.ErrServerClosed { - log.Printf("Error in board HTTP server: %v", err) + log.ERROR.Printf("Error in board HTTP server: %v", err) } }() @@ -115,13 +115,13 @@ func (server *BoardServer) Listen() (string, error) { func (server *BoardServer) Shutdown() { close(server.events) - log.Printf("Waiting for websocket clients to finish") + log.DEBUG.Printf("Waiting for websocket clients to finish") <-server.done - log.Printf("Server is done, exiting") + log.DEBUG.Printf("Server is done, exiting") err := server.httpServer.Shutdown(context.Background()) if err != nil { - log.Printf("Error shutting down HTTP server: %v", err) + log.ERROR.Printf("Error shutting down HTTP server: %v", err) } } diff --git a/cli/commands/info.go b/cli/commands/info.go index 4293f5f..ddf583d 100644 --- a/cli/commands/info.go +++ b/cli/commands/info.go @@ -2,10 +2,11 @@ package commands import ( "fmt" - "log" - "github.com/BattlesnakeOfficial/rules/maps" "github.com/spf13/cobra" + log "github.com/spf13/jwalterweatherman" + + "github.com/BattlesnakeOfficial/rules/maps" ) type mapInfo struct { @@ -35,7 +36,7 @@ func NewMapInfoCommand() *cobra.Command { if len(args) < 1 { err := cmd.Help() if err != nil { - log.Fatal(err) + log.ERROR.Fatal(err) } return } @@ -59,7 +60,7 @@ func NewMapInfoCommand() *cobra.Command { func (m *mapInfo) display(id string) { gameMap, err := maps.GetMap(id) if err != nil { - log.Fatalf("Failed to load game map %#v: %v", id, err) + log.ERROR.Fatalf("Failed to load game map %v: %v", id, err) } meta := gameMap.Meta() fmt.Println("Name:", meta.Name) diff --git a/cli/commands/map.go b/cli/commands/map.go index d310016..6511aff 100644 --- a/cli/commands/map.go +++ b/cli/commands/map.go @@ -1,9 +1,8 @@ package commands import ( - "log" - "github.com/spf13/cobra" + log "github.com/spf13/jwalterweatherman" ) func NewMapCommand() *cobra.Command { @@ -15,7 +14,7 @@ func NewMapCommand() *cobra.Command { Run: func(cmd *cobra.Command, args []string) { err := cmd.Help() if err != nil { - log.Fatal(err) + log.ERROR.Fatal(err) } }, } diff --git a/cli/commands/names.go b/cli/commands/names.go new file mode 100644 index 0000000..cd7dc11 --- /dev/null +++ b/cli/commands/names.go @@ -0,0 +1,153 @@ +// This file uses material from the Wikipedia article "List of snakes by common name", which is released under the Creative Commons Attribution-Share-Alike License 3.0. +package commands + +import ( + "math/rand" + "time" + + "github.com/google/uuid" +) + +var snakeNames = []string{ + "Adder", + "Aesculapian Snake", + "Anaconda", + "Arafura File Snake", + "Asp", + "African Beaked Snake", + "Ball Python", + "Bird Snake", + "Black-headed Snake", + "Mexican Black Kingsnake", + "Black Rat Snake", + "Black Snake", + "Blind Snake", + "Boa", + "Boiga", + "Boomslang", + "Brown Snake", + "Bull Snake", + "Bushmaster", + "Dwarf Beaked Snake", + "Rufous Beaked Snake", + "Canebrake", + "Cantil", + "Cascabel", + "Cat-eyed Snake", + "Cat Snake", + "Chicken Snake", + "Coachwhip Snake", + "Cobra", + "Collett's Snake", + "Congo Snake", + "Copperhead", + "Coral Snake", + "Corn Snake", + "Cottonmouth", + "Crowned Snake", + "Cuban Wood Snake", + "Egg-eater", + "Eyelash Viper", + "Fer-de-lance", + "Fierce Snake", + "Fishing Snake", + "Flying Snake", + "Fox Snake", + "Forest Flame Snake", + "Garter Snake", + "Glossy Snake", + "Gopher Snake", + "Grass Snake", + "Green Snake", + "Ground Snake", + "Habu", + "Harlequin Snake", + "Herald Snake", + "Hognose Snake", + "Hoop Snake", + "Hundred Pacer", + "Ikaheka Snake", + "Indigo Snake", + "Jamaican Tree Snake", + "Jararacussu", + "Keelback", + "King Brown", + "King Cobra", + "King Snake", + "Krait", + "Lancehead", + "Lora", + "Lyre Snake", + "Machete Savane", + "Mamba", + "Mamushi", + "Mangrove Snake", + "Milk Snake", + "Moccasin Snake", + "Montpellier Snake", + "Mud Snake", + "Mussurana", + "Night Snake", + "Nose-horned Viper", + "Parrot Snake", + "Patchnose Snake", + "Pine Snake", + "Pipe Snake", + "Python", + "Queen Snake", + "Racer", + "Raddysnake", + "Rat Snake", + "Rattlesnake", + "Ribbon Snake", + "Rinkhals", + "River Jack", + "Sea Snake", + "Shield-tailed Snake", + "Sidewinder", + "Small-eyed Snake", + "Stiletto Snake", + "Striped Snake", + "Sunbeam Snake", + "Taipan", + "Tentacled Snake", + "Tic Polonga", + "Tiger Snake", + "Tigre Snake", + "Tree Snake", + "Trinket Snake", + "Twig Snake", + "Twin Headed King Snake", + "Titanoboa", + "Urutu", + "Vine Snake", + "Viper", + "Wart Snake", + "Water Moccasin", + "Water Snake", + "Whip Snake", + "Wolf Snake", + "Worm Snake", + "Wutu", + "Yarara", + "Zebra Snake", +} + +func init() { + randGen := rand.New(rand.NewSource(time.Now().UnixNano())) + randGen.Shuffle(len(snakeNames), func(i, j int) { + snakeNames[i], snakeNames[j] = snakeNames[j], snakeNames[i] + }) +} + +// Generate a random unique snake name, or return a UUID if there are no more names available. +func GenerateSnakeName() string { + if len(snakeNames) == 0 { + return uuid.New().String() + } + + name := snakeNames[0] + snakeNames = snakeNames[1:] + + return name +} diff --git a/cli/commands/output.go b/cli/commands/output.go index 44ca6bb..28df9df 100644 --- a/cli/commands/output.go +++ b/cli/commands/output.go @@ -3,9 +3,10 @@ package commands import ( "encoding/json" "fmt" - "log" "os" + log "github.com/spf13/jwalterweatherman" + "github.com/BattlesnakeOfficial/rules/client" ) @@ -30,7 +31,7 @@ func (ge *GameExporter) FlushToFile(filepath string, format string) error { if format == "JSONL" { formattedOutput, formattingErr = ge.ConvertToJSON() } else { - log.Fatalf("Invalid output format passed: %s", format) + log.ERROR.Fatalf("Invalid output format passed: %s", format) } if formattingErr != nil { @@ -50,7 +51,7 @@ func (ge *GameExporter) FlushToFile(filepath string, format string) error { } } - log.Printf("Written %d lines of output to file: %s\n", len(formattedOutput), filepath) + log.DEBUG.Printf("Written %d lines of output to file: %s\n", len(formattedOutput), filepath) return nil } diff --git a/cli/commands/play.go b/cli/commands/play.go index 61883ac..152c559 100644 --- a/cli/commands/play.go +++ b/cli/commands/play.go @@ -5,13 +5,12 @@ import ( "encoding/json" "fmt" "io/ioutil" - "log" "math/rand" "net/http" "net/url" - "os" "path" "strconv" + "strings" "sync" "time" @@ -22,6 +21,7 @@ import ( "github.com/google/uuid" "github.com/pkg/browser" "github.com/spf13/cobra" + log "github.com/spf13/jwalterweatherman" ) // Used to store state for each SnakeState while running a local game @@ -55,7 +55,6 @@ type GameState struct { UseColor bool Seed int64 TurnDelay int - DebugRequests bool Output string ViewInBrowser bool BoardURL string @@ -98,7 +97,6 @@ func NewPlayCommand() *cobra.Command { playCmd.Flags().Int64VarP(&gameState.Seed, "seed", "r", time.Now().UTC().UnixNano(), "Random Seed") playCmd.Flags().IntVarP(&gameState.TurnDelay, "delay", "d", 0, "Turn Delay in Milliseconds") playCmd.Flags().IntVarP(&gameState.TurnDuration, "duration", "D", 0, "Minimum Turn Duration in Milliseconds") - playCmd.Flags().BoolVar(&gameState.DebugRequests, "debug-requests", false, "Log body of all requests sent") playCmd.Flags().StringVarP(&gameState.Output, "output", "o", "", "File path to output game state to. Existing files will be overwritten") playCmd.Flags().BoolVar(&gameState.ViewInBrowser, "browser", false, "View the game in the browser using the Battlesnake game board") playCmd.Flags().StringVar(&gameState.BoardURL, "board-url", "https://board.battlesnake.com", "Base URL for the game board when using --browser") @@ -129,7 +127,7 @@ func (gameState *GameState) initialize() { // Load game map gameMap, err := maps.GetMap(gameState.MapName) if err != nil { - log.Fatalf("Failed to load game map %#v: %v", gameState.MapName, err) + log.ERROR.Fatalf("Failed to load game map %#v: %v", gameState.MapName, err) } gameState.gameMap = gameMap @@ -173,10 +171,6 @@ func (gameState *GameState) Run() { isDraw: false, } - if gameState.ViewMap { - gameState.printMap(boardState) - } - boardGame := board.Game{ ID: gameState.gameID, Status: "running", @@ -194,23 +188,30 @@ func (gameState *GameState) Run() { if gameState.ViewInBrowser { serverURL, err := boardServer.Listen() if err != nil { - log.Fatalf("Error starting HTTP server: %v", err) + log.ERROR.Fatalf("Error starting HTTP server: %v", err) } - log.Printf("Board server listening on %s", serverURL) + defer boardServer.Shutdown() + log.INFO.Printf("Board server listening on %s", serverURL) boardURL := fmt.Sprintf(gameState.BoardURL+"?engine=%s&game=%s&autoplay=true", serverURL, gameState.gameID) - log.Printf("Opening board URL: %s", boardURL) + log.INFO.Printf("Opening board URL: %s", boardURL) if err := browser.OpenURL(boardURL); err != nil { - log.Printf("Failed to open browser: %v", err) + log.ERROR.Printf("Failed to open browser: %v", err) } - } - if gameState.ViewInBrowser { // send turn zero to websocket server boardServer.SendEvent(gameState.buildFrameEvent(boardState)) } + log.INFO.Printf("Ruleset: %v, Seed: %v", gameState.GameType, gameState.Seed) + + if gameState.ViewMap { + gameState.printMap(boardState) + } else { + gameState.printState(boardState) + } + var endTime time.Time for v := false; !v; v, _ = gameState.ruleset.IsGameOver(boardState) { if gameState.TurnDuration > 0 { @@ -238,7 +239,7 @@ func (gameState *GameState) Run() { if gameState.ViewMap { gameState.printMap(boardState) } else { - log.Printf("[%v]: State: %v\n", boardState.Turn, boardState) + gameState.printState(boardState) } if gameState.TurnDelay > 0 { @@ -254,36 +255,29 @@ func (gameState *GameState) Run() { } } - isDraw := true - if gameState.GameType == "solo" { - log.Printf("[DONE]: Game completed after %v turns.", boardState.Turn) - if exportGame { - // These checks for exportGame are present to avoid vacuuming up RAM when an export is not requred. - for _, snakeState := range gameState.snakeStates { - gameExporter.winner = snakeState - break - } - } - } else { - var winner SnakeState - for _, snake := range boardState.Snakes { - snakeState := gameState.snakeStates[snake.ID] - if snake.EliminatedCause == rules.NotEliminated { - isDraw = false - winner = snakeState - } - gameState.sendEndRequest(boardState, snakeState) - } + gameExporter.isDraw = false - if isDraw { - log.Printf("[DONE]: Game completed after %v turns. It was a draw.", boardState.Turn) - } else { - log.Printf("[DONE]: Game completed after %v turns. %v is the winner.", boardState.Turn, winner.Name) - } - if exportGame { - gameExporter.winner = winner - gameExporter.isDraw = isDraw + if len(gameState.snakeStates) > 1 { + // A draw is possible if there is more than one snake in the game. + gameExporter.isDraw = true + } + + for _, snake := range boardState.Snakes { + snakeState := gameState.snakeStates[snake.ID] + if snake.EliminatedCause == rules.NotEliminated { + gameExporter.isDraw = false + gameExporter.winner = snakeState } + + gameState.sendEndRequest(boardState, snakeState) + } + + if gameExporter.isDraw { + log.INFO.Printf("Game completed after %v turns. It was a draw.", boardState.Turn) + } else if gameExporter.winner.Name != "" { + log.INFO.Printf("Game completed after %v turns. %v was the winner.", boardState.Turn, gameExporter.winner.Name) + } else { + log.INFO.Printf("Game completed after %v turns.", boardState.Turn) } if gameState.ViewInBrowser { @@ -296,14 +290,9 @@ func (gameState *GameState) Run() { if exportGame { err := gameExporter.FlushToFile(gameState.Output, "JSONL") if err != nil { - log.Printf("[WARN]: Unable to export game. Reason: %v\n", err.Error()) - os.Exit(1) + log.ERROR.Fatalf("Unable to export game. Reason: %v", err) } } - - if gameState.ViewInBrowser { - boardServer.Shutdown() - } } func (gameState *GameState) initializeBoardFromArgs() *rules.BoardState { @@ -313,11 +302,11 @@ func (gameState *GameState) initializeBoardFromArgs() *rules.BoardState { } boardState, err := maps.SetupBoard(gameState.gameMap.ID(), gameState.ruleset.Settings(), gameState.Width, gameState.Height, snakeIds) if err != nil { - log.Fatalf("Error Initializing Board State: %v", err) + log.ERROR.Fatalf("Error Initializing Board State: %v", err) } boardState, err = gameState.ruleset.ModifyInitialBoardState(boardState) if err != nil { - log.Fatalf("Error Initializing Board State: %v", err) + log.ERROR.Fatalf("Error Initializing Board State: %v", err) } for _, snakeState := range gameState.snakeStates { @@ -325,12 +314,10 @@ func (gameState *GameState) initializeBoardFromArgs() *rules.BoardState { requestBody := serialiseSnakeRequest(snakeRequest) u, _ := url.ParseRequestURI(snakeState.URL) u.Path = path.Join(u.Path, "start") - if gameState.DebugRequests { - log.Printf("POST %s: %v", u, string(requestBody)) - } + log.DEBUG.Printf("POST %s: %v", u, string(requestBody)) _, err = gameState.httpClient.Post(u.String(), "application/json", bytes.NewBuffer(requestBody)) if err != nil { - log.Printf("[WARN]: Request to %v failed", u.String()) + log.WARN.Printf("Request to %v failed", u.String()) } } return boardState @@ -376,12 +363,12 @@ func (gameState *GameState) createNextBoardState(boardState *rules.BoardState) * } boardState, err := gameState.ruleset.CreateNextBoardState(boardState, moves) if err != nil { - log.Fatalf("Error producing next board state: %v", err) + log.ERROR.Fatalf("Error producing next board state: %v", err) } boardState, err = maps.UpdateBoard(gameState.gameMap.ID(), boardState, gameState.ruleset.Settings()) if err != nil { - log.Fatalf("Error updating board with game map: %v", err) + log.ERROR.Fatalf("Error updating board with game map: %v", err) } boardState.Turn += 1 @@ -394,54 +381,52 @@ func (gameState *GameState) getMoveForSnake(boardState *rules.BoardState, snakeS requestBody := serialiseSnakeRequest(snakeRequest) u, _ := url.ParseRequestURI(snakeState.URL) u.Path = path.Join(u.Path, "move") - if gameState.DebugRequests { - log.Printf("POST %s: %v", u, string(requestBody)) - } + log.DEBUG.Printf("POST %s: %v", u, string(requestBody)) res, err := gameState.httpClient.Post(u.String(), "application/json", bytes.NewBuffer(requestBody)) // Use snake's last move as the default in case of an error snakeMove := rules.SnakeMove{ID: snakeState.ID, Move: snakeState.LastMove} if err != nil { - log.Printf( - "[WARN]: Request to %v failed\n"+ - "\tError: %s\n", u.String(), err) + log.WARN.Printf( + "Request to %v failed\n"+ + "\tError: %s", u.String(), err) return snakeMove } if res.Body == nil { - log.Printf( - "[WARN]: Failed to parse response from %v\n"+ - "\tError: body is empty\n", u.String()) + log.WARN.Printf( + "Failed to parse response from %v\n"+ + "\tError: body is empty", u.String()) return snakeMove } defer res.Body.Close() body, readErr := ioutil.ReadAll(res.Body) if readErr != nil { - log.Printf( - "[WARN]: Failed to read response body from %v\n"+ - "\tError: %v\n", u.String(), readErr) + log.WARN.Printf( + "Failed to read response body from %v\n"+ + "\tError: %v", u.String(), readErr) return snakeMove } if res.StatusCode != http.StatusOK { - log.Printf( - "[WARN]: Got non-ok status code from %v\n"+ + log.WARN.Printf( + "Got non-ok status code from %v\n"+ "\tStatusCode: %d (expected %d)\n"+ - "\tBody: %q\n", u.String(), res.StatusCode, http.StatusOK, body) + "\tBody: %q", u.String(), res.StatusCode, http.StatusOK, body) return snakeMove } playerResponse := client.MoveResponse{} jsonErr := json.Unmarshal(body, &playerResponse) if jsonErr != nil { - log.Printf( - "[WARN]: Failed to decode JSON from %v\n"+ + log.WARN.Printf( + "Failed to decode JSON from %v\n"+ "\tError: %v\n"+ "\tBody: %q\n"+ "\tSee https://docs.battlesnake.com/references/api#post-move", u.String(), jsonErr, body) return snakeMove } if playerResponse.Move != "up" && playerResponse.Move != "down" && playerResponse.Move != "left" && playerResponse.Move != "right" { - log.Printf( - "[WARN]: Failed to parse JSON data from %v\n"+ + log.WARN.Printf( + "Failed to parse JSON data from %v\n"+ "\tError: invalid move %q, valid moves are \"up\", \"down\", \"left\" or \"right\"\n"+ "\tBody: %q\n"+ "\tSee https://docs.battlesnake.com/references/api#post-move", u.String(), playerResponse.Move, body) @@ -457,12 +442,10 @@ func (gameState *GameState) sendEndRequest(boardState *rules.BoardState, snakeSt requestBody := serialiseSnakeRequest(snakeRequest) u, _ := url.ParseRequestURI(snakeState.URL) u.Path = path.Join(u.Path, "end") - if gameState.DebugRequests { - log.Printf("POST %s: %v", u, string(requestBody)) - } + log.DEBUG.Printf("POST %s: %v", u, string(requestBody)) _, err := gameState.httpClient.Post(u.String(), "application/json", bytes.NewBuffer(requestBody)) if err != nil { - log.Printf("[WARN]: Request to %v failed", u.String()) + log.WARN.Printf("Request to %v failed", u.String()) } } @@ -507,9 +490,6 @@ func (gameState *GameState) buildSnakesFromOptions() map[string]SnakeState { } else { numSnakes = numURLs } - if numNames != numURLs { - log.Println("[WARN]: Number of Names and URLs do not match: defaults will be applied to missing values") - } for i := int(0); i < numSnakes; i++ { var snakeName string var snakeURL string @@ -519,21 +499,18 @@ func (gameState *GameState) buildSnakesFromOptions() map[string]SnakeState { if i < numNames { snakeName = gameState.Names[i] } else { - log.Printf("[WARN]: Name for URL %v is missing: a default name will be applied\n", gameState.URLs[i]) - snakeName = id + log.DEBUG.Printf("Name for URL %v is missing: a name will be generated automatically", gameState.URLs[i]) + snakeName = GenerateSnakeName() } if i < numURLs { u, err := url.ParseRequestURI(gameState.URLs[i]) if err != nil { - log.Printf("[WARN]: URL %v is not valid: a default will be applied\n", gameState.URLs[i]) - snakeURL = "https://example.com" - } else { - snakeURL = u.String() + log.ERROR.Fatalf("URL %v is not valid: %v", gameState.URLs[i], err) } + snakeURL = u.String() } else { - log.Printf("[WARN]: URL for Name %v is missing: a default URL will be applied\n", gameState.Names[i]) - snakeURL = "https://example.com" + log.ERROR.Fatalf("URL for name %v is missing", gameState.Names[i]) } snakeState := SnakeState{ @@ -542,44 +519,60 @@ func (gameState *GameState) buildSnakesFromOptions() map[string]SnakeState { var snakeErr error res, err := gameState.httpClient.Get(snakeURL) if err != nil { - log.Printf("[WARN]: Request to %v failed: %v", snakeURL, err) - snakeErr = err - } else { - snakeState.StatusCode = res.StatusCode + log.ERROR.Fatalf("Snake metadata request to %v failed: %v", snakeURL, err) + } - if res.Body != nil { - defer res.Body.Close() - body, readErr := ioutil.ReadAll(res.Body) - if readErr != nil { - log.Fatal(readErr) - } + snakeState.StatusCode = res.StatusCode - pingResponse := client.SnakeMetadataResponse{} - jsonErr := json.Unmarshal(body, &pingResponse) - if jsonErr != nil { - snakeErr = jsonErr - log.Printf("Error reading response from %v: %v", snakeURL, jsonErr) - } else { - snakeState.Head = pingResponse.Head - snakeState.Tail = pingResponse.Tail - snakeState.Color = pingResponse.Color - snakeState.Author = pingResponse.Author - snakeState.Version = pingResponse.Version - } - } + if res.Body == nil { + log.ERROR.Fatalf("Empty response body from snake metadata URL: %v", snakeURL) } + + defer res.Body.Close() + body, readErr := ioutil.ReadAll(res.Body) + if readErr != nil { + log.ERROR.Fatalf("Error reading from snake metadata URL %v: %v", snakeURL, readErr) + } + + pingResponse := client.SnakeMetadataResponse{} + jsonErr := json.Unmarshal(body, &pingResponse) + if jsonErr != nil { + log.ERROR.Fatalf("Failed to parse response from %v: %v", snakeURL, jsonErr) + } + + snakeState.Head = pingResponse.Head + snakeState.Tail = pingResponse.Tail + snakeState.Color = pingResponse.Color + snakeState.Author = pingResponse.Author + snakeState.Version = pingResponse.Version + if snakeErr != nil { snakeState.Error = snakeErr } snakes[snakeState.ID] = snakeState + + log.INFO.Printf("Snake ID: %v URL: %v, Name: \"%v\"", snakeState.ID, snakeURL, snakeState.Name) } return snakes } +func (gameState *GameState) printState(boardState *rules.BoardState) { + var aliveSnakeNames []string + for _, snake := range boardState.Snakes { + if snake.EliminatedCause == rules.NotEliminated { + aliveSnakeNames = append(aliveSnakeNames, gameState.snakeStates[snake.ID].Name) + } + } + log.INFO.Printf( + "Turn: %d, Snakes Alive: [%v], Food: %d, Hazards: %d", + boardState.Turn, strings.Join(aliveSnakeNames, ", "), len(boardState.Food), len(boardState.Hazards), + ) +} + func (gameState *GameState) printMap(boardState *rules.BoardState) { var o bytes.Buffer - o.WriteString(fmt.Sprintf("Ruleset: %s, Seed: %d, Turn: %v\n", gameState.GameType, gameState.Seed, boardState.Turn)) + o.WriteString(fmt.Sprintf("Turn: %d\n", boardState.Turn)) board := make([][]string, boardState.Width) for i := range board { board[i] = make([]string, boardState.Height) @@ -618,21 +611,28 @@ func (gameState *GameState) printMap(boardState *rules.BoardState) { o.WriteString(fmt.Sprintf("Food ⚕: %v\n", boardState.Food)) } for _, s := range boardState.Snakes { - red, green, blue := parseSnakeColor(gameState.snakeStates[s.ID].Color) + state := gameState.snakeStates[s.ID] + + red, green, blue := parseSnakeColor(state.Color) for _, b := range s.Body { if b.X >= 0 && b.X < boardState.Width && b.Y >= 0 && b.Y < boardState.Height { if gameState.UseColor { board[b.X][b.Y] = fmt.Sprintf(TERM_FG_RGB+"■", red, green, blue) } else { - board[b.X][b.Y] = string(gameState.snakeStates[s.ID].Character) + board[b.X][b.Y] = string(state.Character) } } } if gameState.UseColor { - o.WriteString(fmt.Sprintf("%v "+TERM_FG_RGB+TERM_BG_WHITE+"■■■"+TERM_RESET+": %v\n", gameState.snakeStates[s.ID].Name, red, green, blue, s)) + o.WriteString(fmt.Sprintf("%v "+TERM_FG_RGB+TERM_BG_WHITE+"■■■"+TERM_RESET+": ", state.Name, red, green, blue)) } else { - o.WriteString(fmt.Sprintf("%v %c: %v\n", gameState.snakeStates[s.ID].Name, gameState.snakeStates[s.ID].Character, s)) + o.WriteString(fmt.Sprintf("%v %c: ", state.Name, state.Character)) + } + o.WriteString(fmt.Sprintf("Health: %d", s.Health)) + if s.EliminatedCause != rules.NotEliminated { + o.WriteString(fmt.Sprintf(", Eliminated: %v, Turn: %d", s.EliminatedCause, s.EliminatedOnTurn)) } + o.WriteString("\n") } for y := boardState.Height - 1; y >= 0; y-- { if gameState.UseColor { @@ -646,7 +646,7 @@ func (gameState *GameState) printMap(boardState *rules.BoardState) { } o.WriteString("\n") } - log.Print(o.String()) + fmt.Println(o.String()) } func (gameState *GameState) buildFrameEvent(boardState *rules.BoardState) board.GameEvent { @@ -705,7 +705,7 @@ func (gameState *GameState) buildFrameEvent(boardState *rules.BoardState) board. func serialiseSnakeRequest(snakeRequest client.SnakeRequest) []byte { requestJSON, err := json.Marshal(snakeRequest) if err != nil { - log.Fatalf("Error marshalling JSON from State: %v", err) + log.ERROR.Fatalf("Error marshalling JSON from State: %v", err) } return requestJSON } diff --git a/cli/commands/play_test.go b/cli/commands/play_test.go index e9e4d88..daf58ae 100644 --- a/cli/commands/play_test.go +++ b/cli/commands/play_test.go @@ -25,7 +25,6 @@ func buildDefaultGameState() *GameState { Seed: 1, TurnDelay: 0, TurnDuration: 0, - DebugRequests: false, Output: "", FoodSpawnChance: 15, MinimumFood: 1, diff --git a/cli/commands/root.go b/cli/commands/root.go index 7fb3a03..72bab2b 100644 --- a/cli/commands/root.go +++ b/cli/commands/root.go @@ -2,15 +2,18 @@ package commands import ( "fmt" + stdlog "log" "os" "github.com/spf13/cobra" homedir "github.com/mitchellh/go-homedir" + log "github.com/spf13/jwalterweatherman" "github.com/spf13/viper" ) var cfgFile string +var verbose bool var rootCmd = &cobra.Command{ Use: "battlesnake", @@ -41,7 +44,7 @@ func init() { // will be global for your application. rootCmd.PersistentFlags().StringVar(&cfgFile, "config", "", "config file (default is $HOME/.battlesnake.yaml)") - + rootCmd.PersistentFlags().BoolVar(&verbose, "verbose", false, "Enable debug logging") } // initConfig reads in config file and ENV variables if set. @@ -68,4 +71,13 @@ func initConfig() { if err := viper.ReadInConfig(); err == nil { fmt.Println("Using config file:", viper.ConfigFileUsed()) } + + // Setup logging + log.SetStdoutOutput(os.Stderr) + log.SetFlags(stdlog.Ltime | stdlog.Lmicroseconds) + if verbose { + log.SetStdoutThreshold(log.LevelDebug) + } else { + log.SetStdoutThreshold(log.LevelInfo) + } } diff --git a/go.mod b/go.mod index 4b13951..ae4ec76 100644 --- a/go.mod +++ b/go.mod @@ -9,6 +9,7 @@ require ( github.com/pkg/browser v0.0.0-20210911075715-681adbf594b8 github.com/rs/cors v1.8.2 github.com/spf13/cobra v1.1.1 + github.com/spf13/jwalterweatherman v1.1.0 github.com/spf13/viper v1.7.1 github.com/stretchr/testify v1.4.0 ) @@ -24,7 +25,6 @@ require ( github.com/pmezard/go-difflib v1.0.0 // indirect github.com/spf13/afero v1.1.2 // indirect github.com/spf13/cast v1.3.0 // indirect - github.com/spf13/jwalterweatherman v1.0.0 // indirect github.com/spf13/pflag v1.0.5 // indirect github.com/subosito/gotenv v1.2.0 // indirect golang.org/x/sys v0.0.0-20220422013727-9388b58f7150 // indirect diff --git a/go.sum b/go.sum index 7566cc4..acfb40c 100644 --- a/go.sum +++ b/go.sum @@ -173,8 +173,9 @@ github.com/spf13/cast v1.3.0 h1:oget//CVOEoFewqQxwr0Ej5yjygnqGkvggSE/gB35Q8= github.com/spf13/cast v1.3.0/go.mod h1:Qx5cxh0v+4UWYiBimWS+eyWzqEqokIECu5etghLkUJE= github.com/spf13/cobra v1.1.1 h1:KfztREH0tPxJJ+geloSLaAkaPkr4ki2Er5quFV1TDo4= github.com/spf13/cobra v1.1.1/go.mod h1:WnodtKOvamDL/PwE2M4iKs8aMDBZ5Q5klgD3qfVJQMI= -github.com/spf13/jwalterweatherman v1.0.0 h1:XHEdyB+EcvlqZamSM4ZOMGlc93t6AcsBEu9Gc1vn7yk= github.com/spf13/jwalterweatherman v1.0.0/go.mod h1:cQK4TGJAtQXfYWX+Ddv3mKDzgVb68N+wFjFa4jdeBTo= +github.com/spf13/jwalterweatherman v1.1.0 h1:ue6voC5bR5F8YxI5S67j9i582FU4Qvo2bmqnqMYADFk= +github.com/spf13/jwalterweatherman v1.1.0/go.mod h1:aNWZUN0dPAAO/Ljvb5BEdw96iTZ0EXowPYD95IqWIGo= github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg=