Merge pull request #223 from HiIAmMoot/profiling-cpu

Add a profiling build: CPU recordings for Perfetto and a report tool

Conflicts resolved: CI runs main's tests and test_profile.py; the build
scripts take both main's opus and target flags and the PR's
configuration_defines; port_config.c keeps debug.memory_watch before the
profile settings; main.c and network_distributed.c keep voice chat, and
network_votekick_host_tick stays its own statement after the game state's
profile scope, not under its if.

.github/workflows/build.yml

@@ -78,7 +78,7 @@ jobs:
 
       - name: Test
         run: |
-          python -m pytest -q tools/test_linux_port.py tools/test_host_watch_hash.py tools/test_touch_menu.py tools/harness
+          python -m pytest -q tools/test_linux_port.py tools/test_host_watch_hash.py tools/test_touch_menu.py tools/harness tools/test_profile.py
           python tools/test_light_storage.py
 
       - name: Compile cache

README.md

@@ -114,6 +114,7 @@ Give these options to `configure.py`:
 | `--lto=thin`, `--lto=off` | Less link-time optimization. The link is faster. |
 | `--pgo=off` | No profile-guided optimization. |
 | `--pgo=train` | Records a new optimization profile. Refer to "Optimization profiles". |
+| `--profile` | A profiling build. It records CPU times. Refer to "Profiling builds". |
 
 Without `--portable`, the Linux and Windows builds use all the instructions
 of the processor that builds them (`-march=native`). Such a build does not
@@ -138,3 +139,40 @@ To record a new profile:
 The build then plays the main menu and the first minute of each campaign
 level. This procedure continues for approximately 15 minutes. The game
 data must be in `assets/`.
+
+### Profiling builds
+
+A profiling build records where the game spends its time.
+
+1. Enter `python configure.py --profile`, then build as usual.
+2. Start a recording. Enter `profile_record` in the console (or the telnet
+   console), or set `debug.profile_record = true` in `config.toml`. To
+   record each game of a session, also set
+   `debug.profile_record_when = "game"`.
+3. Stop the recording. Enter `profile_stop`, load another map, or quit.
+
+The game writes numbered `.part<n>.json` files under `profiles/` in its data root
+and logs their paths. Parts are retained after the recording stops. Logs go to
+standard error; a Windows release build without standard error writes them to
+`halo.log` next to `halo.exe`.
+
+`tools/net_report.py` is a helper for developers. Enter
+`python tools/net_report.py <recording.part1.json>` to read a recording
+as tables. The command also writes `<recording>.summary.txt`, a short text
+file.
+
+| Command | Result |
+| --- | --- |
+| `profile_record [seconds]` | Starts a recording. With a number of seconds, the recording stops after that time. |
+| `profile_stop` | Stops the recording. |
+
+`debug.profile_memory` sets the memory of a recording in MB (default 256,
+from 4 to 1024). A recording has no length limit:
+the game writes a part each time the memory is full. Refer to "Settings" in
+[port/linux/README.md](port/linux/README.md).
+
+On Android, the files are in `/sdcard/Android/data/com.halo.decomp/files/profiles/`.
+Enter `adb pull` to copy the recording parts to a computer.
+
+A profiling build plays with normal builds. It does not use
+`--pgo=train`.

configure.py

@@ -12,7 +12,7 @@ from types import SimpleNamespace
 
 from tools import ninja_syntax
 from tools.android_build import android_configure_inputs, generate_android_build
-from tools.linux_build import generate_linux_build, linux_configure_inputs
+from tools.linux_build import check_profile_options, generate_linux_build, linux_configure_inputs
 from tools.windows_build import generate_windows_build, windows_configure_inputs
 
 # arguments
@@ -33,6 +33,12 @@ parser.add_argument(
     action="store_true",
     help="release builds (Linux, Windows, Android): assertions are not checked",
 )
