RK0 Profiling
The following test was performed on an ARM Cortex-M4F @ 80MHz (Nucleo STM32F401RE)
It has been compiled as follows:
OPT := -O2
DEBUG := -DNDEBUG
CFLAGS_EXTRA := -g -fstack-usage
ASFLAGS_EXTRA := -g -D__FPU_PRESENT=0 -DNDEBUG
STRIPFLAGS :=
COMMON_WARN := -Wall -Wextra -Wsign-compare -Wsign-conversion -pedantic
CFLAGS := -std=gnu11 $(MCU_FLAGS) $(DEBUG) \
$(COMMON_WARN) -ffunction-sections -fdata-sections \
$(CFLAGS_EXTRA) $(OPT) $(INC_DIRS)
ASFLAGS := $(MCU_FLAGS) -x assembler-with-cpp $(ASFLAGS_EXTRA) -ffunction-sections -fdata-sections
LDFLAGS := -nostartfiles -T $(LINKER_SCRIPT) $(MCU_FLAGS) \
-Wl,-Map=$(BUILD_DIR)/rk0_demo.map,--cref -Wl,--gc-sections \
-specs=nano.specs -lc
What it means:
-
NDEBUGflag (error checking is disabled) - FPU is disabled
- Stack overflow checking is disabled
- Optmisation level: -O2 (adequate for release, not strictly optimised for speed)
- Debug symbols were not stripped off (
-gflags ) so we can inspect symbols for the running test.
This test is based on the ThreadX test-suit
Reproducing the description:
1.3. Preemptive Scheduling Test ? This test consists of 5 threads that each have a unique priority. In this test, all threads except the lowest priority thread are left in a suspended state. The lowest priority thread will resume the next highest priority thread. That thread will resume the next highest priority thread and so on until the highest priority thread executes. Each thread will increment its run count and then call thread suspend. Eventually the processing will return to the lowest priority thread, which is still in the middle of the thread resume call. Once processing returns to the lowest priority thread, it will increment its run counter and once again resume the next highest priority thread - starting the whole process over once again.
The ThreadX code is here: https://github.com/eclipse-threadx/threadx/blob/master/utility/benchmarks/thread_metric/tm_preemptive_scheduling_test.c
For RK0, the same is written is as follows:
#include <application.h>
#include <kapi.h>
/* Preemptive scheduling profiling */
/* Each run has 30 sec */
/* Criteria: counters will be at most +/-1 from the average */
#define TM_TEST_DURATION 30000UL /* ms (tick = 1ms) */
#define TM_FLAG 0x01UL
#define kSuspendSelf(timeout) \
do { kTaskFlagsGet(TM_FLAG, RK_FLAGS_ANY, NULL, (timeout)); } while (0)
#define kResumeTask(taskHandle) \
do { kTaskFlagsSet((taskHandle), TM_FLAG); } while (0)
#define STACKSIZE 128
RK_DECLARE_TASK(task1Handle, Task1, stack1, STACKSIZE)
RK_DECLARE_TASK(task2Handle, Task2, stack2, STACKSIZE)
RK_DECLARE_TASK(task4Handle, Task4, stack4, STACKSIZE)
RK_DECLARE_TASK(task5Handle, Task5, stack5, STACKSIZE)
RK_DECLARE_TASK(task3Handle, Task3, stack3, STACKSIZE)
RK_DECLARE_TASK(task6Handle, Task6, stack6, STACKSIZE)
/* counters */
volatile ULONG counter1 = 0UL;
volatile ULONG counter2 = 0UL;
volatile ULONG counter3 = 0UL;
volatile ULONG counter4 = 0UL;
volatile ULONG counter5 = 0UL;
VOID kApplicationInit(VOID)
{
/* lowest priority */
kCreateTask(&task1Handle, Task1, RK_NO_ARGS, "T0", stack1, STACKSIZE, 6, RK_PREEMPT);
kCreateTask(&task2Handle, Task2, RK_NO_ARGS, "T1", stack2, STACKSIZE, 5, RK_PREEMPT);
kCreateTask(&task3Handle, Task3, RK_NO_ARGS, "T2", stack3, STACKSIZE, 4, RK_PREEMPT);
kCreateTask(&task4Handle, Task4, RK_NO_ARGS, "T3", stack4, STACKSIZE, 3, RK_PREEMPT);
kCreateTask(&task5Handle, Task5, RK_NO_ARGS, "T4", stack5, STACKSIZE, 2, RK_PREEMPT);
/* highest priority - reporting task */
kCreateTask(&task6Handle, Task6, RK_NO_ARGS, "REP", stack6, STACKSIZE, 1, RK_PREEMPT);
}
/* lowest priority counter task: does not suspend itself */
/* it should be preempted by higher priority tasks */
VOID Task1(VOID *args)
{
RK_UNUSEARGS
while (1)
{
kResumeTask(task2Handle);
counter1++;
}
}
/* 2..4: start suspended, resume, increment, self-suspend */
VOID Task2(VOID *args)
{
RK_UNUSEARGS
kSuspendSelf(RK_WAIT_FOREVER);
while (1)
{
kResumeTask(task3Handle);
counter2++;
kSuspendSelf(RK_WAIT_FOREVER);
}
}
VOID Task3(VOID *args)
{
RK_UNUSEARGS
kSuspendSelf(RK_WAIT_FOREVER);
while (1)
{
kResumeTask(task4Handle);
counter3++;
kSuspendSelf(RK_WAIT_FOREVER);
}
}
VOID Task4(VOID *args)
{
RK_UNUSEARGS;
kSuspendSelf(RK_WAIT_FOREVER);
while (1)
{
kResumeTask(task5Handle);
counter4++;
kSuspendSelf(RK_WAIT_FOREVER);
}
}
/* highest priority counter task: does not resume any task */
VOID Task5(VOID *args)
{
RK_UNUSEARGS
kSuspendSelf(RK_WAIT_FOREVER);
while (1)
{
counter5++;
kSuspendSelf(RK_WAIT_FOREVER);
}
}
volatile ULONG error = 0UL;
volatile ULONG roundn = 0UL;
volatile RK_TICK time0 = 0UL;
volatile RK_TICK time1 = 0UL;
volatile ULONG total = 0UL;
volatile ULONG average = 0UL;
/* REPORTING TASK: */
/* Highest priority, starts, sleeps for 30000 ticks (30sec), interrupts and
evaluate */
VOID Task6(VOID *args)
{
RK_UNUSEARGS
while (1)
{
time0 = kTickGetMs();
kSleep(TM_TEST_DURATION);
time1 = kTickGetMs();
total = counter1 + counter2 + counter3 + counter4 + counter5;
average = total / 5;
roundn += 1;
/* check: each counter within +-1 of average */
if ( ((LONG)counter1 < (LONG)average - 1) || ((LONG)counter1 > (LONG)average + 1) ||
((LONG)counter2 < (LONG)average - 1) || ((LONG)counter2 > (LONG)average + 1) ||
((LONG)counter3 < (LONG)average - 1) || ((LONG)counter3 > (LONG)average + 1) ||
((LONG)counter4 < (LONG)average - 1) || ((LONG)counter4 > (LONG)average + 1) ||
((LONG)counter5 < (LONG)average - 1) || ((LONG)counter5 > (LONG)average + 1) )
{
error += 1;
}
}
}The results can be seen below:
After 5 runs:
There was no deviation at all.
For measuring the context switching latency the following approach was used:
/* Two tasks at the same priority cooperatively yielding */
/* So we can measure the cycles in the context switch on the low-level scheduler */
/* Tick is 10 ms for less intrusion */
#include <application.h>
#include <kapi.h>
#define STACKSIZE 128
RK_DECLARE_TASK(task1Handle, Task1, stack1, STACKSIZE)
RK_DECLARE_TASK(task2Handle, Task2, stack2, STACKSIZE)
volatile ULONG counter1=0;
volatile ULONG counter2=0;
VOID kApplicationInit(VOID)
{
kCreateTask(&task1Handle, Task1, RK_NO_ARGS, "T0", stack1, STACKSIZE, 1, RK_PREEMPT);
kCreateTask(&task2Handle, Task2, RK_NO_ARGS, "T1", stack2, STACKSIZE, 1, RK_PREEMPT);
}
VOID Task1(VOID *args)
{
RK_UNUSEARGS
while (1)
{
counter1++;
kYield();
}
}
VOID Task2(VOID *args)
{
RK_UNUSEARGS
while (1)
{
counter2++;
kYield();
}
}The PendSV was instrumented this way using the CoreDebug/DWT infrastructure:
(As NDEBUG is defined, FPU is disabled, and Stack Overflow checking is disabled - excerpts of the code dealing with checking, FPU extended frame and stack overflow checking mechanisms were removed for clarity):
.equ DWT_CYCCNT, 0xE0001004 /* Register Address for Data Watch Pointer - Cycle Counter*/
.global ctxtSwtchCycles
.global ctxtSwtchStart
global PendSV_Handler
.type PendSV_Handler, %function
.thumb_func
.text
.align 4
PendSV_Handler:
CPSID I
/* ---- CYCCNT start ---- */
LDR R0, =DWT_CYCCNT
LDR R3, [R0] /* R3 = start */
LDR R2, =ctxtSwtchStart
STR R3, [R2]
/* this takes 8 cycles */
MRS R12, PSP
STMDB R12!, {R4-R11}
LDR R0, =RK_gRunPtr
LDR R1, [R0]
STR R12, [R1, #SP_OFFSET] /* save PSP */
STR LR, [R1, #LR_OFFSET] /* save LR */
/* call scheduler */
BL kSwtch
/* load new task context */
LDR R0, =RK_gRunPtr
LDR R1, [R0]
RESTORE:
MOV R12, #RUNNING
STR R12, [R1, #STATUS_OFFSET]
/* get saved LR at TCB */
LDR LR, [R1, #LR_OFFSET]
/* get saved PSP value */
LDR R2, [R1, #SP_OFFSET]
LDMIA R2!, {R4-R11}
/* assign PSP */
DSB
/* ---- CYCCNT end/delta ---- */
LDR R0, =DWT_CYCCNT
LDR R3, [R0] /* R3 = end */
LDR R2, =ctxtSwtchStart
LDR R1, [R2] /* R1 = start */
SUB R3, R3, R1 /* delta (wrap OK unsigned) */
LDR R2, =ctxtSwtchCycles
STR R3, [R2]
/* this adds 12 cycles */
CPSIE I /* 1 cycle */
BX LR /* restoring hw frame here will take ~12 cycles,
assuming it straight returning to the chosen task as in the example */
/* the ctxtSwtchCycles then must be ctxtSwtchCycles + 13 cycles (CPSI+BX LR) - 20 cycles (DWT math overhead) */
/* total = ctxtSwtchCycles - 7 */
A context switch takes around cycles 132-7=125 cycles of CPU clock, in the simplest case. For a 80MHz clock it means less than 2 microseconds (~1.6us).
