bgammon-benchmark/client.go

package main

import (
	"bufio"
	"bytes"
	"context"
	"encoding/json"
	"errors"
	"fmt"
	"log"
	"math"
	"net"
	"net/http"
	"os"
	"path"
	"strconv"
	"strings"
	"time"

	"code.rocket9labs.com/tslocum/bei"
	"code.rocket9labs.com/tslocum/bgammon"
	"code.rocket9labs.com/tslocum/bgammon/pkg/server"
	"nhooyr.io/websocket"
)

var Debug int

type Client struct {
	Address      string
	Username     string
	Password     string
	Events       chan interface{}
	Out          chan []byte
	points       int
	connecting   bool
	sentGreeting bool
	rolled       bool
	lastActivity time.Time

	barsPlayer       int
	barsPlayerPips   int
	barsOpponent     int
	barsOpponentPips int

	wins   int
	losses int

	pipsWins   int
	pipsLosses int

	beiClient *BEIClient

	game *bgammon.GameState
}

func NewClient(address string, username string, password string, points int) *Client {
	const bufferSize = 10
	c := &Client{
		Address:  address,
		Username: username,
		Password: password,
		Events:   make(chan interface{}, bufferSize),
		Out:      make(chan []byte, bufferSize),
		points:   points,
		game: &bgammon.GameState{
			Game: bgammon.NewGame(bgammon.VariantBackgammon),
		},
	}
	go c.handleTimeout()
	return c
}

func NewLocalClient(conn net.Conn, address string, username string, password string, points int, beiClient *BEIClient) *Client {
	c := NewClient(address, username, password, points)
	c.beiClient = beiClient
	c.connecting = true
	go c.connectTCP(conn)
	return c
}

func (c *Client) Connect() {
	if c.connecting {
		return
	}
	c.connecting = true

	if strings.HasPrefix(c.Address, "ws://") || strings.HasPrefix(c.Address, "wss://") {
		c.connectWebSocket()
		return
	}
	c.connectTCP(nil)
}

func (c *Client) logIn() []byte {
	loginInfo := strings.ReplaceAll(c.Username, " ", "_")
	if c.Username != "" && c.Password != "" {
		loginInfo = fmt.Sprintf("%s %s", strings.ReplaceAll(c.Username, " ", "_"), strings.ReplaceAll(c.Password, " ", "_"))
	}
	return []byte(fmt.Sprintf("lj bgammon-benchmark %s\nset autoplay 0\nlist\n", loginInfo))
}

func (c *Client) LoggedIn() bool {
	return c.connecting
}

func (c *Client) connectWebSocket() {
	reconnect := func() {
		log.Println("*** Reconnecting...")
		time.Sleep(2 * time.Second)
		go c.connectWebSocket()
	}

	ctx, _ := context.WithTimeout(context.Background(), 10*time.Second)

	conn, _, err := websocket.Dial(ctx, c.Address, nil)
	if err != nil {
		reconnect()
		return
	}

	for _, msg := range bytes.Split(c.logIn(), []byte("\n")) {
		if len(msg) == 0 {
			continue
		}

		ctx, _ = context.WithTimeout(context.Background(), 10*time.Second)

		err = conn.Write(ctx, websocket.MessageText, msg)
		if err != nil {
			reconnect()
			return
		}
	}

	go c.handleWebSocketWrite(conn)
	c.handleWebSocketRead(conn)

	reconnect()
}

func (c *Client) handleWebSocketWrite(conn *websocket.Conn) {
	var ctx context.Context
	for buf := range c.Out {
		split := bytes.Split(buf, []byte("\n"))
		for i := range split {
			if len(split[i]) == 0 {
				continue
			}

			ctx, _ = context.WithTimeout(context.Background(), 10*time.Second)

			err := conn.Write(ctx, websocket.MessageText, split[i])
			if err != nil {
				conn.Close(websocket.StatusNormalClosure, "Write error")
				return
			}

			if Debug > 0 {
				log.Printf("-> %s", split[i])
			}
		}
	}
}