+parser.add_argument(
+    "--profile",
+    action="store_true",
+    help="profiling builds (Linux, Windows, Android): CPU scopes recorded on a "
+    "console command or launch setting (README, \"Profiling builds\"); not with --pgo=train",
+)
 parser.add_argument(
     "--lto",
     choices=["full", "thin", "off"],
@@ -78,6 +84,10 @@ parser.add_argument(
     help="clang with the arm64_32 target for the Android guest (default: clang)",
 )
 args = parser.parse_args()
+try:
+    check_profile_options(args.profile, args.pgo)
+except ValueError as error:
+    parser.error(str(error))
 
 # the settings the builds read
 sln = SimpleNamespace(
@@ -85,6 +95,7 @@ sln = SimpleNamespace(
     linux_cc=args.linux_cc,
     compiler_launcher=args.compiler_launcher,
     port_release=args.release,
+    port_profile=args.profile,
     port_lto=args.lto,
     port_portable=args.portable,
     port_pgo=args.pgo,

port/linux/README.md

@@ -400,6 +400,8 @@ the setting for one start of the game. It has priority over the file.
 | `debug.network_latency`, `debug.network_loss`, `debug.network_corrupt`, `debug.network_corrupt_stream`, `debug.network_corrupt_after` | `0` | `HALO_NETWORK_LATENCY`, `HALO_NETWORK_LOSS`, `HALO_NETWORK_CORRUPT`, `HALO_NETWORK_CORRUPT_STREAM`, `HALO_NETWORK_CORRUPT_AFTER` | The game holds all the data that it receives for this number of milliseconds, ignores this percentage of the datagrams, and damages this percentage of the datagrams it receives, and this percentage of its reads of streams, at random (bytes changed, cut short, stretched or replaced), from this many seconds after the start. Use the first two to test the netcode as on the internet, and the others to test that nothing another machine sends can crash the game (a damaged stream is closed, so a little goes a long way; a host's messages to its own client are damaged too, so start damaging once the game has started). |
 | `debug.voice_test` | `false` | `HALO_VOICE_TEST` | Automatic tests of voice chat: a tone replaces the microphone, and each voice that the game hears is written to the log once each second. |
 | `debug.telnet_console`, `debug.telnet_console_port` | `false`, `2323` | `HALO_TELNET_CONSOLE`, `HALO_TELNET_CONSOLE_PORT` | The game listens on 127.0.0.1, on this port, for a script console (connect with telnet). The console has no password, so only this computer can reach it. |
+| `debug.profile_record`, `debug.profile_record_when`, `debug.profile_memory` | `false`, `"start"`, `256` | `HALO_PROFILE_RECORD`, `HALO_PROFILE_RECORD_WHEN`, `HALO_PROFILE_MEMORY` | Profiling builds only (`configure.py --profile`). Record without a command; `"start"` records from the first frame until the first map change, `"game"` records each game outside the main menu. Memory is 4–1024 MB. Numbered `profile_<stamp>_<role>.part<n>.json` files remain in `profiles/` after recording. Refer to "Profiling builds" in the main README. |
+
 
 With Mesa drivers, the game sends its GL calls through the GL thread of
 Mesa. To stop this, set the environment variable `mesa_glthread=false`.

port/linux/game/network_distributed.c

@@ -73,6 +73,7 @@ machine (their datum identifiers need not be).
 #include "network_coop.h"
 #include "network_distributed.h"
 #include "network_voice.h"
+#include "cseries/profile_sections.h"
 
 #include <limits.h>
 #include <stdio.h>
@@ -458,6 +459,28 @@ struct distributed_packer
 
 static long distributed_last_sent_time = NONE;
 
+/* the tick's steps, timed in the profiling build */
+PROFILE_SECTION(distributed_tick_apply_predictions_section, "network_distributed_tick.apply_predictions")
+PROFILE_SECTION(distributed_tick_apply_vehicle_predictions_section, "network_distributed_tick.apply_vehicle_predictions")
+PROFILE_SECTION(distributed_tick_objects_host_tick_section, "network_distributed_tick.objects_host_tick")
+PROFILE_SECTION(distributed_tick_plan_players_section, "network_distributed_tick.plan_players")
+PROFILE_SECTION(distributed_tick_damage_host_tick_section, "network_distributed_tick.damage_host_tick")
+PROFILE_SECTION(distributed_tick_send_statistics_section, "network_distributed_tick.send_statistics")
+PROFILE_SECTION(distributed_tick_send_pings_section, "network_distributed_tick.send_pings")
+PROFILE_SECTION(distributed_tick_send_structure_bsp_section, "network_distributed_tick.send_structure_bsp")
+PROFILE_SECTION(distributed_tick_send_players_section, "network_distributed_tick.send_players")
+PROFILE_SECTION(distributed_tick_actors_host_tick_section, "network_distributed_tick.actors_host_tick")
+PROFILE_SECTION(distributed_tick_coop_host_tick_section, "network_distributed_tick.coop_host_tick")
+PROFILE_SECTION(distributed_tick_send_pickups_section, "network_distributed_tick.send_pickups")
+PROFILE_SECTION(distributed_tick_send_game_state_section, "network_distributed_tick.send_game_state")
+PROFILE_SECTION(distributed_tick_note_own_positions_section, "network_distributed_tick.note_own_positions")
+PROFILE_SECTION(distributed_tick_send_inputs_section, "network_distributed_tick.send_inputs")
+PROFILE_SECTION(distributed_tick_send_predictions_section, "network_distributed_tick.send_predictions")
+PROFILE_SECTION(distributed_tick_objects_client_tick_section, "network_distributed_tick.objects_client_tick")
+PROFILE_SECTION(distributed_tick_damage_client_tick_section, "network_distributed_tick.damage_client_tick")
+PROFILE_SECTION(distributed_tick_coop_client_tick_section, "network_distributed_tick.coop_client_tick")
+PROFILE_SECTION(distributed_tick_batches_flush_section, "network_distributed_tick.batches_flush")
+
 /* how each player last died, by absolute index: the host's own, which it
 sends its clients, and a client's copy of the host's */
 static struct distributed_death
@@ -3345,41 +3368,42 @@ void network_distributed_tick(
 		decided first: the damage goes where the players it hurt do), and a
 		kill's statistics before the kill, so that a client announcing it
 		counts it (a double kill, a killing spree) */
-		distributed_apply_predictions();
-		network_objects_apply_vehicle_predictions();
-		network_objects_host_tick();
-		distributed_host_plan_players();
-		network_damage_host_tick();
+		profile_scope(distributed_tick_apply_predictions_section, distributed_apply_predictions();)
+		profile_scope(distributed_tick_apply_vehicle_predictions_section, network_objects_apply_vehicle_predictions();)
+		profile_scope(distributed_tick_objects_host_tick_section, network_objects_host_tick();)
+		profile_scope(distributed_tick_plan_players_section, distributed_host_plan_players();)
+		profile_scope(distributed_tick_damage_host_tick_section, network_damage_host_tick();)
 		if (distributed_statistics_due || game_time_get() % STATISTICS_INTERVAL_TICKS == 0)
-			distributed_send_statistics(game_time_get() % STATISTICS_REFRESH_TICKS == 0);
+			profile_scope(distributed_tick_send_statistics_section,
+				distributed_send_statistics(game_time_get() % STATISTICS_REFRESH_TICKS == 0);)
 		distributed_statistics_due = FALSE;
 		if (game_time_get() % PING_INTERVAL_TICKS == 0)
-			distributed_send_pings();
+			profile_scope(distributed_tick_send_pings_section, distributed_send_pings();)
 		/* (before the players, so clients load a new BSP before they hear
 		where the host moved everyone into it) */
 		if (network_coop_active() && (global_structure_bsp_index_get() != distributed_sent_structure_bsp_index ||
 			game_time_get() % STRUCTURE_BSP_INTERVAL_TICKS == 0))
 		{
-			distributed_send_structure_bsp();
+			profile_scope(distributed_tick_send_structure_bsp_section, distributed_send_structure_bsp();)
 		}
-		distributed_host_send_players();
-		network_actors_host_tick();
-		network_coop_host_tick();
-		distributed_send_pickups();
+		profile_scope(distributed_tick_send_players_section, distributed_host_send_players();)
+		profile_scope(distributed_tick_actors_host_tick_section, network_actors_host_tick();)
+		profile_scope(distributed_tick_coop_host_tick_section, network_coop_host_tick();)
+		profile_scope(distributed_tick_send_pickups_section, distributed_send_pickups();)
 		if (game_time_get() % GAME_STATE_INTERVAL_TICKS == 0)
-			distributed_send_game_state(NONE);
+			profile_scope(distributed_tick_send_game_state_section, distributed_send_game_state(NONE);)
 		network_votekick_host_tick();
 	}
 	else if (connection == _game_connection_network_client)
 	{
-		distributed_note_own_positions();
-		distributed_client_send_inputs();
-		distributed_client_send_predictions();
-		network_objects_client_tick();
-		network_damage_client_tick();
-		network_coop_client_tick();
+		profile_scope(distributed_tick_note_own_positions_section, distributed_note_own_positions();)
+		profile_scope(distributed_tick_send_inputs_section, distributed_client_send_inputs();)
+		profile_scope(distributed_tick_send_predictions_section, distributed_client_send_predictions();)
+		profile_scope(distributed_tick_objects_client_tick_section, network_objects_client_tick();)
+		profile_scope(distributed_tick_damage_client_tick_section, network_damage_client_tick();)
+		profile_scope(distributed_tick_coop_client_tick_section, network_coop_client_tick();)
 	}
-	distributed_batches_flush();
+	profile_scope(distributed_tick_batches_flush_section, distributed_batches_flush();)
 	distributed_machines.in_tick = FALSE;
 	distributed_machines.valid = FALSE;
 }

port/linux/game/network_objects.c

@@ -64,6 +64,7 @@ same datum index (identifier and all), so that any message can name one:
 #include "cutscene/cinematics.h"
 #include "network_coop.h"
 #include "network_distributed.h"
+#include "cseries/profile_sections.h"
 
 #include <math.h>
 
@@ -1998,15 +1999,22 @@ void network_objects_apply_vehicle_predictions(
 	}
 }
 
+/* the host tick's steps, timed in the profiling build */
+PROFILE_SECTION(objects_host_tick_update_objects_section, "network_objects_host_tick.update_objects")
+PROFILE_SECTION(objects_host_tick_find_viewers_section, "network_objects_host_tick.find_viewers")
+PROFILE_SECTION(objects_host_tick_send_states_section, "network_objects_host_tick.send_states")
+PROFILE_SECTION(objects_host_tick_send_inventories_section, "network_objects_host_tick.send_inventories")
+PROFILE_SECTION(objects_host_tick_send_damage_animations_section, "network_objects_host_tick.send_damage_animations")
+
 void network_objects_host_tick(
 	void)
 {
-	distributed_host_update_objects();
-	distributed_host_find_viewers();
-	distributed_host_send_states();
+	profile_scope(objects_host_tick_update_objects_section, distributed_host_update_objects();)
+	profile_scope(objects_host_tick_find_viewers_section, distributed_host_find_viewers();)
+	profile_scope(objects_host_tick_send_states_section, distributed_host_send_states();)
 	if (game_time_get() % INVENTORY_INTERVAL_TICKS == 0)
-		distributed_host_send_inventories();
-	distributed_host_send_damage_animations();
+		profile_scope(objects_host_tick_send_inventories_section, distributed_host_send_inventories();)
+	profile_scope(objects_host_tick_send_damage_animations_section, distributed_host_send_damage_animations();)
 }
 
 /* ---------- a client */

port/linux/game/profile_console.c

@@ -0,0 +1,304 @@
+/*
+PROFILE_CONSOLE.C
+
+Connect profiling commands and launch settings to game recordings.
+*/
+
+#ifdef HALO_PROFILE
+
+#include "cseries.h"
+#include "game/game.h"
+#include "game/game_engine.h"
+#include "main/console.h"
+#include "networking/network_game_globals.h"
+#include "network_distributed.h"
+#include "profile_console.h"
+#include "profile_console_gametype.h"
+#include "profile_trace.h"
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+
+/* the platform layer's (platform.h, port_config.h), and main.c's */
+void platform_log(const char *format, ...);
+const char *platform_data_root(void);
+int posix_make_directory(const char *path);
+void *posix_directory_open(const char *path);
+void posix_directory_close(void *directory);
+void p2p_profile_lock(void);
+void p2p_profile_unlock(void);
+int config_boolean(const char *name);
+long config_integer(const char *name);
+const char *config_string(const char *name);
+boolean main_menu_is_loaded(void);
+
+
+/* ---------- globals */
+
+static boolean profile_console_installed;
+
+static void profile_console_map_component(const char *map, char *name, int size)
+{
+	const char *component = map;
+	const char *cursor;
+	int used = 0;
+
+	for (cursor = map; *cursor; cursor++)
+		if (*cursor == '/' || *cursor == '\\')
+			component = cursor + 1;
+	for (cursor = component; *cursor && used + 1 < size; cursor++)
+	{
+		unsigned char character = (unsigned char)*cursor;
+		if (character >= 'A' && character <= 'Z')
+			character = (unsigned char)(character + ('a' - 'A'));
+		name[used++] = (character >= 'a' && character <= 'z') || (character >= '0' && character <= '9') ||
+			character == '_' || character == '-' ? (char)character : '-';
+	}
+	name[used] = 0;
+}
+
+static const char *profile_console_gametype(void)
+{
+	long engine;
+
+	if (!game_in_progress() || main_menu_is_loaded() || game_connection() == _game_connection_film_playback)
+		return "none";
+	if (!game_engine_running())
+		return profile_console_engine_gametype(FALSE, 0);
+	engine = game_engine_get_variant()->game_engine_index;
+	return profile_console_engine_gametype(TRUE, engine);
+}
+
+/* the map the header names: the one loading takes its place only after the
+frame boundary that stops a recording on it (profile_console_frame) */
+static char profile_console_map[64];
+static char profile_console_next_map[64];
+
+/* ---------- private code */
+
+static void profile_console_log(
+	const char *text)
+{
+	platform_log("profile: %s", text);
+}
+
+static void profile_console_notify(
+	const char *text)
+{
+	console_printf(FALSE, "%s", text);
+}
+
+static int profile_console_ready(
+	void)
+{
+	return game_in_progress() && !main_menu_is_loaded();
+}
+
+static void profile_console_session(
+	struct profile_trace_session *session)
+{
+	short player_index;
+	const char *scenario = profile_console_scenario_map(profile_console_next_map, profile_console_map);
+	void *folder;
+
+	csmemset(session, 0, sizeof(*session));
+	snprintf(session->folder, sizeof(session->folder), "%s/profiles", platform_data_root());
+	posix_make_directory(session->folder);
+	/* (a folder that can't be made must not lose the recording: the parts go
+	to the data root itself then) */
+	folder = posix_directory_open(session->folder);
+	if (folder)
+		posix_directory_close(folder);
+	else
+		strncpy(session->folder, platform_data_root(), sizeof(session->folder) - 1);
+#ifdef HALO_RELEASE
+	strcpy(session->build, "release profile");
+#else
+	strcpy(session->build, "debug profile");
+#endif
+	session->own_machine = -1;
+	switch (game_connection())
+	{
+	case _game_connection_network_server:
+		strcpy(session->role, "host");
+		break;
+	case _game_connection_network_client:
+		strcpy(session->role, "client");
+		session->own_machine = network_game_client_get_local_machine_index();
+		break;
+	default:
+		strcpy(session->role, "local");
+		break;
+	}
+	strncpy(session->map, scenario, sizeof(session->map) - 1);
+	profile_console_map_component(scenario, session->map_name, sizeof(session->map_name));
+	strncpy(session->gametype, profile_console_gametype(), sizeof(session->gametype) - 1);
+	for (player_index = 0; player_index < MAXIMUM_TRACKED_PLAYERS; player_index++)
+	{
+		if (distributed_player(player_index))
+			session->players++;
+	}
+	session->players_most = session->players;
+}
+
+/* (once a second on the game thread: unlike the start-time description it
+makes and opens no folder, which would land in the measured frame) */
+static void profile_console_sample_session(
+	struct profile_trace_session *session)
+{
+	short player_index;
+	const char *scenario = profile_console_scenario_map(profile_console_next_map, profile_console_map);
+
+	if (!session->map_name[0] && scenario[0])
+	{
+		strncpy(session->map, scenario, sizeof(session->map) - 1);
+		profile_console_map_component(scenario, session->map_name, sizeof(session->map_name));
+		strncpy(session->gametype, profile_console_gametype(), sizeof(session->gametype) - 1);
+	}
+	for (player_index = 0; player_index < MAXIMUM_TRACKED_PLAYERS; player_index++)
+		if (distributed_player(player_index))
+			session->players++;
+}
+
+/* the recording's seams. Not left to the first frame: init.txt's
+profile_record is handled before it, and the recording's name (folder and
+role) is chosen from the session when it is requested */
+static void profile_console_install(
+	void)
+{
+	if (profile_console_installed)
+		return;
+	profile_console_installed = TRUE;
+	profile_trace_set_log(profile_console_log);
+	profile_trace_set_notify(profile_console_notify);
+	profile_trace_set_ready(profile_console_ready);
+	profile_trace_set_session(profile_console_session);
+	profile_trace_set_session_sampler(profile_console_sample_session);
+	profile_trace_set_track_lock(p2p_profile_lock, p2p_profile_unlock);
+	/* (the window's close, debug.exit_after and XLaunchNewImage end the
+	process with exit(), which main_exit never sees) */
+	atexit(profile_trace_shutdown);
+}
+
+/* what follows the command word an expression starts with (past spaces and
+an opening parenthesis, as the console and init.txt give it), else NULL */
+static char const *profile_console_word(
+	char const *expression,
+	char const *word)
+{
+	long length = (long)strlen(word);
+	long index;
+
+	while (*expression == ' ' || *expression == '\t' || *expression == '(')
+		expression++;
+	for (index = 0; index < length; index++)
+	{
+		char character = expression[index] >= 'A' && expression[index] <= 'Z' ? expression[index] - 'A' + 'a' : expression[index];
+
+		if (character != word[index])
+			return NULL;
+	}
+	expression += length;
+	if (*expression && *expression != ' ' && *expression != '\t' && *expression != ')')
+		return NULL;
+	while (*expression == ' ' || *expression == '\t')
+		expression++;
+	return expression;
+}
+
+/* ---------- public code */
+
+void profile_console_launch(
+	void)
+{
+	char const *when = config_string("debug.profile_record_when");
+
+	strcpy(profile_console_map, profile_console_next_map);
+	profile_console_install();
+	profile_trace_thread_register(_profile_track_game);
+	if (strcmp(when, "start") != 0 && strcmp(when, "game") != 0)
+		platform_log("profile: debug.profile_record_when is \"%s\": \"start\" taken", when);
+	if (config_boolean("debug.profile_record"))
+	{
+		profile_trace_request_start(0.0, strcmp(when, "game") == 0 ? _profile_trace_when_game : _profile_trace_when_now,
+			config_integer("debug.profile_memory"));
+	}
+}
+
+void profile_console_frame(
+	void)
+{
+
+	strcpy(profile_console_map, profile_console_next_map);
+}
+
+void profile_console_map_loaded(
+	char const *map_name)
+{
+	strncpy(profile_console_next_map, map_name ? map_name : "", sizeof(profile_console_next_map) - 1);
+	profile_trace_map_loaded();
+}
+
+/* Parse these before the script compiler: compiled map scripts index the
+script function table, so profiling commands must not add entries to it. */
+boolean profile_console_command(
+	char const *expression)
+{
+	struct profile_trace_status status;
+	char const *rest;
+
+	profile_console_install();
+	if ((rest = profile_console_word(expression, "profile_record")) != NULL)
+	{
+		char *end;
+		double seconds = strtod(rest, &end);
+
+		if (end == rest)
+			seconds = 0.0;
+		if ((*rest && end == rest) || seconds < 0.0 ||
+			(*end && *end != ' ' && *end != '\t' && *end != ')'))
+		{
+			console_printf(FALSE, "profile: profile_record takes a number of seconds, 0 or more");
+			return TRUE;
+		}
+		switch (profile_trace_request_start(seconds, _profile_trace_when_now, config_integer("debug.profile_memory")))
+		{
+		case _profile_trace_answer_armed:
+			profile_trace_status(&status);
+			if (seconds > 0.0)
+				console_printf(FALSE, "profile: recording %s, %g s", status.name, seconds);
+			else
+				console_printf(FALSE, "profile: recording %s, until profile_stop", status.name);
+			break;
+		case _profile_trace_answer_still_writing:
+			profile_trace_status(&status);
+			console_printf(FALSE, "profile: still writing %s", status.name);
+			break;
+		default:
+			console_printf(FALSE, "profile: already recording");
+			break;
+		}
+		return TRUE;
+	}
+	if (profile_console_word(expression, "profile_stop"))
+	{
+		profile_trace_status(&status);
+		switch (profile_trace_request_stop())
+		{
+		case _profile_trace_answer_stopping:
+			console_printf(FALSE, "profile: writing %s, %ld parts", status.name, status.part);
+			break;
+		case _profile_trace_answer_disarmed:
+			console_printf(FALSE, "profile: not waiting for a game any more");
+			break;
+		default:
+			console_printf(FALSE, "profile: not recording");
+			break;
+		}
+		return TRUE;
+	}
+	return FALSE;
+}
+
+#endif

port/linux/game/profile_console.h

@@ -0,0 +1,25 @@
+/*
+PROFILE_CONSOLE.H
+
+Expose the game recording console hooks.
+*/
+
+#ifndef __PROFILE_CONSOLE_H
+#define __PROFILE_CONSOLE_H
+#pragma once
+
+#ifdef HALO_PROFILE
+
+/* profile_record [seconds], profile_stop: TRUE
+when the expression was one of them (hs.c, before the script compiler) */
+boolean profile_console_command(char const *expression);
+/* the first frame: the recording's seams, and the launch settings */
+void profile_console_launch(void);
+/* each frame, right after the frame boundary */
+void profile_console_frame(void);
+/* a map starts loading (game_load) */
+void profile_console_map_loaded(char const *map_name);
+
+#endif
+
+#endif

port/linux/include/profile_console_gametype.h

@@ -0,0 +1,30 @@
+/*
+PROFILE_CONSOLE_GAMETYPE.H
+
+Name the current scenario and running game engine for recordings.
+*/
+
+#ifndef __PROFILE_CONSOLE_GAMETYPE_H
+#define __PROFILE_CONSOLE_GAMETYPE_H
+
+static inline const char *profile_console_scenario_map(const char *pending, const char *current)
+{
+	return pending && pending[0] ? pending : current;
+}
+
+/* (engine indices none, ctf, slayer, oddball, king, race; the check program
+cannot include game_engine.h. The variant outlives the engine into campaign
+and co-op, so it is read only while an engine runs) */
+static inline const char *profile_console_engine_gametype(int running, long engine)
+{
+	static const char *const names[] = { "none", "ctf", "slayer", "oddball", "king", "race" };
+	if (!running)
+		return "campaign";
+	if (engine == 0)
+		return "none";
+	if (engine >= 1 && engine <= 5)
+		return names[engine];
+	return "none";
+}
+
+#endif

port/linux/include/profile_trace.h

@@ -0,0 +1,144 @@
+/*
+PROFILE_TRACE.H
+
+Expose bounded CPU trace recording and session controls.
+*/
+
+#ifndef __PROFILE_TRACE_H
+#define __PROFILE_TRACE_H
+
+#ifdef HALO_PROFILE
+
+/* included by C89 game units: keep declarations compatible with them. */
+
+/* ---------- constants */
+
+enum
+{
+	_profile_track_game = 0,
+	_profile_track_p2p,
+	NUMBER_OF_PROFILE_TRACKS,
+
+	MAXIMUM_PROFILE_TRACE_NAMES = 512,
+	MAXIMUM_PROFILE_TRACE_DEPTH = 64,
+	MAXIMUM_PROFILE_TRACE_AGGREGATES = 32,
+	/* debug.profile_memory: both arenas together, megabytes */
+	DEFAULT_PROFILE_TRACE_MEMORY = 256,
+	MINIMUM_PROFILE_TRACE_MEMORY = 4,
+	MAXIMUM_PROFILE_TRACE_MEMORY = 1024,
+};
+
+enum profile_trace_state
+{
+	_profile_trace_idle = 0,
+	_profile_trace_armed,
+	_profile_trace_recording,
+	_profile_trace_finishing,
+};
+
+/* when an armed recording starts: at the next frame, or once a game that is
+not the main menu is in progress (debug.profile_record_when = "game") */
+enum profile_trace_when
+{
+	_profile_trace_when_now = 0,
+	_profile_trace_when_game,
+};
+
+enum profile_trace_stop_reason
+{
+	_profile_trace_stop_none = 0,
+	_profile_trace_stop_command,
+	_profile_trace_stop_seconds,
+	_profile_trace_stop_map_load,
+	_profile_trace_stop_exit,
+};
+
+enum profile_trace_answer
+{
+	_profile_trace_answer_armed = 0,
+	_profile_trace_answer_already_recording,
+	_profile_trace_answer_still_writing,
+	_profile_trace_answer_stopping,
+	_profile_trace_answer_disarmed,
+	_profile_trace_answer_not_recording,
+};
+
+/* ---------- structures */
+
+/* (the recording's identity at start; players_most grows while it runs) */
+struct profile_trace_session
+{
+	char folder[260];
+	char platform[16];
+	char build[48];
+	/* host, client or local */
+	char role[8];
+	/* a client's own machine index, -1 otherwise */
+	long own_machine;
+	char map[64];
+	char map_name[64];
+	char gametype[16];
+	long players;
+	long players_most;
+};
+
+struct profile_trace_status
+{
+	int state;
+	char name[64];
+	long part;
+};
+
+/* ---------- prototypes/PROFILE_TRACE.C */
+
+/* the seams: set once at start-up by the game (profile_console.c), and by
+tools/profile_check.c with fakes */
+void profile_trace_set_clock(unsigned long long (*now_ns)(void));
+void profile_trace_set_track_lock(void (*lock)(void), void (*unlock)(void));
+void profile_trace_set_allocator(void *(*allocate)(unsigned long size), void (*release)(void *block));
+void profile_trace_set_log(void (*log)(const char *text));
+void profile_trace_set_notify(void (*notify)(const char *text));
+/* starts the writer of a new recording (profile_json_writer_start): 0 when
+it cannot */
+void profile_trace_set_writer(int (*start)(void));
+/* whether a game that is not the main menu is in progress */
+void profile_trace_set_ready(int (*ready)(void));
+void profile_trace_set_session(void (*describe)(struct profile_trace_session *session));
+void profile_trace_set_session_sampler(void (*sample)(struct profile_trace_session *session));
+
+/* which track the calling thread records on */
+void profile_trace_thread_register(int track);
+
+/* a name's id (the same name, the same id, for the whole run); an
+aggregate name's scopes are summed per frame rather than recorded */
+int profile_trace_name(const char *name);
+void profile_trace_name_aggregate(const char *name);
+
+void profile_trace_begin(int name);
+void profile_trace_end(int name);
+
+/* the game thread, with no scope open: where a recording starts, is cut
+and stops */
+void profile_trace_frame_boundary(void);
+/* the game thread, at each game tick's start */
+void profile_trace_tick(void);
+
+/* the console's requests (the game thread), applied at the next frame
+boundary; seconds 0 records until stopped */
+int profile_trace_request_start(double seconds, int when, long memory_megabytes);
+int profile_trace_request_stop(void);
+/* a map starts loading: a recording stops, but for the first load after
+launch (the main menu, or init.txt's map) */
+void profile_trace_map_loaded(void);
+/* the process ends: stops a recording, cuts its last part and waits for
+the writer (main_exit, and atexit for the other ways out) */
+void profile_trace_shutdown(void);
+
+/* whether the tracks record now: changed under the track lock, so a p2p
+pass sees one value */
+int profile_trace_recording(void);
+void profile_trace_status(struct profile_trace_status *status);
+
+#endif
+
+#endif

port/linux/src/p2p.c

@@ -58,6 +58,9 @@ only look up and create stand-ins.
 #include "port_config.h"
 #include "p2p_internal.h"
 #include "ikcp.h"
+#ifdef HALO_PROFILE
+#include "profile_trace.h"
+#endif
 
 #include <stddef.h>
 #include <stdio.h>
@@ -276,6 +279,32 @@ struct stun_server
 
 pthread_mutex_t p2p_lock = PTHREAD_MUTEX_INITIALIZER;
 
+#ifdef HALO_PROFILE
+/* the p2p thread's own track of the profiling build's recording
+(profile_trace.c): profile.c's sections are the game thread's alone */
+static struct
+{
+	int pass;
+	int tunnel_receive;
+	int kcp_update;
+	int streams;
+} p2p_profile_names;
+
+/* the recording's track lock: the game thread flips the recording and its
+arenas under it, and this thread records under it, so each record lands in
+one arena; a pass that drops the lock (DNS, key exchange) can straddle a
+cut, and profile_trace_end drops that scope */
+void p2p_profile_lock(void)
+{
+	pthread_mutex_lock(&p2p_lock);
+}
+
+void p2p_profile_unlock(void)
+{
+	pthread_mutex_unlock(&p2p_lock);
+}
+#endif
+
 static struct
 {
 	int running;
@@ -2824,6 +2853,13 @@ static void *p2p_thread(void *unused)
 	static int read_owners[MAXIMUM_SOCKETS], write_owners[MAXIMUM_SOCKETS];
 
 	(void)unused;
+#ifdef HALO_PROFILE
+	profile_trace_thread_register(_profile_track_p2p);
+	p2p_profile_names.pass = profile_trace_name("p2p.pass");
+	p2p_profile_names.tunnel_receive = profile_trace_name("p2p.tunnel_receive");
+	p2p_profile_names.kcp_update = profile_trace_name("p2p.kcp_update");
+	p2p_profile_names.streams = profile_trace_name("p2p.streams");
+#endif
 	pthread_mutex_lock(&p2p_lock);
 #ifndef HALO_ANDROID
 	/* (here: it may wait for a program) */
@@ -2903,6 +2939,9 @@ static void *p2p_thread(void *unused)
 			read_count = write_count = 0;
 		}
 		pthread_mutex_lock(&p2p_lock);
+#ifdef HALO_PROFILE
+		profile_trace_begin(p2p_profile_names.pass);
+#endif
 
 		/* what is ready (the lists now hold only ready sockets, in the order
 		asked, so each one's owner is found going along both); a socket
@@ -2921,7 +2960,13 @@ static void *p2p_thread(void *unused)
 			switch (owner & 255)
 			{
 			case _owner_tunnel:
+#ifdef HALO_PROFILE
+				profile_trace_begin(p2p_profile_names.tunnel_receive);
+#endif
 				tunnel_readable();
+#ifdef HALO_PROFILE
+				profile_trace_end(p2p_profile_names.tunnel_receive);
+#endif
 				break;
 			case _owner_handoff:
 				if (socket == p2p.handoff_socket)
@@ -2941,6 +2986,9 @@ static void *p2p_thread(void *unused)
 				break;
 			}
 		}
+#ifdef HALO_PROFILE
+		profile_trace_begin(p2p_profile_names.streams);
+#endif
 		for (index = 0, asked = 0; index < write_count; index++)
 		{
 			int socket = write[index];
@@ -2965,13 +3013,22 @@ static void *p2p_thread(void *unused)
 			if (stream->used && stream->state == _stream_connecting && elapsed(stream->created_time, 5000))
 				stream_local_closed(stream);
 		}
+#ifdef HALO_PROFILE
+		profile_trace_end(p2p_profile_names.streams);
+#endif
 		p2p_signal_update(read, read_count, write, write_count);
 
+#ifdef HALO_PROFILE
+		profile_trace_begin(p2p_profile_names.kcp_update);
+#endif
 		for (index = 0; index < MAXIMUM_STREAMS; index++)
 		{
 			if (p2p.streams[index].used)
 				stream_update(&p2p.streams[index]);
 		}
+#ifdef HALO_PROFILE
+		profile_trace_end(p2p_profile_names.kcp_update);
+#endif
 		update_peers();
 		expire_proxies();
 		stun_update();
@@ -2999,6 +3056,9 @@ static void *p2p_thread(void *unused)
 		p2p_discord_update();
 #ifdef HALO_ANDROID
 		poll_invite_file();
+#endif
+#ifdef HALO_PROFILE
+		profile_trace_end(p2p_profile_names.pass);
 #endif
 	}
 	return NULL;

port/linux/src/port_config.c

@@ -540,6 +540,21 @@ static const struct config_setting config_settings[] =
 		"protection; false compares page contents once a frame instead, which is\n"
 		"slower. Under ARM translation (the x86 emulator) the app always compares\n"
 		"contents. Read by the app from the file (port/android/host/host_main.c)." },
+#ifdef HALO_PROFILE
+	{ "debug.profile_record", _config_boolean, "false", "HALO_PROFILE_RECORD", _environment_value, _platform_all,
+		"Record a profile with no command (configure.py --profile builds): from\n"
+		"when profile_record_when says until profile_stop, a map change or the\n"
+		"end, into numbered part files in the data folder's profiles folder\n"
+		"(tools/net_report.py reads it)." },
+	{ "debug.profile_record_when", _config_string, "\"start\"", "HALO_PROFILE_RECORD_WHEN", _environment_value,
+		_platform_all,
+		"\"start\": from the first frame until the first map change; \"game\":\n"
+		"each game that is not the main menu, a recording each, until its map\n"
+		"goes." },
+	{ "debug.profile_memory", _config_integer, "256", "HALO_PROFILE_MEMORY", _environment_value, _platform_all,
+		"Megabytes a recording keeps in memory, 4 to 1024: two halves, each\n"
+		"written out as a part when it fills." },
+#endif
 };
 
 #define NUMBER_OF_CONFIG_SETTINGS (sizeof(config_settings) / sizeof(config_settings[0]))

port/linux/src/profile_json.c

@@ -0,0 +1,522 @@
+/*
+PROFILE_JSON.C
+
+Write recording parts on the writer thread.
+*/
+
+#ifdef HALO_PROFILE
+
+#include "profile_part.h"
+
+#include <pthread.h>
+#include <stdlib.h>
+#include <string.h>
+
+/* ---------- constants */
+
+enum
+{
+	PROFILE_JSON_WORST_FRAMES = 10,
+	PROFILE_JSON_LONGEST_CHILDREN = 3,
+};
+
+/* ---------- structures */
+
+/* where the next item of a list goes: a comma and a line before all but
+the first */
+struct profile_json_list
+{
+	FILE *file;
+	int items;
+};
+
+struct profile_json_name_totals
+{
+	unsigned long long count;
+	unsigned long long total;
+	unsigned long long maximum;
+};
+
+/* ---------- globals */
+
+static const char *profile_json_stop_reasons[] = { "", "command", "seconds", "map_load", "exit" };
+
+/* ---------- private code */
+
+static void profile_json_item(
+	struct profile_json_list *list)
+{
+	if (list->items++)
+		fputs(",\n", list->file);
+}
+
+static void profile_json_escaped(
+	FILE *file,
+	const char *text)
+{
+	for (; text && *text; text++)
+	{
+		unsigned char character = (unsigned char)*text;
+
+		if (character == '"' || character == '\\')
+			fprintf(file, "\\%c", character);
+		else if (character < 32 || character > 126)
+			fprintf(file, "\\u%04x", character);
+		else
+			fputc(character, file);
+	}
+}
+
+static void profile_json_string(
+	FILE *file,
+	const char *text)
+{
+	fputc('"', file);
+	profile_json_escaped(file, text);
+	fputc('"', file);
+}
+
+/* microseconds with three decimals, as the trace event format has them */
+static void profile_json_time(
+	FILE *file,
+	unsigned long long nanoseconds)
+{
+	fprintf(file, "%llu.%03llu", nanoseconds / 1000ULL, nanoseconds % 1000ULL);
+}
+
+static int profile_json_compare_records(
+	const void *a,
+	const void *b)
+{
+	const struct profile_trace_record *first = a;
+	const struct profile_trace_record *second = b;
+
+	if (first->start != second->start)
+		return first->start < second->start ? -1 : 1;
+	return (int)first->depth - (int)second->depth;
+}
+
+static int profile_json_name_of(
+	const struct profile_part *part,
+	const char *text)
+{
+	int name;
+
+	for (name = 0; name < part->name_count; name++)
+	{
+		if (strcmp(profile_trace_name_text(name), text) == 0)
+			return name;
+	}
+	return -1;
+}
+
+static void profile_json_header(
+	const struct profile_part *part,
+	FILE *file)
+{
+	const struct profile_trace_session *session = &part->session;
+
+	fputs("\"header\": {\"format\": 1, \"build\": ", file);
+	profile_json_string(file, session->build);
+	fputs(", \"platform\": ", file);
+	profile_json_string(file, session->platform);
+	fputs(", \"role\": ", file);
+	profile_json_string(file, session->role);
+	fprintf(file, ", \"own_machine\": %ld, \"map\": ", session->own_machine);
+	profile_json_string(file, session->map);
+	fputs(", \"map_name\": ", file);
+	profile_json_string(file, session->map_name);
+	fputs(", \"gametype\": ", file);
+	profile_json_string(file, session->gametype);
+	fprintf(file, ", \"players\": %ld, \"players_most\": %ld, \"start_utc\": ", session->players,
+		session->players_most);
+	profile_json_string(file, part->start_utc);
+	fputs(", \"recording\": ", file);
+	profile_json_string(file, part->name);
+	fprintf(file, ", \"part\": %ld, \"last_part\": %s"
+		", \"first_frame\": %ld, \"frames\": %ld, \"first_tick\": %ld, \"ticks\": %ld",
+		part->number, part->last ? "true" : "false",
+		part->first_frame, part->frames, part->first_tick, part->ticks);
+	fprintf(file, ", \"start_s\": %.6f, \"duration_s\": %.6f, \"stop_reason\": ",
+		(double)part->start_ns / 1e9, (double)(part->end_ns - part->start_ns) / 1e9);
+	profile_json_string(file, profile_json_stop_reasons[part->stop_reason]);
+	fprintf(file, ", \"clock_read_ns\": %.1f, \"memory_used\": %lu, \"memory_limit\": %lu, \"writer_wait_ms\": %.3f"
+		", \"foreign_scopes\": %lu, \"deep_scopes\": %lu, \"unbalanced_scopes\": %lu, \"dropped_scopes\": %lu}",
+		part->clock_read_ns, part->memory_used, part->memory_limit, part->writer_wait_ms,
+		part->foreign_scopes, part->deep_scopes, part->unbalanced_scopes, part->dropped_scopes);
+}
+
+/* a worst frame's scopes: the open ones (one a depth, so no more than the
+depth limit) and the three with the most time of their own so far */
+struct profile_json_ranking
+{
+	unsigned long scope[MAXIMUM_PROFILE_TRACE_DEPTH];
+	unsigned long long children[MAXIMUM_PROFILE_TRACE_DEPTH];
+	int open;
+	unsigned long longest[PROFILE_JSON_LONGEST_CHILDREN];
+	unsigned int own[PROFILE_JSON_LONGEST_CHILDREN];
+	int count;
+};
+
+/* the innermost open scope ends: its time less its children's is ranked, and
+all of it is its parent's child time */
+static void profile_json_close(
+	struct profile_json_ranking *ranking,
+	const struct profile_trace_record *game)
+{
+	int open = --ranking->open;
+	unsigned long scope = ranking->scope[open];
+	unsigned long long duration = game[scope].duration;
+	unsigned int own = (unsigned int)(duration > ranking->children[open] ? duration - ranking->children[open] : 0);
+	int slot;
+
+	for (slot = ranking->count; slot > 0 && ranking->own[slot - 1] < own; slot--)
+	{
+		if (slot < PROFILE_JSON_LONGEST_CHILDREN)
+		{
+			ranking->longest[slot] = ranking->longest[slot - 1];
+			ranking->own[slot] = ranking->own[slot - 1];
+		}
+	}
+	if (slot < PROFILE_JSON_LONGEST_CHILDREN)
+	{
+		ranking->longest[slot] = scope;
+		ranking->own[slot] = own;
+		if (ranking->count < PROFILE_JSON_LONGEST_CHILDREN)
+			ranking->count++;
+	}
+	if (open > 0)
+		ranking->children[open - 1] += duration;
+}
+
+static void profile_json_cpu_summary(
+	const struct profile_part *part,
+	FILE *file)
+{
+	struct profile_json_name_totals totals[MAXIMUM_PROFILE_TRACE_NAMES];
+	const struct profile_trace_record *game = part->records[_profile_track_game];
+	unsigned long game_count = part->record_counts[_profile_track_game];
+	unsigned long worst[PROFILE_JSON_WORST_FRAMES];
+	long worst_frame_number[PROFILE_JSON_WORST_FRAMES];
+	int worst_count = 0;
+	struct profile_json_ranking ranking;
+	int frame_name = profile_json_name_of(part, "frame");
+	int tick_name = profile_json_name_of(part, "game_tick");
+	struct profile_json_list list;
+	unsigned long index;
+	long frames = 0;
+	int track, name;
+
+	memset(totals, 0, sizeof(totals));
+	for (track = 0; track < NUMBER_OF_PROFILE_TRACKS; track++)
+	{
+		for (index = 0; index < part->record_counts[track]; index++)
+		{
+			const struct profile_trace_record *record = &part->records[track][index];
+			struct profile_json_name_totals *name_totals;
+
+			if (record->name >= MAXIMUM_PROFILE_TRACE_NAMES)
+				continue;
+			name_totals = &totals[record->name];
+			if (record->depth < MAXIMUM_PROFILE_TRACE_DEPTH || record->depth == PROFILE_TRACE_DEPTH_AGGREGATE_TIME)
+			{
+				name_totals->total += record->duration;
+				if (record->duration > name_totals->maximum)
+					name_totals->maximum = record->duration;
+			}
+			if (record->depth < MAXIMUM_PROFILE_TRACE_DEPTH)
+				name_totals->count++;
+			else if (record->depth == PROFILE_TRACE_DEPTH_AGGREGATE_COUNT)
+				name_totals->count += record->duration;
+		}
+	}
+	/* the worst frames: the game track is sorted, so a frame's children
+	follow it */
+	for (index = 0; index < game_count; index++)
+	{
+		int slot;
+
+		if (game[index].depth >= MAXIMUM_PROFILE_TRACE_DEPTH || game[index].name != frame_name)
+			continue;
+		frames++;
+		for (slot = worst_count; slot > 0 && game[worst[slot - 1]].duration < game[index].duration; slot--)
+		{
+			if (slot < PROFILE_JSON_WORST_FRAMES)
+			{
+				worst[slot] = worst[slot - 1];
+				worst_frame_number[slot] = worst_frame_number[slot - 1];
+			}
+		}
+		if (slot < PROFILE_JSON_WORST_FRAMES)
+		{
+			worst[slot] = index;
+			worst_frame_number[slot] = part->first_frame + frames - 1;
+			if (worst_count < PROFILE_JSON_WORST_FRAMES)
+				worst_count++;
+		}
+	}
+
+	fprintf(file, "{\"frames\": %ld, \"ticks\": %ld, \"columns\": [\"name\", \"count\", \"total_ms\", "
+		"\"mean_ms\", \"max_ms\", \"per_frame\", \"per_tick_ms\"], \"rows\": [\n", frames, part->ticks);
+	list.file = file;
+	list.items = 0;
+	for (name = 0; name < part->name_count && name < MAXIMUM_PROFILE_TRACE_NAMES; name++)
+	{
+		const char *text = profile_trace_name_text(name);
+		struct profile_json_name_totals const *name_totals = &totals[name];
+		int per_tick = strncmp(text, "game_tick", 9) == 0 || strncmp(text, "network_distributed_tick", 24) == 0;
+
+		if (!name_totals->count)
+			continue;
+		profile_json_item(&list);
+		fputc('[', file);
+		profile_json_string(file, text);
+		fprintf(file, ", %llu, %.3f, %.4f, %.3f, %.3f, ", name_totals->count, name_totals->total / 1e6,
+			name_totals->total / 1e6 / (double)name_totals->count, name_totals->maximum / 1e6,
+			frames ? (double)name_totals->count / (double)frames : 0.0);
+		if (per_tick && part->ticks)
+			fprintf(file, "%.4f]", name_totals->total / 1e6 / (double)part->ticks);
+		else
+			fputs("null]", file);
+	}
+	fputs(list.items ? "\n]" : "]", file);
+
+	fputs(", \"worst_frames\": {\"columns\": [\"frame\", \"at_s\", \"frame_ms\", \"ticks\", \"longest\"], \"rows\": [\n", file);
+	list.items = 0;
+	for (index = 0; index < (unsigned long)worst_count; index++)
+	{
+		const struct profile_trace_record *frame = &game[worst[index]];
+		unsigned long long end = frame->start + frame->duration;
+		int ticks = 0;
+		unsigned long child;
+		int slot;
+
+		/* (a tick sits under whatever the main loop wraps it in, so every
+		depth of the frame counts; the scopes are ranked by the time they have
+		of their own, or the parents, which hold all of it, would always come
+		first. The open scopes are a stack, so nothing is allocated for it) */
+		memset(&ranking, 0, sizeof(ranking));
+		for (child = worst[index] + 1; child < game_count && game[child].start < end; child++)
+		{
+			if (game[child].depth >= MAXIMUM_PROFILE_TRACE_DEPTH || game[child].depth <= frame->depth)
+				continue;
+			if (game[child].name == tick_name)
+				ticks++;
+			while (ranking.open && game[ranking.scope[ranking.open - 1]].depth >= game[child].depth)
+				profile_json_close(&ranking, game);
+			ranking.scope[ranking.open] = child;
+			ranking.children[ranking.open++] = 0;
+		}
+		while (ranking.open)
+			profile_json_close(&ranking, game);
+		profile_json_item(&list);
+		fprintf(file, "[%ld, %.3f, %.3f, %d, [", worst_frame_number[index], frame->start / 1e9, frame->duration / 1e6,
+			ticks);
+		for (slot = 0; slot < ranking.count; slot++)
+		{
+			fputs(slot ? ", [" : "[", file);
+			profile_json_string(file, profile_trace_name_text(game[ranking.longest[slot]].name));
+			fprintf(file, ", %.3f]", ranking.own[slot] / 1e6);
+		}
+		fputs("]]", file);
+	}
+	fputs(list.items ? "\n]}}" : "]}}", file);
+}
+
+static void profile_json_event(
+	FILE *file,
+	struct profile_json_list *list,
+	const struct profile_trace_record *record)
+{
+	const char *name = profile_trace_name_text(record->name);
+
+	profile_json_item(list);
+	switch (record->depth)
+	{
+	case PROFILE_TRACE_DEPTH_AGGREGATE_TIME:
+	case PROFILE_TRACE_DEPTH_AGGREGATE_COUNT:
+		fputs("{\"ph\":\"C\",\"name\":\"", file);
+		profile_json_escaped(file, name);
+		fputs(record->depth == PROFILE_TRACE_DEPTH_AGGREGATE_TIME ? "_ms\",\"pid\":1,\"tid\":1,\"ts\":" :
+			"_count\",\"pid\":1,\"tid\":1,\"ts\":", file);
+		profile_json_time(file, record->start);
+		if (record->depth == PROFILE_TRACE_DEPTH_AGGREGATE_TIME)
+			fprintf(file, ",\"args\":{\"value\":%.4f}}", record->duration / 1e6);
+		else
+			fprintf(file, ",\"args\":{\"value\":%u}}", record->duration);
+		break;
+	default:
+		fputs("{\"ph\":\"X\",\"name\":", file);
+		profile_json_string(file, name);
+		fprintf(file, ",\"pid\":1,\"tid\":%d,\"ts\":", record->track + 1);
+		profile_json_time(file, record->start);
+		fputs(",\"dur\":", file);
+		profile_json_time(file, record->duration);
+		fputc('}', file);
+		break;
+	}
+}
+
+/* ---------- public code */
+
+int profile_json_write(
+	struct profile_part *part,
+	FILE *file)
+{
+	struct profile_json_list list;
+	unsigned long next[NUMBER_OF_PROFILE_TRACKS] = { 0, 0 };
+	int track;
+
+	for (track = 0; track < NUMBER_OF_PROFILE_TRACKS; track++)
+	{
+		if (part->record_counts[track])
+		{
+			qsort(part->records[track], part->record_counts[track], sizeof(struct profile_trace_record),
+				profile_json_compare_records);
+		}
+	}
+
+	fputs("{\"halo\": {\n", file);
+	profile_json_header(part, file);
+	fputs("},\n\"cpu_summary\": ", file);
+	profile_json_cpu_summary(part, file);
+	fputs(",\n\"traceEvents\": [\n", file);
+
+	list.file = file;
+	list.items = 0;
+	profile_json_item(&list);
+	fprintf(file, "{\"ph\":\"M\",\"name\":\"process_name\",\"pid\":1,\"args\":{\"name\":\"halo %s %s\"}}",
+		part->session.role, part->session.platform);
+	profile_json_item(&list);
+	fputs("{\"ph\":\"M\",\"name\":\"thread_name\",\"pid\":1,\"tid\":1,\"args\":{\"name\":\"game\"}}", file);
+	profile_json_item(&list);
+	fputs("{\"ph\":\"M\",\"name\":\"thread_name\",\"pid\":1,\"tid\":2,\"args\":{\"name\":\"p2p\"}}", file);
+	if (part->number == 1)
+	{
+		profile_json_item(&list);
+		fputs("{\"ph\":\"i\",\"name\":\"recording_start\",\"s\":\"g\",\"pid\":1,\"tid\":1,\"ts\":0.000}", file);
+	}
+	/* the two tracks merged, in order of start and depth: each scope after
+	its parents */
+	for (;;)
+	{
+		const struct profile_trace_record *game = next[0] < part->record_counts[0] ? &part->records[0][next[0]] : NULL;
+		const struct profile_trace_record *p2p = next[1] < part->record_counts[1] ? &part->records[1][next[1]] : NULL;
+
+		if (!game && !p2p)
+			break;
+		if (game && (!p2p || profile_json_compare_records(game, p2p) <= 0))
+		{
+			profile_json_event(file, &list, game);
+			next[0]++;
+		}
+		else
+		{
+			profile_json_event(file, &list, p2p);
+			next[1]++;
+		}
+	}
+	if (part->last)
+	{
+		profile_json_item(&list);
+		fputs("{\"ph\":\"i\",\"name\":\"recording_stop\",\"s\":\"g\",\"pid\":1,\"tid\":1,\"ts\":", file);
+		profile_json_time(file, part->end_ns);
+		fprintf(file, ",\"args\":{\"reason\":\"%s\"}}", profile_json_stop_reasons[part->stop_reason]);
+	}
+	fputs("\n],\n\"displayTimeUnit\": \"ms\"}\n", file);
+	return !ferror(file);
+}
+
+void profile_json_choose_name(
+	const char *folder,
+	const char *stamp,
+	const char *role,
+	char *name,
+	int size)
+{
+	char path[512];
+	int suffix;
+
+	snprintf(name, (size_t)size, "profile_%s_%s", stamp, role);
+	for (suffix = 2; suffix < 1000; suffix++)
+	{
+		FILE *file;
+		int occupied = 0;
+
+		snprintf(path, sizeof(path), "%s/%s.part1.json", folder, name);
+		file = fopen(path, "rb");
+		if (file)
+		{
+			fclose(file);
+			occupied = 1;
+		}
+		if (!occupied)
+			break;
+		snprintf(name, (size_t)size, "profile_%s_%s_%d", stamp, role, suffix);
+	}
+}
+
+int profile_json_write_part(
+	struct profile_part *part)
+{
+	char temporary[520];
+	char path[512];
+	FILE *file;
+	int written;
+
+	snprintf(path, sizeof(path), "%s/%s.part%ld.json", part->folder, part->name, part->number);
+	snprintf(temporary, sizeof(temporary), "%s.tmp", path);
+	file = fopen(temporary, "wb");
+	if (!file)
+	{
+		profile_trace_log("cannot write %s", temporary);
+		return 0;
+	}
+	written = profile_json_write(part, file);
+	if (fclose(file) != 0)
+		written = 0;
+	/* (Windows' rename does not replace a file: the recording's name was
+	chosen not to be there) */
+	if (written && rename(temporary, path) != 0)
+		written = 0;
+	if (!written)
+	{
+		remove(temporary);
+		profile_trace_log("cannot write %s", path);
+		return 0;
+	}
+	profile_trace_log("wrote %s", path);
+	return 1;
+}
+
+static void *profile_json_writer(
+	void *unused)
+{
+	(void)unused;
+	for (;;)
+	{
+		struct profile_part *part = profile_trace_writer_next();
+		int last = part->last;
+		profile_json_write_part(part);
+		profile_trace_writer_done(part);
+		if (last)
+			break;
+	}
+	return NULL;
+}
+
+int profile_json_writer_start(
+	void)
+{
+	pthread_attr_t attributes;
+	pthread_t thread;
+	int started;
+
+	pthread_attr_init(&attributes);
+	pthread_attr_setdetachstate(&attributes, PTHREAD_CREATE_DETACHED);
+	started = pthread_create(&thread, &attributes, profile_json_writer, NULL) == 0;
+	pthread_attr_destroy(&attributes);
+	return started;
+}
+
+#endif

port/linux/src/profile_part.h

@@ -0,0 +1,97 @@
+/*
+PROFILE_PART.H
+
+Define frozen recording parts shared by the recorder and writer.
+*/
+
+#ifndef __PROFILE_PART_H
+#define __PROFILE_PART_H
+
+#ifdef HALO_PROFILE
+
+#include "profile_trace.h"
+
+#include <stdio.h>
+
+/* ---------- constants */
+
+/* records that are not scopes, by their depth (a scope's is under
+MAXIMUM_PROFILE_TRACE_DEPTH): an aggregate name's time and count over a
+frame (start: the frame's) */
+enum
+{
+	PROFILE_TRACE_DEPTH_AGGREGATE_TIME = 255,
+	PROFILE_TRACE_DEPTH_AGGREGATE_COUNT = 254,
+};
+
+/* ---------- structures */
+
+/* a scope that ended: 16 bytes */
+struct profile_trace_record
+{
+	/* nanoseconds since the recording started */
+	unsigned long long start;
+	/* nanoseconds, saturating (or the counter's value) */
+	unsigned int duration;
+	unsigned short name;
+	unsigned char depth;
+	unsigned char track;
+};
+
+struct profile_part
+{
+	char name[64];
+	char folder[260];
+	long number;
+	int last;
+	int stop_reason;
+	int arena;
+	struct profile_trace_record *records[NUMBER_OF_PROFILE_TRACKS];
+	unsigned long record_counts[NUMBER_OF_PROFILE_TRACKS];
+	unsigned long long start_ns;
+	unsigned long long end_ns;
+	long first_frame;
+	long frames;
+	long first_tick;
+	long ticks;
+	long name_count;
+	struct profile_trace_session session;
+	char start_utc[32];
+	double clock_read_ns;
+	unsigned long memory_used;
+	unsigned long memory_limit;
+	double writer_wait_ms;
+	unsigned long foreign_scopes;
+	unsigned long deep_scopes;
+	unsigned long unbalanced_scopes;
+	unsigned long dropped_scopes;
+};
+
+typedef char profile_trace_record_size_assert[sizeof(struct profile_trace_record) == 16 ? 1 : -1];
+
+/* ---------- prototypes/PROFILE_TRACE.C */
+
+const char *profile_trace_name_text(int name);
+int profile_trace_name_is_aggregate(int name);
+/* the writer: the next part (waits for one), and a part written (its
+arena back; after the last, both arenas freed and the recording over) */
+struct profile_part *profile_trace_writer_next(void);
+/* a line in the log (profile_trace_set_log) */
+void profile_trace_log(const char *format, ...);
+void profile_trace_writer_done(struct profile_part *part);
+
+/* ---------- prototypes/PROFILE_JSON.C */
+
+/* a part as a Chrome trace with the "halo" and "cpu_summary" keys; 0 when
+the file could not be written */
+int profile_json_write(struct profile_part *part, FILE *file);
+/* Part names keep profile_<stamp>_<role>. */
+void profile_json_choose_name(const char *folder, const char *stamp, const char *role, char *name, int size);
+/* the writer thread of a recording: 0 when it cannot start */
+int profile_json_writer_start(void);
+/* a part's file: <folder>/<name>.part<n>.json, written as .tmp and renamed */
+int profile_json_write_part(struct profile_part *part);
+
+#endif
+
+#endif

source/cseries/profile.c

@@ -279,6 +279,11 @@ symbols in this file:
 #include <stdarg.h>
 #include <xtl.h>
 
+#ifdef HALO_PROFILE
+#include "profile_console.h"
+#include "profile_trace.h"
+#endif
+
 /* ---------- constants */
 
 enum
@@ -449,6 +454,24 @@ boolean profile_global_enable = FALSE;
 boolean profile_dump_frames = FALSE;
 boolean profile_dump_lost_frames = FALSE;
 
+#ifdef HALO_PROFILE
+/* port: the profiling build: each section's name in the trace
+(port/linux/src/profile_trace.c) by section_index, as struct
+profile_section's size is fixed (profile.h's assertions); the frame
+timers' names; and whether the first frame has set the recording up */
+static short profile_trace_section_names[MAXIMUM_PROFILE_SECTIONS];
+static struct
+{
+	int frame;
+	int game_tick;
+	int render;
+	int render_window;
+	int idle;
+	int texture;
+} profile_trace_timer_names;
+static boolean profile_trace_launched;
+#endif
+
 /* ---------- public code */
 
 void profile_dump_to_file(
@@ -1076,16 +1099,60 @@ void profile_initialize(
 	profile_globals.lost_frame_count = 999;
 	profile_globals.framedump_file = NULL;
 
+#ifdef HALO_PROFILE
+	profile_trace_timer_names.frame = profile_trace_name("frame");
+	profile_trace_timer_names.game_tick = profile_trace_name("game_tick");
+	profile_trace_timer_names.render = profile_trace_name("render");
+	profile_trace_timer_names.render_window = profile_trace_name("render_window");
+	profile_trace_timer_names.idle = profile_trace_name("idle");
+	profile_trace_timer_names.texture = profile_trace_name("texture");
+	/* (many times a frame: a record each would cost more than the work it
+	times, so a count and a total a frame) */
+	profile_trace_name_aggregate("texture");
+	profile_trace_name_aggregate("render_model");
+	profile_trace_name_aggregate("memory_dynamic_array_resize");
+	profile_trace_name_aggregate("memory_dynamic_array_add_element");
+	profile_trace_name_aggregate("memory_dynamic_array_delete_element");
+	profile_trace_name_aggregate("item_update");
+	profile_trace_name_aggregate("weapon_update");
+	profile_trace_name_aggregate("unit_update");
+	profile_trace_name_aggregate("biped_update");
+	profile_trace_name_aggregate("vehicle_update");
+	profile_trace_name_aggregate("projectile_update");
+	profile_trace_name_aggregate("render_structure_shadows");
+	profile_trace_name_aggregate("render_structure_shadows_draw");
+	profile_trace_name_aggregate("render_structure_diffuse_lights");
+	profile_trace_name_aggregate("render_structure_diffuse_lights_draw");
+	profile_trace_name_aggregate("render_structure_specular_lights");
+	profile_trace_name_aggregate("render_structure_specular_lights_draw");
+#endif
+
 	return;
 }
 
 void profile_frame_start(
 	void)
 {
+#ifdef HALO_PROFILE
+	if (!profile_trace_launched)
+	{
+		profile_trace_launched = TRUE;
+		profile_console_launch();
+	}
+	/* (no section is open here: where a recording starts, is cut and
+	stops) */
+	profile_trace_frame_boundary();
+	profile_console_frame();
+#endif
 	if (!profile_timebase_ticks)
 	{
 		profile_internal_step();
 	}
+#ifdef HALO_PROFILE
+	/* (after the step, which rolls up what the sections timed last frame:
+	the console no longer turns it off mid-frame, console.c) */
+	profile_global_enable = profile_trace_recording();
+#endif
 
 	csmemset(&profile_globals.current_frame, 0, sizeof(profile_globals.current_frame));
 
@@ -1093,6 +1160,9 @@ void profile_frame_start(
 	profile_globals.current_frame.vertical_blank_index = rasterizer_globals.vertical_blank_index;
 	profile_globals.current_frame.game_tick_count = 0;
 	profile_timesection_begin_now(&profile_globals.current_frame.frame);
+#ifdef HALO_PROFILE
+	profile_trace_begin(profile_trace_timer_names.frame);
+#endif
 
 	return;
 }
@@ -1119,6 +1189,10 @@ void profile_tick_start(
 
 	timer = &profile_globals.current_frame.game_ticks[profile_globals.current_frame.game_tick_count-1];
 	profile_timesection_begin_now(timer);
+#ifdef HALO_PROFILE
+	profile_trace_tick();
+	profile_trace_begin(profile_trace_timer_names.game_tick);
+#endif
 
 	return;
 }
@@ -1133,6 +1207,9 @@ void profile_tick_end(
 
 	timer = &profile_globals.current_frame.game_ticks[profile_globals.current_frame.game_tick_count-1];
 	profile_timesection_end_now(timer);
+#ifdef HALO_PROFILE
+	profile_trace_end(profile_trace_timer_names.game_tick);
+#endif
 
 	return;
 }
@@ -1155,6 +1232,9 @@ void profile_render_window_start(
 
 	timer = &profile_globals.current_frame.windows[profile_globals.current_frame.window_count-1];
 	profile_timesection_begin_now(timer);
+#ifdef HALO_PROFILE
+	profile_trace_begin(profile_trace_timer_names.render_window);
+#endif
 
 	return;
 }
@@ -1169,6 +1249,9 @@ void profile_render_window_end(
 
 	timer = &profile_globals.current_frame.windows[profile_globals.current_frame.window_count-1];
 	profile_timesection_end_now(timer);
+#ifdef HALO_PROFILE
+	profile_trace_end(profile_trace_timer_names.render_window);
+#endif
 
 	return;
 }
@@ -1178,6 +1261,9 @@ void profile_render_start(
 {
 	profile_globals.current_frame.window_count = 0;
 	profile_timesection_begin_now(&profile_globals.current_frame.render);
+#ifdef HALO_PROFILE
+	profile_trace_begin(profile_trace_timer_names.render);
+#endif
 
 	return;
 }
@@ -1186,6 +1272,9 @@ void profile_render_end(
 	void)
 {
 	profile_timesection_end_now(&profile_globals.current_frame.render);
+#ifdef HALO_PROFILE
+	profile_trace_end(profile_trace_timer_names.render);
+#endif
 
 	return;
 }
@@ -1201,6 +1290,9 @@ void profile_texture_start(
 	if (PROFILE_TEXTURE_TIMED())
 	{
 		profile_timesection_begin_now(&profile_globals.current_frame.texture);
+#ifdef HALO_PROFILE
+		profile_trace_begin(profile_trace_timer_names.texture);
+#endif
 	}
 
 	return;
@@ -1212,6 +1304,9 @@ void profile_texture_end(
 	if (PROFILE_TEXTURE_TIMED())
 	{
 		profile_timesection_end_now(&profile_globals.current_frame.texture);
+#ifdef HALO_PROFILE
+		profile_trace_end(profile_trace_timer_names.texture);
+#endif
 	}
 
 	return;
@@ -1221,6 +1316,9 @@ void profile_idle_start(
 	void)
 {
 	profile_timesection_begin_now(&profile_globals.current_frame.idle);
+#ifdef HALO_PROFILE
+	profile_trace_begin(profile_trace_timer_names.idle);
+#endif
 
 	return;
 }
@@ -1229,6 +1327,9 @@ void profile_idle_end(
 	void)
 {
 	profile_timesection_end_now(&profile_globals.current_frame.idle);
+#ifdef HALO_PROFILE
+	profile_trace_end(profile_trace_timer_names.idle);
+#endif
 
 	return;
 }
@@ -1250,6 +1351,9 @@ void profile_enter_private(
 	QUERY_TIMEBASE(timebase);
 	section->entry_timebase = timebase;
 	section->frame_call_count++;
+#ifdef HALO_PROFILE
+	profile_trace_begin(profile_trace_section_names[section->section_index]);
+#endif
 
 	return;
 }
@@ -1272,6 +1376,9 @@ void profile_exit_private(
 		QUERY_TIMEBASE(timebase);
 		section->frame_elapsed_timebase += timebase-section->entry_timebase;
 		section->stack_depth = NONE;
+#ifdef HALO_PROFILE
+		profile_trace_end(profile_trace_section_names[section->section_index]);
+#endif
 	}
 	else
 	{
@@ -1492,6 +1599,9 @@ void profile_frame_end(
 	short frame_index;
 
 	profile_timesection_end_now(&profile_globals.current_frame.frame);
+#ifdef HALO_PROFILE
+	profile_trace_end(profile_trace_timer_names.frame);
+#endif
 
 	match_assert("c:\\halo\\SOURCE\\cseries\\profile.c", 448,
 		(profile_globals.current_frame.game_tick_count >= 0) && (profile_globals.current_frame.game_tick_count <= MAXIMUM_GAME_TICKS_PER_FRAME));
@@ -1746,6 +1856,9 @@ void find_profile_section(
 		section->section_index = profile_globals.section_count;
 		profile_globals.section_count++;
 		profile_globals.sections[section->section_index] = section;
+#ifdef HALO_PROFILE
+		profile_trace_section_names[section->section_index] = (short)profile_trace_name(section->name);
+#endif
 
 		csmemset(section->frame_elapsed_timebase_history, 0, sizeof(section->frame_elapsed_timebase_history));
 		csmemset(section->frame_call_count_history, 0, sizeof(section->frame_call_count_history));

source/cseries/profile_sections.h

@@ -0,0 +1,31 @@
+/*
+PROFILE_SECTIONS.H
+
+Wrap game CPU sections without changing normal builds.
+*/
+
+#ifndef __PROFILE_SECTIONS_H
+#define __PROFILE_SECTIONS_H
+
+#ifdef HALO_PROFILE
+
+#include "cseries/profile.h"
+
+/* these macros leave no tokens in a normal build: call sites have no trailing
+semicolon. a call site may be an unbraced if-branch: in a normal build
+profile_scope is the statement alone. */
+#define PROFILE_SECTION(variable, name) static struct profile_section variable = { name, NONE, TRUE };
+#define profile_scope_enter(variable) profile_enter(variable)
+#define profile_scope_exit(variable) profile_exit(variable)
+#define profile_scope(variable, statement) { profile_enter(variable) statement profile_exit(variable) }
+
+#else
+
+#define PROFILE_SECTION(variable, name)
+#define profile_scope_enter(variable)
+#define profile_scope_exit(variable)
+#define profile_scope(variable, statement) statement
+
+#endif
+
+#endif

source/game/game.c

@@ -182,6 +182,10 @@ struct game_options;
 #include "units/units.h"
 #include "units/vehicles.h"
 #include "network_coop.h" /* port: port/linux/game/network_coop.c */
+#ifdef HALO_PROFILE
+#include "profile_console.h"
+#endif
+#include "cseries/profile_sections.h"
 
 /* network_game_globals.c's */
 boolean network_game_distributed_client(void);
@@ -248,6 +252,25 @@ char const *global_game_difficulty_level_names[NUMBER_OF_GAME_DIFFICULTY_LEVELS]
 };
 
 static struct profile_section game_update_section = {"game_update", NONE, TRUE};
+/* port: game_tick's steps, timed in the profiling build */
+PROFILE_SECTION(game_tick_cheats_enforce_section, "game_tick.cheats_enforce")
+PROFILE_SECTION(game_tick_remove_quitting_players_section, "game_tick.remove_quitting_players")
+PROFILE_SECTION(game_tick_allegiance_section, "game_tick.allegiance")
+PROFILE_SECTION(game_tick_units_section, "game_tick.units")
+PROFILE_SECTION(game_tick_ai_section, "game_tick.ai")
+PROFILE_SECTION(game_tick_actors_drive_section, "game_tick.actors_drive")
+PROFILE_SECTION(game_tick_players_before_section, "game_tick.players_before")
+PROFILE_SECTION(game_tick_effects_section, "game_tick.effects")
+PROFILE_SECTION(game_tick_antennas_section, "game_tick.antennas")
+PROFILE_SECTION(game_tick_first_person_section, "game_tick.first_person")
+PROFILE_SECTION(game_tick_game_engine_section, "game_tick.game_engine")
+PROFILE_SECTION(game_tick_editor_section, "game_tick.editor")
+PROFILE_SECTION(game_tick_hs_section, "game_tick.hs")
+PROFILE_SECTION(game_tick_recorded_animations_section, "game_tick.recorded_animations")
+PROFILE_SECTION(game_tick_objects_section, "game_tick.objects")
+PROFILE_SECTION(game_tick_players_after_section, "game_tick.players_after")
+PROFILE_SECTION(game_tick_hud_section, "game_tick.hud")
+PROFILE_SECTION(game_tick_player_effect_section, "game_tick.player_effect")
 
 /* ---------- public code */
 
@@ -328,45 +351,46 @@ void game_tick(
 
 	/* port: a client of another's game, the host's rules (its own cheats and
 	game speed, set before it joined too, put back) */
-	cheats_network_client_enforce();
-	remove_quitting_players_from_game();
-	game_allegiance_update();
-	units_update();
+	profile_scope(game_tick_cheats_enforce_section, cheats_network_client_enforce();)
+	profile_scope(game_tick_remove_quitting_players_section, remove_quitting_players_from_game();)
+	profile_scope(game_tick_allegiance_section, game_allegiance_update();)
+	profile_scope(game_tick_units_section, units_update();)
 	/* (the host's actors drive the host's units, which a client of the
 	distributed netcode has from the host: its own would fight the host's
 	positions, and could place objects of their own) */
 	if (!network_game_distributed_client())
-		ai_update();
+		profile_scope(game_tick_ai_section, ai_update();)
 	else
-		network_actors_drive();
-	players_update_before_game();
+		profile_scope(game_tick_actors_drive_section, network_actors_drive();)
+	profile_scope(game_tick_players_before_section, players_update_before_game();)
 
 	seconds_per_tick = game_globals->players_are_double_speed
 		? 1.0f / (2 * TICKS_PER_SECOND)
 		: 1.0f / TICKS_PER_SECOND;
-	effects_update(seconds_per_tick);
+	profile_scope(game_tick_effects_section, effects_update(seconds_per_tick);)
 	/* An antenna's chain is a simulation of the Xbox's own step, an update a
 	tick: stepped a frame at a time, its springs, its carry and its points'
 	physics act against the frames' own movement of it, and a vehicle at
 	speed swings it far wider than a tick's step does. The frames between the
 	ticks are drawn from what each tick leaves (antenna.c). */
-	antennas_update(seconds_per_tick);
-	lock_global_random_seed();
-	rumble_update();
-	first_person_weapons_update();
-	unlock_global_random_seed();
-	game_engine_update();
-	editor_update();
+	profile_scope(game_tick_antennas_section, antennas_update(seconds_per_tick);)
+	profile_scope(game_tick_first_person_section,
+		lock_global_random_seed();
+		rumble_update();
+		first_person_weapons_update();
+		unlock_global_random_seed();)
+	profile_scope(game_tick_game_engine_section, game_engine_update();)
+	profile_scope(game_tick_editor_section, editor_update();)
 	/* port: in network co-op only the host runs the scripts. A client running
 	them would place the map's actors and objects a second time and make
 	decisions that belong to the host. */
 	if (!(network_game_distributed_client() && network_coop_active()))
-		hs_update();
-	recorded_animations_update();
-	objects_update();
-	players_update_after_game();
-	hud_update();
-	player_effect_update();
+		profile_scope(game_tick_hs_section, hs_update();)
+	profile_scope(game_tick_recorded_animations_section, recorded_animations_update();)
+	profile_scope(game_tick_objects_section, objects_update();)
+	profile_scope(game_tick_players_after_section, players_update_after_game();)
+	profile_scope(game_tick_hud_section, hud_update();)
+	profile_scope(game_tick_player_effect_section, player_effect_update();)
 	/* port: and at its end, before the frame draws the lights */
 	game_state_check_data_arrays();
 	lights_port_recover();
@@ -584,6 +608,11 @@ boolean game_is_cooperative(
 boolean game_load(
 	struct game_options *options)
 {
+#ifdef HALO_PROFILE
+	/* (every map load passes here: main_new_map's and a network game's,
+	network_game_manager.c) */
+	profile_console_map_loaded(options->map_name);
+#endif
 	match_assert(
 		"c:\\halo\\SOURCE\\game\\game.c",
 		0x192,

source/game/game_time.c

@@ -75,9 +75,15 @@ symbols in this file:
 #include "networking/network_game_globals.h"
 #include "networking/network_server_manager.h"
 #include "saved games/game_state.h"
+#include "cseries/profile_sections.h"
 /* port/linux/game/network_distributed.c's */
 void network_distributed_tick(void);
 
+/* port: the tick loop's steps, timed in the profiling build */
+PROFILE_SECTION(game_time_network_distributed_tick_section, "network_distributed_tick")
+PROFILE_SECTION(game_time_render_interpolation_tick_section, "render_interpolation_tick")
+PROFILE_SECTION(game_time_game_frame_section, "game_frame")
+
 /* ---------- constants */
 
 enum
@@ -473,11 +479,11 @@ void game_time_update(
 					for (update_index = 0; update_index < server_updates; update_index++)
 					{
 						game_tick();
-						render_interpolation_tick();
+						profile_scope(game_time_render_interpolation_tick_section, render_interpolation_tick();)
 						game_time_globals->server_time++;
 						game_time_globals->local_time++;
 						/* the distributed netcode's per-tick state */
-						network_distributed_tick();
+						profile_scope(game_time_network_distributed_tick_section, network_distributed_tick();)
 					}
 				}
 
@@ -493,7 +499,7 @@ void game_time_update(
 		(port/linux/game/render_interpolation.c). The frames of one tick share
 		the fraction, so what they hang off is drawn where they put it. */
 		render_interpolation_frame_begin();
-		game_frame(game_time_get_speed()*time_delta_sec);
+		profile_scope(game_time_game_frame_section, game_frame(game_time_get_speed()*time_delta_sec);)
 		render_interpolation_frame_end();
 	}
 	else

source/hs/hs.c

@@ -2841,6 +2841,9 @@ symbols in this file:
 #include "units/units.h"
 #include "units/vehicles.h"
 #include "coop_scripts.h" /* port: port/linux/game/coop_scripts.c */
+#ifdef HALO_PROFILE
+#include "profile_console.h"
+#endif
 
 /* ---------- constants */
 
@@ -15358,6 +15361,12 @@ static boolean hs_compile_and_evaluate_command(
 	char buffer[1024];
 	char expanded[1024];
 
+#ifdef HALO_PROFILE
+	/* port: the profiling build's commands change nothing of the game: a client
+	may give them, and they are no scripts */
+	if (profile_console_command(expression))
+		return TRUE;
+#endif
 	/* port: the co-op host's bringto, which brings every player to the host
 	(players.c; a client is told it is the host's) */
 	if (hs_host_player_command(expression, "bringto"))

source/main/console.c

@@ -130,7 +130,9 @@ void console_open(
 	{
 		console_globals.input_state.result[0] = '\0';
 		console_globals.active = terminal_gets_begin(&console_globals.input_state);
+#ifndef HALO_PROFILE
 		profile_global_enable = FALSE;
+#endif
 	}
 
 	return;
@@ -510,7 +512,12 @@ boolean console_update(
 	{
 		console_globals.input_state.result[0] = '\0';
 		console_globals.active = terminal_gets_begin(&console_globals.input_state);
+		/* port: the profiling build: cleared mid-frame, a section already entered
+		would never exit, and its next enter assert; and opening the console
+		to type profile_stop would end the recording's timing */
+#ifndef HALO_PROFILE
 		profile_global_enable = FALSE;
+#endif
 	}
 
 	return console_globals.active;

source/main/main.c

@@ -381,6 +381,10 @@ symbols in this file:
 #include "networking/network_server_manager.h" /* port: a co-op game's level won */
 #include "network_coop.h" /* port: port/linux/game/network_coop.c */
 #include "network_voice.h" /* port: port/linux/game/network_voice.c */
+#include "cseries/profile_sections.h"
+#ifdef HALO_PROFILE
+#include "profile_trace.h"
+#endif
 #include "camera/director.h"
 #include "camera/observer.h"
 #include "cutscene/cinematics.h"
@@ -1443,6 +1447,16 @@ short main_get_window_count(
 	return single_window ? 1 : PIN(local_player_count(), 1, MAXIMUM_WINDOWS);
 }
 
+#ifdef HALO_PROFILE
+/* port: whether the main menu's map is the one loaded (profile_console.c: a
+recording of debug.profile_record_when = "game" waits for another) */
+boolean main_menu_is_loaded(
+	void)
+{
+	return main_globals.main_menu_scenario_loaded;
+}
+#endif
+
 static void main_new_map(
 	struct game_options *options)
 {
@@ -2367,6 +2381,9 @@ void main_set_map_name(
 static void main_exit(
 	void)
 {
+#ifdef HALO_PROFILE
+	profile_trace_shutdown();
+#endif
 	switch (main_globals.connection)
 	{
 	case _game_connection_network_server:
@@ -3315,6 +3332,18 @@ static void main_game_render(
 	return;
 }
 
+/* port: the main loop's steps, timed in the profiling build */
+PROFILE_SECTION(main_input_section, "input")
+PROFILE_SECTION(main_platform_events_section, "platform_events")
+PROFILE_SECTION(main_network_start_frame_section, "network_start_frame")
+PROFILE_SECTION(main_update_time_section, "main_update_time")
+PROFILE_SECTION(main_ui_update_section, "ui_update")
+PROFILE_SECTION(main_network_end_frame_section, "network_end_frame")
+PROFILE_SECTION(main_game_time_update_section, "game_time_update")
+PROFILE_SECTION(main_non_deterministic_update_section, "non_deterministic_update")
+PROFILE_SECTION(main_throttle_section, "throttle")
+PROFILE_SECTION(main_present_section, "present")
+
 void main_loop(
 	void)
 {
@@ -3428,12 +3457,16 @@ void main_loop(
 		}
 
 		profile_frame_start();
+		profile_scope_enter(main_input_section)
 		input_frame_begin();
 		input_update();
 		input_abstraction_update();
+		profile_scope_exit(main_input_section)
+		profile_scope_enter(main_platform_events_section)
 		shell_idle();
 		event_manager_update();
 		telnet_console_process();
+		profile_scope_exit(main_platform_events_section)
 
 		if (!shell_application_is_paused())
 		{
@@ -3443,6 +3476,7 @@ void main_loop(
 			network_test_update(main_globals.main_menu_scenario_loaded, main_globals.seconds_elapsed);
 			/* port: voice chat, in the lobby and in game (port/linux/game/network_voice.c) */
 			network_voice_update();
+			profile_scope_enter(main_network_start_frame_section)
 			connection = main_globals.connection;
 			if (connection==_game_connection_network_client)
 			{
@@ -3470,12 +3504,16 @@ void main_loop(
 			}
 			else if (connection==_game_connection_film_playback)
 			{
+				profile_scope_exit(main_network_start_frame_section)
 				break;
 			}
+			profile_scope_exit(main_network_start_frame_section)
 
-			main_update_time();
+			profile_scope(main_update_time_section, main_update_time();)
+			profile_scope_enter(main_ui_update_section)
 			process_ui_widgets();
 			bink_playback_update();
+			profile_scope_exit(main_ui_update_section)
 
 			/* port: not the Xbox debug keyboard's End and Escape, which stop
 			the movie and restart the map: this keyboard reaches the game only
@@ -3502,13 +3540,16 @@ void main_loop(
 					player_control_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
 
 					connection = main_globals.connection;
+					profile_scope_enter(main_network_end_frame_section)
 					if (connection>_game_connection_local && connection<=_game_connection_network_server && !network_game_client_end_frame())
 					{
 						display_error_when_main_menu_loaded(1);
 						network_game_abort();
 					}
+					profile_scope_exit(main_network_end_frame_section)
 
-					game_time_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
+					profile_scope(main_game_time_update_section,
+						game_time_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);)
 
 					render_frame = main_globals.main_menu_scenario_loaded ||
 						(main_globals.halt_time_scale &&
@@ -3518,11 +3559,13 @@ void main_loop(
 						render_frame = main_globals.main_menu_scenario_loaded || main_globals.halt_time_scale;
 					render_frame &= !game_engine_running() || game_time_get()>=3;
 
+					profile_scope_enter(main_non_deterministic_update_section)
 					collision_log_continue_period(1);
 					director_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
 					observer_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
 					collision_log_end_period();
 					game_engine_update_non_deterministic((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
+					profile_scope_exit(main_non_deterministic_update_section)
 				}
 
 				if (main_globals.saving_map)
@@ -3546,11 +3589,11 @@ void main_loop(
 				profile_render_end();
 			}
 
-			main_rasterizer_throttle();
+			profile_scope(main_throttle_section, main_rasterizer_throttle();)
 
 			if (render_frame && !debug_no_drawing)
 			{
-				main_present_frame();
+				profile_scope(main_present_section, main_present_frame();)
 			}
 		}
 

tools/android_build.py

@@ -26,7 +26,7 @@ from pathlib import Path
 from typing import Any, Dict, List, Optional
 
 from .linux_build import (LINUX_PROFILE, MINIUPNPC_DEFINES, MINIUPNPC_DIR, MUSL_MATH_DIR, XDK_INCLUDE,
-                          compile_launcher, game_defines_and_includes, game_sources, miniupnpc_sources,
+                          compile_launcher, configuration_defines, game_defines_and_includes, game_sources, miniupnpc_sources,
                           musl_math_sources, opus_cflags, opus_sources, pgo_mode, pgo_profile,
                           profile_use_flags, updater_defines, xdk_headers)
 from .embed_assets import hud_assets_build, hud_configure_inputs
@@ -383,7 +383,7 @@ def generate_android_build(n: Writer, sln: Any) -> None:
         f"-isystem {libc_include}", f"-isystem {arch}", f"-isystem {MUSL_DIR}/arch/generic",
         f"-isystem {MUSL_DIR}/include",
     ]
-    guest_abi = " ".join(GUEST_ABI_FLAGS + (["-DHALO_RELEASE"] if getattr(sln, "port_release", False) else []))
+    guest_abi = " ".join(GUEST_ABI_FLAGS + configuration_defines(sln))
     guest_code = " ".join(GUEST_CODE_FLAGS)
     tool_implicit = [Path("tools/android_asm_convert.py"), *generated_headers]
     # profile-guided optimisation with the Linux build's profile (committed,

tools/linux_build.py

@@ -152,6 +152,25 @@ def updater_defines(release: bool) -> str:
     flavor = "release" if release else "debug"
     return f'-DHALO_BUILD_NUMBER={number} -DHALO_BUILD_FLAVOR=\\"{flavor}\\"'
 
+def configuration_defines(sln: Any) -> List[str]:
+    """what configure.py's options define for every unit of a native build:
+    --release (no assertions), --profile (the profiling build's recording,
+    port/linux/src/profile_trace.c)"""
+    defines = []
+    if getattr(sln, "port_release", False):
+        defines.append("-DHALO_RELEASE")
+    if getattr(sln, "port_profile", False):
+        defines.append("-DHALO_PROFILE")
+    return defines
+
+
+def check_profile_options(profile: bool, pgo: str) -> None:
+    """A profiling build is optimised with the committed profiles or none:
+    trained, a profile would record the profiling code's own paths."""
+    if profile and pgo == "train":
+        raise ValueError("--profile cannot be used with --pgo=train: train profiles with a normal build")
+
+
 PLATFORM_FLAGS = [
     "-std=gnu11",
     "-D_GNU_SOURCE",
@@ -485,8 +504,8 @@ def generate_linux_build(n: Writer, sln: Any) -> None:
     # (a debug build checks its stack frames, and stops at the first one
     # overrun, as it stops at the first failed assertion; a release build
     # does not, so that an overrun nobody has met cannot end a game)
-    abi = " ".join(LINUX_ABI_FLAGS + target + (["-DHALO_RELEASE"] if getattr(sln, "port_release", False)
-                                               else ["-fstack-protector-strong"]))
+    abi = " ".join(LINUX_ABI_FLAGS + target + configuration_defines(sln)
+                   + ([] if getattr(sln, "port_release", False) else ["-fstack-protector-strong"]))
     port_include = PORT_DIR / "include"
     sdk_flags = f"-idirafter {XDK_INCLUDE}"
     libs = " ".join(f"-l{lib}" for lib in config.get("libraries", []))

tools/net_report.py

@@ -0,0 +1,306 @@
+#!/usr/bin/env python3
+"""Summarize CPU profiling recordings.
+Usage: python tools/net_report.py RECORDING [RECORDING2 ...] [options]."""
+
+import argparse
+import csv
+import json
+import re
+import sys
+from pathlib import Path
+
+FORMAT = 1
+SUMMARY_LINE_LIMIT = 300
+# (the summary file always uses this, so its length does not depend on --top)
+SUMMARY_TOP = 40
+REQUIRED_HEADER = ("part", "last_part", "role", "own_machine", "build", "platform", "map",
+                   "players", "start_utc", "start_s", "duration_s",
+                   "stop_reason")
+PER_TICK_PREFIXES = ("game_tick", "network_distributed_tick")
+
+COLUMNS_GLOSSARY = """\
+scope        CPU scope name (a profile section or frame timer); nested names use "."
+count        times the scope ran in the recording
+total_ms     summed inclusive time (children included), milliseconds
+mean_ms      total_ms / count
+max_ms       longest single run; aggregate sections: largest summed time in one frame
+per_frame    count / frames recorded
+per_tick_ms  total_ms / ticks recorded (game_tick.* and network_distributed_tick* only)
+frame        frame number in the recording
+at_s         seconds from the start of the recording to that frame
+frame_ms     that frame's duration
+ticks        game ticks that frame ran
+longest scopes (ms)  the frame's three scopes, at any depth, with the most time of their own (children not counted), name and that time"""
+
+
+class ReportError(Exception):
+    pass
+
+
+# ---------- reading a recording
+
+
+def part_paths(recording):
+    """the recording's name, its part files by number, and the warnings"""
+    path = Path(recording)
+    match = re.match(r"^(.*)\.part(\d+)\.json$", path.name)
+    base = path.parent / (match.group(1) if match else re.sub(r"\.json$", "", path.name))
+    parts = {}
+    for candidate in base.parent.glob(base.name + ".part*.json"):
+        number = re.match(r"^.*\.part(\d+)\.json$", candidate.name)
+        if number and candidate.name.startswith(base.name + ".part"):
+            parts[int(number.group(1))] = candidate
+    if not parts:
+        raise ReportError(f"no parts of {base}")
+    warnings = [f"part {number} of {base.name} is missing" for number in range(1, max(parts) + 1)
+                if number not in parts]
+    return base, [parts[number] for number in sorted(parts)], warnings
+
+
+def read_head(path):
+    """the header and cpu tables, read before the event array"""
+    with open(path, "r", encoding="utf-8") as file:
+        return read_head_stream(file, path)
+
+
+def read_head_stream(file, path):
+    text = ""
+    marker = '"traceEvents"'
+    while marker not in text:
+        chunk = file.read(65536)
+        if not chunk:
+            raise ReportError(f"{path}: has no traceEvents")
+        text += chunk
+    text = text.split(marker, 1)[0].rstrip().rstrip(",") + "}"
+    try:
+        head = json.loads(text)
+    except json.JSONDecodeError as error:
+        raise ReportError(f"{path}: not a recording part ({error})") from None
+    if not isinstance(head, dict):
+        raise ReportError(f"{path}: not a recording part")
+    for key in ("halo", "cpu_summary"):
+        if not isinstance(head.get(key), dict):
+            raise ReportError(f'{path}: has no "{key}"')
+    _validate_head_part(head, path)
+    return [head]
+
+
+def _validate_head_part(head, path):
+    where = str(path)
+    for key in ("halo", "cpu_summary"):
+        if not isinstance(head.get(key), dict):
+            raise ReportError(f'{where}: has no "{key}"')
+    header = head["halo"].get("header")
+    if not isinstance(header, dict):
+        raise ReportError(f'{where}: has no "header" in "halo"')
+    for key in REQUIRED_HEADER:
+        if key not in header:
+            raise ReportError(f'{where}: the header has no "{key}"')
+
+
+def table_dicts(table):
+    columns = table["columns"]
+    return [dict(zip(columns, row)) for row in table["rows"]]
+
+
+class Recording:
+    """a recording's parts with their CPU summaries merged"""
+
+    def __init__(self, recording):
+        self.base, paths, self.warnings = part_paths(recording)
+        heads = [head for part in paths for head in read_head(part)]
+        self.name = self.base.name
+        self.headers = [head["halo"]["header"] for head in heads]
+        self.parts = [header["part"] for header in self.headers]
+        self.complete = any(header["last_part"] for header in self.headers)
+        if not self.complete:
+            self.warnings.append(f"{self.name} has no last part: the recording is incomplete")
+        self.header = self.headers[0]
+        self.cpu = self.merge_cpu([head["cpu_summary"] for head in heads])
+
+    @staticmethod
+    def merge_cpu(summaries):
+        names = {}
+        frames = sum(summary["frames"] for summary in summaries)
+        ticks = sum(summary["ticks"] for summary in summaries)
+        worst = []
+        for summary in summaries:
+            for row in table_dicts(summary):
+                totals = names.setdefault(row["name"], {"count": 0, "total_ms": 0.0, "max_ms": 0.0})
+                totals["count"] += row["count"]
+                totals["total_ms"] += row["total_ms"]
+                totals["max_ms"] = max(totals["max_ms"], row["max_ms"])
+            worst.extend(table_dicts(summary["worst_frames"]))
+        for name, totals in names.items():
+            totals["mean_ms"] = totals["total_ms"] / totals["count"] if totals["count"] else 0.0
+            totals["per_frame"] = totals["count"] / frames if frames else 0.0
+            totals["per_tick_ms"] = (totals["total_ms"] / ticks if ticks and name.startswith(PER_TICK_PREFIXES)
+                                     else None)
+        worst.sort(key=lambda row: -row["frame_ms"])
+        return {"frames": frames, "ticks": ticks, "names": names, "worst": worst[:10]}
+
+    def select(self, start=None, end=None):
+        """Elapsed seconds from the recorded part headers, clipped to a window."""
+        seconds = 0.0
+        for header in self.headers:
+            begin = header["start_s"]
+            finish = begin + header["duration_s"]
+            seconds += max(0.0, min(finish, end if end is not None else finish) -
+                           max(begin, start if start is not None else begin))
+        return seconds
+
+
+# ---------- the tables
+
+
+def cpu_table(recording):
+    rows = [[name, totals["count"], totals["total_ms"], totals["mean_ms"], totals["max_ms"], totals["per_frame"],
+             totals["per_tick_ms"]] for name, totals in recording.cpu["names"].items()]
+    rows.sort(key=lambda row: (-row[2], row[0]))
+    return ["scope", "count", "total_ms", "mean_ms", "max_ms", "per_frame", "per_tick_ms"], rows
+
+
+def worst_frame_table(recording):
+    rows = [[row["frame"], row["at_s"], row["frame_ms"], row["ticks"],
+             ", ".join(f"{name} {ms:.1f}" for name, ms in row["longest"])] for row in recording.cpu["worst"]]
+    return ["frame", "at_s", "frame_ms", "ticks", "longest scopes (ms)"], rows
+
+
+# ---------- text
+
+
+NUMBER_FORMATS = {
+    "count": "{:.0f}", "total_ms": "{:.1f}", "mean_ms": "{:.3f}", "max_ms": "{:.3f}", "per_frame": "{:.2f}",
+    "per_tick_ms": "{:.3f}", "frame": "{:.0f}", "at_s": "{:.2f}", "frame_ms": "{:.2f}", "ticks": "{:.0f}",
+}
+TEXT_WIDTH = {"scope": 40, "longest scopes (ms)": 72}
+
+
+def cell(column, value):
+    if value is None:
+        return "-"
+    if isinstance(value, (int, float)) and not isinstance(value, bool) and column in NUMBER_FORMATS:
+        return NUMBER_FORMATS[column].format(value)
+    text = str(value)
+    width = TEXT_WIDTH.get(column)
+    if width and len(text) > width:
+        text = text[:width - 1] + "~"
+    return text
+
+
+def format_table(columns, rows, limit=None):
+    """aligned lines: names left, numbers right; past the limit a line of
+    how many more"""
+    shown = rows if limit is None else rows[:limit]
+    if not shown:
+        return ["(none)"]
+    cells = [[cell(column, value) for column, value in zip(columns, row)] for row in shown]
+    numeric = [column in NUMBER_FORMATS for column in columns]
+    widths = [max([len(column)] + [len(line[index]) for line in cells]) for index, column in enumerate(columns)]
+
+    def line(values):
+        parts = [value.rjust(width) if is_number else value.ljust(width)
+                 for value, width, is_number in zip(values, widths, numeric)]
+        return "  ".join(parts).rstrip()
+
+    lines = [line(columns)] + [line(values) for values in cells]
+    if limit is not None and len(rows) > limit:
+        lines.append(f"... {len(rows) - limit} more rows (net_report.py --top N)")
+    return lines
+
+
+def problems(recording):
+    found = list(recording.warnings)
+    counters = (("unbalanced_scopes", "unbalanced scopes"), ("deep_scopes", "deep scopes"),
+                ("foreign_scopes", "foreign scopes"), ("dropped_scopes", "dropped scopes"))
+    for key, label in counters:
+        total = sum(header.get(key, 0) for header in recording.headers)
+        if total:
+            found.append(f"{label} {total}")
+    wait = sum(header.get("writer_wait_ms", 0.0) for header in recording.headers[-1:])
+    if wait:
+        found.append(f"writer waited {wait:.0f} ms")
+    return found
+
+
+def summary_lines(recording, start, end, top):
+    seconds = recording.select(start, end)
+    windowed = start is not None or end is not None
+    whole = recording.select()
+    header, last = recording.header, recording.headers[-1]
+    parts = f"parts {min(recording.parts)}-{max(recording.parts)}" if len(recording.parts) > 1 else "part 1"
+    state = "complete" if recording.complete and not any(
+        "missing" in warning for warning in recording.warnings) else "incomplete"
+    found = problems(recording)
+    own = header["own_machine"] if header["own_machine"] >= 0 else "-"
+    lines = [
+        f"# halo profile summary, format {FORMAT}",
+        f"# recording: {recording.name}, {parts} ({state})",
+        f"# build: {header['build']}, platform: {header['platform']}, role: {header['role']}, own_machine: {own}",
+        f"# map: {header['map']}, players: {header['players']} at start, "
+        f"{max(item.get('players_most', item['players']) for item in recording.headers)} most",
+        f"# recorded: {header['start_utc']} UTC, {whole:.1f} s, {recording.cpu['ticks']} ticks, "
+        f"{recording.cpu['frames']} frames, stopped: {last['stop_reason'] or '-'}",
+        *([f"# window: {seconds:.1f} s selected (seconds {start if start is not None else 0:g} to "
+           f"{f'{end:g}' if end is not None else 'end'}); the cpu tables, ticks and frames cover the whole recording"]
+          if windowed else []),
+        f"# problems: {'; '.join(found) if found else 'none'}",
+        "# units: ms = milliseconds", "", "## columns",
+    ]
+    note = ", whole recording" if windowed else ""
+    sections = [(f"cpu scopes (top {min(top, 40)} by total_ms{note})", cpu_table(recording), min(top, 40)),
+                (f"worst frames (10{note})", worst_frame_table(recording), 10)]
+    printed = {column for _, (columns, rows), _ in sections if rows for column in columns}
+    lines.extend(line for line in COLUMNS_GLOSSARY.splitlines() if re.split(r"\s{2,}", line, maxsplit=1)[0] in printed)
+    for title, table, limit in sections:
+        lines.extend(["", f"## {title}", *format_table(*table, limit)])
+    return lines
+
+
+def write_csv(recording, directory):
+    directory.mkdir(parents=True, exist_ok=True)
+    for name, (columns, rows) in {"cpu": cpu_table(recording), "worst_frames": worst_frame_table(recording)}.items():
+        with open(directory / f"{recording.name}.{name}.csv", "w", newline="", encoding="ascii", errors="replace") as file:
+            writer = csv.writer(file)
+            writer.writerow(columns)
+            writer.writerows([[NUMBER_FORMATS[column].format(value)
+                               if column in NUMBER_FORMATS and isinstance(value, (int, float)) else
+                               ("-" if value is None else value) for column, value in zip(columns, row)] for row in rows])
+
+
+def main(arguments=None):
+    parser = argparse.ArgumentParser(description=__doc__.splitlines()[0])
+    parser.add_argument("recordings", nargs="+", metavar="RECORDING")
+    parser.add_argument("--from", dest="start", type=float, help="from this second of the recording")
+    parser.add_argument("--to", dest="end", type=float, help="to this second")
+    parser.add_argument("--top", type=int, default=40, help="CPU rows (default 40)")
+    parser.add_argument("--csv", type=Path, metavar="DIR", help="every table as CSV in DIR")
+    parser.add_argument("--no-summary", action="store_true", help="do not write <name>.summary.txt")
+    options = parser.parse_args(arguments)
+    try:
+        recordings = [Recording(name) for name in options.recordings]
+    except (ReportError, OSError) as error:
+        print(f"net_report: {error}", file=sys.stderr)
+        return 1
+    for recording in recordings:
+        try:
+            lines = summary_lines(recording, options.start, options.end, options.top)
+            file_lines = lines if options.top == SUMMARY_TOP else summary_lines(
+                recording, options.start, options.end, SUMMARY_TOP)
+        except (KeyError, TypeError, IndexError, ValueError) as error:
+            print(f"net_report: {recording.name}: a table is not as the writer wrote it ({error!r})", file=sys.stderr)
+            return 1
+        for warning in recording.warnings:
+            print(f"warning: {warning}", file=sys.stderr)
+        print("\n".join(lines))
+        print()
+        if not options.no_summary:
+            path = recording.base.parent / f"{recording.name}.summary.txt"
+            path.write_text("\n".join(file_lines) + "\n", encoding="ascii", errors="replace")
+        if options.csv:
+            write_csv(recording, options.csv)
+    return 0
+
+
+if __name__ == "__main__":
+    sys.exit(main())

tools/profile_fixture.py

@@ -0,0 +1,66 @@
+"""Hand-written CPU recording parts for the report tests."""
+
+import json
+from pathlib import Path
+
+
+def part(number, intervals, last, frames_before, ticks_before):
+    frames = 60 * len(intervals)
+    ticks = 30 * len(intervals)
+    header = {
+        "format": 1, "build": "0 debug profile", "platform": "windows", "role": "host", "own_machine": -1,
+        "map": "levels\\a30\\a30", "map_name": "a30", "gametype": "campaign",
+        "players": 3 if number == 1 else 4, "players_most": 4, "start_utc": "2026-10-05 14:22:33",
+        "recording": "profile_20261005-142233_host", "part": number, "last_part": last,
+        "first_frame": frames_before, "frames": frames,
+        "first_tick": ticks_before, "ticks": ticks, "start_s": float(intervals[0]), "duration_s": float(len(intervals)),
+        "stop_reason": "command" if last else "", "clock_read_ns": 21.5, "memory_used": 1000, "memory_limit": 16777216,
+        "writer_wait_ms": 0.0, "foreign_scopes": 0, "deep_scopes": 0, "unbalanced_scopes": 0, "dropped_scopes": 0,
+        "dropped_scopes": 0,
+    }
+    halo = {"header": header}
+    cpu_rows = [
+        ["frame", frames, 8.3 * frames, 8.3, 41.2, 1.0, None],
+        ["game_tick", ticks, 3.2 * ticks, 3.2, 6.012, 0.5, 3.2],
+        ["game_tick.objects", ticks, 1.4 * ticks, 1.4, 12.1, 0.5, 1.4],
+        ["network_distributed_tick", ticks, 0.6 * ticks, 0.6, 4.0, 0.5, 0.6],
+        ["render", frames, 4.0 * frames, 4.0, 9.8, 1.0, None],
+    ]
+    worst = [[frames_before + 12, frames_before / 60.0 + 0.2, 41.2 - number, 2,
+              [["game_tick.objects", 12.1], ["render", 9.8], ["network_distributed_tick", 4.0]]]]
+    cpu = {"frames": frames, "ticks": ticks,
+           "columns": ["name", "count", "total_ms", "mean_ms", "max_ms", "per_frame", "per_tick_ms"],
+           "rows": cpu_rows, "worst_frames": {"columns": ["frame", "at_s", "frame_ms", "ticks", "longest"],
+                                              "rows": worst}}
+    return halo, cpu
+
+
+def write_part(path, halo, cpu):
+    """the writer's layout: one item per line, the events last"""
+    lines = ['{"halo": {', '"header": ' + json.dumps(halo["header"])]
+    for name, table in halo.items():
+        if name == "header":
+            continue
+        lines[-1] += ","
+        lines.append(f'"{name}": {{"columns": {json.dumps(table["columns"])}, "rows": [')
+        lines.extend(json.dumps(row) + ("," if index < len(table["rows"]) - 1 else "")
+                     for index, row in enumerate(table["rows"]))
+        lines.append("]}")
+    lines[-1] += "},"
+    lines.append('"cpu_summary": ' + json.dumps(cpu) + ",")
+    lines.append('"traceEvents": [')
+    lines.append('{"ph":"M","name":"process_name","pid":1,"args":{"name":"halo host windows"}}')
+    lines.append("],")
+    lines.append('"displayTimeUnit": "ms"}')
+    Path(path).write_text("\n".join(lines) + "\n", encoding="utf-8")
+
+
+def write_recording(folder, name="profile_20261005-142233_host", split=True):
+    """three parts of two intervals each, or the same six in one part"""
+    folder = Path(folder)
+    folder.mkdir(parents=True, exist_ok=True)
+    spans = [[0, 1], [2, 3], [4, 5]] if split else [[0, 1, 2, 3, 4, 5]]
+    for index, intervals in enumerate(spans):
+        halo, cpu = part(index + 1, intervals, index == len(spans) - 1, intervals[0] * 60, intervals[0] * 30)
+        write_part(folder / f"{name}.part{index + 1}.json", halo, cpu)
+    return folder / name

tools/profile_fixture.summary.txt

@@ -0,0 +1,35 @@
+# halo profile summary, format 1
+# recording: profile_20261005-142233_host, parts 1-3 (complete)
+# build: 0 debug profile, platform: windows, role: host, own_machine: -
+# map: levels\a30\a30, players: 3 at start, 4 most
+# recorded: 2026-10-05 14:22:33 UTC, 6.0 s, 180 ticks, 360 frames, stopped: command
+# problems: none
+# units: ms = milliseconds
+
+## columns
+scope        CPU scope name (a profile section or frame timer); nested names use "."
+count        times the scope ran in the recording
+total_ms     summed inclusive time (children included), milliseconds
+mean_ms      total_ms / count
+max_ms       longest single run; aggregate sections: largest summed time in one frame
+per_frame    count / frames recorded
+per_tick_ms  total_ms / ticks recorded (game_tick.* and network_distributed_tick* only)
+frame        frame number in the recording
+at_s         seconds from the start of the recording to that frame
+frame_ms     that frame's duration
+ticks        game ticks that frame ran
+longest scopes (ms)  the frame's three scopes, at any depth, with the most time of their own (children not counted), name and that time
+
+## cpu scopes (top 40 by total_ms)
+scope                     count  total_ms  mean_ms  max_ms  per_frame  per_tick_ms
+frame                       360    2988.0    8.300  41.200       1.00            -
+render                      360    1440.0    4.000   9.800       1.00            -
+game_tick                   180     576.0    3.200   6.012       0.50        3.200
+game_tick.objects           180     252.0    1.400  12.100       0.50        1.400
+network_distributed_tick    180     108.0    0.600   4.000       0.50        0.600
+
+## worst frames (10)
+frame  at_s  frame_ms  ticks  longest scopes (ms)
+   12  0.20     40.20      2  game_tick.objects 12.1, render 9.8, network_distributed_tick 4.0
+  132  2.20     39.20      2  game_tick.objects 12.1, render 9.8, network_distributed_tick 4.0
+  252  4.20     38.20      2  game_tick.objects 12.1, render 9.8, network_distributed_tick 4.0

tools/test_profile.py

@@ -0,0 +1,569 @@
+"""Profiling build, CPU recorder, written parts and CPU report tests.
+For local WSL runs in a Windows worktree, set HALO_GIT=git.exe.
+"""
+
+import io
+import json
+import os
+import re
+import shlex
+import shutil
+import subprocess
+import tarfile
+from pathlib import Path
+from types import SimpleNamespace
+
+import pytest
+
+from tools import linux_build, net_report, ninja_syntax, profile_fixture
+
+ROOT = Path(__file__).resolve().parent.parent
+GIT = os.environ.get("HALO_GIT", "git")
+
+
+# ---------- the build switch
+
+
+def test_configuration_defines():
+    assert linux_build.configuration_defines(SimpleNamespace()) == []
+    assert linux_build.configuration_defines(SimpleNamespace(port_release=True)) == ["-DHALO_RELEASE"]
+    assert linux_build.configuration_defines(SimpleNamespace(port_release=True, port_profile=True)) == [
+        "-DHALO_RELEASE", "-DHALO_PROFILE"]
+
+
+def test_every_native_build_takes_the_configuration_defines():
+    # (the guest, the game and the platform layer of all three: one place
+    # decides what --release and --profile define)
+    for name in ("linux_build.py", "windows_build.py", "android_build.py"):
+        text = (ROOT / "tools" / name).read_text(encoding="utf-8")
+        assert "configuration_defines(sln)" in text, name
+        assert '["-DHALO_RELEASE"] if' not in text, name
+
+
+def test_profile_refuses_pgo_training():
+    with pytest.raises(ValueError, match="--pgo=train"):
+        linux_build.check_profile_options(True, "train")
+    linux_build.check_profile_options(True, "use")
+    linux_build.check_profile_options(True, "off")
+    linux_build.check_profile_options(False, "train")
+
+
+def test_linux_build_compiles_with_the_profile_define(monkeypatch):
+    monkeypatch.chdir(ROOT)
+    out = io.StringIO()
+    linux_build.generate_linux_build(ninja_syntax.Writer(out), SimpleNamespace(
+        build_dir=Path("build"), linux_cc="clang", compiler_launcher=None, port_release=False, port_lto="off",
+        port_portable=True, port_pgo="off", port_pgo_profile=None, port_profile=True))
+    # (ninja_syntax wraps long lines with " $"; Windows paths have backslashes)
+    text = re.sub(r" \$\n *", " ", out.getvalue()).replace("\\", "/")
+    for obj in ("build/linux/obj/source/game/game.o", "build/linux/obj/port/linux/src/p2p.o"):
+        block = text[text.index(f"build {obj}:"):]
+        cflags = next(line for line in block.splitlines() if line.strip().startswith("cflags = "))
+        assert "-DHALO_PROFILE" in cflags, obj
+
+
+# ---------- the recording's C units (tools/profile_check.c)
+
+PROFILE_SOURCES = ["port/linux/src/profile_trace.c", "port/linux/src/profile_json.c"]
+
+
+def check_compiler():
+    """a C compiler of this machine with POSIX threads, or None (Windows has
+    them only through the port's own layer, so the check runs on Linux and
+    in WSL)"""
+    if os.name == "nt":
+        return None
+    for name in ("clang", "cc", "gcc"):
+        if shutil.which(name):
+            return name
+    return None
+
+
+def build_check(tmp_path, sanitizers):
+    compiler = check_compiler()
+    if not compiler:
+        pytest.skip("needs a C compiler with POSIX threads (Linux, WSL)")
+    program = tmp_path / ("profile_check" + "".join(f"_{name}" for name in sanitizers))
+    flags = [f"-fsanitize={','.join(sanitizers)}", "-fno-omit-frame-pointer"] if sanitizers else []
+    built = subprocess.run([compiler, "-std=gnu11", "-Wall", "-Werror", "-DHALO_PROFILE", "-pthread", "-g", "-O1",
+                            *flags, "-idirafter", "port/linux/include", "-Iport/linux/src",
+                            "-o", str(program),
+                            "tools/profile_check.c", *PROFILE_SOURCES],
+                           cwd=ROOT, capture_output=True, text=True)
+    if built.returncode != 0 and sanitizers and "sanitize" in built.stderr:
+        pytest.skip(f"{compiler} cannot build with {sanitizers}")
+    assert built.returncode == 0, built.stderr[-4000:]
+    return program
+
+
+def run_check(program, folder):
+    folder.mkdir(exist_ok=True)
+    result = subprocess.run([str(program), str(folder)], capture_output=True, text=True, timeout=300,
+                            env={**os.environ, "ASAN_OPTIONS": "detect_leaks=1", "TSAN_OPTIONS": "halt_on_error=1"})
+    assert result.returncode == 0, result.stdout + result.stderr[-4000:]
+    assert "PASS" in result.stdout
+
+
+def test_check_program_passes(tmp_path):
+    run_check(build_check(tmp_path, []), tmp_path / "out")
+
+
+def test_check_program_has_no_leaks_or_memory_errors(tmp_path):
+    """AddressSanitizer and LeakSanitizer over every recording the check
+    makes: arenas, the writer's files, the parts"""
+    run_check(build_check(tmp_path, ["address", "undefined"]), tmp_path / "out")
+
+
+def test_check_program_has_no_data_races(tmp_path):
+    """ThreadSanitizer: the p2p track, the writer hand-off, the recording
+    flag"""
+    run_check(build_check(tmp_path, ["thread"]), tmp_path / "out")
+
+
+@pytest.fixture(scope="module")
+def written_parts(tmp_path_factory):
+    folder = tmp_path_factory.mktemp("written")
+    run_check(build_check(tmp_path_factory.mktemp("build"), []), folder)
+    recordings = {}
+    for path in folder.glob("*.part*.json"):
+        try:
+            header = json.loads(path.read_text(encoding="utf-8"))["halo"]["header"]
+        except (OSError, json.JSONDecodeError, KeyError):
+            continue
+        recordings.setdefault(header["recording"], []).append((header["part"], path))
+    parts = max(recordings.values(), key=len)
+    assert len(parts) >= 2, "the real C recording is split into parts"
+    return [path for number, path in sorted(parts)]
+
+
+def test_written_parts_are_traces(written_parts):
+    for path in written_parts:
+        text = path.read_text(encoding="utf-8")
+        trace = json.loads(text)
+        assert list(trace) == ["halo", "cpu_summary", "traceEvents", "displayTimeUnit"]
+        assert text.startswith('{"halo": {\n"header": {')
+        assert trace["halo"]["header"]["last_part"] == (path == written_parts[-1])
+        header = trace["halo"]["header"]
+        assert (header["role"], header["own_machine"], header["players"], header["players_most"]) == (
+            "host", -1, 2, 5)
+        assert (header["map_name"], header["gametype"]) == ("b30", "campaign")
+        lines = text.splitlines()
+        events = lines.index('"traceEvents": [')
+        # one event a line, the scopes in order of their start
+        starts = [json.loads(line.rstrip(","))["ts"] for line in lines[events + 1:-2] if '"ph":"X"' in line]
+        assert starts == sorted(starts)
+        assert '"quote\\"back\\\\slash"' in text or path != written_parts[0]
+
+
+def test_written_parts_nest_on_tracks(written_parts):
+    trace = json.loads(written_parts[0].read_text(encoding="utf-8"))
+    names = {event["args"]["name"] for event in trace["traceEvents"] if event["ph"] == "M"}
+    assert {"game", "p2p"} <= names
+    scopes = [event for event in trace["traceEvents"] if event["ph"] == "X" and event["tid"] == 1]
+    frame = next(event for event in scopes if event["name"] == "frame")
+    inside = [event for event in scopes if frame["ts"] <= event["ts"] < frame["ts"] + frame["dur"] and event is not frame]
+    assert inside and all(event["ts"] + event["dur"] <= frame["ts"] + frame["dur"] + 0.001 for event in inside)
+
+
+def test_written_parts_import_in_perfetto(written_parts):
+    """trace_processor's import, when the perfetto package is installed (run
+    by hand on a real recording otherwise)"""
+    trace_processor = pytest.importorskip("perfetto.trace_processor")
+    with trace_processor.TraceProcessor(trace=str(written_parts[0])) as processor:
+        errors = processor.query("select name, value from stats where severity = 'error' and value > 0")
+        rows = list(errors)
+    assert not rows, [(row.name, row.value) for row in rows]
+
+
+def test_written_parts_read_by_the_report(written_parts):
+    recording = net_report.Recording(written_parts[0])
+    assert recording.complete and not recording.warnings
+    cpu_rows = [dict(zip(summary["columns"], row)) for summary in
+                [json.loads(path.read_text(encoding="utf-8"))["cpu_summary"] for path in written_parts]
+                for row in summary["rows"]]
+    totals = {}
+    for row in cpu_rows:
+        totals[row["name"]] = totals.get(row["name"], 0) + row["count"]
+    assert totals["texture"] == 2400
+    assert totals["render_model"] == 2400
+    assert totals["aggregate_child"] == 2400
+    frames = sum(1 for path in written_parts for event in json.loads(path.read_text(encoding="utf-8"))["traceEvents"]
+                 if event["ph"] == "X" and event["name"] == "frame")
+    assert recording.cpu["frames"] == frames
+
+
+# ---------- tools/net_report.py
+
+EXPECTED_SUMMARY = ROOT / "tools" / "profile_fixture.summary.txt"
+
+
+def cpu_recording(tmp_path, role="host"):
+    base = tmp_path / f"compat_{role}"
+    for number, start, duration in ((1, 0.0, 1.25), (2, 1.25, 2.75)):
+        halo, cpu = profile_fixture.part(number, [number - 1], number == 2, 0, 0)
+        halo["header"].update(role=role, start_s=start, duration_s=duration)
+        profile_fixture.write_part(Path(f"{base}.part{number}.json"), {"header": halo["header"]}, cpu)
+    return net_report.Recording(base)
+
+
+def test_cpu_only_duration_comes_from_each_part_header(tmp_path):
+    recording = cpu_recording(tmp_path)
+    assert recording.select() == 4.0
+    assert recording.select(0.5, 3.0) == 2.5
+    assert recording.select(5.0, 6.0) == 0.0
+
+
+
+def test_cpu_report_prints_and_exports_only_cpu_measurements(tmp_path, capsys):
+    base = profile_fixture.write_recording(tmp_path)
+    directory = tmp_path / "csv"
+    assert net_report.main([str(base), "--no-summary", "--csv", str(directory)]) == 0
+    output = capsys.readouterr().out
+    assert "## cpu scopes" in output and "## worst frames" in output
+    assert "## traffic" not in output and "## message types" not in output
+    assert "wire_rtt_ms" not in output and "msgs/s" not in output
+    assert {path.name.rsplit(".", 2)[1] for path in directory.glob("*.csv")} == {"cpu", "worst_frames"}
+
+
+@pytest.fixture
+def host(tmp_path):
+    return profile_fixture.write_recording(tmp_path)
+
+
+def test_report_summary_is_the_expected_one(host):
+    assert net_report.main([str(host) + ".part2.json"]) == 0
+    written = Path(str(host) + ".summary.txt").read_text(encoding="ascii")
+    assert written == EXPECTED_SUMMARY.read_text(encoding="ascii")
+    assert len(written.splitlines()) <= net_report.SUMMARY_LINE_LIMIT
+
+
+def test_report_uses_players_most_and_accepts_old_headers(tmp_path):
+    base = profile_fixture.write_recording(tmp_path / "legacy")
+    paths = [Path(f"{base}.part{number}.json") for number in (1, 2, 3)]
+    for index, path in enumerate(paths):
+        data = json.loads(path.read_text(encoding="utf-8"))
+        header = data["halo"]["header"]
+        for key in ("map_name", "gametype", "players_most"):
+            header.pop(key, None)
+        header["players"] = 1 + index
+        profile_fixture.write_part(path, data["halo"], data["cpu_summary"])
+    old_parts_report = net_report.Recording(paths[0])
+    old_summary = net_report.summary_lines(old_parts_report, None, None, 40)
+    assert any("players: 1 at start, 3 most" in line for line in old_summary)
+    assert net_report.main([str(paths[0]), "--no-summary"]) == 0
+
+
+def test_report_summary_uses_current_players_most(tmp_path):
+    base = profile_fixture.write_recording(tmp_path / "current")
+    last = Path(f"{base}.part3.json")
+    data = json.loads(last.read_text(encoding="utf-8"))
+    data["halo"]["header"]["players_most"] = 9
+    profile_fixture.write_part(last, data["halo"], data["cpu_summary"])
+    recording = net_report.Recording(Path(f"{base}.part1.json"))
+    summary = net_report.summary_lines(recording, None, None, 40)
+    assert any("players: 3 at start, 9 most" in line for line in summary)
+
+
+def test_report_merges_parts_as_one(tmp_path):
+    split = profile_fixture.write_recording(tmp_path / "split")
+    whole = profile_fixture.write_recording(tmp_path / "whole", split=False)
+    assert net_report.main([str(split), "--no-summary", "--csv", str(tmp_path / "split_csv")]) == 0
+    assert net_report.main([str(whole), "--no-summary", "--csv", str(tmp_path / "whole_csv")]) == 0
+    for table in sorted((tmp_path / "split_csv").glob("*.csv")):
+        if table.name.endswith(".worst_frames.csv"):
+            continue
+        assert table.read_text() == (tmp_path / "whole_csv" / table.name).read_text(), table.name
+
+
+def test_report_warns_about_a_missing_part(host, capsys):
+    Path(str(host) + ".part2.json").unlink()
+    net_report.main([str(host), "--no-summary"])
+    captured = capsys.readouterr()
+    assert "part 2 of profile_20261005-142233_host is missing" in captured.err
+    assert "(incomplete)" in captured.out
+
+
+def test_report_warns_about_no_last_part(host, capsys):
+    Path(str(host) + ".part3.json").unlink()
+    net_report.main([str(host), "--no-summary"])
+    assert "has no last part: the recording is incomplete" in capsys.readouterr().err
+
+
+def test_summary_glossary_has_one_line_per_printed_column(host):
+    net_report.main([str(host)])
+    lines = Path(str(host) + ".summary.txt").read_text(encoding="ascii").splitlines()
+    start = lines.index("## columns") + 1
+    end = lines.index("", start)
+    glossary = [re.split(r"\s{2,}", line, maxsplit=1)[0] for line in lines[start:end]]
+    printed = set()
+    for index, line in enumerate(lines[end:], end):
+        if line.startswith("## ") and index + 1 < len(lines) and lines[index + 1] not in ("", "(none)"):
+            printed.update(re.split(r"\s{2,}", lines[index + 1].strip()))
+    assert printed and len(glossary) == len(set(glossary))
+    assert set(glossary) == printed
+
+
+def test_summary_file_ignores_top(host):
+    assert net_report.main([str(host), "--top", "1"]) == 0
+    written = Path(str(host) + ".summary.txt").read_text(encoding="ascii")
+    assert written == EXPECTED_SUMMARY.read_text(encoding="ascii")
+    assert len(written.splitlines()) <= net_report.SUMMARY_LINE_LIMIT
+
+
+def test_report_top_limits_the_printed_tables(host, capsys):
+    net_report.main([str(host), "--no-summary", "--top", "1"])
+    assert "... 4 more rows (net_report.py --top N)" in capsys.readouterr().out
+
+
+def test_report_says_cpu_tables_cover_the_whole_recording(host, capsys):
+    net_report.main([str(host), "--no-summary", "--from", "2", "--to", "4"])
+    out = capsys.readouterr().out
+    assert "# window: 2.0 s selected (seconds 2 to 4)" in out
+    assert "cpu tables, ticks and frames cover the whole recording" in out
+    assert "## cpu scopes (top 40 by total_ms, whole recording)" in out
+    assert "## worst frames (10, whole recording)" in out
+
+
+def test_report_names_the_broken_part(host, capsys):
+    path = Path(str(host) + ".part2.json")
+    path.write_text(path.read_text().replace('"cpu_summary"', '"cpu_summery"'), encoding="utf-8")
+    assert net_report.main([str(host), "--no-summary"]) == 1
+    err = capsys.readouterr().err
+    assert err.startswith("net_report: ") and "part2" in err and "cpu_summary" in err
+    path.write_text(Path(str(host) + ".part1.json").read_text().replace('"last_part"', '"last_prt"'), encoding="utf-8")
+    assert net_report.main([str(host), "--no-summary"]) == 1
+    assert "last_part" in capsys.readouterr().err
+
+
+def test_windows_compile_command_parser_preserves_quoted_define_and_paths():
+    command = ('clang -I"source/saved films" -include port\\windows\\include\\prefix.h '
+               '-I"C:\\Program Files\\LLVM\\include" '
+               '-DHALO_BUILD_FLAVOR=\\"release\\" source\\game.c -o build\\game.o')
+    assert parse_compile_command(command, windows=True) == [
+        "clang", "-Isource/saved films", "-include", "port/windows/include/prefix.h",
+        "-IC:/Program Files/LLVM/include", '-DHALO_BUILD_FLAVOR="release"',
+        "source/game.c", "-o", "build/game.o"]
+
+
+def test_console_words_and_record_seconds_use_the_real_parser(tmp_path):
+    compiler = check_compiler()
+    if not compiler:
+        pytest.skip("needs a C compiler (Linux, WSL)")
+    text = (ROOT / "port/linux/game/profile_console.c").read_text()
+    word = text[text.index("static char const *profile_console_word("):text.index("/* ---------- public code */")]
+    command = text[text.index("boolean profile_console_command("):text.rindex("\n#endif")]
+    program = tmp_path / "console_check"
+    code = tmp_path / "console_check.c"
+    # Compile the game's actual parsing functions; only their external game effects are stubbed.
+    code.write_text(r'''
+#include <assert.h>
+#include <stdlib.h>
+#include <string.h>
+#include "profile_trace.h"
+typedef int boolean;
+#define TRUE 1
+#define FALSE 0
+static int requests;
+static double accepted_seconds;
+static void profile_console_install(void) {}
+static long config_integer(const char *name) { (void)name; return 32; }
+static void console_printf(boolean flag, const char *format, ...) { (void)flag; (void)format; }
+int profile_trace_request_start(double seconds, int when, long memory) {
+    assert(when == _profile_trace_when_now && memory == 32);
+    requests++; accepted_seconds = seconds; return _profile_trace_answer_armed;
+}
+int profile_trace_request_stop(void) { return _profile_trace_answer_not_recording; }
+void profile_trace_status(struct profile_trace_status *status) { memset(status, 0, sizeof(*status)); }
+''' + word + command + r'''
+int main(void) {
+    assert(strcmp(profile_console_word(" (PROFILE_RECORD 1.5)", "profile_record"), "1.5)") == 0);
+    assert(profile_console_word("profile_record_extra", "profile_record") == NULL);
+    assert(profile_console_command("PROFILE_RECORD 1.5"));
+    assert(requests == 1 && accepted_seconds == 1.5);
+    assert(profile_console_command("profile_record x"));
+    assert(requests == 1);
+    assert(profile_console_command("profile_record -1"));
+    assert(requests == 1);
+    assert(profile_console_command("profile_record"));
+    assert(requests == 2 && accepted_seconds == 0.0);
+    assert(!profile_console_command("profile_record_extra 1"));
+    return 0;
+}
+''')
+    subprocess.run([compiler, "-std=gnu11", "-Wall", "-Werror", "-DHALO_PROFILE",
+                    "-I", str(ROOT / "port/linux/include"), str(code), "-o", str(program)], check=True)
+    subprocess.run([str(program)], check=True)
+
+
+# ---------- a normal build is unchanged
+
+PROFILE_PREFIXES = ("profile_trace_", "profile_net_", "profile_json_", "profile_overlay_")
+
+
+def parse_compile_command(command, windows=False):
+    """Split a Ninja C command, normalizing Windows path separators without changing escaped quotes."""
+    if windows:
+        command = re.sub(r'\\(?!")', "/", command)
+    return shlex.split(command, posix=True)
+
+
+def unavailable(reason):
+    """a run that asks for the check (HALO_PROFILE_BASE or HALO_PROFILE_OBJECTS) must not skip it silently"""
+    if os.environ.get("HALO_PROFILE_BASE") or os.environ.get("HALO_PROFILE_OBJECTS"):
+        pytest.fail(reason)
+    pytest.skip(reason)
+
+
+def preprocess_flags():
+    """the game's or the platform layer's compile flags for this computer's
+    build, as ninja has them, without HALO_PROFILE and without what makes
+    an object; absolute where they name a generated file"""
+    missing = [name for name in ("clang", "ninja") if not shutil.which(name)]
+    if not (ROOT / "build.ninja").is_file():
+        missing.append("a configured build (build.ninja)")
+    if missing:
+        unavailable("needs " + ", ".join(missing))
+    # (HALO_PROFILE_OBJECTS names another configured flavour's object folder, such as build/android/guest/obj,
+    # where this computer has no build of its own)
+    objects = os.environ.get("HALO_PROFILE_OBJECTS") or f"build/{'windows' if os.name == 'nt' else 'linux'}/obj"
+
+    def flags(object_path):
+        listing = subprocess.run(["ninja", "-t", "commands", object_path], cwd=ROOT, capture_output=True, text=True)
+        if listing.returncode != 0:
+            unavailable(f"needs a build.ninja that has {object_path}")
+        command = listing.stdout.strip().splitlines()[-1]
+        words = parse_compile_command(command, windows=os.name == "nt")
+        while words and not words[0].startswith("-"):
+            words = words[1:]
+        # (the Android guest's command is a pipeline whose first compile makes assembly)
+        words = words[:words.index("&&")] if "&&" in words else words
+        kept, skip = [], False
+        for word in words:
+            if skip:
+                skip = False
+            elif word in ("-MF", "-o", "-c"):
+                skip = True
+            elif word in ("-MMD", "-S") or word == "-DHALO_PROFILE" or word.startswith(("-flto", "-fprofile-use")):
+                continue
+            elif word.endswith(".c") and not word.startswith("-"):
+                continue
+            elif word.startswith(("build/", "build\\")):
+                kept.append(str(ROOT / word))
+            elif word.startswith(("-Ibuild/", "-Ibuild\\")):
+                kept.append("-I" + str(ROOT / word[2:]))
+            else:
+                kept.append(word)
+        return kept
+
+    flag_sets = {
+        "game": flags(f"{objects}/source/game/game.o"),
+        "platform": flags(f"{objects}/port/linux/src/p2p.o"),
+        "port_game": flags(f"{objects}/port/linux/game/network_coop.o"),
+    }
+    # (only a missing 32-bit C library is "no build here"; any other error is a wrong command, which must not hide)
+    probe = subprocess.run(["clang", *flag_sets["game"], "-E", "-P", "-x", "c", "-"], cwd=ROOT,
+                           input="#include <stddef.h>\n#include <stdio.h>\n",
+                           capture_output=True, text=True)
+    if probe.returncode != 0:
+        reason = "the game's flags do not preprocess: " + next((line for line in probe.stderr.splitlines() if "error" in line), "")[:200]
+        if "bits/libc-header-start.h" in probe.stderr:
+            pytest.skip("needs a 32-bit C library (gcc-multilib); " + reason)
+        pytest.fail(reason)
+    return flag_sets
+
+
+def flags_for(path, flag_sets):
+    if path.startswith("port/linux/src/"):
+        return flag_sets["platform"]
+    if path.startswith("port/linux/game/"):
+        return flag_sets["port_game"]
+    return flag_sets["game"]
+
+
+def preprocessed(tree, path, flags):
+    # (path None: an empty file, which is all that the forced includes leave of a file that is empty)
+    arguments = ["-x", "c", "-"] if path is None else [path]
+    # (__DATE__ and __TIME__ pinned: main.c prints them, and the two trees can be preprocessed a second apart)
+    pinned = ["-Wno-builtin-macro-redefined", '-D__DATE__="Jan  1 2000"', '-D__TIME__="00:00:00"']
+    result = subprocess.run(["clang", *flags, *pinned, "-E", "-P", *arguments], cwd=tree,
+                            input="" if path is None else None,
+                            capture_output=True, text=True)
+    assert result.returncode == 0, f"{path}: {result.stderr[-2000:]}"
+    # (only the tokens: blank lines and layout differ where #ifdef blocks were)
+    return " ".join(result.stdout.split())
+
+
+def includers_of_changed_headers(base, already):
+    """the C files that include a header that changed since the base: a header's #ifdef can change them too"""
+    def names(*arguments):
+        return subprocess.run([GIT, *arguments], cwd=ROOT, capture_output=True, text=True, check=True).stdout.split()
+
+    added = set(names("diff", "--name-only", "--diff-filter=A", base, "HEAD", "--", "*.c"))
+    found = set()
+    for header in names("diff", "--name-only", "--diff-filter=M", base, "HEAD", "--", "*.h"):
+        pattern = r'#[ 	]*include[ 	]*[<"]([^">]*/)?' + re.escape(header.rsplit("/", 1)[-1]) + '[">]'
+        for path in names("grep", "-l", "-E", pattern, "HEAD", "--", "*.c"):
+            path = path.split(":", 1)[1]
+            if path.startswith(("source/", "port/linux/src/", "port/linux/game/")) and path not in added:
+                found.add(path)
+    return sorted(found - set(already))
+
+
+@pytest.mark.skipif(not os.environ.get("HALO_PROFILE_BASE"), reason="HALO_PROFILE_BASE names the base commit")
+def test_normal_build_preprocesses_as_before(tmp_path):
+    base = os.environ["HALO_PROFILE_BASE"]
+    flag_sets = preprocess_flags()
+    changed = subprocess.run([GIT, "diff", "--name-only", "--diff-filter=M", base, "HEAD", "--", "*.c"], cwd=ROOT,
+                             capture_output=True, text=True, check=True).stdout.split()
+    assert changed, "no C file changed since the base"
+    changed += includers_of_changed_headers(base, changed)
+    tree = tmp_path / "base"
+    tree.mkdir()
+    archive = subprocess.run([GIT, "archive", "--format=tar", base], cwd=ROOT, check=True, capture_output=True).stdout
+    with tarfile.open(fileobj=io.BytesIO(archive)) as reference:
+        reference.extractall(tree)
+    for path in changed:
+        flags = flags_for(path, flag_sets)
+        assert preprocessed(tree, path, flags) == preprocessed(ROOT, path, flags), path
+
+
+def test_new_files_are_empty_in_a_normal_build():
+    flag_sets = preprocess_flags()
+    # (found, not listed: a new profile_*.c that forgets its #ifdef shows up here)
+    paths = sorted(str(path.relative_to(ROOT)).replace("\\", "/")
+                   for directory in ("port/linux/src", "port/linux/game")
+                   for path in (ROOT / directory).glob("profile_*.c"))
+    assert set(paths) == {*PROFILE_SOURCES, "port/linux/game/profile_console.c"}, paths
+    for path in paths:
+        flags = flags_for(path, flag_sets)
+        assert preprocessed(ROOT, path, flags) == preprocessed(ROOT, None, flags), path
+
+
+def test_normal_build_has_no_profiling_symbols():
+    ninja_file = ROOT / "build.ninja"
+    if not ninja_file.is_file():
+        pytest.skip("needs a configured build (build.ninja)")
+    if "-DHALO_PROFILE" in ninja_file.read_text(encoding="utf-8"):
+        pytest.skip("a profiling build is configured")
+    nm = shutil.which("llvm-nm") or shutil.which("nm")
+    if os.name == "nt" or os.environ.get("HALO_PROFILE_OBJECTS"):
+        folder = ROOT / (os.environ.get("HALO_PROFILE_OBJECTS") or "build/windows/obj")
+        objects = sorted(str(path) for path in folder.rglob("*.o"))
+    else:
+        objects = [str(ROOT / "build/linux/halo")] if (ROOT / "build/linux/halo").is_file() else []
+    if not nm:
+        unavailable("needs nm")
+    if not objects:
+        unavailable("needs a built normal build (build/windows/obj/**/*.o, build/linux/halo, or the objects in HALO_PROFILE_OBJECTS)")
+    found, words, defined = set(), set(), 0
+    for start in range(0, len(objects), 200):
+        listing = subprocess.run([nm, "--defined-only", *objects[start:start + 200]], capture_output=True, text=True)
+        # (an nm that cannot read the objects, such as bitcode from --lto, lists nothing and would pass)
+        assert listing.returncode == 0, listing.stderr[-1000:]
+        words |= {word.lstrip("_") for word in listing.stdout.split()}
+        defined += sum(len(line.split()) == 3 for line in listing.stdout.splitlines())
+    found = {word for word in words if word.startswith(PROFILE_PREFIXES)}
+    # (a count, not a named symbol: link-time optimization inlines the functions that have one caller. The game's
+    # objects list thousands; an unreadable or a near-empty set lists none)
+    assert defined >= 300, f"nm lists {defined} defined symbols: it cannot read these objects"
+    assert not found, sorted(found)[:20]

tools/windows_build.py

@@ -19,7 +19,7 @@ from pathlib import Path
 from typing import Any, Dict, List, Optional
 
 from .linux_build import (LINUX_PROFILE, MINIUPNPC_DIR, OPTIMISATION, WINDOWS_PROFILE, XDK_INCLUDE, lto_mode,
-                          march_flag, miniupnpc_sources, pgo_mode, compile_launcher, game_defines_and_includes,
+                          march_flag, miniupnpc_sources, pgo_mode, compile_launcher, configuration_defines, game_defines_and_includes,
                           game_sources, musl_math_cflags, musl_math_sources, opus_cflags, opus_sources, pgo_profile,
                           profile_use_flags, xdk_headers)
 from .embed_assets import hud_assets_build, hud_configure_inputs
@@ -324,8 +324,8 @@ def generate_windows_build(n: Writer, sln: Any) -> None:
     # (a debug build checks its stack frames (/GS), and stops at the first
     # one overrun, as at the first failed assertion; a release build does
     # not, so that an overrun nobody has met cannot end a game)
-    abi = " ".join(WINDOWS_ABI_FLAGS + [march_flag(sln)] + (["-DHALO_RELEASE"] if getattr(sln, "port_release", False)
-                                                            else ["-fstack-protector-strong"]))
+    abi = " ".join(WINDOWS_ABI_FLAGS + [march_flag(sln)] + configuration_defines(sln)
+                   + ([] if getattr(sln, "port_release", False) else ["-fstack-protector-strong"]))
     sdl_include = SDL_DIR / "include"
     libs = " ".join(
         [_quote(SDL_DIR / "lib" / "x86" / "SDL3.lib")]