[Concept,13/14] expo: Expand timing to include render and poll

Message ID 20251006205856.2009292-14-sjg@u-boot.org
State New
Headers
Series expo: More mouse development for expo |

Commit Message

Simon Glass Oct. 6, 2025, 8:58 p.m. UTC
  From: Simon Glass <sjg@chromium.org>

Provide more timing information for expo operation, including the time
taken to:

- render the scene
- sync the framebuffer to the display
- poll for keyboard / mouse input

These are averages calculated over the past second.

Update the documentation to mention these features.

Signed-off-by: Simon Glass <sjg@chromium.org>
---

 boot/expo.c          | 11 ++++++-
 boot/expo_test.c     | 74 +++++++++++++++++++++++++++++++++++++++++++-
 doc/develop/expo.rst | 28 ++++++++++++++---
 include/expo_test.h  | 62 +++++++++++++++++++++++++++++++++++++
 4 files changed, 169 insertions(+), 6 deletions(-)
  

Patch

diff --git a/boot/expo.c b/boot/expo.c
index 2a75eed2c39..4f2c6d928a3 100644
--- a/boot/expo.c
+++ b/boot/expo.c
@@ -323,6 +323,7 @@  static int expo_render_(struct expo *exp, bool dirty_only)
 	u32 colour;
 	int ret;
 
+	expo_test_mark(exp);
 	expo_test_update(exp);
 
 	back = vid_priv->white_on_black ? VID_BLACK : VID_WHITE;
@@ -352,6 +353,7 @@  static int expo_render_(struct expo *exp, bool dirty_only)
 		return log_msg_ret("tst", ret);
 
 	video_sync(dev, true);
+	expo_test_sync(exp);
 
 	return scn ? 0 : -ECHILD;
 }
@@ -528,6 +530,8 @@  int expo_poll(struct expo *exp, struct expo_action *act)
 {
 	int key, ret = -EAGAIN;
 
+	expo_test_mark(exp);
+
 	/* update mouse position if mouse is enabled */
 	update_mouse_position(exp);
 
@@ -541,11 +545,16 @@  int expo_poll(struct expo *exp, struct expo_action *act)
 		if (!ret)
 			ret = expo_send_click(exp, pos.x, pos.y);
 	}
-	if (ret)
+	if (ret) {
+		expo_test_poll(exp);
 		return log_msg_ret("epk", ret);
+	}
 
 	/* get the action (either a key or a click) */
 	ret = expo_action_get(exp, act);
+
+	expo_test_poll(exp);
+
 	if (ret)
 		return log_msg_ret("eag", ret);
 
diff --git a/boot/expo_test.c b/boot/expo_test.c
index 726027aabb6..3ddeb86fb2c 100644
--- a/boot/expo_test.c
+++ b/boot/expo_test.c
@@ -49,6 +49,13 @@  void expo_test_checkenv(struct expo *exp)
 	test->last_update = get_timer(0);
 }
 
+void expo_test_mark(struct expo *exp)
+{
+	struct expo_test_mode *test = exp->test;
+
+	test->base_time_us = timer_get_us();
+}
+
 void expo_test_update(struct expo *exp)
 {
 	struct expo_test_mode *test = exp->test;
@@ -56,6 +63,20 @@  void expo_test_update(struct expo *exp)
 	test->render_count++;
 }
 
