VR performance diagnostics: the frame's parts, the layer copies, Mesa's GL thread switch

- vr.log_performance: frames with game ticks and without, how many late,
  and their time by part (input, ticks, camera, draw, present)
- with XR_META_performance_metrics: per frame, each layer copy's time, the
  waits for swapchain images and xrEndFrame
- debug.gl_thread: Mesa's GL thread on or off (mesa_glthread) for trying

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

port/android/host/host_main.c

@@ -326,6 +326,17 @@ static void *game_main(void *unused)
 	ranges: the headset's runtime, loaded by the probe, maps its libraries
 	wherever there is room, the Xbox window at 0x80000000 included */
 	snprintf(path, sizeof(path), "%s/config.toml", data_root);
+	{
+		/* (debug.gl_thread: Mesa's GL thread on or off, as the driver's
+		mesa_glthread, before the GL context is made; -1 leaves it be) */
+		double gl_thread = config_number(path, "debug.gl_thread", -1.0);
+
+		if (gl_thread >= 0.0)
+		{
+			setenv("mesa_glthread", gl_thread != 0.0 ? "true" : "false", 1);
+			host_logf(HOST_LOG_INFO, "Mesa's GL thread %s (debug.gl_thread)", gl_thread != 0.0 ? "on" : "off");
+		}
+	}
 	{
 		int eye_width, eye_height;
 

port/android/host/host_xr.c

@@ -38,6 +38,8 @@ picture; the copy flips them to GL's bottom-up images.
 #include <string.h>
 #include <time.h>
 #include <unistd.h>
+#include <sched.h>
+#include <stdio.h>
 
 #define XR_USE_PLATFORM_ANDROID
 #define XR_USE_GRAPHICS_API_OPENGL_ES
@@ -119,6 +121,22 @@ static struct
 	int left_grip_valid;
 
 	int has_performance_settings;
+	/* (XR_META_performance_metrics: the compositor's counts, in the log,
+	for telling frames shown late from the game's own pace) */
+	int has_metrics;
+	PFN_xrQueryPerformanceMetricsCounterMETA query_metric;
+	XrPath metric_paths[16];
+	uint32_t metric_count;
+	struct timespec metrics_logged;
+	/* (SteamVR: the frames' thread kept on the fast cores, xr_fast_cores) */
+	int steamvr;
+	int cores_pinned;
+	/* (with the metrics: the time the copies into the layers' images and
+	xrEndFrame took, since the last line, and the frames) */
+	double copy_seconds[HALO_XR_LAYER_COUNT];
+	double end_seconds;
+	double acquire_seconds;
+	int timed_frames;
 	int has_refresh_rate;
 	PFN_xrRequestDisplayRefreshRateFB request_refresh_rate;
 	PFN_xrGetDisplayRefreshRateFB get_refresh_rate;
@@ -1080,6 +1098,9 @@ int host_xr_probe(float resolution_scale, int *eye_width, int *eye_height)
 	xr.has_refresh_rate = has_extension(extensions, extension_count, XR_FB_DISPLAY_REFRESH_RATE_EXTENSION_NAME);
 	if (xr.has_refresh_rate)
 		enabled[enabled_count++] = XR_FB_DISPLAY_REFRESH_RATE_EXTENSION_NAME;
+	xr.has_metrics = has_extension(extensions, extension_count, XR_META_PERFORMANCE_METRICS_EXTENSION_NAME);
+	if (xr.has_metrics)
+		enabled[enabled_count++] = XR_META_PERFORMANCE_METRICS_EXTENSION_NAME;
 
 	android.applicationVM = machine;
 	android.applicationActivity = activity;
@@ -1113,6 +1134,7 @@ int host_xr_probe(float resolution_scale, int *eye_width, int *eye_height)
 		if (XR_SUCCEEDED(xrGetInstanceProperties(xr.instance, &instance)))
 		{
 			xr.quad_alpha_from_colour = strstr(instance.runtimeName, "SteamVR") != NULL;
+			xr.steamvr = xr.quad_alpha_from_colour;
 			host_logf(HOST_LOG_INFO, "xr: runtime %s", instance.runtimeName);
 		}
 		if (choice)
@@ -1226,6 +1248,25 @@ int host_xr_initialize(struct halo_xr_info *info, float wanted_refresh_rate)
 			xr.get_refresh_rate(xr.session, &info->refresh_rate);
 	}
 
