[PATCH v2 1/2] seq_buf: Add printing formatted hex dumps

[PATCH v2 1/2] seq_buf: Add printing formatted hex dumps

[Piotr Maziarz]

Provided function is an analogue of print_hex_dump().

Implementing this function in seq_buf allows using for multiple
purposes (e.g. for tracing) and therefore prevents from code duplication
in every layer that uses seq_buf.

print_hex_dump() is an essential part of logging data to dmesg. Adding
similar capability for other purposes is beneficial to all users.

Example usage:
seq_buf_hex_dump(seq, "", DUMP_PREFIX_OFFSET, 16, 4, buf,
		 ARRAY_SIZE(buf), true);
Example output:
00000000: 00000000 ffffff10 ffffff32 ffff3210  ........2....2..
00000010: ffff3210 83d00437 c0700000 00000000  .2..7.....p.....
00000020: 02010004 0000000f 0000000f 00004002  .............@..
00000030: 00000fff 00000000                    ........

Signed-off-by: Piotr Maziarz <piotrx.maziarz@linux.intel.com>
Signed-off-by: Cezary Rojewski <cezary.rojewski@intel.com>
---
v2
Add kernel doc header
Explain linebuf magic number size

Decided not to change declaration order or remaining -= rowsize to
remaining -= linelen in order to stay aligned with base print_hex_dump
function. However I can change it if requested.

 include/linux/seq_buf.h |  3 +++
 lib/seq_buf.c           | 62 +++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 65 insertions(+)

diff --git a/include/linux/seq_buf.h b/include/linux/seq_buf.h
index aa5deb0..fb0205d 100644
--- a/include/linux/seq_buf.h
+++ b/include/linux/seq_buf.h
@@ -125,6 +125,9 @@ extern int seq_buf_putmem(struct seq_buf *s, const void *mem, unsigned int len);
 extern int seq_buf_putmem_hex(struct seq_buf *s, const void *mem,
 			      unsigned int len);
 extern int seq_buf_path(struct seq_buf *s, const struct path *path, const char *esc);
+extern int seq_buf_hex_dump(struct seq_buf *s, const char *prefix_str,
+			    int prefix_type, int rowsize, int groupsize,
+			    const void *buf, size_t len, bool ascii);
 
 #ifdef CONFIG_BINARY_PRINTF
 extern int
diff --git a/lib/seq_buf.c b/lib/seq_buf.c
index bd807f5..4e865d4 100644
--- a/lib/seq_buf.c
+++ b/lib/seq_buf.c
@@ -328,3 +328,65 @@ int seq_buf_to_user(struct seq_buf *s, char __user *ubuf, int cnt)
 	s->readpos += cnt;
 	return cnt;
 }
+
+/**
+ * seq_buf_hex_dump - print formatted hex dump into the sequence buffer
+ * @s: seq_buf descriptor
+ * @prefix_str: string to prefix each line with;
+ *  caller supplies trailing spaces for alignment if desired
+ * @prefix_type: controls whether prefix of an offset, address, or none
+ *  is printed (%DUMP_PREFIX_OFFSET, %DUMP_PREFIX_ADDRESS, %DUMP_PREFIX_NONE)
+ * @rowsize: number of bytes to print per line; must be 16 or 32
+ * @groupsize: number of bytes to print at a time (1, 2, 4, 8; default = 1)
+ * @buf: data blob to dump
+ * @len: number of bytes in the @buf
+ * @ascii: include ASCII after the hex output
+ *
+ * Function is an analogue of print_hex_dump() and thus has similar interface.
+ *
+ * linebuf size is maximal length for one line.
+ * 32 * 3 - maximum bytes per line, each printed into 2 chars + 1 for
+ *	separating space
+ * 2 - spaces separating hex dump and ascii representation
+ * 32 - ascii representation
+ * 1 - terminating '\0'
+ *
+ * Returns zero on success, -1 on overflow
+ */
+int seq_buf_hex_dump(struct seq_buf *s, const char *prefix_str, int prefix_type,
+		     int rowsize, int groupsize,
+		     const void *buf, size_t len, bool ascii)
+{
+	const u8 *ptr = buf;
+	int i, linelen, remaining = len;
+	unsigned char linebuf[32 * 3 + 2 + 32 + 1];
+	int ret;
+
+	if (rowsize != 16 && rowsize != 32)
+		rowsize = 16;
+
+	for (i = 0; i < len; i += rowsize) {
+		linelen = min(remaining, rowsize);
+		remaining -= rowsize;
+
+		hex_dump_to_buffer(ptr + i, linelen, rowsize, groupsize,
+				   linebuf, sizeof(linebuf), ascii);
+
+		switch (prefix_type) {
+		case DUMP_PREFIX_ADDRESS:
+			ret = seq_buf_printf(s, "%s%p: %s\n",
+			       prefix_str, ptr + i, linebuf);
+			break;
+		case DUMP_PREFIX_OFFSET:
+			ret = seq_buf_printf(s, "%s%.8x: %s\n",
+					     prefix_str, i, linebuf);
+			break;
+		default:
+			ret = seq_buf_printf(s, "%s%s\n", prefix_str, linebuf);
+			break;
+		}
+		if (ret)
+			return ret;
+	}
+	return 0;
+}
-- 
2.7.4