+void expo_test_sync(struct expo *exp)
+{
+	struct expo_test_mode *test = exp->test;
+
+	test->sync_delta_us = get_timer_us(test->base_time_us);
+}
+
+void expo_test_poll(struct expo *exp)
+{
+	struct expo_test_mode *test = exp->test;
+
+	test->poll_delta_us = get_timer_us(test->base_time_us);
+}
+
 int expo_calc_fps(struct expo_test_mode *test)
 {
 	ulong oldest_time, newest_time;
@@ -108,6 +129,10 @@  int expo_test_render(struct expo *exp)
 	if (!test->enabled)
 		return 0;
 
+	/* Calculate time between update and render */
+	if (test->base_time_us)
+		test->render_delta_us = get_timer_us(test->base_time_us);
+
 	/* Select 8x16 font for test display */
 	ret = vidconsole_select_font(exp->cons, "8x16", 0);
 	if (ret && ret != -ENOSYS)
@@ -116,13 +141,36 @@  int expo_test_render(struct expo *exp)
 	vid_priv = dev_get_uclass_priv(dev);
 	cons_priv = dev_get_uclass_priv(exp->cons);
 
-	/* Update FPS if at least 1 second has elapsed */
+	/* Accumulate delta times for averaging */
+	test->render_total_us += test->render_delta_us;
+	test->sync_total_us += test->sync_delta_us;
+	test->poll_total_us += test->poll_delta_us;
+	test->frame_count_last_sec++;
+
+	/* Update FPS and averages if at least 1 second has elapsed */
 	if (get_timer(test->last_update) >= 1000) {
 		now = get_timer(test->start_time_ms);
 		test->fps_index = (test->fps_index + 1) % EXPO_FPS_AVG_SECONDS;
 		test->fps_timestamps_ms[test->fps_index] = now;
 		test->fps_frame_counts[test->fps_index] = test->render_count;
 		test->fps_last = expo_calc_fps(test);
+
+		/* Calculate averages over the last second */
+		if (test->frame_count_last_sec > 0) {
+			test->render_avg_us = test->render_total_us /
+				test->frame_count_last_sec;
+			test->sync_avg_us = test->sync_total_us /
+				test->frame_count_last_sec;
+			test->poll_avg_us = test->poll_total_us /
+				test->frame_count_last_sec;
+		}
+
+		/* Reset accumulation counters */
+		test->render_total_us = 0;
+		test->sync_total_us = 0;
+		test->poll_total_us = 0;
+		test->frame_count_last_sec = 0;
+
 		test->last_update = get_timer(0);
 	}
 
@@ -141,5 +189,29 @@  int expo_test_render(struct expo *exp)
 		vidconsole_put_string(exp->cons, buf);
 	}
 
+	/* Display average render time in milliseconds on next line */
+	snprintf(buf, sizeof(buf), "render %6lu.%01lums",
+		 test->render_avg_us / 1000,
+		 (test->render_avg_us % 1000) / 100);
+	y += cons_priv->y_charsize;
+	vidconsole_set_cursor_pos(exp->cons, x, y);
+	vidconsole_put_string(exp->cons, buf);
+
+	/* Display average sync time in milliseconds on next line */
+	snprintf(buf, sizeof(buf), "sync   %6lu.%01lums",
+		 test->sync_avg_us / 1000,
+		 (test->sync_avg_us % 1000) / 100);
+	y += cons_priv->y_charsize;
+	vidconsole_set_cursor_pos(exp->cons, x, y);
+	vidconsole_put_string(exp->cons, buf);
+
+	/* Display average poll time in milliseconds on next line */
+	snprintf(buf, sizeof(buf), "poll   %6lu.%01lums",
+		 test->poll_avg_us / 1000,
+		 (test->poll_avg_us % 1000) / 100);
+	y += cons_priv->y_charsize;
+	vidconsole_set_cursor_pos(exp->cons, x, y);
+	vidconsole_put_string(exp->cons, buf);
+
 	return 0;
 }
diff --git a/doc/develop/expo.rst b/doc/develop/expo.rst
index 85ccbe7fd63..9ce00e621e5 100644
--- a/doc/develop/expo.rst
+++ b/doc/develop/expo.rst
@@ -578,10 +578,10 @@  Future ideas
 ------------
 
 Test Mode
----------
+~~~~~~~~~
 
 Expo supports a test mode that can be enabled by setting the environment
-variable `expotest` to 1. When enabled, expo displays the frame count in the
+variable `expotest` to 1. When enabled, expo displays performance metrics in the
 top-right corner of the display. This is useful for debugging and performance
 analysis.
 
@@ -590,8 +590,28 @@  To enable test mode::
    => setenv expotest 1
    => bootflow menu
 
