[PATCH 0/2] Add "trace clear"
This short series implements the "trace clear" command. Originally sent as a single patch [1] but here with a sandbox test added.
Jerome Forissier (2): trace: add support for "trace clear" test: test_trace.py: test "trace clear" command
cmd/trace.c | 13 +++++++++- include/trace.h | 2 ++ lib/trace.c | 47 ++++++++++++++++++++++++++----------- test/py/tests/test_trace.py | 30 +++++++++++++++++++++++ 4 files changed, 77 insertions(+), 15 deletions(-)
v2: - Added patch: 'test: test_trace.py: test "trace clear" command'
v1: - Sent as a single patch: https://lists.denx.de/pipermail/u-boot/2024-December/574148.html
Implement a "trace clear" command to delete the currently accumulated trace data. This comes handy when someone needs to trace a particular command. For example:
=> trace clear; dhcp; trace pause => trace stats => trace calls 0x02100000 0x10000000 => tftpput $profbase $profoffset 192.168.0.16:trace.bin
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org --- cmd/trace.c | 13 ++++++++++++- include/trace.h | 2 ++ lib/trace.c | 47 +++++++++++++++++++++++++++++++++-------------- 3 files changed, 47 insertions(+), 15 deletions(-)
diff --git a/cmd/trace.c b/cmd/trace.c index 937e6a682ad..e95ac7ca9da 100644 --- a/cmd/trace.c +++ b/cmd/trace.c @@ -87,8 +87,18 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) trace_set_enabled(0); break; case 'c': - if (create_call_list(argc, argv)) + switch (*(cmd + 1)) { + case 'a': + if (create_call_list(argc, argv)) + return cmd_usage(cmdtp); + break; + case 'l': + if (trace_clear()) + return CMD_RET_FAILURE; + break; + default: return cmd_usage(cmdtp); + } break; case 'r': trace_set_enabled(1); @@ -113,6 +123,7 @@ U_BOOT_CMD( "stats - display tracing statistics\n" "trace pause - pause tracing\n" "trace resume - resume tracing\n" + "trace clear - clear traces\n" "trace funclist [<addr> <size>] - dump function list into buffer\n" "trace calls [<addr> <size>] " "- dump function call trace into buffer" diff --git a/include/trace.h b/include/trace.h index 763d6d1255a..782eaae2fc2 100644 --- a/include/trace.h +++ b/include/trace.h @@ -100,6 +100,8 @@ void trace_set_enabled(int enabled);
int trace_early_init(void);
+int trace_clear(void); + /** * Init the trace system * diff --git a/lib/trace.c b/lib/trace.c index cabbe47b58a..def9f912c92 100644 --- a/lib/trace.c +++ b/lib/trace.c @@ -351,14 +351,8 @@ static int get_func_count(void) return gd->mon_len / FUNC_SITE_SIZE; }
-/** - * trace_init() - initialize the tracing system and enable it - * - * @buff: Pointer to trace buffer - * @buff_size: Size of trace buffer - * Return: 0 if ok - */ -int notrace trace_init(void *buff, size_t buff_size) +static int notrace trace_init_(void *buff, size_t buff_size, bool copy_early, + bool enable) { int func_count = get_func_count(); size_t needed; @@ -368,7 +362,7 @@ int notrace trace_init(void *buff, size_t buff_size) return func_count; trace_save_gd();
- if (!was_disabled) { + if (copy_early) { #ifdef CONFIG_TRACE_EARLY ulong used, count; char *end; @@ -394,9 +388,6 @@ int notrace trace_init(void *buff, size_t buff_size) } puts("\n"); memcpy(buff, hdr, used); -#else - puts("trace: already enabled\n"); - return -EALREADY; #endif } hdr = (struct trace_hdr *)buff; @@ -419,13 +410,41 @@ int notrace trace_init(void *buff, size_t buff_size) hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); hdr->depth_limit = CONFIG_TRACE_CALL_DEPTH_LIMIT;
- puts("trace: enabled\n"); - trace_enabled = 1; + printf("trace: initialized, %senabled\n", enable ? "" : "not "); + trace_enabled = enable; trace_inited = 1;
return 0; }
+/** + * trace_init() - initialize the tracing system and enable it + * + * @buff: Pointer to trace buffer + * @buff_size: Size of trace buffer + * Return: 0 if ok + */ +int notrace trace_init(void *buff, size_t buff_size) +{ + /* If traces are enabled already, we may have early traces to copy */ + return trace_init_(buff, buff_size, trace_enabled, true); +} + +/** + * trace_clear() - clear accumulated traced data + * + * May be called with tracing enabled or disabled. + */ +int notrace trace_clear(void) +{ + bool was_enabled = trace_enabled; + + if (trace_enabled) + trace_enabled = 0; + return trace_init_(gd->trace_buff, CONFIG_TRACE_BUFFER_SIZE, + false, was_enabled); +} + #ifdef CONFIG_TRACE_EARLY /** * trace_early_init() - initialize the tracing system for early tracing
Hi Jerome
On Mon, 9 Dec 2024 at 17:32, Jerome Forissier jerome.forissier@linaro.org wrote:
Implement a "trace clear" command to delete the currently accumulated trace data. This comes handy when someone needs to trace a particular command. For example:
=> trace clear; dhcp; trace pause => trace stats => trace calls 0x02100000 0x10000000 => tftpput $profbase $profoffset 192.168.0.16:trace.bin
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org
cmd/trace.c | 13 ++++++++++++- include/trace.h | 2 ++ lib/trace.c | 47 +++++++++++++++++++++++++++++++++-------------- 3 files changed, 47 insertions(+), 15 deletions(-)
diff --git a/cmd/trace.c b/cmd/trace.c index 937e6a682ad..e95ac7ca9da 100644 --- a/cmd/trace.c +++ b/cmd/trace.c @@ -87,8 +87,18 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) trace_set_enabled(0); break; case 'c':
if (create_call_list(argc, argv))
switch (*(cmd + 1)) {case 'a':if (create_call_list(argc, argv))return cmd_usage(cmdtp);break;case 'l':if (trace_clear())return CMD_RET_FAILURE;break;
Instead of this, mind changing the command to trace wipe or something similar? Then we can have a discrete case for 'w' rather than scanning for a string
Cheers /Ilias
default: return cmd_usage(cmdtp);} break; case 'r': trace_set_enabled(1);@@ -113,6 +123,7 @@ U_BOOT_CMD( "stats - display tracing statistics\n" "trace pause - pause tracing\n" "trace resume - resume tracing\n"
"trace clear - clear traces\n" "trace funclist [<addr> <size>] - dump function list into buffer\n" "trace calls [<addr> <size>] " "- dump function call trace into buffer"diff --git a/include/trace.h b/include/trace.h index 763d6d1255a..782eaae2fc2 100644 --- a/include/trace.h +++ b/include/trace.h @@ -100,6 +100,8 @@ void trace_set_enabled(int enabled);
int trace_early_init(void);
+int trace_clear(void);
/**
- Init the trace system
diff --git a/lib/trace.c b/lib/trace.c index cabbe47b58a..def9f912c92 100644 --- a/lib/trace.c +++ b/lib/trace.c @@ -351,14 +351,8 @@ static int get_func_count(void) return gd->mon_len / FUNC_SITE_SIZE; }
-/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
-int notrace trace_init(void *buff, size_t buff_size) +static int notrace trace_init_(void *buff, size_t buff_size, bool copy_early,
bool enable){ int func_count = get_func_count(); size_t needed; @@ -368,7 +362,7 @@ int notrace trace_init(void *buff, size_t buff_size) return func_count; trace_save_gd();
if (!was_disabled) {
if (copy_early) {#ifdef CONFIG_TRACE_EARLY ulong used, count; char *end; @@ -394,9 +388,6 @@ int notrace trace_init(void *buff, size_t buff_size) } puts("\n"); memcpy(buff, hdr, used); -#else
puts("trace: already enabled\n");return -EALREADY;#endif } hdr = (struct trace_hdr *)buff; @@ -419,13 +410,41 @@ int notrace trace_init(void *buff, size_t buff_size) hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); hdr->depth_limit = CONFIG_TRACE_CALL_DEPTH_LIMIT;
puts("trace: enabled\n");trace_enabled = 1;
printf("trace: initialized, %senabled\n", enable ? "" : "not ");trace_enabled = enable; trace_inited = 1; return 0;}
+/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
+int notrace trace_init(void *buff, size_t buff_size) +{
/* If traces are enabled already, we may have early traces to copy */return trace_init_(buff, buff_size, trace_enabled, true);+}
+/**
- trace_clear() - clear accumulated traced data
- May be called with tracing enabled or disabled.
- */
+int notrace trace_clear(void) +{
bool was_enabled = trace_enabled;if (trace_enabled)trace_enabled = 0;return trace_init_(gd->trace_buff, CONFIG_TRACE_BUFFER_SIZE,false, was_enabled);+}
#ifdef CONFIG_TRACE_EARLY /**
- trace_early_init() - initialize the tracing system for early tracing
-- 2.43.0
On 12/13/24 13:09, Ilias Apalodimas wrote:
Hi Jerome
On Mon, 9 Dec 2024 at 17:32, Jerome Forissier jerome.forissier@linaro.org wrote:
Implement a "trace clear" command to delete the currently accumulated trace data. This comes handy when someone needs to trace a particular command. For example:
=> trace clear; dhcp; trace pause => trace stats => trace calls 0x02100000 0x10000000 => tftpput $profbase $profoffset 192.168.0.16:trace.bin
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org
cmd/trace.c | 13 ++++++++++++- include/trace.h | 2 ++ lib/trace.c | 47 +++++++++++++++++++++++++++++++++-------------- 3 files changed, 47 insertions(+), 15 deletions(-)
diff --git a/cmd/trace.c b/cmd/trace.c index 937e6a682ad..e95ac7ca9da 100644 --- a/cmd/trace.c +++ b/cmd/trace.c @@ -87,8 +87,18 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) trace_set_enabled(0); break; case 'c':
if (create_call_list(argc, argv))
switch (*(cmd + 1)) {case 'a':if (create_call_list(argc, argv))return cmd_usage(cmdtp);break;case 'l':if (trace_clear())return CMD_RET_FAILURE;break;Instead of this, mind changing the command to trace wipe or something similar? Then we can have a discrete case for 'w' rather than scanning for a string
Good idea.
Thanks,
Thanks,
Apologies I missed something else as well
On Fri, 13 Dec 2024 at 14:14, Jerome Forissier jerome.forissier@linaro.org wrote:
On 12/13/24 13:09, Ilias Apalodimas wrote:
Hi Jerome
On Mon, 9 Dec 2024 at 17:32, Jerome Forissier jerome.forissier@linaro.org wrote:
Implement a "trace clear" command to delete the currently accumulated trace data. This comes handy when someone needs to trace a particular command. For example:
=> trace clear; dhcp; trace pause => trace stats => trace calls 0x02100000 0x10000000 => tftpput $profbase $profoffset 192.168.0.16:trace.bin
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org
cmd/trace.c | 13 ++++++++++++- include/trace.h | 2 ++ lib/trace.c | 47 +++++++++++++++++++++++++++++++++-------------- 3 files changed, 47 insertions(+), 15 deletions(-)
diff --git a/cmd/trace.c b/cmd/trace.c index 937e6a682ad..e95ac7ca9da 100644 --- a/cmd/trace.c +++ b/cmd/trace.c @@ -87,8 +87,18 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) trace_set_enabled(0); break; case 'c':
if (create_call_list(argc, argv))
switch (*(cmd + 1)) {case 'a':if (create_call_list(argc, argv))return cmd_usage(cmdtp);break;case 'l':if (trace_clear())return CMD_RET_FAILURE;break;Instead of this, mind changing the command to trace wipe or something similar? Then we can have a discrete case for 'w' rather than scanning for a string
Good idea.
Thanks,
Jerome
Cheers /Ilias
default: return cmd_usage(cmdtp);} break; case 'r': trace_set_enabled(1);@@ -113,6 +123,7 @@ U_BOOT_CMD( "stats - display tracing statistics\n" "trace pause - pause tracing\n" "trace resume - resume tracing\n"
"trace clear - clear traces\n" "trace funclist [<addr> <size>] - dump function list into buffer\n" "trace calls [<addr> <size>] " "- dump function call trace into buffer"diff --git a/include/trace.h b/include/trace.h index 763d6d1255a..782eaae2fc2 100644 --- a/include/trace.h +++ b/include/trace.h @@ -100,6 +100,8 @@ void trace_set_enabled(int enabled);
int trace_early_init(void);
+int trace_clear(void);
/**
- Init the trace system
diff --git a/lib/trace.c b/lib/trace.c index cabbe47b58a..def9f912c92 100644 --- a/lib/trace.c +++ b/lib/trace.c @@ -351,14 +351,8 @@ static int get_func_count(void) return gd->mon_len / FUNC_SITE_SIZE; }
-/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
-int notrace trace_init(void *buff, size_t buff_size) +static int notrace trace_init_(void *buff, size_t buff_size, bool copy_early,
bool enable){ int func_count = get_func_count(); size_t needed; @@ -368,7 +362,7 @@ int notrace trace_init(void *buff, size_t buff_size) return func_count; trace_save_gd();
if (!was_disabled) {
if (copy_early) {#ifdef CONFIG_TRACE_EARLY ulong used, count; char *end; @@ -394,9 +388,6 @@ int notrace trace_init(void *buff, size_t buff_size) } puts("\n"); memcpy(buff, hdr, used); -#else
puts("trace: already enabled\n");return -EALREADY;#endif } hdr = (struct trace_hdr *)buff; @@ -419,13 +410,41 @@ int notrace trace_init(void *buff, size_t buff_size) hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); hdr->depth_limit = CONFIG_TRACE_CALL_DEPTH_LIMIT;
puts("trace: enabled\n");trace_enabled = 1;
printf("trace: initialized, %senabled\n", enable ? "" : "not ");trace_enabled = enable; trace_inited = 1; return 0;}
+/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
+int notrace trace_init(void *buff, size_t buff_size) +{
/* If traces are enabled already, we may have early traces to copy */return trace_init_(buff, buff_size, trace_enabled, true);
This is a global, so you can skip passing it and just check the trace_enabled in trace_init_()
Thanks /Ilias
+}
+/**
- trace_clear() - clear accumulated traced data
- May be called with tracing enabled or disabled.
- */
+int notrace trace_clear(void) +{
bool was_enabled = trace_enabled;if (trace_enabled)trace_enabled = 0;return trace_init_(gd->trace_buff, CONFIG_TRACE_BUFFER_SIZE,false, was_enabled);+}
#ifdef CONFIG_TRACE_EARLY /**
- trace_early_init() - initialize the tracing system for early tracing
-- 2.43.0
On 12/13/24 13:16, Ilias Apalodimas wrote:
Thanks,
Apologies I missed something else as well
On Fri, 13 Dec 2024 at 14:14, Jerome Forissier jerome.forissier@linaro.org wrote:
On 12/13/24 13:09, Ilias Apalodimas wrote:
Hi Jerome
On Mon, 9 Dec 2024 at 17:32, Jerome Forissier jerome.forissier@linaro.org wrote:
Implement a "trace clear" command to delete the currently accumulated trace data. This comes handy when someone needs to trace a particular command. For example:
=> trace clear; dhcp; trace pause => trace stats => trace calls 0x02100000 0x10000000 => tftpput $profbase $profoffset 192.168.0.16:trace.bin
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org
cmd/trace.c | 13 ++++++++++++- include/trace.h | 2 ++ lib/trace.c | 47 +++++++++++++++++++++++++++++++++-------------- 3 files changed, 47 insertions(+), 15 deletions(-)
diff --git a/cmd/trace.c b/cmd/trace.c index 937e6a682ad..e95ac7ca9da 100644 --- a/cmd/trace.c +++ b/cmd/trace.c @@ -87,8 +87,18 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) trace_set_enabled(0); break; case 'c':
if (create_call_list(argc, argv))
switch (*(cmd + 1)) {case 'a':if (create_call_list(argc, argv))return cmd_usage(cmdtp);break;case 'l':if (trace_clear())return CMD_RET_FAILURE;break;Instead of this, mind changing the command to trace wipe or something similar? Then we can have a discrete case for 'w' rather than scanning for a string
Good idea.
Thanks,
Jerome
Cheers /Ilias
default: return cmd_usage(cmdtp);} break; case 'r': trace_set_enabled(1);@@ -113,6 +123,7 @@ U_BOOT_CMD( "stats - display tracing statistics\n" "trace pause - pause tracing\n" "trace resume - resume tracing\n"
"trace clear - clear traces\n" "trace funclist [<addr> <size>] - dump function list into buffer\n" "trace calls [<addr> <size>] " "- dump function call trace into buffer"diff --git a/include/trace.h b/include/trace.h index 763d6d1255a..782eaae2fc2 100644 --- a/include/trace.h +++ b/include/trace.h @@ -100,6 +100,8 @@ void trace_set_enabled(int enabled);
int trace_early_init(void);
+int trace_clear(void);
/**
- Init the trace system
diff --git a/lib/trace.c b/lib/trace.c index cabbe47b58a..def9f912c92 100644 --- a/lib/trace.c +++ b/lib/trace.c @@ -351,14 +351,8 @@ static int get_func_count(void) return gd->mon_len / FUNC_SITE_SIZE; }
-/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
-int notrace trace_init(void *buff, size_t buff_size) +static int notrace trace_init_(void *buff, size_t buff_size, bool copy_early,
bool enable){ int func_count = get_func_count(); size_t needed; @@ -368,7 +362,7 @@ int notrace trace_init(void *buff, size_t buff_size) return func_count; trace_save_gd();
if (!was_disabled) {
if (copy_early) {#ifdef CONFIG_TRACE_EARLY ulong used, count; char *end; @@ -394,9 +388,6 @@ int notrace trace_init(void *buff, size_t buff_size) } puts("\n"); memcpy(buff, hdr, used); -#else
puts("trace: already enabled\n");return -EALREADY;#endif } hdr = (struct trace_hdr *)buff; @@ -419,13 +410,41 @@ int notrace trace_init(void *buff, size_t buff_size) hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); hdr->depth_limit = CONFIG_TRACE_CALL_DEPTH_LIMIT;
puts("trace: enabled\n");trace_enabled = 1;
printf("trace: initialized, %senabled\n", enable ? "" : "not ");trace_enabled = enable; trace_inited = 1; return 0;}
+/**
- trace_init() - initialize the tracing system and enable it
- @buff: Pointer to trace buffer
- @buff_size: Size of trace buffer
- Return: 0 if ok
- */
+int notrace trace_init(void *buff, size_t buff_size) +{
/* If traces are enabled already, we may have early traces to copy */return trace_init_(buff, buff_size, trace_enabled, true);This is a global, so you can skip passing it and just check the trace_enabled in trace_init_()
Unfortunately not, because trace_clear() needs to be able to invoke trace_init_() with copy_early = false (we never want to copy the early trace buffer when coming from the 'trace clear' command).
Thanks,
Also test the newly added command 'trace clear'.
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org --- test/py/tests/test_trace.py | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+)
diff --git a/test/py/tests/test_trace.py b/test/py/tests/test_trace.py index ec1e624722c..29c115275da 100644 --- a/test/py/tests/test_trace.py +++ b/test/py/tests/test_trace.py @@ -70,6 +70,32 @@ def collect_trace(cons): return fname, int(dm_f_time[0])
+def clear_and_collect_trace(cons): + """Pause and clear traces, return the number of calls (should be zero) + + Args: + cons (ConsoleBase): U-Boot console + + Returns: + int: the number of traced function calls reported by 'trace stats' + """ + cons.run_command('trace pause') + cons.run_command('trace clear') + out = cons.run_command('trace stats') + + # The output is something like this: + # 117,221 function sites + # 0 function calls + # 0 untracked function calls + # 0 traced function calls + + # Get a dict of values from the output + lines = [line.split(maxsplit=1) for line in out.splitlines() if line] + vals = {key: val.replace(',', '') for val, key in lines} + + return int(vals['traced function calls']) + + def check_function(cons, fname, proftool, map_fname, trace_dat): """Check that the 'function' output works
@@ -304,3 +330,7 @@ def test_trace(u_boot_console): # This allows for CI being slow to run diff = abs(fg_time - dm_f_time) assert diff / dm_f_time < 0.3 + + # Check that the trace buffer can be cleared + numcalls = clear_and_collect_trace(cons) + assert numcalls == 0
On Mon, 9 Dec 2024 at 17:32, Jerome Forissier jerome.forissier@linaro.org wrote:
Also test the newly added command 'trace clear'.
Signed-off-by: Jerome Forissier jerome.forissier@linaro.org
test/py/tests/test_trace.py | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+)
diff --git a/test/py/tests/test_trace.py b/test/py/tests/test_trace.py index ec1e624722c..29c115275da 100644 --- a/test/py/tests/test_trace.py +++ b/test/py/tests/test_trace.py @@ -70,6 +70,32 @@ def collect_trace(cons): return fname, int(dm_f_time[0])
+def clear_and_collect_trace(cons):
- """Pause and clear traces, return the number of calls (should be zero)
- Args:
cons (ConsoleBase): U-Boot console- Returns:
int: the number of traced function calls reported by 'trace stats'- """
- cons.run_command('trace pause')
- cons.run_command('trace clear')
- out = cons.run_command('trace stats')
- # The output is something like this:
- # 117,221 function sites
- # 0 function calls
- # 0 untracked function calls
- # 0 traced function calls
- # Get a dict of values from the output
- lines = [line.split(maxsplit=1) for line in out.splitlines() if line]
- vals = {key: val.replace(',', '') for val, key in lines}
- return int(vals['traced function calls'])
def check_function(cons, fname, proftool, map_fname, trace_dat): """Check that the 'function' output works
@@ -304,3 +330,7 @@ def test_trace(u_boot_console): # This allows for CI being slow to run diff = abs(fg_time - dm_f_time) assert diff / dm_f_time < 0.3
- # Check that the trace buffer can be cleared
- numcalls = clear_and_collect_trace(cons)
- assert numcalls == 0
-- 2.43.0
Acked-by: Ilias Apalodimas ilias.apalodimas@linaro.org
participants (2)
-
Ilias Apalodimas -
Jerome Forissier