diff --git a/tests/kernel/timer/timer_behavior/src/jitter_drift.c b/tests/kernel/timer/timer_behavior/src/jitter_drift.c index d78adb40eaf..28ea47a790e 100644 --- a/tests/kernel/timer/timer_behavior/src/jitter_drift.c +++ b/tests/kernel/timer/timer_behavior/src/jitter_drift.c @@ -126,7 +126,7 @@ static double cycles_to_us(uint64_t cycles) /** * @brief Test a timers jitter and drift over time */ -static void do_test_using(void (*sample_collection_fn)(void)) +static void do_test_using(void (*sample_collection_fn)(void), const char *mechanism) { k_timeout_t actual_timeout = K_USEC(CONFIG_TIMER_TEST_PERIOD); uint64_t expected_duration = (uint64_t)actual_timeout.ticks * CONFIG_TIMER_TEST_SAMPLES; @@ -262,6 +262,51 @@ static void do_test_using(void (*sample_collection_fn)(void)) periodic_start, periodic_end, actual_time_us, expected_time_us, expected_time_drift_us, time_diff_us); + /* Record the stats gathered as a JSON object including related CONFIG_* params. */ + TC_PRINT("RECORD: {" + "\"testcase\":\"jitter_drift_timer\", \"mechanism\":\"%s\"" + ", \"stats_count\":%d, \"rollovers\":%d" + ", \"mean_us\":%.6f, \"mean_cycles\":%.0f" + ", \"stddev_us\":%.6f, \"stddev_cycles\":%.0f" + ", \"var_us\":%.6f, \"var_cycles\":%.0f" + ", \"min_us\":%.6f, \"min_cycles\":%llu" + ", \"max_us\":%.6f, \"max_cycles\":%llu" + ", \"timer_start_cycle\": %llu, \"timer_end_cycle\": %llu" + ", \"total_time_us\":%.6f" + ", \"expected_total_time_us\":%.6f" + ", \"expected_total_drift_us\":%.6f" + ", \"total_drift_us\":%.6f" + ", \"expected_period_cycles\":%.0f" + ", \"expected_period_drift_us\":%.6f" + ", \"sys_clock_hw_cycles_per_sec\":%d" + ", \"CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC\":%d" + ", \"CONFIG_SYS_CLOCK_TICKS_PER_SEC\":%d" + ", \"CONFIG_TIMER_TEST_PERIOD\":%d" + ", \"CONFIG_TIMER_TEST_SAMPLES\":%d" + ", \"CONFIG_TIMER_TEST_MAX_STDDEV\":%d" + "}\n", + mechanism, + CONFIG_TIMER_TEST_SAMPLES - periodic_rollovers, periodic_rollovers, + mean_us, mean_cyc, + stddev_us, stddev_cyc, + variance_us, variance_cyc, + min_us, min_cyc, + max_us, max_cyc, + periodic_start, periodic_end, + actual_time_us, + expected_time_us, + expected_time_drift_us, + time_diff_us, + expected_period, + expected_period_drift, + sys_clock_hw_cycles_per_sec(), + CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC, + CONFIG_SYS_CLOCK_TICKS_PER_SEC, + CONFIG_TIMER_TEST_PERIOD, + CONFIG_TIMER_TEST_SAMPLES, + CONFIG_TIMER_TEST_MAX_STDDEV + ); + /* Validate the maximum/minimum timer period is off by no more than 10% */ double test_period = (double)CONFIG_TIMER_TEST_PERIOD; double period_max_drift_percentage = @@ -300,7 +345,7 @@ ZTEST(timer_jitter_drift, test_jitter_drift_timer_period) k_sleep(K_SECONDS(CONFIG_TIMER_EXTERNAL_TEST_SYNC_DELAY)); gpio_pin_configure_dt(&timer_out, GPIO_OUTPUT_LOW); #endif - do_test_using(collect_timer_period_time_samples); + do_test_using(collect_timer_period_time_samples, "builtin"); } ZTEST(timer_jitter_drift, test_jitter_drift_timer_startdelay) @@ -314,7 +359,7 @@ ZTEST(timer_jitter_drift, test_jitter_drift_timer_startdelay) k_sleep(K_SECONDS(CONFIG_TIMER_EXTERNAL_TEST_SYNC_DELAY)); gpio_pin_configure_dt(&timer_out, GPIO_OUTPUT_LOW); #endif - do_test_using(collect_timer_startdelay_time_samples); + do_test_using(collect_timer_startdelay_time_samples, "startdelay"); } ZTEST_SUITE(timer_jitter_drift, NULL, NULL, NULL, NULL, NULL); diff --git a/tests/kernel/timer/timer_behavior/src/tick_timer_train.c b/tests/kernel/timer/timer_behavior/src/tick_timer_train.c index e4532b3f13b..a1daabb132e 100644 --- a/tests/kernel/timer/timer_behavior/src/tick_timer_train.c +++ b/tests/kernel/timer/timer_behavior/src/tick_timer_train.c @@ -136,6 +136,23 @@ ZTEST(timer_tick_train, test_one_tick_timer_train) timers[i].late_callbacks, (1000 * timers[i].late_callbacks + MAX_CALLBACKS/2) / MAX_CALLBACKS / 10, (1000 * timers[i].late_callbacks + MAX_CALLBACKS/2) / MAX_CALLBACKS % 10); + /* Record the stats gathered as a JSON object including related CONFIG_* params. */ + TC_PRINT("RECORD: {" + "\"testcase\":\"one_tick_timer_train\"" + ", \"timer\":%d, \"max_delta_cycles\":%u, \"max_delta_us\":%u" + ", \"late_callbacks\":%u" + ", \"perfect_delta_cycles\":%u, \"perfect_delta_us\":%u" + ", \"train_time_ms\":%u, \"busy_loops\":%u" + ", \"timers\":%u, \"expected_callbacks\":%u, \"expected_time_ms\":%u" + ", \"CONFIG_SYS_CLOCK_TICKS_PER_SEC\":%u" + "}\n", + i, timers[i].max_delta, k_cyc_to_us_near32(timers[i].max_delta), + timers[i].late_callbacks, + k_ticks_to_cyc_floor32(TIMERS), k_ticks_to_us_near32(TIMERS), + delta_time, busy_loops, + TIMERS, MAX_CALLBACKS, max_time, + CONFIG_SYS_CLOCK_TICKS_PER_SEC + ); max_delta = timers[i].max_delta > max_delta ? timers[i].max_delta : max_delta; k_timer_stop(&timers[i].tm); } diff --git a/tests/kernel/timer/timer_behavior/testcase.yaml b/tests/kernel/timer/timer_behavior/testcase.yaml index 11ac75e5597..b1417dce985 100644 --- a/tests/kernel/timer/timer_behavior/testcase.yaml +++ b/tests/kernel/timer/timer_behavior/testcase.yaml @@ -8,6 +8,10 @@ tests: - mcu simulation_exclude: - renode + harness_config: + record: + regex: "RECORD:(?P.*)" + as_json: ['metrics'] kernel.timer.timer_behavior_external: filter: dt_compat_enabled("test-kernel-timer-behavior-external") harness: pytest