-The frame count shows the number of times `expo_render()` has been called since
-`expo_enter_mode()` was invoked. The counter resets each time expo mode is entered.
+Test mode displays the following metrics:
+
+Frame count
+    Shows the total number of frames rendered. This is the number of times
+    `expo_render()` has been called since `expo_enter_mode()` was invoked.
+    The counter resets each time expo mode is entered.
+
+FPS (frames per second)
+    Shows the rendering rate averaged over the past 5 seconds. This provides
+    a stable indication of rendering performance.
+
+Timing information
+    Shows average timings (in millisecond) for the following operations,
+    measured over the past second:
+
+    - Render: Time taken to render the scene
+    - Sync: Time taken to sync the framebuffer to the display
+    - Poll: Time taken to poll for keyboard/mouse input
+
+These metrics help identify performance bottlenecks and verify that expo is
+operating efficiently. The timing information is particularly useful when
+optimizing display drivers or debugging slow rendering issues.
 
 Some ideas for future work:
 
diff --git a/include/expo_test.h b/include/expo_test.h
index 9d557e29c87..6363e70a3e5 100644
--- a/include/expo_test.h
+++ b/include/expo_test.h
@@ -23,6 +23,17 @@  struct expo;
  * @fps_index: Current index in the FPS tracking arrays
  * @fps_last: Last calculated FPS value
  * @last_update: Time of last FPS update (milliseconds)
+ * @base_time_us: Base time in microseconds for delta calculations
+ * @render_delta_us: Time between update and render in microseconds
+ * @sync_delta_us: Time taken by video_manual_sync() in microseconds
+ * @poll_delta_us: Time taken by expo_poll() in microseconds
+ * @render_total_us: Cumulative render time in current second (us)
+ * @sync_total_us: Cumulative sync time in current second (us)
+ * @poll_total_us: Cumulative poll time in current second (us)
+ * @frame_count_last_sec: Number of frames in current measurement second
+ * @render_avg_us: Average render time over last second (microseconds)
+ * @sync_avg_us: Average sync time over last second (microseconds)
+ * @poll_avg_us: Average poll time over last second (microseconds)
  */
 struct expo_test_mode {
 	bool enabled;
@@ -33,6 +44,17 @@  struct expo_test_mode {
 	int fps_index;
 	int fps_last;
 	ulong last_update;
+	ulong base_time_us;
+	ulong render_delta_us;
+	ulong sync_delta_us;
+	ulong poll_delta_us;
+	ulong render_total_us;
+	ulong sync_total_us;
+	ulong poll_total_us;
+	int frame_count_last_sec;
+	ulong render_avg_us;
+	ulong sync_avg_us;
+	ulong poll_avg_us;
 };
 
 #if CONFIG_IS_ENABLED(EXPO_TEST)
@@ -62,6 +84,16 @@  void expo_test_uninit(struct expo *exp);
  */
 void expo_test_checkenv(struct expo *exp);
 
+/**
+ * expo_test_mark() - Mark the current time for delta calculations
+ *
+ * @exp: Expo to update test mode for
+ *
+ * Records the current time in microseconds as the base time for subsequent
+ * delta calculations
+ */
+void expo_test_mark(struct expo *exp);
+
 /**
  * expo_test_update() - Update test mode counters
  *
@@ -69,6 +101,24 @@  void expo_test_checkenv(struct expo *exp);
  */
 void expo_test_update(struct expo *exp);
 
+/**
+ * expo_test_poll() - Calculate poll delta time
+ *
+ * @exp: Expo to update test mode for
+ *
+ * Calculates the time taken by expo_poll() based on the base time
+ */
+void expo_test_poll(struct expo *exp);
+
+/**
+ * expo_test_sync() - Calculate sync delta time
+ *
+ * @exp: Expo to update test mode for
+ *
+ * Calculates the time taken by video_manual_sync() based on the base time
+ */
+void expo_test_sync(struct expo *exp);
+
 /**
  * expo_test_render() - Render test mode information
  *
@@ -100,10 +150,22 @@  static inline void expo_test_checkenv(struct expo *exp)
 {
 }
 
+static inline void expo_test_mark(struct expo *exp)
+{
+}
+
 static inline void expo_test_update(struct expo *exp)
 {
 }
 
+static inline void expo_test_poll(struct expo *exp)
+{
+}
+
+static inline void expo_test_sync(struct expo *exp)
+{
+}
+
 static inline int expo_test_render(struct expo *exp)
 {
 	return 0;