[PATCH] common: add printf debugging automation

[Ahmad Fatoum <a.fatoum@pengutronix.de>]

This allows automating pinpointing of breakage outside PBL. For example
if barebox is stuck during startup:

  - Turn on CONFIG_DEBUG_LL and CONFIG_DEBUG_INITCALLS
  - Note last $initcall executed
  - Set CONFIG_FTRACE_CALLCHAIN=$initcall
  - Serial output will stop at the last called traced function

Alternatively, enable CONFIG_FTRACE and stick tracing_on() somewhere.

Output will look like:

 [<4fd859a5>]   (netconsole_init+0x1/0x120) from [<4fd014c7>] (start_barebox+0x43/0x7c)
 [<4fd77209>]     (xzalloc+0x1/0x34) from [<4fd859bd>] (netconsole_init+0x19/0x120)
 [<4fd7719d>]       (xmalloc+0x1/0x34) from [<4fd77221>] (xzalloc+0x19/0x34)
 [<4fd0995d>]         (malloc+0x1/0x54) from [<4fd771b5>] (xmalloc+0x19/0x34)
 [<4fd0aae1>]           (tlsf_malloc+0x1/0x48) from [<4fd09983>] (malloc+0x27/0x54)
 [<4fd0a1d9>]             (adjust_request_size+0x1/0x44) from [<4fd0aaff>] (tlsf_malloc+0x1f/0x48)
 [<4fd0a18d>]               (align_up+0x1/0x4c) from [<4fd0a205>] (adjust_request_size+0x2d/0x44)
 [<4fd0aa55>]             (block_locate_free+0x1/0x8c) from [<4fd0ab09>] (tlsf_malloc+0x29/0x48)

This is added as an experimental feature as it's not meant to be enabled
at all time due to large overhead and may change considerably in future,
e.g. to allow dumping to memory buffer and to record timestamps for
profiling.

Signed-off-by: Ahmad Fatoum <a.fatoum@pengutronix.de>
---
 Makefile           | 10 +++++-
 common/Kconfig     | 15 +++++++++
 include/ftrace.h   | 18 +++++++++++
 lib/Makefile       |  4 +++
 lib/ftrace.c       | 77 ++++++++++++++++++++++++++++++++++++++++++++++
 lib/kasan/Makefile |  5 +++
 6 files changed, 128 insertions(+), 1 deletion(-)
 create mode 100644 include/ftrace.h
 create mode 100644 lib/ftrace.c

diff --git a/Makefile b/Makefile
index c04deaaa0f69..34743f4b6b45 100644
--- a/Makefile
+++ b/Makefile
@@ -469,7 +469,7 @@ export KBUILD_AFLAGS AFLAGS_KERNEL AFLAGS_MODULE
 export KBUILD_AFLAGS_MODULE KBUILD_CFLAGS_MODULE
 export KBUILD_AFLAGS_KERNEL KBUILD_CFLAGS_KERNEL
 export LDFLAGS_barebox
-export LDFLAGS_pbl
+export LDFLAGS_pbl PBL_CPPFLAGS
 
 export CFLAGS_UBSAN
 export CFLAGS_KASAN CFLAGS_KASAN_NOSANITIZE
@@ -682,6 +682,14 @@ KBUILD_CFLAGS += $(call cc-option,-Wno-pointer-sign,)
 # change __FILE__ to the relative path from the srctree
 KBUILD_CFLAGS += $(call cc-option,-fmacro-prefix-map=$(srctree)/=)
 
+# The arch Makefiles can override CC_FLAGS_FTRACE. We may also append it later.
+ifdef CONFIG_FTRACE
+CC_FLAGS_FTRACE := -finstrument-functions
+export CC_FLAGS_FTRACE
+KBUILD_CFLAGS	+= $(CC_FLAGS_FTRACE)
+PBL_CPPFLAGS   += -fno-instrument-functions
+endif
+
 include-y +=scripts/Makefile.ubsan
 include-$(CONFIG_KASAN)         += scripts/Makefile.kasan
 
diff --git a/common/Kconfig b/common/Kconfig
index b8c3e34c0a58..2a35b43e2717 100644
--- a/common/Kconfig
+++ b/common/Kconfig
@@ -1592,6 +1592,21 @@ config ASAN
 	  Enables ASAN (AddressSANitizer) - runtime memory debugger,
 	  designed to find out-of-bounds accesses and use-after-free bugs.
 
+config FTRACE
+	bool "Enable function tracing (Only for debugging!)
+	depends on EXPERIMENTAL
+	help
+	  This is not Linux-like ftrace, but a poor man's substitute using
+	  GCC function instrumentation.
+
+config FTRACE_CALLCHAIN
+	string "Print execution trace of all function below"
+	depends on FTRACE && KALLSYMS
+	default ""
+	help
+	  All functions called directly or indirectly by the specified
+	  function will be logged to serial. Keep empty to disable
+
 config COMPILE_TEST
 	bool "compile-test drivers of other platforms"
 	default n
