Handle game chats and write them into the log (#421)

Players sometimes say things in the game chat, which I would be
interested in at least becoming aware of.

example_config.json5

@@ -348,6 +348,11 @@
      */
     // verbosity: 0,
 
+    /** Enable logging game chat content.
+     *  @default false
+     */
+    // log_game_chat: true,
+
     /** Sets how often the status lines are printed to the screen. Set to 0 to
      * disable.
      * units: milliseconds

schema/Config.schema.json

@@ -18,6 +18,11 @@
                     "description": "Enable verbose logging.",
                     "default": 0
                 },
+                "log_game_chat": {
+                    "type": "boolean",
+                    "description": "Enable logging game chat.",
+                    "default": false
+                },
                 "status_update_frequency": {
                     "type": "number",
                     "description": "Sets how often the status lines are printed to the screen. Set to 0 to disable. units: milliseconds",

src/Game.ts

@@ -26,6 +26,7 @@ export class Game extends EventEmitter<Events> {
     state: GoEngineConfig;
     opponent_evenodd: null | number;
     greeted: boolean;
+    startup_timestamp: number;
     bot?: Bot;
     using_opening_bot: boolean = false;
     ending_bot?: Bot;
@@ -56,6 +57,7 @@ export class Game extends EventEmitter<Events> {
         this.verbose = trace.debug.bind(null, `[game ${game_id}]`);
         this.warn = trace.warn.bind(null, `[game ${game_id}]`);
         this.error = trace.error.bind(null, `[game ${game_id}]`);
+        this.startup_timestamp = Date.now() / 1000;
         this.state = null;
         this.opponent_evenodd = null;
         this.greeted = false;
@@ -226,6 +228,7 @@ export class Game extends EventEmitter<Events> {
                 // Try to connect again, to get the server to send the gamedata over.
                 socket.send("game/connect", {
                     game_id: game_id,
+                    chat: config.log_game_chat,
                 });
                 return;
             }
@@ -341,8 +344,25 @@ export class Game extends EventEmitter<Events> {
             socket.off(`game/${game_id}/move`, on_move);
         });
 
+        if (config.log_game_chat) {
+            socket.send("chat/join", {
+                channel: `game-${game_id}`,
+            });
+            const on_chat = (d) => {
+                // Since there is no explicit tracking of which chats are
+                // "read", we assume anything from before we connected to the
+                // game has already been dealt with.
+                handleChatLine(game_id, d.line, this.startup_timestamp);
+            };
+            socket.on(`game/${game_id}/chat`, on_chat);
+            this.on("disconnecting", () => {
+                socket.off(`game/${game_id}/chat`, on_chat);
+            });
+        }
+
         socket.send("game/connect", {
             game_id: game_id,
+            chat: config.log_game_chat,
         });
 
         /*
@@ -827,6 +847,21 @@ export class Game extends EventEmitter<Events> {
     }
 }
 
+export function handleChatLine(game_id: string, line: any, cutoff_timestamp: number) {
+    if (typeof line.body !== "string") {
+        return;
+    }
+    if (line.username === config.username) {
+        return;
+    }
+    // Both are UNIX epoch times.
+    if (line.date < cutoff_timestamp) {
+        return;
+    }
+
+    trace.info(`[game ${game_id}] Game chat from ${line.username}: ${line.body}`);
+}
+
 function num2char(num: number): string {
     if (num === -1) {
         return ".";

src/config.ts

@@ -28,6 +28,11 @@ export interface Config {
      */
     verbosity?: number;
 
+    /** Enable logging game chat.
+     *  @default false
+     */
+    log_game_chat?: boolean;
+
     /** Sets how often the status lines are printed to the screen. Set to 0 to
      * disable.
      * units: milliseconds
@@ -372,6 +377,7 @@ function defaults(): Config {
         apikey: "",
         server: "https://online-go.com",
         verbosity: 1,
+        log_game_chat: false,
         max_pause_time: 300,
         status_update_frequency: 60000,
         allowed_time_control_systems: ["fischer", "byoyomi", "simple"],

src/main.ts

@@ -6,7 +6,7 @@ import { config, config_event_emitter, TimeControlRanges } from "./config";
 import { socket } from "./socket";
 import { trace } from "./trace";
 import { post, api1 } from "./util";
-import { Game } from "./Game";
+import { Game, handleChatLine } from "./Game";
 import { bot_pools } from "./pools";
 import { JGOFTimeControl } from "goban/src/JGOF";
 import { Speed } from "./types";
@@ -65,6 +65,7 @@ interface RejectionDetails {
 class Main {
     notification_connect_interval: ReturnType<typeof setInterval>;
     connected_games: { [game_id: string]: Game };
+    connected_finished_games: { [game_id: string]: boolean };
 
     //games_by_player: { [player_id: string]: Game[] };
     connected: boolean;
@@ -77,6 +78,7 @@ class Main {
 
     constructor() {
         this.connected_games = {};
+        this.connected_finished_games = {};
         //this.games_by_player = {}; // Keep track of connected games per player
         this.connected = false;
 
@@ -329,6 +331,51 @@ class Main {
                 }
                 break;
 
+            case "lateChatReceivedInGame":
+                {
+                    this.deleteNotification(notification);
+                    if (!config.log_game_chat) {
+                        break;
+                    }
+                    const game_id = notification.game_id;
+                    if (game_id in this.connected_finished_games) {
+                        // Already connected to the finished game.
+                        break;
+                    }
+
+                    trace.debug(`Connecting to ${game_id} to receive late chats`);
+                    socket.send("chat/join", {
+                        channel: `game-${game_id}`,
+                    });
+                    const on_chat = (chat) => {
+                        handleChatLine(game_id, chat.line, notification.timestamp - 1);
+                    };
+                    socket.on(`game/${game_id}/chat`, on_chat);
+
+                    // Connecting to a game from outside Game deserves a little
+                    // bit of care, but I think it should be OK, because
+                    // lateChatReceivedInGame implies the game is over, so we
+                    // should not be getting in the way of anything here.
+                    //
+                    // We could connect to the game as we usually do, but this
+                    // would confuse the logic there that expects to handle an
+                    // unfinished game.
+                    this.connected_finished_games[game_id] = true;
+                    socket.send("game/connect", {
+                        game_id: game_id,
+                        chat: true,
+                    });
+                    setTimeout(() => {
+                        trace.debug(`Disconnecting from ${game_id} (chats)`);
+                        delete this.connected_finished_games[game_id];
+                        socket.send("game/disconnect", {
+                            game_id: game_id,
+                        });
+                        socket.off(`game/${game_id}/chat`, on_chat);
+                    }, 5000);
+                }
+                break;
+
             default:
                 {
                     if (!(notification.type in ignorable_notifications)) {