func (c *Client) handleWebSocketRead(conn *websocket.Conn) {
	for {
		msgType, msg, err := conn.Read(context.Background())
		if err != nil || msgType != websocket.MessageText {
			conn.Close(websocket.StatusNormalClosure, "Read error")
			return
		}

		ev, err := bgammon.DecodeEvent(msg)
		if err != nil {
			log.Printf("error: failed to parse message: %s", msg)
			conn.Close(websocket.StatusNormalClosure, "Read error")
			return
		}
		c.Events <- ev

		if Debug > 0 {
			log.Printf("<- %s", msg)
		}
	}
}

func (c *Client) connectTCP(conn net.Conn) {
	address := c.Address
	if strings.HasPrefix(c.Address, "tcp://") {
		address = c.Address[6:]
	}

	reconnect := func() {
		log.Println("*** Disconnected")
		os.Exit(0) // TODO Reconnecting is currently disabled.

		log.Println("*** Reconnecting...")
		time.Sleep(2 * time.Second)
		go c.connectTCP(nil)
	}

	if conn == nil {
		var err error
		conn, err = net.DialTimeout("tcp", address, 10*time.Second)
		if err != nil {
			reconnect()
			return
		}
	}

	// Read a single line of text and parse remaining output as JSON.
	buf := make([]byte, 1)
	var readBytes int
	for {
		_, err := conn.Read(buf)
		if err != nil {
			reconnect()
			return
		}

		if buf[0] == '\n' {
			break
		}

		readBytes++
		if readBytes == 512 {
			reconnect()
			return
		}
	}

	conn.SetWriteDeadline(time.Now().Add(10 * time.Second))

	_, err := conn.Write(c.logIn())
	if err != nil {
		reconnect()
		return
	}

	go c.handleTCPWrite(conn)
	c.handleTCPRead(conn)

	reconnect()
}

func (c *Client) handleTCPWrite(conn net.Conn) {
	for buf := range c.Out {
		conn.SetWriteDeadline(time.Now().Add(10 * time.Second))

		_, err := conn.Write(buf)
		if err != nil {
			conn.Close()
			return
		}

		conn.SetWriteDeadline(time.Now().Add(10 * time.Second))

		_, err = conn.Write([]byte("\n"))
		if err != nil {
			conn.Close()
			return
		}

		if Debug > 0 {
			log.Printf("-> %s", buf)
		}
	}
}

func (c *Client) handleTCPRead(conn net.Conn) {
	conn.SetReadDeadline(time.Now().Add(40 * time.Second))

	scanner := bufio.NewScanner(conn)
	for scanner.Scan() {
		if scanner.Err() != nil {
			conn.Close()
			return
		}

		ev, err := bgammon.DecodeEvent(scanner.Bytes())
		if err != nil {
			log.Printf("error: failed to parse message: %s", scanner.Bytes())
			conn.Close()
			return
		}
		c.Events <- ev

		if Debug > 0 {
			log.Printf("<- %s", scanner.Bytes())
		}

		conn.SetReadDeadline(time.Now().Add(40 * time.Second))
	}
}

func (c *Client) createMatch() {
	c.Out <- []byte(fmt.Sprintf("c public %d", c.points))
	c.sentGreeting = false
	c.rolled = false
}

func (c *Client) handleTimeout() {
	t := time.NewTicker(time.Minute)
	for range t.C {
		if !c.rolled {
			continue
		}

		if len(c.game.Player2.Name) == 0 && time.Since(c.lastActivity) >= 2*time.Minute {
			c.Out <- []byte("leave")
			continue
		}

		t := time.Now()
		delta := t.Sub(c.lastActivity)
		if delta >= 5*time.Minute {
			c.Out <- []byte("say Sorry, this match has timed out.")
			c.Out <- []byte("leave")
		} else if t.Sub(c.lastActivity) >= 2*time.Minute {
			plural := "s"
			if 6-math.Ceil(delta.Minutes()) == 1 {
				plural = ""
			}
			c.Out <- []byte(fmt.Sprintf("say Warning: This match will time out in %d minute%s. Please roll or make a move.", int(6-math.Ceil(delta.Minutes())), plural))
		}
	}
}

