...
 
Commits (9)
......@@ -17,7 +17,7 @@ endif
# Build up our settings from our inputs and our environment
LEON ?= leon3
RTEMS ?= /opt/rtems-4.8
RTEMS ?= /opt/rtems-4.8-edisoft/
RTEMS_MAKEFILE_PATH = ${RTEMS}/sparc-rtems4.8/${LEON}
RTEMS_LIB=${RTEMS_MAKEFILE_PATH}/lib
EDISOFT_SUPPORT_PATH ?= ${RTEMS}/support
......@@ -55,7 +55,9 @@ EDISOFT_SRC += ${LEON}.c
NONFPU_SRC= \
init.c \
common.c \
task2.c
task2.c \
highres_timer.c \
cpuLoad.c
NONFPU_SRC+=${EDISOFT_SRC}
......@@ -86,7 +88,7 @@ INCLUDEFLAGS= -I${EDISOFT_SUPPORT_PATH}/include -I src
# Compilation flags (common)
COMMON += -B${RTEMS_LIB} -specs bsp_specs -qrtems -nodefaultlibs \
-mcpu=cypress -DBSP_${LEON}
-mcpu=cypress -DBSP_${LEON} -DCARRIAGE_RETURN_HACK
# Separate compile options per configuration
ifeq ($(CFG),debug)
......@@ -109,7 +111,7 @@ LDFLAGS += ${COMMON} -nodefaultlibs -Wl,--wrap,_IO_Initialize_all_drivers \
${RTEMS_LIB}/libno_sem.a ${RTEMS_LIB}/libno_timer.a \
${RTEMS_LIB}/libno_rtmon.a ${RTEMS_LIB}/libno_ext.a \
-Wl,--start-group -lrtemscpu -lio -lno_event -lmsg -lno_sem \
-lno_timer -lno_rtmon -lno_ext -lrtemsbsp -llibc -lrtemscpu \
-ltimer -lno_rtmon -lext -lrtemsbsp -llibc -lrtemscpu \
-Wl,--end-group -Wl,--script=linkcmds \
-B${RTEMS}/support/edilib/library -lm -lgcc -lc
......@@ -144,8 +146,8 @@ else
@$(CC) -g -o $@ $^ ${LDFLAGS}
endif
ifeq ($(CFG),release)
@${CROSS_PREFIX}-objcopy --only-keep-debug $@ ${@}.debug
@${CROSS_PREFIX}-strip $@
@${RTEMS}/bin/${CROSS_PREFIX}-objcopy --only-keep-debug $@ ${@}.debug
@${RTEMS}/bin/${CROSS_PREFIX}-strip $@
endif
@echo Built with RTEMS at ${RTEMS_LIB} for ${LEON}.
......
#include "system.h"
#include "printk.h"
#include "highres_timer.h"
#include "cpuLoad.h"
/////////////////////////////////////////////////////////////////////
// Hooking the RTEMS scheduler, to get accurate CPU load measurements
/////////////////////////////////////////////////////////////////////
// Data we keep for each task to perform CPU-load accounting
typedef struct {
// Ideally, we'd store the task_id and hunt it down during the user_task_switch:
//
// rtems_id task_id;
//
// Sadly, this scan would take time - we need to impose minimal overhead in
// the context switch, so we want to "instantly" locate the slot for the task
// being switched out.
//
// We will therefore index via the priority, which Christophe has guaranteed
// will be different for each task, and allows for relatively easy indexing.
//
// The last high-resolution timestamp (i.e. microseconds since restart_highres_timer)
// that we've seen this task being context-switched in. Note that initially,
// all tasks are set to have this at 0xFFFFFFFF; which acts as a sentinel value
// deciding whether we've set this before or not.
uint32_t lastTime;
// Total CPU time that this task has been eating.
uint64_t accumulatedTime;
} Tasks_CPU_usage;
typedef struct {
// Given the fact that priority values are not contiguous, this table will have
// some empty slots - but that's not a major issue, since (a) the table will be
// small, in the couple of KB range, and (b) the important thing is to provide
// instant access to the relevant task slot during context switch!
//
// Note also that this is NOT annotated as static, because we want to be able
// to dump this over grmon; we need the symbol to be visible!
Tasks_CPU_usage cpuLoad[PRIO_MAX - PRIO_MIN + 1];
// Total time we've been running; used to get percentage of CPU impact from each task.
uint32_t totalTimeInMicroSec;
} Scheduler_accounting;
// The Book of Life.
Scheduler_accounting accounting;
// The function that RTEMS will call every time we context switch a task.
rtems_extension user_task_switch(rtems_tcb *current, rtems_tcb *new)
{
uint32_t current_highres_time = get_highres_ticks_passed();
// We index via the priorityj, which Christophe has guaranteed will be
// different for each task:
size_t current_task_index = current->real_priority - PRIO_MIN;
size_t new_task_index = new->real_priority - PRIO_MIN;
// Has the current task ever been context-switched in?
if (accounting.cpuLoad[current_task_index].lastTime == 0xFFFFFFFF) {
// Nope, it's the first time we see it - store the timestamp
accounting.cpuLoad[current_task_index].lastTime = get_highres_ticks_passed();
} else {
// Yep - accumulate the total time this task hogged the CPU
accounting.cpuLoad[current_task_index].accumulatedTime +=
current_highres_time - accounting.cpuLoad[current_task_index].lastTime;
}
// Store the timestamp for the new task: "I've just started working again"
// Note that this approach works even if current and new are the same;
// We'll accumulate the execution since last time, and update the timestamp
// so we'll be able to accurately accumulate again the next time.
accounting.cpuLoad[new_task_index].lastTime = current_highres_time;
// Record total time passed since we started accounting.
accounting.totalTimeInMicroSec = current_highres_time;
}
void setup_RTEMS_scheduler_tracking()
{
size_t i;
rtems_id user_extensions_id;
rtems_extensions_table table = {
.thread_switch = user_task_switch
};
// Dependency check.
setup_high_accuracy_timer();
// We don't need to zero-init; the variable is in BSS, it's already done.
// accounting.totalTimeInMicroSec = 0;
for(i = 0; i < sizeof(accounting.cpuLoad)/sizeof(accounting.cpuLoad[0]); i++)
accounting.cpuLoad[i].lastTime = 0xFFFFFFFF; // Sentinel value.
// On your marks... get set... GO!
rtems_extension_create(
rtems_build_name('C', 'T', 'X', 'T'),
&table,
&user_extensions_id);
}
void report_CPU_Load()
{
size_t i;
uint64_t percentage;
uint32_t totalMicrosecondsOfCPUused = 0;
printk("===================================\n");
for(i = 0; i < sizeof(accounting.cpuLoad)/sizeof(accounting.cpuLoad[0]); i++) {
// Is this a real task slot, or just filler space because of the spacing
// of the priority values?
if (accounting.cpuLoad[i].lastTime != 0xFFFFFFFF) {
// IT IS REAL.
// The accumulatedTime is stored in microseconds ; multiply by 100 and
// divide by total milliseconds passed in real-world time.
percentage = (100ULL*accounting.cpuLoad[i].accumulatedTime) / accounting.totalTimeInMicroSec;
printk("Task with priority %3u took %3u%% of CPU time (%9u / %u ms).\n",
i+PRIO_MIN,
(uint32_t) percentage,
(uint32_t) (accounting.cpuLoad[i].accumulatedTime / 1000ULL),
accounting.totalTimeInMicroSec/1000U);
totalMicrosecondsOfCPUused += accounting.cpuLoad[i].accumulatedTime;
}
}
percentage = (100ULL*totalMicrosecondsOfCPUused) / accounting.totalTimeInMicroSec;
printk("Total CPU load of %3u%% time (%9u / %u ms).\n",
(uint32_t) percentage,
(uint32_t) (totalMicrosecondsOfCPUused / 1000ULL),
accounting.totalTimeInMicroSec/1000U);
}
#ifndef __CPU_LOAD_H__
#define __CPU_LOAD_H__
#define PRIO_MIN 1
#define PRIO_MAX 9
void setup_high_accuracy_timer(void);
uint32_t get_highres_ticks_passed(void);
void setup_RTEMS_scheduler_tracking(void);
void report_CPU_Load(void);
#endif
#include <bsp.h>
#include <leon.h>
#include "printk.h"
#include "highres_timer.h"
/////////////////////////////////////////////////////////////////////////////////////
// Helper functions - and their data - related to high-accuracy (microsecond) timing.
/////////////////////////////////////////////////////////////////////////////////////
//
static LEON3_Timer_Regs_Map *tregs; // = (LEON3_Timer_Regs_Map *) 0x80000300;
static uint32_t baseTimestamp = 0;
// In theory, we should not need to profile things taking longer than
// 2^32 microseconds = 4295 seconds. But if it turns out that we do,
// I will simply need to count seconds via an ISR attached to IRQ9.
//
// volatile uint32_t total_gptimer0_Timer1_ISR = 0;
// static rtems_isr gptimer0_Timer1_ISR(rtems_vector_number ignored)
// {
// (void) ignored;
// total_gptimer0_Timer1_ISR++;
// }
void setup_high_accuracy_timer()
{
struct ambapp_apb_info dev;
// Sanity check - don't do it again.
if (tregs)
return;
if(ambapp_find_apbslv(&ambapp_plb, VENDOR_GAISLER, GAISLER_GPTIMER, &dev) > 0) {
tregs = (LEON3_Timer_Regs_Map *) dev.start;
// In theory, we should not need to profile things taking longer than
// 2^32 microseconds = 4295 seconds. But if it turns out that we do,
// I will simply need to hook an ISR to IRQ8 + 1 = 9.
//
// {
// uint32_t irq = 1 + ((tregs->status & 0xf8) >> 3);
// rtems_isr_entry previous_isr;
// rtems_interrupt_catch(gptimer0_Timer1_ISR, LEON_TRAP_TYPE(irq), &previous_isr);
// LEON_Clear_interrupt(irq);
// LEON_Unmask_interrupt(irq);
// printk("[INFO] Detected interrupt for 2nd timer of gptimer0: %u\n", irq);
// }
// tregs->timer[1].reload = 10; // Fire once every 10us
// tregs->timer[1].conf = 0xF; // 3 ie 0x0 Interrupt Enable
// // 2 ld 0x0 Load
// // 1 rs 0x0 Restart
// // 0 en 0x0 Enable
tregs->timer[1].reload = 0xFFFFFFFF;
tregs->timer[1].conf = 0x7; // Load, Enable, Restart (no Interrupt)
printk("[INFO] Detected system frequency of %u Hz\n", (tregs->scaler_reload+1)*1000000U);
} else {
printk("[FATAL] Failed to detect system frequency!\n");
}
}
void restart_highres_timer()
{
// In case I do hook an ISR...
// tregs->timer[1].conf = 0xF;
tregs->timer[1].conf = 0x7;
// Record the baseTimestamp to compare against it in the future
baseTimestamp = tregs->timer[1].value;
}
uint32_t get_highres_ticks_passed()
{
if (!baseTimestamp)
// This will never be zero, unless we actually waited for more than an hour,
// or are just starting (global file-scoped variable, ergo BSS, ergo zero)
baseTimestamp = tregs->timer[1].value;
// Compare against the baseTimestamp
return baseTimestamp - tregs->timer[1].value;
}
#ifndef __HIGHRES_TIMER_H__
#define __HIGHRES_TIMER_H__
void setup_high_accuracy_timer(void);
uint32_t get_highres_ticks_passed(void);
void restart_highres_timer(void);
#endif
......@@ -8,6 +8,11 @@
#include "system.h"
#include "printk.h"
#include "cpuLoad.h"
#define REPORT_EVERY_THIS_MANY_SEC 1
rtems_id timer_id;
rtems_task shepherd_EntryPoint(rtems_task_argument argument)
{
......@@ -41,6 +46,16 @@ rtems_task shepherd_EntryPoint(rtems_task_argument argument)
printk("[SHEPHERD] Some tests failed... :-(\n");
else
printk("[SHEPHERD] All tests passed! :-)\n");
rtems_timer_cancel(timer_id);
report_CPU_Load();
}
rtems_timer_service_routine timer_routine(
rtems_id timer_id,
void *unused_param)
{
report_CPU_Load();
rtems_timer_fire_after(timer_id, 1000*REPORT_EVERY_THIS_MANY_SEC, timer_routine, unused_param);
}
rtems_task Init(rtems_task_argument argument)
......@@ -48,9 +63,11 @@ rtems_task Init(rtems_task_argument argument)
int i;
rtems_name Task_name[TASKS+1]; /* task names */
rtems_id Task_id[TASKS+1]; /* task ids */
(void) argument;
setup_RTEMS_scheduler_tracking();
// Create the synchronization msg Q first
rtems_status_code status = rtems_message_queue_create(
rtems_build_name('Q', '1', ' ', ' '),
......@@ -63,6 +80,17 @@ rtems_task Init(rtems_task_argument argument)
rtems_task_delete(RTEMS_SELF);
}
status = rtems_timer_create(rtems_build_name('T', 'M', '0', '1'), &timer_id);
if (RTEMS_SUCCESSFUL != status) {
printk("Failed to rtems_timer_create... status:%0x\n", status);
rtems_task_delete(RTEMS_SELF);
}
status = rtems_timer_fire_after(timer_id, 1000*REPORT_EVERY_THIS_MANY_SEC, timer_routine, NULL);
if (RTEMS_SUCCESSFUL != status) {
printk("Failed to rtems_timer_fire_after... status:%0x\n", status);
rtems_task_delete(RTEMS_SELF);
}
all_OK = 1;
for(i = 0; i < TASKS; i++)
{
......@@ -72,7 +100,7 @@ rtems_task Init(rtems_task_argument argument)
// Create Task
status = rtems_task_create(
Task_name[i],
(rtems_task_priority) 2,
(rtems_task_priority) PRIO_MAX - (TASKS-1-i),
RTEMS_MINIMUM_STACK_SIZE,
RTEMS_DEFAULT_MODES | RTEMS_TIMESLICE, // Force pre-emption
i == 1 ? RTEMS_FLOATING_POINT // 2nd task does FPU
......@@ -82,19 +110,13 @@ rtems_task Init(rtems_task_argument argument)
printk("Failed to rtems_task_create, status: %d\n", status);
rtems_task_delete(RTEMS_SELF);
}
// Start Task
status = rtems_task_start(
Task_id[i],
i == 1 ? Task1_EntryPoint : Task2_EntryPoint,
i); // task argument passed in the function pointer (the task no)
}
// Launch the last task - the "shepherd"
Task_name[i] = rtems_build_name('T', 'T', "0" + i / 10, "0" + i % 10);
status = rtems_task_create(
Task_name[i],
(rtems_task_priority) 2,
(rtems_task_priority) PRIO_MIN,
RTEMS_MINIMUM_STACK_SIZE,
RTEMS_DEFAULT_MODES | RTEMS_TIMESLICE,
RTEMS_DEFAULT_ATTRIBUTES,
......@@ -103,7 +125,18 @@ rtems_task Init(rtems_task_argument argument)
printk("Failed to rtems_task_create... status:%0x\n", status);
rtems_task_delete(RTEMS_SELF);
}
status = rtems_task_start(Task_id[i], shepherd_EntryPoint, i);
status = rtems_task_start(Task_id[TASKS], shepherd_EntryPoint, TASKS);
//rtems_task_wake_after(1000);
for(i = 0; i < TASKS; i++) {
// Start Task
status = rtems_task_start(
Task_id[i],
i == 1 ? Task1_EntryPoint : Task2_EntryPoint,
i); // task argument passed in the function pointer (the task no)
//rtems_task_wake_after(1000);
}
// Now die and let the shepherd take care of the flock :-)
rtems_task_delete(RTEMS_SELF);
......
......@@ -9,12 +9,15 @@ rtems_task Task2_EntryPoint(rtems_task_argument argument);
void die(int task_no, unsigned exitCode);
#define CONFIGURE_APPLICATION_NEEDS_CLOCK_DRIVER
#define CONFIGURE_APPLICATION_NEEDS_TIMER_DRIVER
#define CONFIGURE_MAXIMUM_TASKS 64
#define CONFIGURE_MAXIMUM_TIMERS 10
#define CONFIGURE_MAXIMUM_MESSAGE_QUEUES 20
#define CONFIGURE_TICKS_PER_TIMESLICE 100
#define CONFIGURE_MICROSECONDS_PER_TICK 1000
#define CONFIGURE_TICKS_PER_TIMESLICE 1
#define CONFIGURE_MAXIMUM_USER_EXTENSIONS 10
#define CONFIGURE_RTEMS_INIT_TASKS_TABLE
#ifndef DEFINE_VARS
#define GLOBAL
#else
......
......@@ -2,14 +2,20 @@
#include "system.h"
#include "printk.h"
#include "highres_timer.h"
rtems_task Task1_EntryPoint(rtems_task_argument argument)
{
int j = 0;
int task_no = (int) argument;
double d = task_no;
rtems_interval begin, end;
unsigned highres_ticks_start, highres_ticks_end;
printk("Inside task %d...\n", task_no);
rtems_clock_get(RTEMS_CLOCK_GET_TICKS_SINCE_BOOT, &begin);
highres_ticks_start = get_highres_ticks_passed();
//printk("Inside task %d...\n", task_no);
for(j=0; j<10000; j++) {
int k;
for(k=0; k<10000; k++)
......@@ -18,10 +24,13 @@ rtems_task Task1_EntryPoint(rtems_task_argument argument)
}
{
long result = (long) d;
long target = 172003608;
long target =
j == 1000?10528109:
j == 10000?172003608:
0;
if (target != result) {
printk(
"[TASK %d] Failed! Computed value was %ld instead of %ld\n",
"[TASK %d] Failed! Computed value was %u instead of %u\n",
task_no, result, target);
all_OK = 0;
die(task_no, 1);
......@@ -30,5 +39,26 @@ rtems_task Task1_EntryPoint(rtems_task_argument argument)
}
}
printk("[TASK %d] Computed the correct floating point result.\n", task_no);
rtems_clock_get(RTEMS_CLOCK_GET_TICKS_SINCE_BOOT, &end);
printk("[TASK %d] Took %d ticks.\n", task_no, end - begin);
// extern volatile uint32_t total_gptimer0_Timer1_ISR;
// printk("[TASK %d] The ISR-counts reported: %u counts\n", task_no, total_gptimer0_Timer1_ISR);
highres_ticks_end = get_highres_ticks_passed();
printk("[TASK %d] Note that the high-resolution timer reported: %u us\n",
task_no, highres_ticks_end-highres_ticks_start);
//rtems_task_wake_after(1000);
highres_ticks_start = get_highres_ticks_passed();
{
int k;
for(k=0; k<1000; k++)
d+=1.001;
}
highres_ticks_end = get_highres_ticks_passed();
printk("[TASK %d] ...result: %u \n", task_no, (unsigned) d);
printk("[TASK %d] ...and a sum of 1000 doubles took: %u us\n",
task_no, highres_ticks_end - highres_ticks_start);
die(task_no, 0);
}
......@@ -6,21 +6,25 @@ rtems_task Task2_EntryPoint(rtems_task_argument argument)
int j = 0;
int task_no = (int) argument;
long long int dummy = 0;
rtems_interval begin, end;
printk("Inside task %d...\n", task_no);
for(j=0; j<500000; j++) {
rtems_clock_get(RTEMS_CLOCK_GET_TICKS_SINCE_BOOT, &begin);
//printk("Inside task %d...\n", task_no);
for(j=0; j<50000; j++) {
int k;
for(k=0; k<100; k++)
for(k=0; k<1000; k++)
dummy ^= k;
dummy++;
}
if (dummy != 500000) {
if (dummy != j) {
printk(
"[TASK %d] Failed! Computed value was %lld instead of 500000\n",
task_no, dummy);
"[TASK %d] Failed! Computed value was %u instead of %u\n",
task_no, dummy, j);
all_OK = 0;
die(task_no, 1);
}
printk("[TASK %d] Computed the correct integer result.\n", task_no);
rtems_clock_get(RTEMS_CLOCK_GET_TICKS_SINCE_BOOT, &end);
printk("[TASK %d] Took %d ticks.\n", task_no, end - begin);
die(task_no, 0);
}