+	if (xr.has_metrics)
+	{
+		PFN_xrEnumeratePerformanceMetricsCounterPathsMETA enumerate = NULL;
+		PFN_xrSetPerformanceMetricsStateMETA set_state = NULL;
+		XrPerformanceMetricsStateMETA state = { XR_TYPE_PERFORMANCE_METRICS_STATE_META };
+
+		xrGetInstanceProcAddr(xr.instance, "xrEnumeratePerformanceMetricsCounterPathsMETA",
+			(PFN_xrVoidFunction *)&enumerate);
+		xrGetInstanceProcAddr(xr.instance, "xrSetPerformanceMetricsStateMETA", (PFN_xrVoidFunction *)&set_state);
+		xrGetInstanceProcAddr(xr.instance, "xrQueryPerformanceMetricsCounterMETA",
+			(PFN_xrVoidFunction *)&xr.query_metric);
+		state.enabled = XR_TRUE;
+		xr.has_metrics = enumerate && set_state && xr.query_metric &&
+			XR_SUCCEEDED(enumerate(xr.instance, 16, &xr.metric_count, xr.metric_paths)) &&
+			XR_SUCCEEDED(set_state(xr.session, &state));
+		host_logf(HOST_LOG_INFO, "xr: performance metrics %s (%u counters)", xr.has_metrics ? "on" : "off",
+			xr.has_metrics ? xr.metric_count : 0);
+	}
+
 	if (xr.has_performance_settings)
 	{
 		/* the game's one busy thread and its GPU work both need the clocks
@@ -1405,8 +1446,30 @@ int host_xr_copy_layer_array(int layer, uint32_t texture, int array_layer)
 
 /* copies part of a render target (left, top, right, bottom, 0..1 from its
 top left) into a layer's image */
+static double seconds_now(void)
+{
+	struct timespec now;
+
+	clock_gettime(CLOCK_MONOTONIC, &now);
+	return (double)now.tv_sec + (double)now.tv_nsec * 1e-9;
+}
+
+static int copy_layer_region(int layer, uint32_t texture, int clear_alpha, float left, float top, float right,
+	float bottom);
+
 int host_xr_copy_layer_region(int layer, uint32_t texture, int clear_alpha, float left, float top, float right,
 	float bottom)
+{
+	double start = xr.has_metrics ? seconds_now() : 0.0;
+	int copied = copy_layer_region(layer, texture, clear_alpha, left, top, right, bottom);
+
+	if (xr.has_metrics && layer >= 0 && layer < HALO_XR_LAYER_COUNT)
+		xr.copy_seconds[layer] += seconds_now() - start;
+	return copied;
+}
+
+static int copy_layer_region(int layer, uint32_t texture, int clear_alpha, float left, float top, float right,
+	float bottom)
 {
 	struct xr_swapchain *swapchain;
 	XrSwapchainImageAcquireInfo acquire = { XR_TYPE_SWAPCHAIN_IMAGE_ACQUIRE_INFO };
@@ -1425,8 +1488,14 @@ int host_xr_copy_layer_region(int layer, uint32_t texture, int clear_alpha, floa
 		return 0;
 	}
 	wait.timeout = XR_INFINITE_DURATION;
-	if (!xr_ok(xrWaitSwapchainImage(swapchain->handle, &wait), "xrWaitSwapchainImage"))
-		return 0;
+	{
+		double start = xr.has_metrics ? seconds_now() : 0.0;
+
+		if (!xr_ok(xrWaitSwapchainImage(swapchain->handle, &wait), "xrWaitSwapchainImage"))
+			return 0;
+		if (xr.has_metrics)
+			xr.acquire_seconds += seconds_now() - start;
+	}
 
 	gl_save(&saved);
 	glBindFramebuffer(GL_DRAW_FRAMEBUFFER, swapchain->framebuffers[swapchain->acquired_index]);
@@ -1520,6 +1589,59 @@ int host_xr_copy_layer_region(int layer, uint32_t texture, int clear_alpha, floa
 	return 1;
 }
 
+/* The Steam Frame: Android in a container, without XR_EXT_performance_settings
+to ask for the clocks, and the scheduler free to put the game's one busy
+thread, which simulates and draws each frame, on a slow core (its two
+2.3 GHz ones) now and then: frames late to the compositor, shown twice,
+the picture doubled as the head turns. The thread that ends the frames is
+kept on the cores no slower than nine tenths of the fastest. */
+static void xr_fast_cores(void)
+{
+	cpu_set_t set;
+	long fastest = 0, speeds[CPU_SETSIZE];
+	int cpu, count = 0;
+	char line[128] = "";
+
+	for (cpu = 0; cpu < CPU_SETSIZE && cpu < 64; cpu++)
+	{
+		char path[96];
+		FILE *file;
+
+		speeds[cpu] = 0;
+		snprintf(path, sizeof(path), "/sys/devices/system/cpu/cpu%d/cpufreq/cpuinfo_max_freq", cpu);
+		file = fopen(path, "r");
+		if (!file)
+			continue;
+		if (fscanf(file, "%ld", &speeds[cpu]) != 1)
+			speeds[cpu] = 0;
+		fclose(file);
+		if (speeds[cpu] > fastest)
+			fastest = speeds[cpu];
+	}
+	if (!fastest)
+	{
+		host_logf(HOST_LOG_INFO, "xr: the cores' speeds unknown: the frames' thread left where it runs");
+		return;
+	}
+	CPU_ZERO(&set);
+	for (cpu = 0; cpu < CPU_SETSIZE && cpu < 64; cpu++)
+	{
+		if (speeds[cpu] && speeds[cpu] * 10 >= fastest * 9)
+		{
+			char item[8];
+
+			CPU_SET(cpu, &set);
+			count++;
+			snprintf(item, sizeof(item), " %d", cpu);
+			strcat(line, item);
+		}
+	}
+	if (count && sched_setaffinity(0, sizeof(set), &set) == 0)
+		host_logf(HOST_LOG_INFO, "xr: the frames' thread on the fast cores:%s (fastest %ld MHz)", line, fastest / 1000);
+	else
+		host_logf(HOST_LOG_INFO, "xr: the frames' thread could not be kept on the fast cores");
+}
+
 int host_xr_end_frame(const struct halo_xr_submit *submit)
 {
 	XrFrameEndInfo end = { XR_TYPE_FRAME_END_INFO };
@@ -1662,11 +1784,81 @@ int host_xr_end_frame(const struct halo_xr_submit *submit)
 		}
 	}
 
+	if (xr.steamvr && !xr.cores_pinned)
+	{
+		xr.cores_pinned = 1;
+		if (!getenv("HALO_XR_ANY_CORE"))
+			xr_fast_cores();
+	}
+	/* (every five seconds, the compositor's counters, and the core the
+	frames' thread is on) */
+	if (xr.has_metrics)
+	{
+		struct timespec now;
+
+		clock_gettime(CLOCK_MONOTONIC, &now);
+		if (now.tv_sec - xr.metrics_logged.tv_sec >= 5)
+		{
+			char line[768] = "";
+			uint32_t counter;
+
+			xr.metrics_logged = now;
+			for (counter = 0; counter < xr.metric_count && counter < 16; counter++)
+			{
+				XrPerformanceMetricsCounterMETA value = { XR_TYPE_PERFORMANCE_METRICS_COUNTER_META };
+				char name[XR_MAX_PATH_LENGTH];
+				uint32_t length = 0;
+				char item[96];
+
+				if (!XR_SUCCEEDED(xr.query_metric(xr.session, xr.metric_paths[counter], &value)) ||
+					!XR_SUCCEEDED(xrPathToString(xr.instance, xr.metric_paths[counter], sizeof(name), &length, name)))
+				{
+					continue;
+				}
+				snprintf(item, sizeof(item), " %s=%g", strrchr(name, '/') ? strrchr(name, '/') + 1 : name,
+					(value.counterFlags & XR_PERFORMANCE_METRICS_COUNTER_FLOAT_VALUE_VALID_BIT_META) ?
+						(double)value.floatValue : (double)value.uintValue);
+				if (strlen(line) + strlen(item) < sizeof(line))
+					strcat(line, item);
+			}
+			host_logf(HOST_LOG_INFO, "xr: metrics%s, on core %d", line, sched_getcpu());
+			if (xr.timed_frames)
+			{
+				double frames = (double)xr.timed_frames;
+				char copies[256] = "";
+				int timed;
+
+				for (timed = 0; timed < HALO_XR_LAYER_COUNT; timed++)
+				{
+					char item[24];
+
+					snprintf(item, sizeof(item), " %d:%.2f", timed, xr.copy_seconds[timed] * 1e3 / frames);
+					strcat(copies, item);
+					xr.copy_seconds[timed] = 0.0;
+				}
+				host_logf(HOST_LOG_INFO, "xr: per frame ms: copies (layer:ms)%s; of them waiting for images %.2f; "
+					"xrEndFrame %.2f", copies, xr.acquire_seconds * 1e3 / frames, xr.end_seconds * 1e3 / frames);
+				xr.acquire_seconds = xr.end_seconds = 0.0;
+				xr.timed_frames = 0;
+			}
+		}
+	}
+
 	end.displayTime = xr.frame_state.predictedDisplayTime;
 	end.environmentBlendMode = XR_ENVIRONMENT_BLEND_MODE_OPAQUE;
 	end.layerCount = layer_count;
 	end.layers = layers;
-	return xr_ok(xrEndFrame(xr.session, &end), "xrEndFrame");
+	{
+		double start = xr.has_metrics ? seconds_now() : 0.0;
+		int ended = xr_ok(xrEndFrame(xr.session, &end), "xrEndFrame");
+
+		if (xr.has_metrics)
+		{
+			xr.end_seconds += seconds_now() - start;
+			xr.timed_frames++;
+		}
+		return ended;
+	}
 }
 
 void host_xr_set_vignette(float strength)

