michaelh/zephyr
1
0
Fork 0
Code Releases Activity

tests/benchmarks: fix BOOT_TIME_MEASUREMENT

Browse source 
The boot time measurement sample was giving bogus values on x86: an
assumption was made that the system timer is in sync with the CPU TSC,
which is not the case on most x86 boards.

Boot time measurements are no longer permitted unless the timer source
is the local APIC. To avoid issues of TSC scaling, the startup datum
has been forced to 0, which is in line with the ARM implementation
(which is the only other platform which supports this feature).

Cleanups along the way:

As the datum is now assumed zero, some variables are removed and
calculations simplified. The global variables involved in boot time
measurements are moved to the kernel.h header rather than being
redeclared in every place they are referenced. Since none of the
measurements actually use 64-bit precision, the samples are reduced
to 32-bit quantities.

In addition, this feature has been enabled in long mode.

Fixes: #19144

Signed-off-by: Charles E. Youse <charles.youse@intel.com>
This commit is contained in:
Charles E. Youse 2019-09-16 11:13:12 -04:00 • committed by Andrew Boie
commit 3036faf88a
10 changed files with 47 additions and 91 deletions
Download patch file Download diff file Expand all files Collapse all files

6
arch/arm/core/prep_c.c
View file

@ -155,9 +155,6 @@ extern FUNC_NORETURN void z_cstart(void);
*
* @return N/A
*/
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
extern u64_t __start_time_stamp;
#endif
void _PrepC(void)
{
relocate_vector_table();
@ -166,9 +163,6 @@ void _PrepC(void)
z_data_copy();
#if defined(CONFIG_ARMV7_R) && defined(CONFIG_INIT_STACKS)
init_stacks();
#endif
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
__start_time_stamp = 0U;
#endif
z_IntLibInit();
z_cstart();

6
arch/x86/core/cpuhalt.c
View file

@ -7,10 +7,6 @@
#include <debug/tracing.h>
#include <arch/cpu.h>
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
extern u64_t __idle_time_stamp; /* timestamp when CPU went idle */
#endif
/**
*
* @brief Power save idle routine
@ -26,7 +22,7 @@ void k_cpu_idle(void)
{
z_sys_trace_idle();
#if defined(CONFIG_BOOT_TIME_MEASUREMENT)
__idle_time_stamp = (u64_t)k_cycle_get_32();
__idle_time_stamp = k_cycle_get_32();
#endif
__asm__ volatile (

25
arch/x86/core/ia32/crt0.S
View file

@ -37,10 +37,6 @@
GDATA(_sse_mxcsr_default_value)
#endif
#if defined(CONFIG_BOOT_TIME_MEASUREMENT)
GDATA(__start_time_stamp)
#endif
#ifdef CONFIG_SYS_POWER_DEEP_SLEEP_STATES
GTEXT(_sys_resume_from_deep_sleep)
#endif
@ -71,15 +67,12 @@ SECTION_FUNC(TEXT_START, __start)
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
/*
* Record BootTime from start of Kernel.
* Store value temporarily in Register edi & esi and
* write to memory once memory access is allowed.
* That is, once the data segment register has been setup to access
* the .data/.rodata/.bss section of the linked image.
* Reset the TSC to 0, since that's the datum for boot metrics.
*/
rdtsc
mov %eax, %esi /* low value */
mov %edx, %edi /* high value */
xorl %eax, %eax
xorl %edx, %edx
movl $X86_TIME_STAMP_COUNTER_MSR, %ecx
wrmsr
#endif
/* Enable write-back caching by clearing the NW and CD bits */
@ -122,14 +115,6 @@ __csSet:
#endif /* CONFIG_SET_GDT */
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
/*
* Store rdtsc result from temporary regiter ESI & EDI into memory.
*/
mov %esi, __start_time_stamp /* low value */
mov %edi, __start_time_stamp+4 /* high value */
#endif
#if !defined(CONFIG_FLOAT)
/*
* Force an #NM exception for floating point instructions

8
arch/x86/core/intel64/locore.S
View file

@ -31,8 +31,16 @@ __start:
1:
#endif
/* FIXME: ...resetting TSC here is common to IA32 and Intel64... */
/* FIXME: ...disabling the PICs is common to IA32 and Intel64... */
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
xorl %eax, %eax
xorl %edx, %edx
movl $X86_TIME_STAMP_COUNTER_MSR, %ecx
wrmsr
#endif
#ifdef CONFIG_PIC_DISABLE
movb $0xff, %al
outb %al, $0x21

2
include/arch/x86/msr.h
View file

@ -10,6 +10,8 @@
* Model specific registers (MSR). Access with z_x86_msr_read/write().
*/
#define X86_TIME_STAMP_COUNTER_MSR 0x00000010
#define X86_SPEC_CTRL_MSR 0x00000048
#define X86_SPEC_CTRL_MSR_IBRS BIT(0)
#define X86_SPEC_CTRL_MSR_SSBD BIT(2)

5
include/kernel.h
View file

@ -23,6 +23,11 @@
extern "C" {
#endif
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
extern u32_t __main_time_stamp; /* timestamp when main task starts */
extern u32_t __idle_time_stamp; /* timestamp when CPU goes idle */
#endif
/**
* @brief Kernel APIs
* @defgroup kernel_apis Kernel APIs

4
kernel/idle.c
View file

@ -140,9 +140,9 @@ void idle(void *unused1, void *unused2, void *unused3)
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
/* record timestamp when idling begins */
extern u64_t __idle_time_stamp;
extern u32_t __idle_time_stamp;
__idle_time_stamp = (u64_t)k_cycle_get_32();
__idle_time_stamp = k_cycle_get_32();
#endif
#ifdef CONFIG_SMP

10
kernel/init.c
View file

@ -66,9 +66,8 @@ LOG_MODULE_REGISTER(os);
/* boot time measurement items */
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
u64_t __noinit __start_time_stamp; /* timestamp when kernel starts */
u64_t __noinit __main_time_stamp; /* timestamp when main task starts */
u64_t __noinit __idle_time_stamp; /* timestamp when CPU goes idle */
u32_t __noinit __main_time_stamp; /* timestamp when main task starts */
u32_t __noinit __idle_time_stamp; /* timestamp when CPU goes idle */
#endif
/* init/main and idle threads */
@ -284,10 +283,7 @@ static void bg_thread_main(void *unused1, void *unused2, void *unused3)
#endif
#ifdef CONFIG_BOOT_TIME_MEASUREMENT
/* record timestamp for kernel's _main() function */
extern u64_t __main_time_stamp;
__main_time_stamp = (u64_t)k_cycle_get_32();
__main_time_stamp = k_cycle_get_32();
#endif
extern void main(void);

8
subsys/debug/Kconfig
View file

@ -9,12 +9,10 @@
menu "System Monitoring Options"
config BOOT_TIME_MEASUREMENT
bool "Boot time measurements [EXPERIMENTAL]"
bool "Boot time measurements"
depends on ARCH_POSIX || ARM || (X86 && APIC_TIMER && APIC_TIMER_TSC)
help
This option enables the recording of timestamps during system start
up. The global variable __start_time_stamp records the time kernel
begins executing, while __main_time_stamp records when main() begins
executing, and __idle_time_stamp records when the CPU becomes idle.
This option enables the recording of timestamps during system boot.
config STATS
bool "Statistics support"

64
tests/benchmarks/boot_time/src/main.c
View file

@ -10,33 +10,22 @@
* @brief Measure boot time
*
* Measuring the boot time
* 1. From reset to kernel's __start
* 2. From __start to main()
* 3. From __start to task
* 4. From __start to idle
* 1. From __start to main()
* 2. From __start to task
* 3. From __start to idle
*/
#include <zephyr.h>
#include <tc_util.h>
/* externs */
extern u64_t __start_time_stamp; /* timestamp when kernel begins executing */
extern u64_t __main_time_stamp; /* timestamp when main() begins executing */
extern u64_t __idle_time_stamp; /* timestamp when CPU went idle */
void main(void)
{
u64_t task_time_stamp; /* timestamp at beginning of first task */
u64_t _start_us; /* being of __start timestamp in us */
u64_t main_us; /* begin of main timestamp in us */
u64_t task_us; /* begin of task timestamp in us */
u64_t s_main_time_stamp; /* __start->main timestamp */
u64_t s_task_time_stamp; /*__start->task timestamp */
u64_t idle_us; /* begin of idle timestamp in us */
u64_t s_idle_time_stamp; /*__start->idle timestamp */
u32_t task_time_stamp; /* timestamp at beginning of first task */
u32_t main_us; /* begin of main timestamp in us */
u32_t task_us; /* begin of task timestamp in us */
u32_t idle_us; /* begin of idle timestamp in us */
task_time_stamp = (u64_t)k_cycle_get_32();
task_time_stamp = k_cycle_get_32();
/*
* Go to sleep for 1 tick in order to timestamp when idle thread halts.
@ -45,37 +34,20 @@ void main(void)
int freq = sys_clock_hw_cycles_per_sec() / 1000000;
_start_us = __start_time_stamp / freq;
s_main_time_stamp = __main_time_stamp - __start_time_stamp;
main_us = s_main_time_stamp / freq;
s_task_time_stamp = task_time_stamp - __start_time_stamp;
task_us = s_task_time_stamp / freq;
s_idle_time_stamp = __idle_time_stamp - __start_time_stamp;
idle_us = s_idle_time_stamp / freq;
main_us = __main_time_stamp / freq;
task_us = task_time_stamp / freq;
idle_us = __idle_time_stamp / freq;
/* Indicate start for sanity test suite */
TC_START("Boot Time Measurement");
/* Only print lower 32bit of time result */
TC_PRINT("Boot Result: Clock Frequency: %d MHz\n",
freq);
TC_PRINT("__start : %u cycles, %u us\n",
(u32_t)(__start_time_stamp & 0xFFFFFFFFULL),
(u32_t) (_start_us & 0xFFFFFFFFULL));
TC_PRINT("_start->main(): %u cycles, %u us\n",
(u32_t)(s_main_time_stamp & 0xFFFFFFFFULL),
(u32_t) (main_us & 0xFFFFFFFFULL));
TC_PRINT("_start->task : %u cycles, %u us\n",
(u32_t)(s_task_time_stamp & 0xFFFFFFFFULL),
(u32_t) (task_us & 0xFFFFFFFFULL));
TC_PRINT("_start->idle : %u cycles, %u us\n",
(u32_t)(s_idle_time_stamp & 0xFFFFFFFFULL),
(u32_t) (idle_us & 0xFFFFFFFFULL));
TC_PRINT("Boot Result: Clock Frequency: %d MHz\n", freq);
TC_PRINT("_start->main(): %u cycles, %u us\n", __main_time_stamp,
main_us);
TC_PRINT("_start->task : %u cycles, %u us\n", task_time_stamp,
task_us);
TC_PRINT("_start->idle : %u cycles, %u us\n", __idle_time_stamp,
idle_us);
TC_PRINT("Boot Time Measurement finished\n");
/* for sanity regression test utility. */
TC_END_RESULT(TC_PASS);
TC_END_REPORT(TC_PASS);
}