[PATCH v2 2/2] tracing: Use seq_buf_hex_dump() to dump buffers

[Piotr Maziarz]

Without this, buffers can be printed with __print_array macro that has
no formatting options and can be hard to read. The other way is to
mimic formatting capability with multiple calls of trace event with one
call per row which gives performance impact and different timestamp in
each row.

Signed-off-by: Piotr Maziarz <piotrx.maziarz@linux.intel.com>
Signed-off-by: Cezary Rojewski <cezary.rojewski@intel.com>
---
no changes

 include/linux/trace_events.h |  5 +++++
 include/linux/trace_seq.h    |  4 ++++
 include/trace/trace_events.h |  6 ++++++
 kernel/trace/trace_output.c  | 15 +++++++++++++++
 kernel/trace/trace_seq.c     | 30 ++++++++++++++++++++++++++++++
 5 files changed, 60 insertions(+)

diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h
index 30a8cdc..60a41b7 100644
--- a/include/linux/trace_events.h
+++ b/include/linux/trace_events.h
@@ -45,6 +45,11 @@ const char *trace_print_array_seq(struct trace_seq *p,
 				   const void *buf, int count,
 				   size_t el_size);
 
+const char *
+trace_print_hex_dump_seq(struct trace_seq *p, const char *prefix_str,
+			 int prefix_type, int rowsize, int groupsize,
+			 const void *buf, size_t len, bool ascii);
+
 struct trace_iterator;
 struct trace_event;
 
diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
index 6609b39a..6c30508 100644
--- a/include/linux/trace_seq.h
+++ b/include/linux/trace_seq.h
@@ -92,6 +92,10 @@ extern int trace_seq_path(struct trace_seq *s, const struct path *path);
 extern void trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
 			     int nmaskbits);
 
+extern int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
+			      int prefix_type, int rowsize, int groupsize,
+			      const void *buf, size_t len, bool ascii);
+
 #else /* CONFIG_TRACING */
 static inline void trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 {
diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
index 4ecdfe2..7089760 100644
--- a/include/trace/trace_events.h
+++ b/include/trace/trace_events.h
@@ -340,6 +340,12 @@ TRACE_MAKE_SYSTEM_STR();
 		trace_print_array_seq(p, array, count, el_size);	\
 	})
 
+#undef __print_hex_dump
+#define __print_hex_dump(prefix_str, prefix_type,			\
+			 rowsize, groupsize, buf, len, ascii)		\
+	trace_print_hex_dump_seq(p, prefix_str, prefix_type,		\
+				 rowsize, groupsize, buf, len, ascii)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 static notrace enum print_line_t					\
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index d54ce25..d9b4b7c 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -274,6 +274,21 @@ trace_print_array_seq(struct trace_seq *p, const void *buf, int count,
 }
 EXPORT_SYMBOL(trace_print_array_seq);
 