port/linux/game/bots.c

@@ -117,6 +117,10 @@ enum
 
 /* ---------- structures */
 
+/* (how many things to pick up it gives up at once, and for how long) */
+#define BOT_IGNORED_ITEMS 4
+#define BOT_IGNORE_ITEM_TICKS 600
+
 struct bot
 {
 	long player_index;
@@ -141,8 +145,20 @@ struct bot
 	while on that account: following a person, a thing to pick up */
 	short path_failures;
 	long follow_again_time;
-	long ignored_item_index;
-	long ignored_item_time;
+	/* things to pick up given up for a while (no way to them, or there and
+	not taken: on a ledge, out of reach), and how long it has stood by the
+	one it goes for */
+	long ignored_items[BOT_IGNORED_ITEMS];
+	long ignored_item_times[BOT_IGNORED_ITEMS];
+	short ignored_item_next;
+	/* (the nearest it has come to the thing it goes for, and when) */
+	long item_progress_index;
+	real item_best_distance;
+	long item_best_time;
+	/* stuck again and again about the same place (as at the foot of a ramp
+	or behind its rail): how often since when, to give the goal up */
+	short stuck_count;
+	long stuck_count_time;
 	real wander_yaw;
 	short weave_phase;
 	/* where it is going, and the way there */
@@ -231,6 +247,7 @@ static struct
 	long switches;
 	long stucks;
 	long long_stucks;
+	long gave_up;
 	long fail_start;
 	long fail_goal;
 	long fail_search;
@@ -540,18 +557,40 @@ the level between them at its knees */
 static boolean bot_clear_walk(
 	long unit_index,
 	real_point3d const *from,
-	real_point3d const *to)
+	real_point3d const *to,
+	boolean wide)
 {
 	struct collision_result collision;
-	real_point3d start = *from;
 	real_vector3d vector;
+	real length;
+	short line;
 
-	start.z += 0.3f;
 	vector.i = to->x - from->x;
 	vector.j = to->y - from->y;
 	vector.k = to->z - from->z;
-	return !collision_test_vector(FLAG(_collision_test_structure_bit) | FLAG(_collision_test_front_facing_surfaces_bit),
-		&start, &vector, unit_index, &collision);
+	length = (real)sqrt(vector.i * vector.i + vector.j * vector.j);
+	/* (at its knees and at its chest: a rail with room under it, a slit in
+	a wall, are not ways through; wide, along its shoulders too: a door it
+	would pass the middle of but catch its frame) */
+	for (line = 0; line < (wide && length > 0.001f ? 4 : 2); line++)
+	{
+		real_point3d start = *from;
+
+		start.z += line == 1 ? 1.0f : line ? 0.6f : 0.3f;
+		if (line >= 2)
+		{
+			real side = line == 2 ? 0.35f : -0.35f;
+
+			start.x += -vector.j / length * side;
+			start.y += vector.i / length * side;
+		}
+		if (collision_test_vector(FLAG(_collision_test_structure_bit) | FLAG(_collision_test_front_facing_surfaces_bit),
+			&start, &vector, unit_index, &collision))
+		{
+			return FALSE;
+		}
+	}
+	return TRUE;
 }
 
 static boolean bot_next_point_now(
@@ -592,7 +631,7 @@ static boolean bot_next_point_now(
 		real dy = bot->goal.y - position->y;
 
 		if (dx * dx + dy * dy < 3.0f * 3.0f && fabsf(bot->goal.z - position->z) < 0.6f &&
-			bot_clear_walk(unit_index, position, &bot->goal))
+			bot_clear_walk(unit_index, position, &bot->goal, FALSE))
 		{
 			*point = bot->goal;
 			return TRUE;
@@ -620,7 +659,7 @@ static boolean bot_next_point_now(
 
 				/* (on its own level only: one above may be in view over a
 				ledge that a ramp leads round to) */
-				if (fabsf(next->z - position->z) < 0.6f && bot_clear_walk(unit_index, position, next))
+				if (fabsf(next->z - position->z) < 0.6f && bot_clear_walk(unit_index, position, next, TRUE))
 				{
 					bot->path.step_index++;
 					if (bot->path.step_index >= bot->path.step_count)
@@ -642,17 +681,20 @@ static boolean bot_next_point_now(
 	return TRUE;
 }
 
-/* a goal when none is in sight: the nearest enemy, or somewhere near
-someone at random */
+/* a goal when none is in sight: an enemy, or somewhere near someone at
+random. Not all the nearest: each bot one of the three nearest (by its
+number), and while it is far, a few metres beside them, so that a team
+spreads out over the ways there instead of going as one crowd */
 static void bot_choose_goal(
 	struct bot *bot,
 	struct player_datum const *player,
 	real_point3d const *position)
 {
 	boolean teams = game_engine_has_teams();
-	real best_distance = 1000000.0f;
+	real best_distance[3] = { 1000000.0f, 1000000.0f, 1000000.0f };
+	real_point3d best_origin[3];
+	short found = 0;
 	short index;
-	boolean found = FALSE;
 
 	for (index = 0; index < MAXIMUM_TRACKED_PLAYERS; index++)
 	{
@@ -660,6 +702,7 @@ static void bot_choose_goal(
 		long unit_index;
 		real_point3d origin;
 		real distance;
+		short rank;
 
 		if (!other || other == player || (teams && other->team_index == player->team_index))
 			continue;
@@ -668,14 +711,38 @@ static void bot_choose_goal(
 			continue;
 		object_get_origin(unit_index, &origin);
 		distance = distance3d(position, &origin);
-		if (distance < best_distance)
+		/* (kept in order, nearest first) */
+		for (rank = 0; rank < 3 && distance >= best_distance[rank]; rank++)
+			;
+		if (rank == 3)
+			continue;
+		found = (short)MIN(found + 1, 3);
 		{
-			best_distance = distance;
-			bot->goal = origin;
-			found = TRUE;
+			short move;
+
+			for (move = 2; move > rank; move--)
+			{
+				best_distance[move] = best_distance[move - 1];
+				best_origin[move] = best_origin[move - 1];
+			}
+		}
+		best_distance[rank] = distance;
+		best_origin[rank] = origin;
+	}
+	if (found)
+	{
+		short pick = (short)(DATUM_INDEX_TO_ABSOLUTE_INDEX(bot->player_index) % found);
+
+		bot->goal = best_origin[pick];
+		if (best_distance[pick] > 25.0f)
+		{
+			real angle = (real)DATUM_INDEX_TO_ABSOLUTE_INDEX(bot->player_index) * 2.4f;
+
+			bot->goal.x += (real)cos(angle) * 6.0f;
+			bot->goal.y += (real)sin(angle) * 6.0f;
 		}
 	}
-	if (!found)
+	else
 	{
 		/* (no enemy alive: a few metres off, somewhere) */
 		real angle = bot_random() * 2.0f * _pi;
@@ -817,7 +884,59 @@ static real bot_item_worth(
 }
 
 /* the thing most worth going for near the bot, or NONE */
+static boolean bot_item_ignored(
+	struct bot const *bot,
+	long item_index)
+{
+	short index;
+
+	for (index = 0; index < BOT_IGNORED_ITEMS; index++)
+	{
+		if (bot->ignored_items[index] == item_index &&
+			game_time_get() - bot->ignored_item_times[index] < BOT_IGNORE_ITEM_TICKS &&
+			game_time_get() >= bot->ignored_item_times[index])
+		{
+			return TRUE;
+		}
+	}
+	return FALSE;
+}
+
+static void bot_ignore_item(
+	struct bot *bot,
+	long item_index)
+{
+	bot->ignored_items[bot->ignored_item_next] = item_index;
+	bot->ignored_item_times[bot->ignored_item_next] = game_time_get();
+	bot->ignored_item_next = (short)((bot->ignored_item_next + 1) % BOT_IGNORED_ITEMS);
+	bot->item_progress_index = NONE;
+}
+
+/* going for a thing to pick up: whether to give it up, coming no nearer
+(half a metre) for two and a half seconds: out of reach, past a rail, up
+where no way it finds goes, or in a crowd */
+static boolean bot_item_out_of_reach(
+	struct bot *bot,
+	real distance)
+{
+	if (bot->item_progress_index != bot->item_index || game_time_get() < bot->item_best_time)
+	{
+		bot->item_progress_index = bot->item_index;
+		bot->item_best_distance = distance;
+		bot->item_best_time = game_time_get();
+		return FALSE;
+	}
+	if (distance < bot->item_best_distance - 0.5f)
+	{
+		bot->item_best_distance = distance;
+		bot->item_best_time = game_time_get();
+		return FALSE;
+	}
+	return game_time_get() - bot->item_best_time > 75;
+}
+
 static long bot_find_item(
+	struct bot const *bot,
 	struct unit_datum const *unit,
 	real_point3d const *position,
 	real range,
@@ -840,7 +959,7 @@ static long bot_find_item(
 		if (distance > range)
 			continue;
 		worth = bot_item_worth(unit, iterator.index);
-		if (worth <= 0.0f || worth < least_worth)
+		if (worth <= 0.0f || worth < least_worth || bot_item_ignored(bot, iterator.index))
 			continue;
 		/* (the strong ones worth a longer way) */
 		score = worth * worth / (1.0f + distance / 15.0f);
@@ -2393,7 +2512,7 @@ static void bot_think(
 			game_time_get() < bot->item_look_time))
 		{
 			bot->item_look_time = game_time_get();
-			bot->item_index = bot_find_item(unit, &position, 10.0f, 4.0f);
+			bot->item_index = bot_find_item(bot, unit, &position, 10.0f, 4.0f);
 		}
 		if (bot->item_index != NONE && !bot->carrying && !bot->has_objective && object_try_and_get(bot->item_index) &&
 			bot_item_worth(unit, bot->item_index) > 0.0f)
@@ -2408,6 +2527,11 @@ static void bot_think(
 				bot_walk_to(action, bot->yaw, &position, &point);
 			if (distance3d(&position, &item_position) < 2.0f)
 				bot_take_item(bot, player, unit, action);
+			if (bot_item_out_of_reach(bot, distance3d(&position, &item_position)))
+			{
+				bot_ignore_item(bot, bot->item_index);
+				bot->item_index = NONE;
+			}
 		}
 		/* closes on it along its way, weaving, until near */
 		else if (bot->has_objective && bot->objective_unit_index != bot->target_unit_index)
@@ -2497,11 +2621,9 @@ static void bot_think(
 		/* something worth having near: there first */
 		else if (game_time_get() - bot->item_look_time >= ITEM_LOOK_TICKS || game_time_get() < bot->item_look_time)
 		{
-			long item = bot_find_item(unit, &position, BOT_ITEM_RANGE, 0.0f);
+			long item = bot_find_item(bot, unit, &position, BOT_ITEM_RANGE, 0.0f);
 
 			bot->item_look_time = game_time_get();
-			if (item == bot->ignored_item_index && game_time_get() - bot->ignored_item_time < 600)
-				item = NONE;
 			if (item != bot->item_index)
 			{
 				bot->item_index = item;
@@ -2519,8 +2641,7 @@ static void bot_think(
 			/* (taken or gone, or no way to it: on) */
 			if (bot->path_failures >= 3)
 			{
-				bot->ignored_item_index = bot->item_index;
-				bot->ignored_item_time = game_time_get();
+				bot_ignore_item(bot, bot->item_index);
 				bot->path_failures = 0;
 				bot->item_index = NONE;
 				bot->has_goal = FALSE;
@@ -2536,6 +2657,14 @@ static void bot_think(
 				bot->goal_time = game_time_get();
 				if (distance3d(&position, &bot->goal) < 2.0f)
 					bot_take_item(bot, player, unit, action);
+				/* (no nearer a while: out of reach, as on a ledge, or not
+				offered: given up for a while) */
+				if (bot_item_out_of_reach(bot, distance3d(&position, &bot->goal)))
+				{
+					bot_ignore_item(bot, bot->item_index);
+					bot->item_index = NONE;
+					bot->has_goal = FALSE;
+				}
 			}
 		}
 		/* (in a team, every third bot with nothing to do keeps near the
@@ -2590,7 +2719,15 @@ static void bot_think(
 			bot->path_failures = 0;
 		}
 		wanted_yaw = bot->wander_yaw;
-		if (bot_next_point(bot, player->unit_index, &position, &point))
+		/* (holding a spot and near it: there, not pressing on into what may
+		stand on it, a pillar, a wall) */
+		if (bot->holding && bot->has_objective &&
+			(bot->goal.x - position.x) * (bot->goal.x - position.x) +
+				(bot->goal.y - position.y) * (bot->goal.y - position.y) < 1.5f * 1.5f)
+		{
+			bot->walking = FALSE;
+		}
+		else if (bot_next_point(bot, player->unit_index, &position, &point))
 		{
 			real dx = point.x - position.x;
 			real dy = point.y - position.y;
@@ -2680,7 +2817,8 @@ static void bot_think(
 		boolean progress = distance < bot->walk_distance - 0.015f || moved > 0.06f;
 
 		bot->walk_distance = MIN(bot->walk_distance, distance);
-		if (progress && moved > 0.02f)
+		/* (at the point, as on a thing to pick up: there, not stuck) */
+		if ((progress && moved > 0.02f) || distance < 0.5f)
 		{
 			bot->stuck_ticks = 0;
 		}
@@ -2689,8 +2827,27 @@ static void bot_think(
 			bot->stuck_ticks++;
 			if (bot->stuck_ticks == 6)
 			{
-				bot->sidestep = bot_random() < 0.5f ? 1.0f : -1.0f;
+				/* (to the side that is open, as round a pillar; either, at
+				random: left, the strafe's positive, bot_walk_to) */
+				real_point3d left = position, right = position;
+				boolean left_open, right_open;
+
+				left.x += -(real)sin(bot->yaw) * 1.2f;
+				left.y += (real)cos(bot->yaw) * 1.2f;
+				right.x -= -(real)sin(bot->yaw) * 1.2f;
+				right.y -= (real)cos(bot->yaw) * 1.2f;
+				left_open = bot_clear_walk(player->unit_index, &position, &left, FALSE);
+				right_open = bot_clear_walk(player->unit_index, &position, &right, FALSE);
+				bot->sidestep = left_open != right_open ? (left_open ? 1.0f : -1.0f) :
+					bot_random() < 0.5f ? 1.0f : -1.0f;
 				bot->sidestep_ticks = 10;
+				/* (the point a little above and near, up a step or the lip of
+				a ramp: a jump on towards it, not a step aside) */
+				if (bot->walk_point.z - position.z > 0.3f && distance < 3.0f)
+				{
+					bot->sidestep_ticks = 0;
+					SET_FLAG(action->control_flags, _unit_control_jump_bit, TRUE);
+				}
 				/* (near a point of its path it cannot reach, at a corner: the
 				next one) */
 				if (distance < 1.5f && bot->path.valid && bot->path.step_index < bot->path.step_count)
@@ -2699,6 +2856,38 @@ static void bot_think(
 					bot->sidestep_ticks = 4;
 				}
 				bots.stucks++;
+				/* (the third time in five seconds: the goal given up, the
+				thing to pick up for a while, and somewhere else, away from
+				where it could not get) */
+				if (game_time_get() - bot->stuck_count_time > 150 || game_time_get() < bot->stuck_count_time)
+				{
+					bot->stuck_count = 0;
+					bot->stuck_count_time = game_time_get();
+				}
+				if (++bot->stuck_count >= 3)
+				{
+					real away = (real)atan2(position.y - bot->walk_point.y, position.x - bot->walk_point.x) +
+						(bot_random() - 0.5f) * 1.5f;
+
+					bot->stuck_count = 0;
+					if (bot->item_index != NONE)
+					{
+						bot_ignore_item(bot, bot->item_index);
+						bot->item_index = NONE;
+					}
+					if (bot->holding)
+						bot->path_failures = 3;
+					else if (!bot->has_objective)
+					{
+						bot->goal = position;
+						bot->goal.x += (real)cos(away) * 10.0f;
+						bot->goal.y += (real)sin(away) * 10.0f;
+						bot->has_goal = TRUE;
+						bot->goal_time = game_time_get();
+						bot->follow_again_time = game_time_get() + 150;
+					}
+					bots.gave_up++;
+				}
 
 				bot->path_time = game_time_get() - PATH_REFRESH_TICKS;
 				bot->walk_distance = 1000000.0f;
@@ -2707,6 +2896,10 @@ static void bot_think(
 				SET_FLAG(action->control_flags, _unit_control_jump_bit, TRUE);
 			if (bot->stuck_ticks == 24)
 				bots.long_stucks++;
+			/* (a spot to hold it cannot get to: the place's centre instead,
+			bot_hold_spot) */
+			if (bot->stuck_ticks == 18 && bot->holding)
+				bot->path_failures = 3;
 		}
 	}
 	else
@@ -2735,7 +2928,13 @@ static struct bot *bot_get(
 		free_bot->player_index = player_index;
 		free_bot->target_unit_index = NONE;
 		free_bot->item_index = NONE;
-		free_bot->ignored_item_index = NONE;
+		free_bot->item_progress_index = NONE;
+		{
+			short ignored;
+
+			for (ignored = 0; ignored < BOT_IGNORED_ITEMS; ignored++)
+				free_bot->ignored_items[ignored] = NONE;
+		}
 		free_bot->vehicle_index = NONE;
 		free_bot->ignored_vehicle_index = NONE;
 		free_bot->step_radius = BOT_STEP_RADIUS;
@@ -2823,12 +3022,12 @@ void bots_tick(
 			}
 		}
 		bots.logged_time = game_time_get();
-		platform_log("bots: driving %d; paths found %ld, not %ld; weapon swaps asked %ld; grenades %ld; changes %ld; stuck %ld, long %ld (no start %ld, no goal %ld, no way %ld); vehicles: in %ld, out %ld",
-			(int)count, bots.paths_found, bots.paths_failed, bots.pickups, bots.grenades, bots.switches, bots.stucks, bots.long_stucks, bots.fail_start, bots.fail_goal, bots.fail_search,
+		platform_log("bots: driving %d; paths found %ld, not %ld; weapon swaps asked %ld; grenades %ld; changes %ld; stuck %ld, long %ld, gave up %ld (no start %ld, no goal %ld, no way %ld); vehicles: in %ld, out %ld",
+			(int)count, bots.paths_found, bots.paths_failed, bots.pickups, bots.grenades, bots.switches, bots.stucks, bots.long_stucks, bots.gave_up, bots.fail_start, bots.fail_goal, bots.fail_search,
 			bots.vehicle_entries, bots.vehicle_exits);
 		bots.vehicle_entries = bots.vehicle_exits = 0;
 		bots.fail_start = bots.fail_goal = bots.fail_search = 0;
-		bots.paths_found = bots.paths_failed = bots.pickups = bots.grenades = bots.switches = bots.stucks = bots.long_stucks = 0;
+		bots.paths_found = bots.paths_failed = bots.pickups = bots.grenades = bots.switches = bots.stucks = bots.long_stucks = bots.gave_up = 0;
 		for (index = 0; index < MAXIMUM_TRACKED_PLAYERS; index++)
 		{
 			struct player_datum *player = distributed_player(index);

port/linux/include/halo_vr.h

@@ -247,6 +247,18 @@ void halo_vr_network_grenade_thrown(short local_player_index, long unit_index, c
 /* the platform layer's side (vr.c) */
 void halo_vr_initialize(void);
 void halo_vr_frame_begin(void);
+/* vr.log_performance: the end of a part of the frame, for the report: the
+input and network, the game's ticks (how many), the camera and director,
+the drawing; the rest is presenting */
+enum
+{
+	HALO_VR_PHASE_INPUT,
+	HALO_VR_PHASE_TICKS,
+	HALO_VR_PHASE_CAMERA,
+	HALO_VR_PHASE_DRAW,
+	HALO_VR_PHASE_COUNT
+};
+void halo_vr_phase(int phase, int ticks);
 void halo_vr_present(unsigned int back_buffer_texture);
 /* the eye image size: the back buffer's size in pixels in VR */
 int halo_vr_eye_size(int *width, int *height);

port/linux/src/port_config.c

@@ -505,6 +505,9 @@ static const struct config_setting config_settings[] =
 		"machines of twice it), to test the netcode as over the internet; 0 none." },
 	{ "debug.network_loss", _config_real, "0.0", "HALO_NETWORK_LOSS", _environment_value, _platform_all,
 		"Percent of datagrams received that are dropped, for the same; 0 none." },
+	{ "debug.gl_thread", _config_integer, "-1", "HALO_GL_THREAD", _environment_value, _platform_android,
+		"Mesa's GL thread (its drivers: the Steam Frame's): 1 on, 0 off, -1 as the\n"
+		"driver chooses. Read when the app starts." },
 	{ "debug.test_input", _config_string, "\"\"", "HALO_TEST_INPUT", _environment_value, _platform_all,
 		"\"bot:<seed>\" plays controller 1 with a scripted pattern (automated\n"
 		"network tests); \"look:<seed>\" stands still, only turning and looking\n"

port/linux/src/vr.c

@@ -69,6 +69,14 @@ static struct
 	unsigned long long wait_us;
 	int report_frames;
 	int report_stereo_frames;
+	/* (the frame's parts, halo_vr_phase: when each ended, and the game's
+	ticks in it; summed apart for frames with ticks and without, with how
+	many took longer than the headset's frame) */
+	unsigned long long phase_end_us[HALO_VR_PHASE_COUNT];
+	int frame_ticks;
+	unsigned long long phase_us[2][HALO_VR_PHASE_COUNT + 1];
+	int phase_frames[2];
+	int phase_late[2];
 
 	/* the view's turning, gathered for halo_vr_look_delta */
 	float look_yaw;
@@ -530,10 +538,47 @@ static unsigned long long now_us(void)
 /* vr.log_performance: every five seconds, the frames the game gave the
 headset, and where their time went: waiting for the headset (xrWaitFrame),
 drawing the eyes, and the rest (the game's update, the overlay, the copies) */
+void halo_vr_phase(int phase, int ticks)
+{
+	if (!vr.active || !vr.log_performance || phase < 0 || phase >= HALO_VR_PHASE_COUNT)
+		return;
+	vr.phase_end_us[phase] = now_us();
+	if (phase == HALO_VR_PHASE_TICKS)
+		vr.frame_ticks = ticks;
+}
+
+/* the frame's parts, from the marks halo_vr_phase left (a part not marked
+this frame: none) */
+static void performance_phases(unsigned long long now)
+{
+	int kind = vr.frame_ticks > 0;
+	unsigned long long last = vr.frame_start_us;
+	int phase;
+
+	for (phase = 0; phase < HALO_VR_PHASE_COUNT; phase++)
+	{
+		unsigned long long end = vr.phase_end_us[phase];
+
+		if (end >= last && end <= now)
+		{
+			vr.phase_us[kind][phase] += end - last;
+			last = end;
+		}
+	}
+	vr.phase_us[kind][HALO_VR_PHASE_COUNT] += now - last;
+	vr.phase_frames[kind]++;
+	/* (late: longer than the headset's frame, less a millisecond) */
+	if (vr.info.refresh_rate > 1.0f && (float)(now - vr.frame_start_us + 1000) > 1e6f / vr.info.refresh_rate)
+		vr.phase_late[kind]++;
+	memset(vr.phase_end_us, 0, sizeof(vr.phase_end_us));
+	vr.frame_ticks = 0;
+}
+
 static void performance_report(int stereo)
 {
 	unsigned long long now = now_us();
 
+	performance_phases(now);
 	vr.work_us += now - vr.frame_start_us;
 	vr.report_frames++;
 	vr.report_stereo_frames += stereo != 0;
@@ -548,6 +593,25 @@ static void performance_report(int stereo)
 		platform_log("VR: %.1f fps (%d%% stereo); per frame %.1f ms working (eyes %.1f ms), %.1f ms waiting "
 			"for the headset", frames / seconds, (int)(100.0f * vr.report_stereo_frames / frames),
 			vr.work_us * 1e-3f / frames, vr.eyes_us * 1e-3f / frames, vr.wait_us * 1e-3f / frames);
+		{
+			int kind;
+
+			for (kind = 1; kind >= 0; kind--)
+			{
+				float count = (float)(vr.phase_frames[kind] ? vr.phase_frames[kind] : 1);
+
+				platform_log("VR:   %s: %d frames, %d late; ms input %.1f, ticks %.1f, camera %.1f, draw %.1f, "
+					"present %.1f", kind ? "with ticks" : "no ticks", vr.phase_frames[kind], vr.phase_late[kind],
+					vr.phase_us[kind][HALO_VR_PHASE_INPUT] * 1e-3f / count,
+					vr.phase_us[kind][HALO_VR_PHASE_TICKS] * 1e-3f / count,
+					vr.phase_us[kind][HALO_VR_PHASE_CAMERA] * 1e-3f / count,
+					vr.phase_us[kind][HALO_VR_PHASE_DRAW] * 1e-3f / count,
+					vr.phase_us[kind][HALO_VR_PHASE_COUNT] * 1e-3f / count);
+			}
+		}
+		memset(vr.phase_us, 0, sizeof(vr.phase_us));
+		memset(vr.phase_frames, 0, sizeof(vr.phase_frames));
+		memset(vr.phase_late, 0, sizeof(vr.phase_late));
 	}
 	vr.report_start_us = now;
 	vr.report_frames = vr.report_stereo_frames = 0;

source/main/main.c

@@ -3338,7 +3338,13 @@ void main_loop(
 						network_game_abort();
 					}
 
+#ifdef HALO_ANDROID
+					halo_vr_phase(HALO_VR_PHASE_INPUT, 0);
+#endif
 					game_time_update((real)main_globals.halt_time_scale*main_globals.seconds_elapsed);
+#ifdef HALO_ANDROID
+					halo_vr_phase(HALO_VR_PHASE_TICKS, game_time_get_elapsed());
+#endif
 
 					render_frame = main_globals.main_menu_scenario_loaded ||
 						(main_globals.halt_time_scale &&
@@ -3353,6 +3359,9 @@ void main_loop(
 					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);
+#ifdef HALO_ANDROID
+					halo_vr_phase(HALO_VR_PHASE_CAMERA, 0);
+#endif
 				}
 
 				if (main_globals.saving_map)
@@ -3367,6 +3376,9 @@ void main_loop(
 					main_game_render((double)main_globals.seconds_elapsed);
 					render_interpolation_frame_end();
 					profile_render_end();
+#ifdef HALO_ANDROID
+					halo_vr_phase(HALO_VR_PHASE_DRAW, 0);
+#endif
 				}
 			}
 			else