func (c *Client) HandleEvents() {
	for e := range c.Events {
		switch ev := e.(type) {
		case *bgammon.EventWelcome:
			c.Username = ev.PlayerName
			if c.beiClient == nil {
				c.createMatch()
			}
		case *bgammon.EventNotice:
			if c.beiClient != nil {
				continue
			}
			log.Printf("*** %s", ev.Message)
		case *bgammon.EventSay:
			if c.beiClient == nil {
				log.Printf("<%s> %s", ev.Player, ev.Message)
			}
		case *bgammon.EventList:
		case *bgammon.EventJoined:
			if ev.PlayerNumber == 1 {
				c.game.Player1.Name = ev.Player
			} else if ev.PlayerNumber == 2 {
				c.lastActivity = time.Now()
				c.game.Player2.Name = ev.Player
			}
		case *bgammon.EventFailedJoin:
			log.Printf("*** Failed to join match: %s", ev.Reason)
		case *bgammon.EventFailedLeave:
			log.Printf("*** Failed to leave match: %s", ev.Reason)

			c.createMatch()
		case *bgammon.EventLeft:
			if c.game.Player1.Name == ev.Player {
				c.game.Player1.Name = ""
			} else if c.game.Player2.Name == ev.Player {
				c.game.Player2.Name = ""
			}
			if ev.Player == c.Username {
				c.createMatch()
			} else {
				log.Printf("%s left the match.", ev.Player)
			}
		case *bgammon.EventBoard:
			*c.game = ev.GameState
			*c.game.Game = *ev.GameState.Game
			if c.game.Winner != 0 {
				continue
			}

			c.lastActivity = time.Now()

			if c.game.DoubleOffered && c.game.DoublePlayer != c.game.PlayerNumber {
				acceptCube := true
				if c.beiClient != nil {
					event, err := c.beiClient.Double(beiState(c.game.Game))
					if err != nil {
						log.Fatalf("failed to retrieve cube evaluation from engine: %s", err)
					}
					switch ev := event.(type) {
					case *bei.EventFailDouble:
						log.Fatalf("failed to retrieve cube evaluation from engine: %s", ev.Reason)
					case *bei.EventOkDouble:
						acceptCube = ev.Cube.Take
					default:
						log.Fatalf("unexpected engine reply: %+v", ev)
					}
				}
				if acceptCube {
					c.Out <- []byte("ok")
				} else {
					c.Out <- []byte("resign")
				}
				c.rolled = true
				continue
			}

			if c.game.Roll1 == 0 && len(c.game.Player2.Name) != 0 && (c.game.Turn == 0 || c.game.Turn == c.game.PlayerNumber) && c.game.MayRoll() {
				if c.game.MayDouble() && c.beiClient != nil {
					event, err := c.beiClient.Double(beiState(c.game.Game))
					if err != nil {
						log.Fatalf("failed to retrieve cube evaluation from engine: %s", err)
					}
					switch ev := event.(type) {
					case *bei.EventFailDouble:
						log.Fatalf("failed to retrieve cube evaluation from engine: %s", ev.Reason)
					case *bei.EventOkDouble:
						if ev.Cube.Offer {
							c.Out <- []byte("d")
							c.lastActivity = time.Now()
							continue
						}
					default:
						log.Fatalf("unexpected engine reply: %+v", ev)
					}
				}
				c.Out <- []byte("r")
				c.rolled = true
				continue
			} else if c.game.Turn == 0 || c.game.Turn != c.game.PlayerNumber {
				continue
			}

			if len(c.game.Available) == 0 {
				if c.game.MayChooseRoll() {
					event, err := c.beiClient.Choose(beiState(c.game.Game))
					if err != nil {
						log.Fatalf("failed to retrieve cube evaluation from engine: %s", err)
					}
					switch ev := event.(type) {
					case *bei.EventFailChoose:
						log.Fatalf("failed to retrieve roll choice from engine: %s", ev.Reason)
					case *bei.EventOkChoose:
						if len(ev.Rolls) == 0 {
							log.Fatalf("failed to retrieve roll choice from engine: no rolls were returned: %+v", ev)
						}
						c.Out <- []byte(fmt.Sprintf("ok %d", ev.Rolls[0].Roll))
						c.lastActivity = time.Now()
						continue
					default:
						log.Fatalf("unexpected engine reply: %+v", ev)
					}
				}
				c.Out <- []byte("ok")
				c.lastActivity = time.Now()
				continue
			}

			if thinkTime != 0 {
				time.Sleep(time.Duration(thinkTime) * time.Millisecond)
			}

			if c.beiClient == nil && wildbgAddress == "" {
				move := c.game.Available[server.RandInt(len(c.game.Available))]
				c.Out <- []byte(fmt.Sprintf("mv %d/%d", move[0], move[1]))
				c.lastActivity = time.Now()
				continue
			} else if len(c.game.Moves) != 0 {
				continue
			}

			if c.beiClient != nil {
				event, err := c.beiClient.Move(beiState(c.game.Game))
				if err != nil {
					log.Fatalf("failed to retrieve move from engine: %s", err)
				}
				switch ev := event.(type) {
				case *bei.EventFailMove:
				case *bei.EventOkMove:
					if len(ev.Moves) == 0 || len(ev.Moves[0].Play) == 0 {
						log.Fatalf("failed to retrieve move from engine: no moves were returned")
					}
					l := len(ev.Moves[0].Play)
					for i, play := range ev.Moves[0].Play {
						if play.From == 0 || play.From == 25 {
							c.Out <- []byte(fmt.Sprintf("mv off/%d", play.To))
						} else if play.From == 26 || play.From == 27 {
							c.Out <- []byte(fmt.Sprintf("mv bar/%d", play.To))
						} else {
							c.Out <- []byte(fmt.Sprintf("mv %d/%d", play.From, play.To))
						}
						if thinkTime != 0 && i < l-1 {
							time.Sleep(time.Duration(thinkTime) * time.Millisecond)
						}
					}
					c.lastActivity = time.Now()
				default:
					log.Fatalf("unexpected engine reply: %+v", ev)
				}
				continue
			}

			var response = &MoveResponse{}
			err := getJson(c, MoveURL(c.game), response)
			if err != nil {
				log.Fatalf("failed to communicate with wildbg service: %s", err)
			} else if len(response.Moves) == 0 {
				log.Printf("AVAILABLE: %+v", c.game.Available)
				log.Fatalf("NO MOVES RETURNED: %+v", response)
			}

			var bestPlay int
			var bestOdds float64
			for i, move := range response.Moves {
				if move.Probabilites.Win > bestOdds {
					bestPlay = i
					bestOdds = move.Probabilites.Win
				}
			}

			move := response.Moves[bestPlay]
			if len(move.Play) == 0 {
				log.Printf("AVAILABLE: %+v", c.game.Available)
				log.Fatalf("NO PLAYABLE MOVES RETURNED: %+v", response)
			}

			for _, play := range move.Play {
				if play.From == 0 || play.From == 25 {
					c.Out <- []byte(fmt.Sprintf("mv bar/%d", play.To))
				} else {
					c.Out <- []byte(fmt.Sprintf("mv %d/%d", play.From, play.To))
				}
			}
			c.lastActivity = time.Now()
		case *bgammon.EventRolled:
			if !c.sentGreeting {
				if matchDelay != 0 {
					time.Sleep(time.Duration(matchDelay) * time.Second)
				}
				c.sentGreeting = true
			}

			c.game.Roll1 = ev.Roll1
			c.game.Roll2 = ev.Roll2
			var diceFormatted string
			if c.game.Turn == 0 {
				if ev.Player == c.game.Player1.Name {
					diceFormatted = fmt.Sprintf("%d", c.game.Roll1)
				} else {
					diceFormatted = fmt.Sprintf("%d", c.game.Roll2)
				}
			} else {
				diceFormatted = fmt.Sprintf("%d-%d", c.game.Roll1, c.game.Roll2)
				if c.game.Roll3 != 0 {
					diceFormatted += fmt.Sprintf("-%d", c.game.Roll3)
				}
			}
			if ev.Player == c.game.Player2.Name {
				c.lastActivity = time.Now()
			}
			c.rolled = true
			if !quietOutput && (c.beiClient == nil || (c.beiClient.primary && !c.beiClient.quiet)) {
				log.Printf("%s rolled %s.", ev.Player, diceFormatted)
			}
		case *bgammon.EventFailedRoll:
			log.Printf("*** Failed to roll: %s", ev.Reason)
		case *bgammon.EventMoved:
			playerNumber := 1
			if ev.Player == c.game.Player2.Name {
				playerNumber = 2
				c.lastActivity = time.Now()
			}
			for _, m := range ev.Moves {
				if playerNumber == 1 && c.game.Board[m[1]] == -1 {
					c.barsPlayer++
					c.barsPlayerPips += int(bgammon.SpaceDiff(bgammon.SpaceBarOpponent, m[1], c.game.Variant))
				} else if playerNumber == 2 && c.game.Board[m[1]] == 1 {
					c.barsOpponent++
					c.barsOpponentPips += int(bgammon.SpaceDiff(bgammon.SpaceBarPlayer, m[1], c.game.Variant))
				}
				c.game.AddLocalMove(m)
			}
			if !quietOutput && (c.beiClient == nil || (c.beiClient.primary && !c.beiClient.quiet)) {
				log.Printf("%s moved %s.", ev.Player, bgammon.FormatMoves(ev.Moves))
			}
		case *bgammon.EventFailedMove:
			log.Printf("%+v", c.game.Game)
			log.Printf("%+v", c.game.Board)
			var extra string
			if ev.From != 0 || ev.To != 0 {
				extra = fmt.Sprintf(" from %s to %s", bgammon.FormatSpace(ev.From), bgammon.FormatSpace(ev.To))
			}
			log.Printf("*** Failed to move checker%s: %s", extra, ev.Reason)
			log.Printf("*** Legal moves: %s", bgammon.FormatMoves(c.game.Available))
		case *bgammon.EventFailedOk:
			c.Out <- []byte("board") // Refresh game state.
			log.Printf("*** Failed to submit moves: %s", ev.Reason)
		case *bgammon.EventWin:
			if c.beiClient == nil || (c.beiClient.primary && !c.beiClient.quiet) {
				log.Printf("%s wins!", ev.Player)
			}
			var pips int
			if ev.Player == c.Username {
				pips = c.game.Pips(2)
				c.losses++
				c.pipsLosses += pips
			} else {
				pips = c.game.Pips(1)
				c.wins++
				c.pipsWins += pips
			}
			total := c.wins + c.losses
			pct := float64(c.losses) / float64(total) * 100
			pw, pl := 0, 0
			if c.wins != 0 {
				pw = c.pipsWins / c.wins
			}
			if c.losses != 0 {
				pl = c.pipsLosses / c.losses
			}

			var barsPlayerPips, barsOpponentPips, pctBarsPips float64
			if c.barsPlayer != 0 || c.barsOpponent != 0 {
				if c.barsPlayer != 0 {
					barsPlayerPips = float64(c.barsPlayerPips) / float64(c.barsPlayer)
				}
				if c.barsOpponent != 0 {
					barsOpponentPips = float64(c.barsOpponentPips) / float64(c.barsOpponent)
				}
				pctBarsPips = (barsPlayerPips / (barsPlayerPips + barsOpponentPips)) * 100
			}

			pctBar := 0.0
			if c.barsOpponent != 0 || c.barsPlayer != 0 {
				pctBar = (float64(c.barsPlayer) / float64(c.barsOpponent+c.barsPlayer)) * 100
			}

			if c.beiClient != nil && c.beiClient.replayDir != "" {
				c.Out <- []byte("replay")
			}

			summary := fmt.Sprintf("W %02d / L %02d (%02d, %03.1f%%) Pips %02d / %02d (%03d) Bars %.2f / %.2f (%03.1f%%) Bar pips %.2f / %.2f (%03.1f%%)", c.losses, c.wins, total, pct, pl, pw, pips, float64(c.barsPlayer)/float64(total), float64(c.barsOpponent)/float64(total), pctBar, barsPlayerPips, barsOpponentPips, pctBarsPips)
			if c.beiClient == nil || c.beiClient.primary {
				log.Printf("<%s> %s", c.Username, summary)
			}
			c.Out <- []byte("say " + summary)

			if c.beiClient != nil && c.beiClient.count != 0 && total == c.beiClient.count {
				delta := time.Since(c.beiClient.started)
				gamesPerSecond := 0.0
				if delta.Seconds() != 0 {
					gamesPerSecond = float64(c.beiClient.count) / delta.Seconds()
				}
				log.Printf("<%s> Played %d matches in %s. (%.1f games/sec)", c.Username, c.beiClient.count, delta.Truncate(time.Second), gamesPerSecond)
				os.Exit(0)
			}
			c.Out <- []byte("rematch")
		case *bgammon.EventReplay:
			if c.beiClient == nil || c.beiClient.replayDir == "" {
				continue
			}
			err := saveReplay(ev.Content, c.Username, c.beiClient.replayDir)
			if err != nil {
				log.Fatalf("failed to save match: %s", err)
			}
		case *bgammon.EventPing:
			c.Out <- []byte(fmt.Sprintf("pong %s", ev.Message))
		default:
			log.Printf("*** Warning: Received unknown event: %+v", ev)
			log.Println("*** You may need to upgrade your client.")
		}
	}
}