+const char *
+trace_print_hex_dump_seq(struct trace_seq *p, const char *prefix_str,
+			 int prefix_type, int rowsize, int groupsize,
+			 const void *buf, size_t len, bool ascii)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	trace_seq_putc(p, '\n');
+	trace_seq_hex_dump(p, prefix_str, prefix_type,
+			   rowsize, groupsize, buf, len, ascii);
+	trace_seq_putc(p, 0);
+	return ret;
+}
+EXPORT_SYMBOL(trace_print_hex_dump_seq);
+
 int trace_raw_output_prep(struct trace_iterator *iter,
 			  struct trace_event *trace_event)
 {
diff --git a/kernel/trace/trace_seq.c b/kernel/trace/trace_seq.c
index 6b1c562..344e4c1 100644
--- a/kernel/trace/trace_seq.c
+++ b/kernel/trace/trace_seq.c
@@ -376,3 +376,33 @@ int trace_seq_to_user(struct trace_seq *s, char __user *ubuf, int cnt)
 	return seq_buf_to_user(&s->seq, ubuf, cnt);
 }
 EXPORT_SYMBOL_GPL(trace_seq_to_user);
+
+int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
+		       int prefix_type, int rowsize, int groupsize,
+		       const void *buf, size_t len, bool ascii)
+{
+		unsigned int save_len = s->seq.len;
+
+	if (s->full)
+		return 0;
+
+	__trace_seq_init(s);
+
+	if (TRACE_SEQ_BUF_LEFT(s) < 1) {
+		s->full = 1;
+		return 0;
+	}
+
+	seq_buf_hex_dump(&(s->seq), prefix_str,
+		   prefix_type, rowsize, groupsize,
+		   buf, len, ascii);
+
+	if (unlikely(seq_buf_has_overflowed(&s->seq))) {
+		s->seq.len = save_len;
+		s->full = 1;
+		return 0;
+	}
+
+	return 1;
+}
+EXPORT_SYMBOL(trace_seq_hex_dump);
-- 
2.7.4

Re: [PATCH v2 1/2] seq_buf: Add printing formatted hex dumps

[Steven Rostedt]

On Thu,  7 Nov 2019 13:45:37 +0100
Piotr Maziarz <piotrx.maziarz@linux.intel.com> wrote:

> Provided function is an analogue of print_hex_dump().
> 
> Implementing this function in seq_buf allows using for multiple
> purposes (e.g. for tracing) and therefore prevents from code duplication
> in every layer that uses seq_buf.
> 
> print_hex_dump() is an essential part of logging data to dmesg. Adding
> similar capability for other purposes is beneficial to all users.
> 
> Example usage:
> seq_buf_hex_dump(seq, "", DUMP_PREFIX_OFFSET, 16, 4, buf,
> 		 ARRAY_SIZE(buf), true);
> Example output:
> 00000000: 00000000 ffffff10 ffffff32 ffff3210  ........2....2..
> 00000010: ffff3210 83d00437 c0700000 00000000  .2..7.....p.....
> 00000020: 02010004 0000000f 0000000f 00004002  .............@..
> 00000030: 00000fff 00000000                    ........
> 
> Signed-off-by: Piotr Maziarz <piotrx.maziarz@linux.intel.com>
> Signed-off-by: Cezary Rojewski <cezary.rojewski@intel.com>

I'm curious about the two signed off bys? Was Cezary a co-author?


> ---
> v2
> Add kernel doc header
> Explain linebuf magic number size
> 
> Decided not to change declaration order or remaining -= rowsize to
> remaining -= linelen in order to stay aligned with base print_hex_dump
> function. However I can change it if requested.

I don't care as much to make the change. Perhaps we can clean that up
in the future.

-- Steve

> 
>  include/linux/seq_buf.h |  3 +++
>  lib/seq_buf.c           | 62 +++++++++++++++++++++++++++++++++++++++++++++++++
>  2 files changed, 65 insertions(+)
> 
>

Re: [PATCH v2 2/2] tracing: Use seq_buf_hex_dump() to dump buffers

[Steven Rostedt]

On Thu,  7 Nov 2019 13:45:38 +0100
Piotr Maziarz <piotrx.maziarz@linux.intel.com> wrote:

> diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
> index 4ecdfe2..7089760 100644
> --- a/include/trace/trace_events.h
> +++ b/include/trace/trace_events.h
> @@ -340,6 +340,12 @@ TRACE_MAKE_SYSTEM_STR();
>  		trace_print_array_seq(p, array, count, el_size);	\
>  	})
>  
> +#undef __print_hex_dump
> +#define __print_hex_dump(prefix_str, prefix_type,			\
> +			 rowsize, groupsize, buf, len, ascii)		\
> +	trace_print_hex_dump_seq(p, prefix_str, prefix_type,		\
> +				 rowsize, groupsize, buf, len, ascii)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  static notrace enum print_line_t					\

