expo: Expand timing to include render and poll

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>
This commit is contained in:
Simon Glass
2025-10-05 07:19:22 -06:00
parent 9d9e00b3de
commit aa83cf00ce
4 changed files with 169 additions and 6 deletions

View File

@@ -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);

View File

@@ -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;
}

View File

@@ -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:

View File

@@ -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;