Add a priority inversion test for Semaphores.
authorlottaviano <lottaviano@38d2e660-2303-0410-9eaa-f027e97ec537>
Tue, 17 May 2011 14:07:59 +0000 (14:07 +0000)
committerlottaviano <lottaviano@38d2e660-2303-0410-9eaa-f027e97ec537>
Tue, 17 May 2011 14:07:59 +0000 (14:07 +0000)
Introduce a test case in sem_test.c for a typical priority
inversion situation where some high and low priority processes
share one or more semaphores and are disturbed by a non-interacting
medium priority process. The test shows, by logging the finishing
time of the procecsses, that the execution of an high priority
process can be noticeably delayed by someone with lower priority
because of interactions happening on semaphores.

Signed-off-by: Dario Faggioli <raistlin@linux.it>
git-svn-id: https://src.develer.com/svnoss/bertos/trunk@4907 38d2e660-2303-0410-9eaa-f027e97ec537

bertos/kern/sem_test.c
examples/demo/demo.c
examples/demo/demo.mk

index 1045205df9fc0bd5828124f6d429f6534c05a99f..8f88ced309f6b8d8f6d931b630f8c0b7e82e9bf1 100644 (file)
  *
  * \brief Semaphore test.
  *
+ * For testing priority inversion (avoidance) a set of processes
+ * interacting among each others by means of two semaphores are
+ * disturbed by an unrelated process, i.e., a process not using
+ * any semaphore at all.
+ *
+ * In case of priority inversion, high priority processes
+ * are affected (delayed!) by such process, even it has lower
+ * priority, because of semaphores. On the other hand, when priority
+ * inheritance is enabled, non interacting low priority processes
+ * can't affect the execution of high priority ones.
+ *
+ * It all can be seen looking at the finishing time of the various
+ * processes involved in sem_inv_test (logged).
+ *
+ * Notice that priority inheritance makes sense iff priorities
+ * exist, so the whole test depends on CONFIG_KERN_PRI.
  *
  * \author Daniele Basile <asterix@develer.com>
  * \author Stefano Fedrigo <aleph@develer.com>
+ * \author Dario Faggioli <raistlin@linux.it>
  *
  * $test$: cp bertos/cfg/cfg_proc.h $cfgdir/
  * $test$: echo  "#undef CONFIG_KERN" >> $cfgdir/cfg_proc.h
  * $test$: echo "#define CONFIG_KERN 1" >> $cfgdir/cfg_proc.h
+ * $test$: echo  "#undef CONFIG_KERN_PRI" >> $cfgdir/cfg_proc.h
+ * $test$: echo "#define CONFIG_KERN_PRI 1" >> $cfgdir/cfg_proc.h
  * $test$: cp bertos/cfg/cfg_sem.h $cfgdir/
  * $test$: echo  "#undef CONFIG_KERN_SEMAPHORES" >> $cfgdir/cfg_sem.h
  * $test$: echo "#define CONFIG_KERN_SEMAPHORES 1" >> $cfgdir/cfg_sem.h
 
 #include <drv/timer.h>
 
-// Global settings for the test.
+// Global settings for the serialization test.
 #define MAX_GLOBAL_COUNT             1024
 #define TEST_TIME_OUT_MS             6000
 #define DELAY                           5
 
-// Settings for the test process.
+// Settings for the test processes (serialization test).
 //Process 1
 #define INC_PROC_T1                     1
 #define DELAY_PROC_T1   INC_PROC_T1*DELAY
@@ -111,7 +130,7 @@ unsigned int global_count = 0;
 #define PROC_TEST_STACK(num)  PROC_DEFINE_STACK(proc_sem_test##num##_stack, KERN_MINSTACKSIZE * 2)
 #define PROC_TEST_INIT(num)   proc_new(proc_semTest##num, NULL, sizeof(proc_sem_test##num##_stack), proc_sem_test##num##_stack);
 
-// Define process
+// Define processes for the serialization test.
 PROC_TEST(1)
 PROC_TEST(2)
 PROC_TEST(3)
@@ -121,7 +140,99 @@ PROC_TEST(6)
 PROC_TEST(7)
 PROC_TEST(8)
 
