diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 2ca9eb7e..12357e53 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -104,6 +104,8 @@ jobs: run: python tools/vendor/vendor_lock.py --check - name: Vendor lock unit tests run: python -m unittest discover -s tools/vendor -v + - name: Booth tools unit tests + run: python -m unittest discover -s tools/booth -v gitleaks: name: gitleaks diff --git a/docs/builds.md b/docs/builds.md index bbad89f7..9726d5f8 100644 --- a/docs/builds.md +++ b/docs/builds.md @@ -36,6 +36,14 @@ open -a "Hoppy’s Adventure Arcade.app" --args -- --booth --route=heroes_vs_vil - **Idle reset.** After 90 seconds with no keyboard, mouse, touch or controller input, any game returns to the hub, whose rotating previews act as the attract screen. - **No quitting from the menu.** The menu's **Quit Game** does nothing in booth mode; staff close the window (Cmd+Q, Alt+F4). - **Launch route.** `--route=` opens a route at launch (`heroes_vs_villains`, `code_city_brawl`, `bay_area_blitz`, `orbital_ops`, `enchanted_repo`, `runner`, `platformer`, `beatem_up`, `hub`), with or without `--booth`. An unknown name logs an error and opens the hub. +- **Session log.** Booth mode records each game session's start and end in `user://booth/`, one file per run of the game (`sessions--.jsonl`). Each entry records the game, the local start and end times, the duration, how the session ended (`menu`, `idle` or `quit`) and how many times the player retried. It records nothing about players and never uses the network. A start with no end means the game stopped without quitting: a crash, a power cut or a forced kill. The game prints its file's full path at startup. `--session-log=` writes to another folder and works without `--booth`, for playtests. + +`user://` is `~/Library/Application Support/Godot/app_userdata/Hoppy’s Adventure Arcade/` on macOS, `%APPDATA%\Godot\app_userdata\Hoppy’s Adventure Arcade\` on Windows and `~/.local/share/godot/app_userdata/Hoppy’s Adventure Arcade/` on Linux. To summarize the logs, copy each machine's `booth` folder and run: + +```sh +python3 tools/booth/sessions_report.py booth/ # sessions per game, durations, end reasons, starts by hour +python3 tools/booth/sessions_report.py booth-a/ booth-b/ --csv sessions.csv # combine machines; one CSV row per session +``` ## Build locally diff --git a/hoppys-adventure-arcade/app/app_router.gd b/hoppys-adventure-arcade/app/app_router.gd index 9f9a7eb2..85ef6a3d 100644 --- a/hoppys-adventure-arcade/app/app_router.gd +++ b/hoppys-adventure-arcade/app/app_router.gd @@ -1,4 +1,5 @@ extends CanvasLayer +const BoothLog := preload("res://app/booth_log.gd") const ROUTES := { "heroes_vs_villains": "res://scenes/beatem_up/reinvent/heroes_vs_villains.tscn", "code_city_brawl": "res://scenes/beatem_up/code_city_brawl.tscn", @@ -23,11 +24,18 @@ const BOOTH_FLAG := "--booth" const ROUTE_PREFIX := "--route=" const IDLE_SECONDS := 90.0 const STICK_DEADZONE := 0.4 +## Booth analytics (app/booth_log.gd): with --booth, each game session's start and end go to a file +## for this run in the SESSION_LOG_DEFAULT folder. `--session-log=` (absolute or user://) +## picks another folder and also works without --booth, for playtests. Nothing is logged unless one +## of them is passed. +const SESSION_LOG_PREFIX := "--session-log=" +const SESSION_LOG_DEFAULT := "user://booth" var busy := false var veil: ColorRect var booth := false var idle_limit := IDLE_SECONDS var idle_seconds := 0.0 +var session_log: BoothLog func _ready() -> void: # The veil tween must keep running while a microgame has the tree paused. process_mode = Node.PROCESS_MODE_ALWAYS @@ -44,10 +52,15 @@ func _ready() -> void: smoke_routes.call_deferred() return set_booth(BOOTH_FLAG in args) + var log_path := session_log_path(args, booth) + if log_path != "": + start_session_log(log_path) var start := launch_route(args) if start != "": _launch.call_deferred(start) -func go(route: String) -> void: +## `reason` is how a game session in progress ends, for the session log: "menu" unless the router +## itself is leaving the game (booth mode's idle return passes "idle"). +func go(route: String, reason := "menu") -> void: if busy or not ROUTES.has(route) or not ResourceLoader.exists(ROUTES[route]): return busy = true @@ -60,6 +73,8 @@ func go(route: String) -> void: else: # A microgame may have paused the tree; never hand a paused tree to the next scene. get_tree().paused = false + if session_log: + session_log.route_changed(route, reason) if route == "hub": AudioService.play_default_music() await create_tween().tween_property(veil, "modulate:a", 0.0, 0.25).finished @@ -70,10 +85,13 @@ func go(route: String) -> void: func quit_game(force := false) -> void: if booth and not force: return + if busy and not force: + return + if session_log: + session_log.end("quit") if busy: - if force: - AudioService.shutdown() - get_tree().quit() + AudioService.shutdown() + get_tree().quit() return busy = true veil.mouse_filter = Control.MOUSE_FILTER_STOP @@ -95,6 +113,18 @@ static func launch_route(args: PackedStringArray) -> String: push_error("Unknown --route %s; expected one of %s" % [route, ", ".join(ROUTES.keys())]) return "" +## The session-log folder these arguments ask for: `--session-log=`, else the default in +## booth mode, else "" (no logging). +static func session_log_path(args: PackedStringArray, booth_mode: bool) -> String: + for arg in args: + if arg.begins_with(SESSION_LOG_PREFIX) and arg.length() > SESSION_LOG_PREFIX.length(): + return arg.trim_prefix(SESSION_LOG_PREFIX) + return SESSION_LOG_DEFAULT if booth_mode else "" + +func start_session_log(folder: String) -> void: + session_log = BoothLog.new(folder) + print("AppRouter: session log at %s" % ProjectSettings.globalize_path(session_log.path)) + func _launch(route: String) -> void: await go(route) var scene := get_tree().current_scene @@ -123,7 +153,7 @@ func _process(delta: float) -> void: idle_seconds = 0.0 var scene := get_tree().current_scene if scene == null or scene.scene_file_path != ROUTES["hub"]: - go("hub") + go("hub", "idle") func smoke_routes() -> void: # Let the launch scene finish its opening frames, as a player would, before switching. diff --git a/hoppys-adventure-arcade/app/booth_log.gd b/hoppys-adventure-arcade/app/booth_log.gd new file mode 100644 index 00000000..83bb799e --- /dev/null +++ b/hoppys-adventure-arcade/app/booth_log.gd @@ -0,0 +1,94 @@ +extends RefCounted +## Local booth analytics: JSON Lines, one line per event, in a folder that holds one file per run of +## the game (sessions--.jsonl). A watchdog relaunch or a second +## copy started by mistake never writes to another run's file. Nothing leaves the machine and +## nothing identifies a player. The only fields are the game, local times, the session length and +## how it ended: +## {"event":"launch","launch":"2026-11-30T09:58:12.345","time":"2026-11-30T09:58:12", +## "version":"0.1.0"} +## {"event":"start","launch":"2026-11-30T09:58:12.345","session":1,"game":"heroes_vs_villains", +## "time":"2026-11-30T10:02:03"} +## {"event":"end","launch":"2026-11-30T09:58:12.345","session":1,"game":"heroes_vs_villains", +## "time":"2026-11-30T10:04:26","duration_s":143.2,"ended_by":"idle","retries":0} +## A session is one visit to a game route. Re-entering the same game (the runner's or a platformer +## level's Retry) counts as a retry within it. `ended_by` is "menu" (the player left through the +## game's own menu), "idle" (booth mode's idle return) or "quit". A start with no end means the game +## stopped without quitting: a crash, a power cut or a forced kill. +## tools/booth/sessions_report.py summarizes a folder of these files. + +## Routes that are games. The hub and mode menus end a session but never start one. +const GAMES: Array[String] = ["heroes_vs_villains", "code_city_brawl", "bay_area_blitz", + "orbital_ops", "enchanted_repo", "runner_game"] +## This run's file. +var path := "" +## When this run of the game started, to the millisecond. With `session` it identifies a session +## when logs from several runs are read together. +var launch := "" +## The game being played, or "" between sessions. +var game := "" +var session := 0 +var retries := 0 +var started_msec := 0 +## Set after the first failed write: the game keeps running, unlogged, rather than retrying. +var failed := false + +## Start this run's file in `folder` (absolute or user://), creating the folder if needed. +func _init(folder: String) -> void: + var now := Time.get_unix_time_from_system() + var local := int(now) + int(Time.get_time_zone_from_system().bias) * 60 + var stamp := Time.get_datetime_string_from_unix_time(local) + var millis := int(fmod(now, 1.0) * 1000.0) + launch = "%s.%03d" % [stamp, millis] + path = folder.path_join("sessions-%s-%03d-%d.jsonl" % [stamp.replace(":", "-"), millis, + OS.get_process_id()]) + if not DirAccess.dir_exists_absolute(folder): + DirAccess.make_dir_recursive_absolute(folder) + _write({"event": "launch", "time": launch.get_slice(".", 0), + "version": str(ProjectSettings.get_setting("application/config/version", ""))}) + +## AppRouter calls this after each successful route change. `reason` is how the session in +## progress, if any, ends. +func route_changed(route: String, reason: String) -> void: + if game != "" and route == game: + retries += 1 + return + end(reason) + if route in GAMES: + game = route + session += 1 + retries = 0 + started_msec = Time.get_ticks_msec() + _write({"event": "start", "session": session, "game": game, + "time": Time.get_datetime_string_from_system()}) + +## Close the session in progress, if any. Durations use the monotonic clock, so a wall-clock change +## mid-session can't skew them. +func end(reason: String) -> void: + if game == "": + return + var seconds := (Time.get_ticks_msec() - started_msec) / 1000.0 + _write({"event": "end", "session": session, "game": game, + "time": Time.get_datetime_string_from_system(), "duration_s": snappedf(seconds, 0.1), + "ended_by": reason, "retries": retries}) + game = "" + +## Open, append and close per event, so a crash loses at most the line being written. +func _write(fields: Dictionary) -> void: + if failed: + return + var record := {"event": fields.event, "launch": launch} + record.merge(fields) + var file := FileAccess.open(path, FileAccess.READ_WRITE if FileAccess.file_exists(path) + else FileAccess.WRITE) + if file == null: + _fail(error_string(FileAccess.get_open_error())) + return + file.seek_end() + var written := file.store_line(JSON.stringify(record, "", false)) + file.close() + if not written: + _fail("write failed") + +func _fail(reason: String) -> void: + failed = true + push_warning("Booth session log: cannot write %s (%s); session logging is off." % [path, reason]) diff --git a/hoppys-adventure-arcade/app/booth_log.gd.uid b/hoppys-adventure-arcade/app/booth_log.gd.uid new file mode 100644 index 00000000..1d336df3 --- /dev/null +++ b/hoppys-adventure-arcade/app/booth_log.gd.uid @@ -0,0 +1 @@ +uid://0qkhsv822dvw diff --git a/hoppys-adventure-arcade/tests/booth_session_log.gd b/hoppys-adventure-arcade/tests/booth_session_log.gd new file mode 100644 index 00000000..86836f96 --- /dev/null +++ b/hoppys-adventure-arcade/tests/booth_session_log.gd @@ -0,0 +1,251 @@ +extends SceneTree +## Booth session log (app/booth_log.gd): each visit to a game writes a start and an end line, +## re-entering the same game counts as a retry, menus never start a session, idle and quit say how +## a session ended, and nothing is written unless --booth or --session-log asks for it. The flags +## and the window-close quit are checked in child processes, so _ready()'s argument handling and +## quit_game() are covered. Child launches get a throwaway user-data root, so a standalone run never +## reads or writes a real booth log. Run headless with --script res://tests/booth_session_log.gd. +const BoothLog := preload("res://app/booth_log.gd") +const LOG_DIR := "user://test_booth_sessions" +const CHILD_DIR := "user://test_booth_child_sessions" +const QUIT_DIR := "user://test_booth_quit_sessions" +const RELAUNCH_DIR := "user://test_booth_relaunch_sessions" +const BLOCKER := "user://test_booth_blocker" +const CHILD_HOME := "user://test_booth_home" +const ISOLATED := ["HOME", "XDG_DATA_HOME", "XDG_CONFIG_HOME", "APPDATA", "LOCALAPPDATA", + "USERPROFILE"] +## Every field the log may contain. Anything else would be new data about players: review it first. +const FIELDS := ["event", "launch", "time", "version", "session", "game", "duration_s", "ended_by", + "retries"] +var failures := 0 +var router: Node + +func _initialize() -> void: + call_deferred("run") + +func check(ok: bool, message: String) -> void: + print("PASS: " if ok else "FAIL: ", message) + if not ok: + failures += 1 + +func wait(seconds: float) -> void: + await create_timer(seconds, true).timeout + +func settle_route() -> void: + for i in 300: + if not router.busy: + break + await process_frame + await process_frame + +func visit(route: String) -> void: + router.go(route) + await settle_route() + +## Run Godot on this project and return its exit code and output. +func godot(args: Array[String]) -> Dictionary: + var full: Array[String] = ["--headless", "--path", ProjectSettings.globalize_path("res://")] + full.append_array(args) + var output: Array = [] + var code := OS.execute(OS.get_executable_path(), full, output, true) + return {"code": code, "log": "\n".join(output)} + +## Launch the game for two simulated seconds with a throwaway user-data root (the variables Godot +## reads on each OS), so the default booth log is never a real one. +func launch(user_args: Array[String]) -> Dictionary: + var home := ProjectSettings.globalize_path(CHILD_HOME) + var saved := {} + for variable in ISOLATED: + saved[variable] = OS.get_environment(variable) if OS.has_environment(variable) else null + var values := [home, home.path_join(".local/share"), home.path_join(".config"), + home.path_join("AppData/Roaming"), home.path_join("AppData/Local"), home] + for i in ISOLATED.size(): + OS.set_environment(ISOLATED[i], values[i]) + var args: Array[String] = ["--fixed-fps", "60", "--quit-after", "120", "--"] + args.append_array(user_args) + var result := godot(args) + for variable in saved: + if saved[variable] == null: + OS.unset_environment(variable) + else: + OS.set_environment(variable, saved[variable]) + return result + +## The log path a child printed at startup, or "". +func logged_path(output: String) -> String: + for line in output.split("\n"): + if line.begins_with("AppRouter: session log at "): + return line.trim_prefix("AppRouter: session log at ").strip_edges() + return "" + +## The log's records in order; a line that isn't a JSON object is a failed check. +func records(path: String) -> Array[Dictionary]: + var result: Array[Dictionary] = [] + var file := FileAccess.open(path, FileAccess.READ) + if file == null: + return result + while not file.eof_reached(): + var line := file.get_line() + if line.is_empty(): + continue + var parsed: Variant = JSON.parse_string(line) + check(parsed is Dictionary, "Log line is a JSON object: " + line) + if parsed is Dictionary: + result.append(parsed) + return result + +func events(entries: Array[Dictionary], kind: String) -> Array[Dictionary]: + return entries.filter(func(record: Dictionary) -> bool: return record.event == kind) + +## True when a file whose name starts with `prefix` exists anywhere under `directory`. +func find_file(directory: String, prefix: String) -> bool: + var dir := DirAccess.open(directory) + if dir == null: + return false + dir.include_hidden = true + for file_name in dir.get_files(): + if file_name.begins_with(prefix): + return true + for child in dir.get_directories(): + if find_file(directory.path_join(child), prefix): + return true + return false + +func remove_tree(directory: String) -> void: + var dir := DirAccess.open(directory) + if dir == null: + return + dir.include_hidden = true + for file_name in dir.get_files(): + dir.remove(file_name) + for child in dir.get_directories(): + remove_tree(directory.path_join(child)) + DirAccess.remove_absolute(directory) + +func clean() -> void: + if FileAccess.file_exists(BLOCKER): + DirAccess.remove_absolute(BLOCKER) + for folder in [LOG_DIR, CHILD_DIR, QUIT_DIR, RELAUNCH_DIR, CHILD_HOME]: + remove_tree(ProjectSettings.globalize_path(folder)) + +func run() -> void: + router = root.get_node("AppRouter") + clean() + await wait(0.3) + check(router.session_log == null, "No session log without --booth or --session-log") + check(router.session_log_path(PackedStringArray(), false) == "", + "No flags means no session log") + check(router.session_log_path(PackedStringArray(["--booth"]), true) == "user://booth", + "Booth mode logs to the booth folder") + check(router.session_log_path(PackedStringArray(["--session-log=user://playtest"]), false) + == "user://playtest", "--session-log picks a folder, with or without --booth") + check(router.session_log_path(PackedStringArray(["--session-log="]), false) == "", + "An empty --session-log is ignored") + + var plain := launch(["--route=bay_area_blitz"]) + check(plain.code == 0, "A plain launch exits cleanly") + check(logged_path(plain.log) == "" + and not find_file(ProjectSettings.globalize_path(CHILD_HOME), "sessions-"), + "A launch without --booth writes no session log") + var kiosk := launch(["--booth", "--route=heroes_vs_villains"]) + var booth_path := logged_path(kiosk.log) + check(kiosk.code == 0, "A booth launch exits cleanly") + check(booth_path.begins_with(ProjectSettings.globalize_path(CHILD_HOME)) + and booth_path.get_base_dir().ends_with("/booth") + and booth_path.get_file().begins_with("sessions-") and booth_path.ends_with(".jsonl"), + "--booth logs this run to booth/sessions-