OK, so the __print_hex_dump() will be exported to the format files.

Would you be willing to add a function to handle __print_hex_dump() in
tools/lib/traceevent/event-parse.c, like __print_flags(),
__print_symbolic(), and other __print_*() functions are handled. This
will allow trace-cmd and perf to be able to parse the data when you
used it via the userspace tools.

This can be a separate patch, but ideally before any trace events start
using this.

Thanks,

-- Steve

Re: [PATCH v2 1/2] seq_buf: Add printing formatted hex dumps

[Cezary Rojewski]

On 2019-11-13 22:02, Steven Rostedt wrote:
> On Thu,  7 Nov 2019 13:45:37 +0100
> Piotr Maziarz <piotrx.maziarz@linux.intel.com> wrote:
> 
>> Provided function is an analogue of print_hex_dump().
>>
>> Implementing this function in seq_buf allows using for multiple
>> purposes (e.g. for tracing) and therefore prevents from code duplication
>> in every layer that uses seq_buf.
>>
>> print_hex_dump() is an essential part of logging data to dmesg. Adding
>> similar capability for other purposes is beneficial to all users.
>>
>> Example usage:
>> seq_buf_hex_dump(seq, "", DUMP_PREFIX_OFFSET, 16, 4, buf,
>> 		 ARRAY_SIZE(buf), true);
>> Example output:
>> 00000000: 00000000 ffffff10 ffffff32 ffff3210  ........2....2..
>> 00000010: ffff3210 83d00437 c0700000 00000000  .2..7.....p.....
>> 00000020: 02010004 0000000f 0000000f 00004002  .............@..
>> 00000030: 00000fff 00000000                    ........
>>
>> Signed-off-by: Piotr Maziarz <piotrx.maziarz@linux.intel.com>
>> Signed-off-by: Cezary Rojewski <cezary.rojewski@intel.com>
> 
> I'm curious about the two signed off bys? Was Cezary a co-author?
> 

Hello Steven,

Code is done by Piotr. I merely took part in shaping this idea and doing 
initial reviews. Kudos to Andy for helping us out here.

As a dev lead and maintainer for Intel ASoC team, patches coming from my 
team are also being signed off me so any reviewer has a person to 
complain to in case of any issues for extended period of time.

Czarek

Re: [PATCH v2 1/2] seq_buf: Add printing formatted hex dumps

[Steven Rostedt]

On Thu, 14 Nov 2019 09:00:40 +0100
Cezary Rojewski <cezary.rojewski@intel.com> wrote:

> >> Signed-off-by: Piotr Maziarz <piotrx.maziarz@linux.intel.com>
> >> Signed-off-by: Cezary Rojewski <cezary.rojewski@intel.com>  
> > 
> > I'm curious about the two signed off bys? Was Cezary a co-author?
> >   
> 
> Hello Steven,
> 
> Code is done by Piotr. I merely took part in shaping this idea and doing 
> initial reviews. Kudos to Andy for helping us out here.
> 
> As a dev lead and maintainer for Intel ASoC team, patches coming from my 
> team are also being signed off me so any reviewer has a person to 
> complain to in case of any issues for extended period of time.

That's fine. Just was curious about it.

I have this queued, but due to other patches failing some of my tests,
I haven't pushed to linux-next yet.

-- Steve

Re: [PATCH v2 2/2] tracing: Use seq_buf_hex_dump() to dump buffers

[Piotr Maziarz]

On 2019-11-13 22:09, Steven Rostedt wrote:
> OK, so the __print_hex_dump() will be exported to the format files.
> 
> Would you be willing to add a function to handle __print_hex_dump() in
> tools/lib/traceevent/event-parse.c, like __print_flags(),
> __print_symbolic(), and other __print_*() functions are handled. This
> will allow trace-cmd and perf to be able to parse the data when you
> used it via the userspace tools.
> 
> This can be a separate patch, but ideally before any trace events start
> using this.
> 
> Thanks,
> 
> -- Steve
> 

Hello Steven,

