1
0
mirror of https://github.com/RIOT-OS/RIOT.git synced 2025-01-18 12:52:44 +01:00

Merge pull request #14087 from bergzand/pr/tests/periph_spi/add_thread_time

tests/periph_spi: Add thread runtime stats
This commit is contained in:
benpicco 2020-05-19 16:37:54 +02:00 committed by GitHub
commit fbad1dff01
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 116 additions and 16 deletions

View File

@ -6,5 +6,6 @@ FEATURES_REQUIRED = periph_spi
USEMODULE += xtimer USEMODULE += xtimer
USEMODULE += shell USEMODULE += shell
USEMODULE += shell_commands USEMODULE += shell_commands
USEMODULE += schedstatistics
include $(RIOTBASE)/Makefile.include include $(RIOTBASE)/Makefile.include

View File

@ -27,6 +27,8 @@
#include "xtimer.h" #include "xtimer.h"
#include "shell.h" #include "shell.h"
#include "periph/spi.h" #include "periph/spi.h"
#include "schedstatistics.h"
#include "thread.h"
/** /**
* @brief Some parameters used for benchmarking * @brief Some parameters used for benchmarking
@ -45,6 +47,8 @@
static uint8_t bench_wbuf[BENCH_LARGE]; static uint8_t bench_wbuf[BENCH_LARGE];
static uint8_t bench_rbuf[BENCH_LARGE]; static uint8_t bench_rbuf[BENCH_LARGE];
extern void sched_statistics_cb(kernel_pid_t active_thread, kernel_pid_t next_thread);
/** /**
* @brief Generic buffer used for receiving * @brief Generic buffer used for receiving
*/ */
@ -57,6 +61,25 @@ static struct {
spi_cs_t cs; spi_cs_t cs;
} spiconf; } spiconf;
/*
* @brief Trigger an update of the scheduler runtime statistics.
*
* Increases the number of context switches by one as a side effect
*/
static void _sched_statistics_trigger(void)
{
sched_statistics_cb(sched_active_pid, sched_active_pid);
}
static xtimer_ticks32_t _sched_ticks(void)
{
_sched_statistics_trigger();
xtimer_ticks32_t runtime_ticks = {
.ticks32 = sched_pidlist[sched_active_pid].runtime_ticks
};
return runtime_ticks;
}
void print_bytes(char* title, uint8_t* data, size_t len) void print_bytes(char* title, uint8_t* data, size_t len)
{ {
printf("%4s\n", title); printf("%4s\n", title);
@ -223,7 +246,10 @@ int cmd_bench(int argc, char **argv)
(void)argv; (void)argv;
uint32_t start, stop; uint32_t start, stop;
xtimer_ticks32_t sched_start, sched_stop;
uint32_t sched_diff_us;
uint32_t sum = 0; uint32_t sum = 0;
uint32_t sched_sum = 0;
uint8_t in; uint8_t in;
uint8_t out = (uint8_t)BENCH_PAYLOAD; uint8_t out = (uint8_t)BENCH_PAYLOAD;
@ -242,163 +268,236 @@ int cmd_bench(int argc, char **argv)
return 1; return 1;
} }
puts("### Running some benchmarks, all values in [us] ###\n"); puts("### Running some benchmarks, all values in [us] ###");
puts("### Test\t\t\t\tTransfer time\tuser time\n");
/* 1 - write 1000 times 1 byte */ /* 1 - write 1000 times 1 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
in = spi_transfer_byte(spiconf.dev, spiconf.cs, false, out); in = spi_transfer_byte(spiconf.dev, spiconf.cs, false, out);
(void)in; (void)in;
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 1 - write %i times %i byte:", BENCH_REDOS, 1); printf(" 1 - write %i times %i byte:", BENCH_REDOS, 1);
printf("\t\t\t%i\n", (int)(stop - start)); printf("\t\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 2 - write 1000 times 2 byte */ /* 2 - write 1000 times 2 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
bench_wbuf, NULL, BENCH_SMALL); bench_wbuf, NULL, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 2 - write %i times %i byte:", BENCH_REDOS, BENCH_SMALL); printf(" 2 - write %i times %i byte:", BENCH_REDOS, BENCH_SMALL);
printf("\t\t\t%i\n", (int)(stop - start)); printf("\t\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 3 - write 1000 times 100 byte */ /* 3 - write 1000 times 100 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
bench_wbuf, NULL, BENCH_LARGE); bench_wbuf, NULL, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 3 - write %i times %i byte:", BENCH_REDOS, BENCH_LARGE); printf(" 3 - write %i times %i byte:", BENCH_REDOS, BENCH_LARGE);
printf("\t\t%i\n", (int)(stop - start)); printf("\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 4 - write 1000 times 1 byte to register */ /* 4 - write 1000 times 1 byte to register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
in = spi_transfer_reg(spiconf.dev, spiconf.cs, BENCH_REGADDR, out); in = spi_transfer_reg(spiconf.dev, spiconf.cs, BENCH_REGADDR, out);
(void)in; (void)in;
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 4 - write %i times %i byte to register:", BENCH_REDOS, 1); printf(" 4 - write %i times %i byte to register:", BENCH_REDOS, 1);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 5 - write 1000 times 2 byte to register */ /* 5 - write 1000 times 2 byte to register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
bench_wbuf, NULL, BENCH_SMALL); bench_wbuf, NULL, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 5 - write %i times %i byte to register:", BENCH_REDOS, BENCH_SMALL); printf(" 5 - write %i times %i byte to register:", BENCH_REDOS, BENCH_SMALL);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 6 - write 1000 times 100 byte to register */ /* 6 - write 1000 times 100 byte to register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
bench_wbuf, NULL, BENCH_LARGE); bench_wbuf, NULL, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 6 - write %i times %i byte to register:", BENCH_REDOS, BENCH_LARGE); printf(" 6 - write %i times %i byte to register:", BENCH_REDOS, BENCH_LARGE);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 7 - read 1000 times 2 byte */ /* 7 - read 1000 times 2 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
NULL, bench_rbuf, BENCH_SMALL); NULL, bench_rbuf, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 7 - read %i times %i byte:", BENCH_REDOS, BENCH_SMALL); printf(" 7 - read %i times %i byte:", BENCH_REDOS, BENCH_SMALL);
printf("\t\t\t%i\n", (int)(stop - start)); printf("\t\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 8 - read 1000 times 100 byte */ /* 8 - read 1000 times 100 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
NULL, bench_rbuf, BENCH_LARGE); NULL, bench_rbuf, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 8 - read %i times %i byte:", BENCH_REDOS, BENCH_LARGE); printf(" 8 - read %i times %i byte:", BENCH_REDOS, BENCH_LARGE);
printf("\t\t\t%i\n", (int)(stop - start)); printf("\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 9 - read 1000 times 2 byte from register */ /* 9 - read 1000 times 2 byte from register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
NULL, bench_rbuf, BENCH_SMALL); NULL, bench_rbuf, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf(" 9 - read %i times %i byte from register:", BENCH_REDOS, BENCH_SMALL); printf(" 9 - read %i times %i byte from register:", BENCH_REDOS, BENCH_SMALL);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 10 - read 1000 times 100 byte from register */ /* 10 - read 1000 times 100 byte from register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
NULL, bench_rbuf, BENCH_LARGE); NULL, bench_rbuf, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf("10 - read %i times %i byte from register:", BENCH_REDOS, BENCH_LARGE); printf("10 - read %i times %i byte from register:", BENCH_REDOS, BENCH_LARGE);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 11 - transfer 1000 times 2 byte */ /* 11 - transfer 1000 times 2 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
bench_wbuf, bench_rbuf, BENCH_SMALL); bench_wbuf, bench_rbuf, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf("11 - transfer %i times %i byte:", BENCH_REDOS, BENCH_SMALL); printf("11 - transfer %i times %i byte:", BENCH_REDOS, BENCH_SMALL);
printf("\t\t%i\n", (int)(stop - start)); printf("\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 12 - transfer 1000 times 100 byte */ /* 12 - transfer 1000 times 100 byte */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_bytes(spiconf.dev, spiconf.cs, false, spi_transfer_bytes(spiconf.dev, spiconf.cs, false,
bench_wbuf, bench_rbuf, BENCH_LARGE); bench_wbuf, bench_rbuf, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf("12 - transfer %i times %i byte:", BENCH_REDOS, BENCH_LARGE); printf("12 - transfer %i times %i byte:", BENCH_REDOS, BENCH_LARGE);
printf("\t\t%i\n", (int)(stop - start)); printf("\t\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 13 - transfer 1000 times 2 byte from/to register */ /* 13 - transfer 1000 times 2 byte from/to register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
bench_wbuf, bench_rbuf, BENCH_SMALL); bench_wbuf, bench_rbuf, BENCH_SMALL);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf("13 - transfer %i times %i byte to register:", BENCH_REDOS, BENCH_SMALL); printf("13 - transfer %i times %i byte to register:", BENCH_REDOS, BENCH_SMALL);
printf("\t%i\n", (int)(stop - start)); printf("\t%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
/* 14 - transfer 1000 times 100 byte from/to register */ /* 14 - transfer 1000 times 100 byte from/to register */
sched_start = _sched_ticks();
start = xtimer_now_usec(); start = xtimer_now_usec();
for (int i = 0; i < BENCH_REDOS; i++) { for (int i = 0; i < BENCH_REDOS; i++) {
spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR, spi_transfer_regs(spiconf.dev, spiconf.cs, BENCH_REGADDR,
bench_wbuf, bench_rbuf, BENCH_LARGE); bench_wbuf, bench_rbuf, BENCH_LARGE);
} }
stop = xtimer_now_usec(); stop = xtimer_now_usec();
sched_stop = _sched_ticks();
sched_diff_us = xtimer_usec_from_ticks(xtimer_diff(sched_stop,
sched_start));
printf("14 - transfer %i times %i byte to register:", BENCH_REDOS, BENCH_LARGE); printf("14 - transfer %i times %i byte to register:", BENCH_REDOS, BENCH_LARGE);
printf("\t%i\n", (int)(stop - start)); printf("%"PRIu32"\t%"PRIu32"\n", (stop - start), sched_diff_us);
sum += (stop - start); sum += (stop - start);
sched_sum += sched_diff_us;
printf("-- - SUM:\t\t\t\t\t%i\n", (int)sum); xtimer_sleep(1);
printf("-- - SUM:\t\t\t\t\t%"PRIu32"\t%"PRIu32"\n", sum, sched_sum);
spi_release(spiconf.dev); spi_release(spiconf.dev);
puts("\n### All runs complete ###"); puts("\n### All runs complete ###");