func saveReplay(content []byte, username string, outDir string) error {
	var (
		timestamp int64
		player1   string
		player2   string
		err       error
	)
	scanner := bufio.NewScanner(bytes.NewReader(content))
	for scanner.Scan() {
		if bytes.HasPrefix(scanner.Bytes(), []byte("i ")) {
			split := bytes.Split(scanner.Bytes(), []byte(" "))
			if len(split) < 4 {
				return fmt.Errorf("failed to parse replay")
			}

			timestamp, err = strconv.ParseInt(string(split[1]), 10, 64)
			if err != nil {
				return fmt.Errorf("failed to parse replay timestamp")
			}

			if bytes.Equal(split[3], []byte(username)) {
				player1, player2 = string(split[3]), string(split[2])
			} else {
				player1, player2 = string(split[2]), string(split[3])
			}
		}
	}

	fileName := fmt.Sprintf("%d_%s_%s", timestamp, player1, player2)

	var filePath string
	i := 1
	for {
		filePath = path.Join(outDir, fileName+"_"+strconv.Itoa(i)+".match")
		if _, err := os.Stat(filePath); errors.Is(err, os.ErrNotExist) {
			break
		}
		i++
	}
	err = os.WriteFile(filePath, content, 0600)
	if err != nil {
		return fmt.Errorf("failed to write replay to %s: %s", filePath, err)
	}
	return nil
}

