Ronald G. Minnich (rminnich@gmail.com) just uploaded a new patch set to gerrit, which you can find at http://review.coreboot.org/7116
-gerrit
commit bf736f5e37b8593993e3c2c06bb90301071a5477 Author: Ronald G. Minnich rminnich@gmail.com Date: Sat Oct 18 06:09:24 2014 +0000
Poor man's ftrace from akaros
This is the poor man's ftrace from Akaros (just search for that term)
To use: suppose you want to trace all file entry and exit in some piece of code, e.g. cbfs.
Just: spatch --in-place --sp-file scripts/spatch/poor-ftrace.coci src/lib/cbfs*.c Build as usual.
When you run, you'll see function calls, and they will be spaced in according to their call depth, e.g.: a b c b d b a
Sadly, in pre-ram stage, this indenting is not possible. Instead, we print ENTER on entry and EXIT on exit. It's usable.
It's incredibly useful for debugging. We have been able to very quickly zero in on bugs in Akaros with this code. I print at BIOS_EMERG so you're sure to take it out when done (just git checkout the files you're tracing or reverse the spatch.)
For example, on riscv, I know it's dying, I don't know where.
spatch --sp-file util/spatch/poor-ftrace.cocci src/arch/riscv/*.c src/lib/cbfs.c
I get this:
Find fallback cbfs_load_stage() in src/lib/cbfs.c init_default_cbfs_media() in src/arch/riscv/rom_media.c ---- init_default_cbfs_media() init_rom_media_cbfs() in src/arch/riscv/rom_media.c
And I know where to start.
You do need spatch installed.
Change-Id: I69c3c20d30ebd666c0e859cea906a3fd5a094441 Signed-off-by: Ronald G. Minnich rminnich@gmail.com --- src/console/printk.c | 42 ++++++++++++++++++++++++++++++++++++++++++ src/include/console/console.h | 6 ++++++ util/spatch/poor-ftrace.cocci | 18 ++++++++++++++++++ 3 files changed, 66 insertions(+)
diff --git a/src/console/printk.c b/src/console/printk.c index b6777e1..4597007 100644 --- a/src/console/printk.c +++ b/src/console/printk.c @@ -12,6 +12,7 @@ #include <smp/node.h> #include <stddef.h> #include <trace.h> +#include <stdlib.h>
DECLARE_SPIN_LOCK(console_lock)
@@ -62,3 +63,44 @@ void do_vtxprintf(const char *fmt, va_list args) console_tx_flush(); } #endif /* CONFIG_CHROMEOS */ + +#ifdef __PRE_RAM__ +/* sadly, pretty printing the call depth in pre-ram is not an option. How sad! */ + +void __print_func_entry(const char *func, const char *file) +{ + printk(BIOS_EMERG, "ENTER %s() in %s\n", func, file); +} +/* for tracing. You can call these on func entry and exit. + * Or, better, you can use the spatch in utils to add + * such tracing. + */ +void __print_func_exit(const char *func, const char *file) +{ + printk(BIOS_EMERG, "EXIT ---- %s()\n", func); +} + +#else +int tab_depth = 0; + +void __print_func_entry(const char *func, const char *file) +{ + char tentabs[] = "\t\t\t\t\t\t\t\t\t\t"; // ten tabs and a \0 + char *ourtabs = &tentabs[10 - MIN(tab_depth, 10)]; + printk(BIOS_EMERG, "%s%s() in %s\n", ourtabs, func, file); + tab_depth++; +} +/* for tracing. You can call these on func entry and exit. + * Or, better, you can use the spatch in utils to add + * such tracing. + */ +void __print_func_exit(const char *func, const char *file) +{ + char tentabs[] = "\t\t\t\t\t\t\t\t\t\t"; // ten tabs and a \0 + char *ourtabs; + tab_depth--; + ourtabs = &tentabs[10 - MIN(tab_depth, 10)]; + printk(BIOS_EMERG, "%s---- %s()\n", ourtabs, func); +} + +#endif diff --git a/src/include/console/console.h b/src/include/console/console.h index 9e98bfc..d5ec2f3 100644 --- a/src/include/console/console.h +++ b/src/include/console/console.h @@ -75,6 +75,12 @@ static inline void do_vtxprintf(const char *fmt, va_list args) {}; */ #include <console/early_print.h>
+/* for the poor man's ftrace. */ +void __print_func_entry(const char *func, const char *file); +void __print_func_exit(const char *func, const char *file); +#define print_func_entry() __print_func_entry(__FUNCTION__, __FILE__) +#define print_func_exit() __print_func_exit(__FUNCTION__, __FILE__) + #else /* __ROMCC__ */
#include "arch/x86/lib/romcc_console.c" diff --git a/util/spatch/poor-ftrace.cocci b/util/spatch/poor-ftrace.cocci new file mode 100644 index 0000000..3754374 --- /dev/null +++ b/util/spatch/poor-ftrace.cocci @@ -0,0 +1,18 @@ +// prints entry/exit when entering/leaving a function + +// for example, spatch with: +// $ for i in kern/src/ns/ kern/src/net kern/drivers/; do \ +// spatch --sp-file scripts/spatch/poor-ftrace.cocci --in-place $i; done +// if you have functions you want to ignore, add them to the blacklist in +// kern/src/kdebug.c +@@ +type t; +function f; +@@ +t f(...) { ++print_func_entry(); +<... ++print_func_exit(); +return ...; +...> +}