tests: latency_measure: Fix MPU fault

Fixes an MPU fault that was occurring on some ARM platforms when
executing the events portion of the latency_measure benchmark. The
fault was tracked to an attempt by a user thread to read an MMIO
register that it did not have permissions to access.

The solution was to move the printing of the stats averages out of
the test thread and into the main thread as the main thread always
executes at kernel/supervisor level and will always have permissions
to read that MMIO register.

Fixes #67438

Signed-off-by: Peter Mitsis <peter.mitsis@intel.com>
This commit is contained in:
Peter Mitsis 2024-01-19 13:45:16 -05:00 committed by Carles Cufí
commit 7c5a57b87b

View file

@ -28,13 +28,11 @@ static K_EVENT_DEFINE(event_set);
static void event_ops_entry(void *p1, void *p2, void *p3) static void event_ops_entry(void *p1, void *p2, void *p3)
{ {
uint32_t num_iterations = (uint32_t)(uintptr_t)p1; uint32_t num_iterations = (uint32_t)(uintptr_t)p1;
uint32_t options = (uint32_t)(uintptr_t)p2;
timing_t start; timing_t start;
timing_t finish; timing_t finish;
uint32_t i; uint32_t i;
uint64_t cycles;
char tag[50]; /* 2. Benchmark k_event_post() with no waiters */
char description[120];
k_event_clear(&event_set, ALL_EVENTS); k_event_clear(&event_set, ALL_EVENTS);
@ -44,13 +42,13 @@ static void event_ops_entry(void *p1, void *p2, void *p3)
} }
finish = timing_timestamp_get(); finish = timing_timestamp_get();
snprintf(tag, sizeof(tag), "events.post.immediate.%s", timestamp.cycles = timing_cycles_get(&start, &finish);
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description), /* 3. Pause to allow main thread to print results */
"%-40s - Post events (nothing wakes)", tag);
cycles = timing_cycles_get(&start, &finish); k_sem_take(&pause_sem, K_FOREVER);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, ""); /* 5. Benchmark k_event_set() with no waiters */
start = timing_timestamp_get(); start = timing_timestamp_get();
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
@ -58,13 +56,13 @@ static void event_ops_entry(void *p1, void *p2, void *p3)
} }
finish = timing_timestamp_get(); finish = timing_timestamp_get();
snprintf(tag, sizeof(tag), "events.set.immediate.%s", timestamp.cycles = timing_cycles_get(&start, &finish);
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description), /* 6. Pause to allow main thread to print results */
"%-40s - Set events (nothing wakes)", tag);
cycles = timing_cycles_get(&start, &finish); k_sem_take(&pause_sem, K_FOREVER);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, ""); /* 8. Benchmark k_event_wait() (events have already been set) */
start = timing_timestamp_get(); start = timing_timestamp_get();
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
@ -72,13 +70,13 @@ static void event_ops_entry(void *p1, void *p2, void *p3)
} }
finish = timing_timestamp_get(); finish = timing_timestamp_get();
snprintf(tag, sizeof(tag), "events.wait.immediate.%s", timestamp.cycles = timing_cycles_get(&start, &finish);
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description), /* 9. Pause to allow main thread to print results */
"%-40s - Wait for any events (no ctx switch)", tag);
cycles = timing_cycles_get(&start, &finish); k_sem_take(&pause_sem, K_FOREVER);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, ""); /* 11. Benchmark k_event_wait_all() (events have already been set) */
start = timing_timestamp_get(); start = timing_timestamp_get();
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
@ -86,24 +84,15 @@ static void event_ops_entry(void *p1, void *p2, void *p3)
} }
finish = timing_timestamp_get(); finish = timing_timestamp_get();
snprintf(tag, sizeof(tag), "events.wait_all.immediate.%s", timestamp.cycles = timing_cycles_get(&start, &finish);
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description), /* 12. Thread finishes */
"%-40s - Wait for all events (no ctx switch)", tag);
cycles = timing_cycles_get(&start, &finish);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
} }
static void start_thread_entry(void *p1, void *p2, void *p3) static void start_thread_entry(void *p1, void *p2, void *p3)
{ {
uint32_t num_iterations = (uint32_t)(uintptr_t)p1; uint32_t num_iterations = (uint32_t)(uintptr_t)p1;
uint32_t options = (uint32_t)(uintptr_t)p2;
uint32_t alt_options = (uint32_t)(uintptr_t)p3;
uint32_t i; uint32_t i;
uint64_t cycles;
char tag[50];
char description[120];
k_thread_start(&alt_thread); k_thread_start(&alt_thread);
@ -115,30 +104,6 @@ static void start_thread_entry(void *p1, void *p2, void *p3)
k_event_set(&event_set, BENCH_EVENT_SET); k_event_set(&event_set, BENCH_EVENT_SET);
} }
snprintf(tag, sizeof(tag),
"events.wait.blocking.%c_to_%c",
(alt_options & K_USER) ? 'u' : 'k',
(options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Wait for any events (w/ ctx switch)", tag);
cycles = timestamp.cycles -
timestamp_overhead_adjustment(options, alt_options);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
snprintf(tag, sizeof(tag),
"events.set.wake+ctx.%c_to_%c",
(options & K_USER) ? 'u' : 'k',
(alt_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Set events (w/ ctx switch)", tag);
cycles = timestamp.cycles -
timestamp_overhead_adjustment(options, alt_options);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
/* 5. Post the events to wake alt_thread */ /* 5. Post the events to wake alt_thread */
@ -147,27 +112,6 @@ static void start_thread_entry(void *p1, void *p2, void *p3)
k_event_post(&event_set, BENCH_EVENT_SET); k_event_post(&event_set, BENCH_EVENT_SET);
} }
snprintf(tag, sizeof(tag),
"events.wait_all.blocking.%c_to_%c",
(alt_options & K_USER) ? 'u' : 'k',
(options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Wait for all events (w/ ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
snprintf(tag, sizeof(tag),
"events.post.wake+ctx.%c_to_%c",
(options & K_USER) ? 'u' : 'k',
(alt_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Post events (w/ ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_thread_join(&alt_thread, K_FOREVER); k_thread_join(&alt_thread, K_FOREVER);
} }
@ -178,8 +122,7 @@ static void alt_thread_entry(void *p1, void *p2, void *p3)
timing_t start; timing_t start;
timing_t mid; timing_t mid;
timing_t finish; timing_t finish;
uint64_t sum1 = 0ULL; uint64_t sum[4] = {0ULL, 0ULL, 0ULL, 0ULL};
uint64_t sum2 = 0ULL;
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
@ -193,21 +136,10 @@ static void alt_thread_entry(void *p1, void *p2, void *p3)
finish = timing_timestamp_get(); finish = timing_timestamp_get();
mid = timestamp.sample; mid = timestamp.sample;
sum1 += timing_cycles_get(&start, &mid); sum[0] += timing_cycles_get(&start, &mid);
sum2 += timing_cycles_get(&mid, &finish); sum[1] += timing_cycles_get(&mid, &finish);
} }
/* Let start_thread print the results */
timestamp.cycles = sum1;
k_sem_take(&pause_sem, K_FOREVER);
timestamp.cycles = sum2;
k_sem_take(&pause_sem, K_FOREVER);
sum1 = 0ULL;
sum2 = 0ULL;
for (i = 0; i < num_iterations; i++) { for (i = 0; i < num_iterations; i++) {
/* 4. Wait for all of the events */ /* 4. Wait for all of the events */
@ -220,21 +152,30 @@ static void alt_thread_entry(void *p1, void *p2, void *p3)
finish = timing_timestamp_get(); finish = timing_timestamp_get();
mid = timestamp.sample; mid = timestamp.sample;
sum1 += timing_cycles_get(&start, &mid); sum[2] += timing_cycles_get(&start, &mid);
sum2 += timing_cycles_get(&mid, &finish); sum[3] += timing_cycles_get(&mid, &finish);
} }
/* Let start_thread print the results */ /* Let the main thread print the results */
timestamp.cycles = sum1; timestamp.cycles = sum[0];
k_sem_take(&pause_sem, K_FOREVER); k_sem_take(&pause_sem, K_FOREVER);
timestamp.cycles = sum2; timestamp.cycles = sum[1];
k_sem_take(&pause_sem, K_FOREVER);
timestamp.cycles = sum[2];
k_sem_take(&pause_sem, K_FOREVER);
timestamp.cycles = sum[3];
} }
int event_ops(uint32_t num_iterations, uint32_t options) int event_ops(uint32_t num_iterations, uint32_t options)
{ {
int priority; int priority;
char tag[50];
char description[120];
uint64_t cycles;
priority = k_thread_priority_get(k_current_get()); priority = k_thread_priority_get(k_current_get());
@ -244,13 +185,61 @@ int event_ops(uint32_t num_iterations, uint32_t options)
K_THREAD_STACK_SIZEOF(start_stack), K_THREAD_STACK_SIZEOF(start_stack),
event_ops_entry, event_ops_entry,
(void *)(uintptr_t)num_iterations, (void *)(uintptr_t)num_iterations,
(void *)(uintptr_t)options, NULL, NULL, NULL,
priority - 1, options, K_FOREVER); priority - 1, options, K_FOREVER);
k_thread_access_grant(&start_thread, &event_set); k_thread_access_grant(&start_thread, &event_set, &pause_sem);
/* 1. Start test thread */
k_thread_start(&start_thread); k_thread_start(&start_thread);
/* 4. Benchmark thread has paused */
snprintf(tag, sizeof(tag), "events.post.immediate.%s",
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description),
"%-40s - Post events (nothing wakes)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
/* 7. Benchmark thread has paused */
snprintf(tag, sizeof(tag), "events.set.immediate.%s",
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description),
"%-40s - Set events (nothing wakes)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
/* 10. Benchmark thread has paused */
snprintf(tag, sizeof(tag), "events.wait.immediate.%s",
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description),
"%-40s - Wait for any events (no ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
/* 13. Benchmark thread has finished */
snprintf(tag, sizeof(tag), "events.wait_all.immediate.%s",
(options & K_USER) ? "user" : "kernel");
snprintf(description, sizeof(description),
"%-40s - Wait for all events (no ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_thread_join(&start_thread, K_FOREVER); k_thread_join(&start_thread, K_FOREVER);
timing_stop(); timing_stop();
@ -261,7 +250,10 @@ int event_ops(uint32_t num_iterations, uint32_t options)
int event_blocking_ops(uint32_t num_iterations, uint32_t start_options, int event_blocking_ops(uint32_t num_iterations, uint32_t start_options,
uint32_t alt_options) uint32_t alt_options)
{ {
int priority; int priority;
char tag[50];
char description[120];
uint64_t cycles;
priority = k_thread_priority_get(k_current_get()); priority = k_thread_priority_get(k_current_get());
@ -271,15 +263,14 @@ int event_blocking_ops(uint32_t num_iterations, uint32_t start_options,
K_THREAD_STACK_SIZEOF(start_stack), K_THREAD_STACK_SIZEOF(start_stack),
start_thread_entry, start_thread_entry,
(void *)(uintptr_t)num_iterations, (void *)(uintptr_t)num_iterations,
(void *)(uintptr_t)start_options, NULL, NULL,
(void *)(uintptr_t)alt_options,
priority - 1, start_options, K_FOREVER); priority - 1, start_options, K_FOREVER);
k_thread_create(&alt_thread, alt_stack, k_thread_create(&alt_thread, alt_stack,
K_THREAD_STACK_SIZEOF(alt_stack), K_THREAD_STACK_SIZEOF(alt_stack),
alt_thread_entry, alt_thread_entry,
(void *)(uintptr_t)num_iterations, (void *)(uintptr_t)num_iterations,
(void *)(uintptr_t)alt_options, NULL, NULL, NULL,
priority - 2, alt_options, K_FOREVER); priority - 2, alt_options, K_FOREVER);
k_thread_access_grant(&start_thread, &alt_thread, &event_set, k_thread_access_grant(&start_thread, &alt_thread, &event_set,
@ -288,6 +279,51 @@ int event_blocking_ops(uint32_t num_iterations, uint32_t start_options,
k_thread_start(&start_thread); k_thread_start(&start_thread);
snprintf(tag, sizeof(tag),
"events.wait.blocking.%c_to_%c",
(alt_options & K_USER) ? 'u' : 'k',
(start_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Wait for any events (w/ ctx switch)", tag);
cycles = timestamp.cycles -
timestamp_overhead_adjustment(start_options, alt_options);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
snprintf(tag, sizeof(tag),
"events.set.wake+ctx.%c_to_%c",
(start_options & K_USER) ? 'u' : 'k',
(alt_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Set events (w/ ctx switch)", tag);
cycles = timestamp.cycles -
timestamp_overhead_adjustment(start_options, alt_options);
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
snprintf(tag, sizeof(tag),
"events.wait_all.blocking.%c_to_%c",
(alt_options & K_USER) ? 'u' : 'k',
(start_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Wait for all events (w/ ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_sem_give(&pause_sem);
snprintf(tag, sizeof(tag),
"events.post.wake+ctx.%c_to_%c",
(start_options & K_USER) ? 'u' : 'k',
(alt_options & K_USER) ? 'u' : 'k');
snprintf(description, sizeof(description),
"%-40s - Post events (w/ ctx switch)", tag);
cycles = timestamp.cycles;
PRINT_STATS_AVG(description, (uint32_t)cycles,
num_iterations, false, "");
k_thread_join(&start_thread, K_FOREVER); k_thread_join(&start_thread, K_FOREVER);
timing_stop(); timing_stop();