func QueryString(g *bgammon.GameState) string {
	b := g.Board
	var buf strings.Builder
	buf.Write([]byte("die1=" + strconv.Itoa(int(g.Roll1)) + "&die2=" + strconv.Itoa(int(g.Roll2)) + "&p0=" + strconv.Itoa(int(b[bgammon.SpaceBarOpponent]))))
	for i := 1; i < 25; i++ {
		buf.Write([]byte("&p" + strconv.Itoa(i) + "=" + strconv.Itoa(int(b[i]))))
	}
	buf.Write([]byte("&p25=" + strconv.Itoa(int(b[bgammon.SpaceBarPlayer]))))
	return buf.String()
}

func EvalURL(g *bgammon.GameState) string {
	return wildbgAddress + "/eval?" + QueryString(g)
}

func MoveURL(g *bgammon.GameState) string {
	return wildbgAddress + "/move?" + QueryString(g)
}

type EvalResponseCube struct {
	Accept bool
	Double bool
}

type EvalResponse struct {
	Cube *EvalResponseCube
}

type MoveResponsePlay struct {
	From int
	To   int
}

type MoveResponseProbability struct {
	Win float64
}

type MoveResponseMove struct {
	Play         []MoveResponsePlay
	Probabilites MoveResponseProbability
}

type MoveResponse struct {
	Moves []MoveResponseMove
}

var httpClient = &http.Client{Timeout: 40 * time.Second}

func getJson(c *Client, url string, target interface{}) error {
	const attempts = 5
	var err error
	for i := 0; i < attempts; i++ {
		if Debug > 0 {
			log.Printf("REQUEST %s", url)
		}

		r, err := httpClient.Get(url)
		if err != nil {
			return err
		}
		defer r.Body.Close()

		err = json.NewDecoder(r.Body).Decode(target)
		if err == nil {
			return nil
		} else if i < attempts-1 {
			time.Sleep(5 * time.Second)
		}
	}
	c.Out <- []byte("say Sorry, the wildbg backgammon engine is currently unavailable. Please try again later.")
	c.Out <- []byte("disconnect")
	return err
}