-// Define process stacks for test.
+#if CONFIG_KERN_PRI
+
+// Global settings for the priority inversion test.
+// 0.5 secs, enough for seeing the effects
+#define BASETIME 500
+
+Semaphore s1, s2;
+unsigned int loops = 0;        // For counting iterations
+int finishing_time[8];
+
+enum ProcType {NONE, S1, S2, S1S2};
+/*
+ * Macros for the processes of the priority inversion test.
+ */
+#define PROC_INV_TEST(num) static void proc_semInvTest##num(void) \
+{ \
+       ProcType p_type = (ProcType)((long) proc_currentUserData()); \
+       int mult = p_type == NONE ? 5 : 1; \
+       unsigned int i, local_count = 0; \
+       ticks_t start; \
+       \
+       kprintf("> test%d(%d): Start.\n", num, proc_current()->link.pri); \
+       finishing_time[num-1] = timer_clock(); \
+       \
+       if (p_type == S1 || p_type == S1S2) { \
+               kprintf("> test%d(prio=%d): Obtain %p..\n", num, \
+                               proc_current()->link.pri, &s1); \
+               sem_obtain(&s1); \
+               kprintf("> test%d(prio=%d): Obtained %p.\n", num, \
+                               proc_current()->link.pri, &s1); \
+       } \
+       if (p_type == S2 || p_type == S1S2) { \
+               kprintf("> test%d(prio=%d): Obtain %p..\n", num, \
+                               proc_current()->link.pri, &s2); \
+               sem_obtain(&s2); \
+               kprintf("> test%d(prio=%d): Obtained %p.\n", num, \
+                               proc_current()->link.pri, &s2); \
+       } \
+       \
+       start = timer_clock(); \
+       for (i = 0; i < loops * mult && (((unsigned)timer_clock()-start) <= loops*mult); i++) { \
+               local_count++; \
+       } \
+       \
+       sem_obtain(&sem); \
+       global_count += local_count; \
+       kprintf("> test%d(prio=%d): global_count=%u..\n", num, \
+                       proc_current()->link.pri, global_count); \
+       sem_release(&sem); \
+       \
+       if (p_type == S2 || p_type == S1S2) { \
+               kprintf("> test%d(prio=%d): Release %p..\n", num, \
+                               proc_current()->link.pri, &s2); \
+               sem_release(&s2); \
+               kprintf("> test%d(prio=%d): %p Released.\n", num, \
+                               proc_current()->link.pri, &s2); \
+       } \
+       if (p_type == S1 || p_type == S1S2) { \
+               kprintf("> test%d(prio=%d): Release %p..\n", num, \
+                               proc_current()->link.pri, &s1); \
+               sem_release(&s1); \
+               kprintf("> test%d(prio=%d): %p Released.\n", num, \
+                               proc_current()->link.pri, &s1); \
+       } \
+       \
+       finishing_time[num-1] = timer_clock() - finishing_time[num-1]; \
+       kprintf("> test%d(prio=%d): Exit.\n", num, proc_current()->link.pri); \
+} \
+
+#define PROC_INV_TEST_INIT(num, pri, type) \
+do { \
+       struct Process *p; \
+       \
+       timer_delay(10); \
+       p = proc_new(proc_semInvTest##num, \
+                       ((void*)type), sizeof(proc_sem_test##num##_stack), \
+                       proc_sem_test##num##_stack); \
+       proc_setPri(p, pri); \
+} while (0) \
+
+// Define processes for the priority inversion test.
+PROC_INV_TEST(1)
+PROC_INV_TEST(2)
+PROC_INV_TEST(3)
+PROC_INV_TEST(4)
+PROC_INV_TEST(5)
+PROC_INV_TEST(6)
+PROC_INV_TEST(7)
+PROC_INV_TEST(8)
+
+#endif /* CONFIG_KERN_PRI */
+
+// Define process stacks for both of the tests.
 PROC_TEST_STACK(1)
 PROC_TEST_STACK(2)
 PROC_TEST_STACK(3)
@@ -131,16 +242,16 @@ PROC_TEST_STACK(6)
 PROC_TEST_STACK(7)
 PROC_TEST_STACK(8)
 
-/**
- * Run semaphore test
- */
-int sem_testRun(void)
+int sem_ser_test(void)
 {
        ticks_t start_time = timer_clock();
 
-       kprintf("Run semaphore test..\n");
+       sem_init(&sem);
+       global_count = 0;
+
+       kprintf("Run semaphore serialization test..\n");
 
-       //Init the process tests
+       // Initialize the processes.
        PROC_TEST_INIT(1)
        PROC_TEST_INIT(2)
        PROC_TEST_INIT(3)
@@ -171,17 +282,96 @@ int sem_testRun(void)
                proc_yield();
        }
 
-       kputs("Semaphore Test fail..\n");
+       kputs("Semaphore serialization test failed..\n");
        return -1;
 }
 
-int sem_testSetup(void)
+#if CONFIG_KERN_PRI
+
+int sem_inv_test(void)
 {
-       kdbg_init();
+       int i, orig_pri = proc_current()->link.pri;
+       ticks_t fake, start_time;
 
-       kprintf("Init Semaphore..");
        sem_init(&sem);
-       kprintf("Done.\n");
+       global_count = 0;
+       loops = 0;
+
+       sem_init(&s1);
+       sem_init(&s2);
+
+       kputs("> Main: calibration for the busy wait cycle..\n");
+       proc_setPri(proc_current(), 10);
+
+       fake = start_time = timer_clock();
+       while ((fake - start_time) < ms_to_ticks(BASETIME)) {
+               fake = timer_clock();
+               loops++;
+       }
+       kprintf("> Main: calibration done, %dms equals to %u cycles!\n", BASETIME, loops);
+
+       kputs("> Main: Run Priority Inversion test...\n");
+
+       // Will take s2
+       PROC_INV_TEST_INIT(1, 2, S2);
+
+       // 2 will block on s2; 3 will take s2 and still block on s2
+       PROC_INV_TEST_INIT(2, 3, S2);
+       PROC_INV_TEST_INIT(3, 4, S1S2);
+
+       // Will block on s1, nothing happens..
+       PROC_INV_TEST_INIT(4, 5, S1);
+
+       // No semaphore, without PI this will delay everyone!
+       PROC_INV_TEST_INIT(5, 6, NONE);
+
+       // Will block on s1 and boost
+       PROC_INV_TEST_INIT(6, 7, S1);
+       PROC_INV_TEST_INIT(7, 8, S1);
+       PROC_INV_TEST_INIT(8, 9, S1);
+
+       // All processes created, let them run.
+       proc_setPri(proc_current(), orig_pri);
+       while ((timer_clock() - start_time) < ms_to_ticks(TEST_TIME_OUT_MS*2)) {
+               if (sem_attempt(&sem)) {
+                       if (global_count >= loops*7 + loops*5) {
+                               for (i = 0; i < 8; i++)
+                                       kprintf("> Main: I-O latency of %d = %dms\n", i+1, ms_to_ticks(finishing_time[i]));
+                               kputs("> Main: Test Finished..Ok!\n");
+                               return 0;
+                       }
+                       sem_release(&sem);
+               }
+               proc_yield();
+       }
+
+       kputs("> Main: Priority Inversion Test failed..\n");
+       return -1;
+}
+
+#else
+
+void sem_inv_test(void)
+{
+}
+
+#endif /* CONFIG_KERN_PRI */
+
+/**
+ * Run semaphore test
+ */
+int sem_testRun(void)
+{
+       /* Start tests */
+       sem_ser_test();         // Serialization
+       sem_inv_test();         // Priority Inversion
+
+       return 0;
+}
+
+int sem_testSetup(void)
+{
+       kdbg_init();
 
        kprintf("Init Timer..");
        timer_init();
index a7e151a6a2015c8e3404665baea3e597597b22b0..efdf37ec334aa26b5e161433b424e659f4accd06 100644 (file)
@@ -40,6 +40,7 @@
 
 #include <kern/irq.h>
 #include <kern/proc.h>
+#include <kern/sem.h>
 #include <kern/monitor.h>
 #include <kern/msg.h>
 
@@ -227,6 +228,12 @@ void proc_demo(void)
        proc_testRun();
 }
 
+void sem_demo(void)
+{
+       sem_testRun();
+       sem_testTearDown();
+}
+
 void timer_demo(void)
 {
        timer_testRun();
@@ -283,6 +290,7 @@ static struct MenuItem main_items[] =
        { (const_iptr_t)"Bounce!",     0, (MenuHook)bouncing_logo,(iptr_t)&lcd_bitmap    },
        { (const_iptr_t)"Hello World", 0, (MenuHook)hello_world,  (iptr_t)&lcd_bitmap    },
        { (const_iptr_t)"Scheduling",  0, (MenuHook)proc_demo,    (iptr_t)&lcd_bitmap    },
+       { (const_iptr_t)"Semaphores",  0, (MenuHook)sem_demo,     (iptr_t)&lcd_bitmap    },
        { (const_iptr_t)"Timer Test",  0, (MenuHook)timer_demo,   (iptr_t)&lcd_bitmap    },
        { (const_iptr_t)"Menu MX",     0, (MenuHook)menu_handle,  (iptr_t)&mx_menu       },
        { (const_iptr_t)"Display",     0, (MenuHook)menu_handle,  (iptr_t)&display_menu  },
index b9ded303b5459801e54ff593bfe1c272638f45b3..714867ed674471aa72bb35bac8bd3cb40a9e0c14 100644 (file)
@@ -60,6 +60,7 @@ demo_CSRC = \
        bertos/kern/proc.c \
        bertos/kern/proc_test.c \
        bertos/kern/sem.c \
+       bertos/kern/sem_test.c \
        bertos/kern/signal.c \
        bertos/kern/monitor.c \
        bertos/verstag.c