I'm writing handle in event-parse and I came across some technical 
problems. I have an event which print function looks like that:
TP_printk("%s",
	  __print_hex_dump("", DUMP_PREFIX_OFFSET, 16, 4,
			   __get_dynamic_array(buf),
			   __get_dynamic_array_len(buf), false))
It works properly when printing events to debugfs.
I'm testing my implementation with trace-cmd and it has problem with 
parsing DUMP_PREFIX_OFFSET and false (I'm using 
alloc_and_process_delim()). Instead of having numerical values 
tep_print_args are of type TEP_PRINT_ATOM and have char array 
"DUMP_PREFIX_OFFSET" or "true".
Am I doing something incorrect? Parsing it this way is problematic 
because instead of false someone may use 0 or logic expression. And 
writing it to support all possible scenarios may be tedious and prone to 
errors.

Best regards,
Piotr Maziarz

Re: [PATCH v2 2/2] tracing: Use seq_buf_hex_dump() to dump buffers

[Steven Rostedt]

On Tue, 26 Nov 2019 15:53:26 +0100
Piotr Maziarz <piotrx.maziarz@linux.intel.com> wrote:
> Hello Steven,
> 
> I'm writing handle in event-parse and I came across some technical 
> problems. I have an event which print function looks like that:
> TP_printk("%s",
> 	  __print_hex_dump("", DUMP_PREFIX_OFFSET, 16, 4,
> 			   __get_dynamic_array(buf),
> 			   __get_dynamic_array_len(buf), false))
> It works properly when printing events to debugfs.
> I'm testing my implementation with trace-cmd and it has problem with 
> parsing DUMP_PREFIX_OFFSET and false (I'm using 
> alloc_and_process_delim()). Instead of having numerical values 
> tep_print_args are of type TEP_PRINT_ATOM and have char array 
> "DUMP_PREFIX_OFFSET" or "true".
> Am I doing something incorrect? Parsing it this way is problematic 
> because instead of false someone may use 0 or logic expression. And 
> writing it to support all possible scenarios may be tedious and prone to 
> errors.

You can force the enum to be a number by including the following in the
trace event header:

TRACE_DEFINE_ENUM(DUMP_PREFIX_OFFSET);
TRACE_DEFINE_ENUM(DUMP_PREFIX_ADDRESS);
TRACE_DEFINE_ENUM(DUMP_PREFIX_NONE);

and the format files will convert these to their actual numbers when
displaying it to user space.

-- Steve

Re: [PATCH v2 2/2] tracing: Use seq_buf_hex_dump() to dump buffers

[Piotr Maziarz]

On 2019-11-26 20:51, Steven Rostedt wrote:
> On Tue, 26 Nov 2019 15:53:26 +0100
> Piotr Maziarz <piotrx.maziarz@linux.intel.com> wrote:
>> Hello Steven,
>>
>> I'm writing handle in event-parse and I came across some technical
>> problems. I have an event which print function looks like that:
>> TP_printk("%s",
>> 	  __print_hex_dump("", DUMP_PREFIX_OFFSET, 16, 4,
>> 			   __get_dynamic_array(buf),
>> 			   __get_dynamic_array_len(buf), false))
>> It works properly when printing events to debugfs.
>> I'm testing my implementation with trace-cmd and it has problem with
>> parsing DUMP_PREFIX_OFFSET and false (I'm using
>> alloc_and_process_delim()). Instead of having numerical values
>> tep_print_args are of type TEP_PRINT_ATOM and have char array
>> "DUMP_PREFIX_OFFSET" or "true".
>> Am I doing something incorrect? Parsing it this way is problematic
>> because instead of false someone may use 0 or logic expression. And
>> writing it to support all possible scenarios may be tedious and prone to
>> errors.
> 
> You can force the enum to be a number by including the following in the
> trace event header:
> 
> TRACE_DEFINE_ENUM(DUMP_PREFIX_OFFSET);
> TRACE_DEFINE_ENUM(DUMP_PREFIX_ADDRESS);
> TRACE_DEFINE_ENUM(DUMP_PREFIX_NONE);
> 
> and the format files will convert these to their actual numbers when
> displaying it to user space.
> 
> -- Steve
> 
Thanks, that's what I was looking for.

Best regards,
Piotr Maziarz