diff --git a/include/ftrace.h b/include/ftrace.h
new file mode 100644
index 000000000000..68b46f1fa1d4
--- /dev/null
+++ b/include/ftrace.h
@@ -0,0 +1,18 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+
+#ifndef _FTRACE_H__
+#define _FTRACE_H__
+
+#ifdef CONFIG_FTRACE
+void tracing_on(void);
+void tracing_off(void);
+#else
+static inline void tracing_on(void)
+{
+}
+static inline void tracing_off(void)
+{
+}
+#endif
+
+#endif /* _FTRACE_H */
diff --git a/lib/Makefile b/lib/Makefile
index 3f6653d74e9a..7b86ad3383c3 100644
--- a/lib/Makefile
+++ b/lib/Makefile
@@ -73,6 +73,7 @@ obj-$(CONFIG_CRC_CCITT) += crc-ccitt.o
 obj-$(CONFIG_CRC8)	+= crc8.o
 obj-$(CONFIG_NLS)	+= nls_base.o
 obj-$(CONFIG_FSL_QE_FIRMWARE) += fsl-qe-firmware.o
+obj-$(CONFIG_FTRACE)	+= ftrace.o
 obj-$(CONFIG_UBSAN)	+= ubsan.o
 
 # GCC library routines
@@ -85,6 +86,9 @@ pbl-$(CONFIG_GENERIC_LIB_ASHLDI3) += ashldi3.o
 
 UBSAN_SANITIZE_ubsan.o := n
 
+CFLAGS_REMOVE_ubsan.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_ftrace.o = $(CC_FLAGS_FTRACE)
+
 libfdt_files = fdt.o fdt_ro.o fdt_wip.o fdt_rw.o fdt_sw.o fdt_strerror.o \
 	                      fdt_empty_tree.o
 $(foreach file, $(libfdt_files), \
diff --git a/lib/ftrace.c b/lib/ftrace.c
new file mode 100644
index 000000000000..1d0b36c10550
--- /dev/null
+++ b/lib/ftrace.c
@@ -0,0 +1,77 @@
+// SPDX-License-Identifier: GPL-2.0-or-later
+
+#include <common.h>
+#include <clock.h>
+#include <ftrace.h>
+#include <kallsyms.h>
+
+static int trace_enabled __section(".data");
+static volatile int trace_lock __section(".data");
+static int depth __section(".data");
+static const void *trigger __section(".data");
+
+void notrace tracing_on(void)
+{
+	if (trace_lock)
+		return;
+	trigger = NULL;
+	trace_enabled = 1;
+}
+
+void notrace tracing_off(void)
+{
+	if (trace_lock)
+		return;
+	trigger = NULL;
+	trace_enabled = 0;
+}
+
+void notrace __cyg_profile_func_enter(void *where, void *from)
+{
+	if (trace_lock)
+		return;
+
+	if (trace_enabled <= 0) {
+		if (where == trigger)
+			trace_enabled++;
+		else
+			return;
+	}
+
+	depth++;
+
+	trace_lock = true;
+
+	printf(" [<%08lx>] %*s(%pS) from [<%08lx>] (%pS)\n", (ulong) where,
+	       depth * 2, "", where, (ulong)from, from);
+
+	trace_lock = false;
+}
+
+void notrace __cyg_profile_func_exit(void *where, void *from)
+{
+	if (trace_lock || !trace_enabled)
+		return;
+
+	depth--;
+
+	if (where == trigger)
+		trace_enabled--;
+}
+
+static int init_trace(void)
+{
+	ulong _trigger;
+
+	trace_lock = true;
+
+	_trigger = kallsyms_lookup_name(CONFIG_FTRACE_CALLCHAIN);
+	if (IS_ENABLED(CONFIG_THUMB2_BAREBOX))
+		_trigger |= 1;
+	trigger = (void *)_trigger;
+
+	trace_lock = false;
+
+	return 0;
+}
+pure_initcall(init_trace);
diff --git a/lib/kasan/Makefile b/lib/kasan/Makefile
index e3f4bb61f900..06fa906ff620 100644
--- a/lib/kasan/Makefile
+++ b/lib/kasan/Makefile
@@ -13,3 +13,8 @@ CFLAGS_generic_report.o := $(CC_FLAGS_KASAN_RUNTIME)
 CFLAGS_generic.o := $(CC_FLAGS_KASAN_RUNTIME)
 CFLAGS_report.o := $(CC_FLAGS_KASAN_RUNTIME)
 CFLAGS_common.o := $(CC_FLAGS_KASAN_RUNTIME)
+
+CFLAGS_REMOVE_generic_report.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_generic.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_report.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_common.o = $(CC_FLAGS_FTRACE)
-- 
2.30.2


_______________________________________________
barebox mailing list
barebox@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/barebox