test/xtimer_hang: DEBUG_PINS

Add the option to use debug pins to investigate timing issues.

tests/xtimer_hang/Makefile

@@ -6,4 +6,18 @@ USEMODULE += xtimer
 
 TEST_ON_CI_WHITELIST += all
 
+# Port and pin configuration for probing with oscilloscope
+# Define Test pin for hardware timer interrupt, hardware dependent
+# For all ATmega Platforms
+#CFLAGS += -DDEBUG_TIMER_PORT=PORTF
+#CFLAGS += -DDEBUG_TIMER_DDR=DDRF
+#CFLAGS += -DDEBUG_TIMER_PIN=PORTF4
+
+# Define test probing pins GPIO API based.
+# Port number should be found in port enum e.g in cpu/include/periph_cpu.h
+#FEATURES_REQUIRED += periph_gpio
+# Jiminy probing Pins
+#CFLAGS += -DWORKER_THREAD_PIN=GPIO_PIN\(5,7\)
+#CFLAGS += -DMAIN_THREAD_PIN=GPIO_PIN\(5,6\)
+
 include $(RIOTBASE)/Makefile.include

tests/xtimer_hang/README.md

@@ -9,3 +9,14 @@ the test has failed.
 
 Please note (again), this is a runtime test to check if xtimer runs into a
 deadlock, it is not about clock stability nor accuracy of timing intervals.
+
+When debug pins are used and observed the expected output is as follows:
+The MAIN_THREAD_PIN is on for ca. 100ms and that in a regular interval. If this interval is not regular or has gaps this
+is an error. The WORKER_THREAD_PIN should toggle after 1ms and 1.1ms. (As this might fall in the XTIMER_ISR_BACKOFF the
+first pin toggle is delayed untill the second is ready. Thus the time interval can be longer.)
+If the Timer fall in the same interrupt there might be a interrupt before the second worker thread timer is set.
+This leads to a separation of the timer interrupts until they again fall in the same interrupt.
+It might happen that from the seperation of the interrupts till the merge there is only a uneven count of
+WORKER_THREAD_PIN toggles, which means a loss of one worker time 2, which is expected as it has a lower priority then
+worker timer 1. And thus in the moment when the hardware interrupt for the 2 worker is executet it has to wait for the
+1 worker timer because of the XTIMER_ISR_BACKOFF and so the first timer is executed first as it has the higher priority.

tests/xtimer_hang/main.c

@@ -29,6 +29,11 @@
 #include "thread.h"
 #include "log.h"
 
+#if defined(MAIN_THREAD_PIN) || defined(WORKER_THREAD_PIN)
+#include "board.h"
+#include "periph/gpio.h"
+#endif
+
 #define TEST_TIME_S             (10LU)
 #define TEST_INTERVAL_MS        (100LU)
 #define TEST_TIMER_STACKSIZE    (THREAD_STACKSIZE_DEFAULT)
@@ -38,14 +43,27 @@ char stack_timer2[TEST_TIMER_STACKSIZE];
 
 void* timer_func(void* arg)
 {
+#if defined(WORKER_THREAD_PIN)
+    gpio_t worker_pin = WORKER_THREAD_PIN;
+    gpio_init(worker_pin, GPIO_OUT);
+#endif
     LOG_DEBUG("run thread %" PRIkernel_pid "\n", thread_getpid());
     while(1) {
+#if defined(WORKER_THREAD_PIN)
+        gpio_set(worker_pin);
+        gpio_clear(worker_pin);
+#endif
         xtimer_usleep(*(uint32_t *)(arg));
     }
 }
 
 int main(void)
 {
+#if defined(MAIN_THREAD_PIN)
+    gpio_t main_pin = MAIN_THREAD_PIN;
+    gpio_init(main_pin, GPIO_OUT);
+#endif
+
     LOG_DEBUG("[INIT]\n");
     uint32_t sleep_timer1 = 1000;
     uint32_t sleep_timer2 = 1100;
@@ -63,7 +81,13 @@ int main(void)
     puts("[START]");
     while((now = xtimer_now_usec()) < until) {
         unsigned percent = (100 * (now - start)) / (until - start);
+#if defined(MAIN_THREAD_PIN)
+        gpio_set(main_pin);
+#endif
         xtimer_usleep(TEST_INTERVAL_MS * US_PER_MS);
+#if defined(MAIN_THREAD_PIN)
+        gpio_clear(main_pin);
+#endif
         printf("Testing (%3u%%)\n", percent);
     }
     puts("Testing (100%)");