[PATCH v2 0/3] Add 'trace wipe'

[PATCH v2 0/3] Add 'trace wipe'

[Jerome Forissier]

This short series adds the 'trace wipe' command which clears the trace
buffer, allowing to re-start a capture from scratch.

Jerome Forissier (3):
  trace: add support for 'trace wipe'
  test: test_trace.py: test 'trace wipe'
  trace: document 'trace wipe'

 cmd/trace.c                 |  5 ++++
 doc/develop/trace.rst       | 11 +++++++++
 include/trace.h             |  2 ++
 lib/trace.c                 | 47 ++++++++++++++++++++++++++-----------
 test/py/tests/test_trace.py | 30 +++++++++++++++++++++++
 5 files changed, 81 insertions(+), 14 deletions(-)

v2:
- Change 'trace clear' to 'trace wipe'
- Add doc patch
- Minor edits to the patch descriptions

v1:
- Added patch: 'test: test_trace.py: test "trace clear" command'

v0:
- Sent as a single patch:
https://lists.denx.de/pipermail/u-boot/2024-December/574148.html

-- 
2.43.0

[PATCH v2 1/3] trace: add support for 'trace wipe'

[Jerome Forissier]

Implement a 'trace wipe' command to delete the currently accumulated
trace data. This comes handy when someone needs to trace a particular
command. For example:

  => trace pause; trace wipe
  => trace resume; 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     |  5 +++++
 include/trace.h |  2 ++
 lib/trace.c     | 47 +++++++++++++++++++++++++++++++++--------------
 3 files changed, 40 insertions(+), 14 deletions(-)

diff --git a/cmd/trace.c b/cmd/trace.c
index 937e6a682ad..d36008720db 100644
--- a/cmd/trace.c
+++ b/cmd/trace.c
@@ -100,6 +100,10 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[])
 	case 's':
 		trace_print_stats();
 		break;
+	case 'w':
+		if (trace_wipe())
+			return CMD_RET_FAILURE;
+		break;
 	default:
 		return CMD_RET_USAGE;
 	}
@@ -113,6 +117,7 @@ U_BOOT_CMD(
 	"stats                        - display tracing statistics\n"
 	"trace pause                        - pause tracing\n"
 	"trace resume                       - resume tracing\n"
+	"trace wipe                         - wipe 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

Re: [PATCH v2 1/3] trace: add support for 'trace wipe'

[Ilias Apalodimas]

On Fri, 13 Dec 2024 at 14:46, Jerome Forissier
<jerome.forissier@linaro.org> wrote:
>
> Implement a 'trace wipe' command to delete the currently accumulated
> trace data. This comes handy when someone needs to trace a particular
> command. For example:
>
>   => trace pause; trace wipe
>   => trace resume; 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     |  5 +++++
>  include/trace.h |  2 ++
>  lib/trace.c     | 47 +++++++++++++++++++++++++++++++++--------------
>  3 files changed, 40 insertions(+), 14 deletions(-)
>
> diff --git a/cmd/trace.c b/cmd/trace.c
> index 937e6a682ad..d36008720db 100644
> --- a/cmd/trace.c
> +++ b/cmd/trace.c
> @@ -100,6 +100,10 @@ int do_trace(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[])
>         case 's':
>                 trace_print_stats();
>                 break;
> +       case 'w':
> +               if (trace_wipe())
> +                       return CMD_RET_FAILURE;
> +               break;
>         default:
>                 return CMD_RET_USAGE;
>         }
> @@ -113,6 +117,7 @@ U_BOOT_CMD(
>         "stats                        - display tracing statistics\n"
>         "trace pause                        - pause tracing\n"
>         "trace resume                       - resume tracing\n"
> +       "trace wipe                         - wipe 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
>

Reviewed-by: Ilias Apalodimas <ilias.apalodimas@linaro.org>

[PATCH v2 2/3] test: test_trace.py: test 'trace wipe'

[Jerome Forissier]

Test the newly added 'trace wipe' command.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Acked-by: Ilias Apalodimas <ilias.apalodimas@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..44239da5280 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 wipe_and_collect_trace(cons):
+    """Pause and wipe 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 wipe')
+    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 wiped
+    numcalls = wipe_and_collect_trace(cons)
+    assert numcalls == 0
-- 
2.43.0

[PATCH v2 3/3] trace: document 'trace wipe'

[Jerome Forissier]

Add documentation for the 'trace wipe' command.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---
 doc/develop/trace.rst | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/doc/develop/trace.rst b/doc/develop/trace.rst
index 546862020b1..d3c8628d124 100644
--- a/doc/develop/trace.rst
+++ b/doc/develop/trace.rst
@@ -163,6 +163,17 @@ you will see the time taken by each function shown against its exit record.
               u-boot-1     [000]     3.116466: funcgraph_entry:        0.063 us   |        memset();
               u-boot-1     [000]     3.116539: funcgraph_exit:         0.143 us   |        }
 
+The `trace wipe` command may be used to clear the trace buffer. It leaves
+tracing in its current enable state. This command is convenient when tracing a
+single command, for example:
+
+.. code-block:: console
+
+   => trace pause; trace wipe
+   => trace resume; dhcp; trace pause
+   => trace stats
+   ...
+
 Flame graph
 -----------
 
-- 
2.43.0

Re: [PATCH v2 3/3] trace: document 'trace wipe'

[Ilias Apalodimas]

On Fri, 13 Dec 2024 at 14:46, Jerome Forissier
<jerome.forissier@linaro.org> wrote:
>
> Add documentation for the 'trace wipe' command.
>
> Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
> ---
>  doc/develop/trace.rst | 11 +++++++++++
>  1 file changed, 11 insertions(+)
>
> diff --git a/doc/develop/trace.rst b/doc/develop/trace.rst
> index 546862020b1..d3c8628d124 100644
> --- a/doc/develop/trace.rst
> +++ b/doc/develop/trace.rst
> @@ -163,6 +163,17 @@ you will see the time taken by each function shown against its exit record.
>                u-boot-1     [000]     3.116466: funcgraph_entry:        0.063 us   |        memset();
>                u-boot-1     [000]     3.116539: funcgraph_exit:         0.143 us   |        }
>
> +The `trace wipe` command may be used to clear the trace buffer. It leaves
> +tracing in its current enable state. This command is convenient when tracing a
> +single command, for example:
> +
> +.. code-block:: console
> +
> +   => trace pause; trace wipe
> +   => trace resume; dhcp; trace pause
> +   => trace stats
> +   ...
> +
>  Flame graph
>  -----------
>
> --
> 2.43.0
>

Acked-by: Ilias Apalodimas <ilias.apalodimas@linaro.org>

Re: [PATCH v2 0/3] Add 'trace wipe'

[Tom Rini]

On Fri, 13 Dec 2024 13:45:35 +0100, Jerome Forissier wrote:

> This short series adds the 'trace wipe' command which clears the trace
> buffer, allowing to re-start a capture from scratch.
> 
> Jerome Forissier (3):
>   trace: add support for 'trace wipe'
>   test: test_trace.py: test 'trace wipe'
>   trace: document 'trace wipe'
> 
> [...]

Applied to u-boot/next, thanks!

-- 
Tom