2020-06-23 12:13:48

by Alan Maguire

[permalink] [raw]
Subject: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF

printk supports multiple pointer object type specifiers (printing
netdev features etc). Extend this support using BTF to cover
arbitrary types. "%pT" specifies the typed format, and the pointer
argument is a "struct btf_ptr *" where struct btf_ptr is as follows:

struct btf_ptr {
void *ptr;
const char *type;
u32 id;
};

Either the "type" string ("struct sk_buff") or the BTF "id" can be
used to identify the type to use in displaying the associated "ptr"
value. A convenience function to create and point at the struct
is provided:

printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));

When invoked, BTF information is used to traverse the sk_buff *
and display it. Support is present for structs, unions, enums,
typedefs and core types (though in the latter case there's not
much value in using this feature of course).

Default output is indented, but compact output can be specified
via the 'c' option. Type names/member values can be suppressed
using the 'N' option. Zero values are not displayed by default
but can be using the '0' option. Pointer values are obfuscated
unless the 'x' option is specified. As an example:

struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
pr_info("%pT", BTF_PTR_TYPE(skb, struct sk_buff));

...gives us:

(struct sk_buff){
.transport_header = (__u16)65535,
.mac_header = (__u16)65535,
.end = (sk_buff_data_t)192,
.head = (unsigned char *)0x000000006b71155a,
.data = (unsigned char *)0x000000006b71155a,
.truesize = (unsigned int)768,
.users = (refcount_t){
.refs = (atomic_t){
.counter = (int)1,
},
},
.extensions = (struct skb_ext *)0x00000000f486a130,
}

printk output is truncated at 1024 bytes. For cases where overflow
is likely, the compact/no type names display modes may be used.

Signed-off-by: Alan Maguire <[email protected]>

i
---
Documentation/core-api/printk-formats.rst | 17 ++++++
include/linux/btf.h | 3 +-
include/linux/printk.h | 16 +++++
lib/vsprintf.c | 98 +++++++++++++++++++++++++++++++
4 files changed, 133 insertions(+), 1 deletion(-)

diff --git a/Documentation/core-api/printk-formats.rst b/Documentation/core-api/printk-formats.rst
index 8c9aba2..8f255d0 100644
--- a/Documentation/core-api/printk-formats.rst
+++ b/Documentation/core-api/printk-formats.rst
@@ -563,6 +563,23 @@ For printing netdev_features_t.

Passed by reference.

+BTF-based printing of pointer data
+----------------------------------
+If '%pT' is specified, use the struct btf_ptr * along with kernel vmlinux
+BPF Type Format (BTF) to show the typed data. For example, specifying
+
+ printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct_sk_buff));
+
+will utilize BTF information to traverse the struct sk_buff * and display it.
+
+Supported modifers are
+ 'c' compact output (no indentation, newlines etc)
+ 'N' do not show type names
+ 'u' unsafe printing; probe_kernel_read() is not used to copy data safely
+ before use
+ 'x' show raw pointers (no obfuscation)
+ '0' show zero-valued data (it is not shown by default)
+
Thanks
======

diff --git a/include/linux/btf.h b/include/linux/btf.h
index a8a4563..e8dbf0c 100644
--- a/include/linux/btf.h
+++ b/include/linux/btf.h
@@ -172,10 +172,11 @@ static inline const struct btf_member *btf_type_member(const struct btf_type *t)
return (const struct btf_member *)(t + 1);
}

+struct btf *btf_parse_vmlinux(void);
+
#ifdef CONFIG_BPF_SYSCALL
const struct btf_type *btf_type_by_id(const struct btf *btf, u32 type_id);
const char *btf_name_by_offset(const struct btf *btf, u32 offset);
-struct btf *btf_parse_vmlinux(void);
struct btf *bpf_prog_get_target_btf(const struct bpf_prog *prog);
#else
static inline const struct btf_type *btf_type_by_id(const struct btf *btf,
diff --git a/include/linux/printk.h b/include/linux/printk.h
index fc8f03c..8f8f5d2 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -618,4 +618,20 @@ static inline void print_hex_dump_debug(const char *prefix_str, int prefix_type,
#define print_hex_dump_bytes(prefix_str, prefix_type, buf, len) \
print_hex_dump_debug(prefix_str, prefix_type, 16, 1, buf, len, true)

+/**
+ * struct btf_ptr is used for %pT (typed pointer) display; the
+ * additional type string/BTF id are used to render the pointer
+ * data as the appropriate type.
+ */
+struct btf_ptr {
+ void *ptr;
+ const char *type;
+ u32 id;
+};
+
+#define BTF_PTR_TYPE(ptrval, typeval) \
+ (&((struct btf_ptr){.ptr = ptrval, .type = #typeval}))
+
+#define BTF_PTR_ID(ptrval, idval) \
+ (&((struct btf_ptr){.ptr = ptrval, .id = idval}))
#endif
diff --git a/lib/vsprintf.c b/lib/vsprintf.c
index 259e558..c0d209d 100644
--- a/lib/vsprintf.c
+++ b/lib/vsprintf.c
@@ -44,6 +44,7 @@
#ifdef CONFIG_BLOCK
#include <linux/blkdev.h>
#endif
+#include <linux/btf.h>

#include "../mm/internal.h" /* For the trace_print_flags arrays */

@@ -2092,6 +2093,87 @@ char *fwnode_string(char *buf, char *end, struct fwnode_handle *fwnode,
return widen_string(buf, buf - buf_start, end, spec);
}

+#define btf_modifier_flag(c) (c == 'c' ? BTF_SHOW_COMPACT : \
+ c == 'N' ? BTF_SHOW_NONAME : \
+ c == 'x' ? BTF_SHOW_PTR_RAW : \
+ c == 'u' ? BTF_SHOW_UNSAFE : \
+ c == '0' ? BTF_SHOW_ZERO : 0)
+
+static noinline_for_stack
+char *btf_string(char *buf, char *end, void *ptr, struct printf_spec spec,
+ const char *fmt)
+{
+ struct btf_ptr *bp = (struct btf_ptr *)ptr;
+ u8 btf_kind = BTF_KIND_TYPEDEF;
+ const struct btf_type *t;
+ const struct btf *btf;
+ char *buf_start = buf;
+ const char *btf_type;
+ u64 flags = 0, mod;
+ s32 btf_id;
+
+ if (check_pointer(&buf, end, ptr, spec))
+ return buf;
+
+ if (check_pointer(&buf, end, bp->ptr, spec))
+ return buf;
+
+ while (isalnum(*fmt)) {
+ mod = btf_modifier_flag(*fmt);
+ if (!mod)
+ break;
+ flags |= mod;
+ fmt++;
+ }
+
+ btf = bpf_get_btf_vmlinux();
+ if (IS_ERR_OR_NULL(btf))
+ return ptr_to_id(buf, end, bp->ptr, spec);
+
+ if (bp->type != NULL) {
+ btf_type = bp->type;
+
+ if (strncmp(bp->type, "struct ", strlen("struct ")) == 0) {
+ btf_kind = BTF_KIND_STRUCT;
+ btf_type += strlen("struct ");
+ } else if (strncmp(btf_type, "union ", strlen("union ")) == 0) {
+ btf_kind = BTF_KIND_UNION;
+ btf_type += strlen("union ");
+ } else if (strncmp(btf_type, "enum ", strlen("enum ")) == 0) {
+ btf_kind = BTF_KIND_ENUM;
+ btf_type += strlen("enum ");
+ }
+
+ if (strlen(btf_type) == 0)
+ return ptr_to_id(buf, end, bp->ptr, spec);
+
+ /*
+ * Assume type specified is a typedef as there's not much
+ * benefit in specifying int types other than wasting time
+ * on BTF lookups; we optimize for the most useful path.
+ *
+ * Fall back to BTF_KIND_INT if this fails.
+ */
+ btf_id = btf_find_by_name_kind(btf, btf_type, btf_kind);
+ if (btf_id < 0)
+ btf_id = btf_find_by_name_kind(btf, btf_type,
+ BTF_KIND_INT);
+ } else if (bp->id > 0)
+ btf_id = bp->id;
+ else
+ return ptr_to_id(buf, end, bp->ptr, spec);
+
+ if (btf_id > 0)
+ t = btf_type_by_id(btf, btf_id);
+ if (btf_id <= 0 || !t)
+ return ptr_to_id(buf, end, bp->ptr, spec);
+
+ buf += btf_type_snprintf_show(btf, btf_id, bp->ptr, buf,
+ end - buf_start, flags);
+
+ return widen_string(buf, buf - buf_start, end, spec);
+}
+
/*
* Show a '%p' thing. A kernel extension is that the '%p' is followed
* by an extra set of alphanumeric characters that are extended format
@@ -2206,6 +2288,20 @@ char *fwnode_string(char *buf, char *end, struct fwnode_handle *fwnode,
* bpf_trace_printk() where [ku] prefix specifies either kernel (k)
* or user (u) memory to probe, and:
* s a string, equivalent to "%s" on direct vsnprintf() use
+ * - 'T[cNx0]' For printing struct btf_ptr * data using BPF Type Format (BTF).
+ *
+ * Optional arguments are
+ * c compact (no indentation/newlines)
+ * N do not print type and member names
+ * x do not obfuscate pointers
+ * u do not copy data to safe buffer prior
+ * to display
+ * 0 show 0-valued data
+ *
+ * BPF_PTR_TYPE(ptr, type) can be used to place pointer and type string
+ * in the "struct btf_ptr *" expected; for example:
+ *
+ * printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));
*
* ** When making changes please also update:
* Documentation/core-api/printk-formats.rst
@@ -2297,6 +2393,8 @@ char *pointer(const char *fmt, char *buf, char *end, void *ptr,
default:
return error_string(buf, end, "(einval)", spec);
}
+ case 'T':
+ return btf_string(buf, end, ptr, spec, fmt + 1);
}

/* default is to _not_ leak addresses, hash before printing */
--
1.8.3.1


2020-06-23 12:44:44

by Andy Shevchenko

[permalink] [raw]
Subject: Re: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF

On Tue, Jun 23, 2020 at 01:07:07PM +0100, Alan Maguire wrote:
> printk supports multiple pointer object type specifiers (printing
> netdev features etc). Extend this support using BTF to cover
> arbitrary types.

Is there any plans to cover (all?) existing %p extensions?

> "%pT"

One letter namespace is quite busy area. Perhaps %pOT ?

> specifies the typed format, and the pointer
> argument is a "struct btf_ptr *" where struct btf_ptr is as follows:
>
> struct btf_ptr {
> void *ptr;
> const char *type;
> u32 id;
> };
>
> Either the "type" string ("struct sk_buff") or the BTF "id" can be
> used to identify the type to use in displaying the associated "ptr"
> value. A convenience function to create and point at the struct
> is provided:
>
> printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));
>
> When invoked, BTF information is used to traverse the sk_buff *
> and display it. Support is present for structs, unions, enums,
> typedefs and core types (though in the latter case there's not
> much value in using this feature of course).
>
> Default output is indented, but compact output can be specified
> via the 'c' option. Type names/member values can be suppressed
> using the 'N' option. Zero values are not displayed by default
> but can be using the '0' option. Pointer values are obfuscated
> unless the 'x' option is specified. As an example:
>
> struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
> pr_info("%pT", BTF_PTR_TYPE(skb, struct sk_buff));
>
> ...gives us:
>
> (struct sk_buff){
> .transport_header = (__u16)65535,
> .mac_header = (__u16)65535,
> .end = (sk_buff_data_t)192,
> .head = (unsigned char *)0x000000006b71155a,
> .data = (unsigned char *)0x000000006b71155a,
> .truesize = (unsigned int)768,
> .users = (refcount_t){
> .refs = (atomic_t){
> .counter = (int)1,
> },
> },
> .extensions = (struct skb_ext *)0x00000000f486a130,
> }

I don't see how it looks on a real console when kernel dumps something.
Care to provide? These examples better to have documented.

> printk output is truncated at 1024 bytes. For cases where overflow
> is likely, the compact/no type names display modes may be used.

How * is handled? (I mean %*pOT case)

...

> +#define BTF_PTR_TYPE(ptrval, typeval) \
> + (&((struct btf_ptr){.ptr = ptrval, .type = #typeval}))
> +
> +#define BTF_PTR_ID(ptrval, idval) \
> + (&((struct btf_ptr){.ptr = ptrval, .id = idval}))

Wouldn't be better if these will leave in its own (linker) section?

...

> +static noinline_for_stack
> +char *btf_string(char *buf, char *end, void *ptr, struct printf_spec spec,
> + const char *fmt)
> +{

> + struct btf_ptr *bp = (struct btf_ptr *)ptr;

Unneeded casting.

> + u8 btf_kind = BTF_KIND_TYPEDEF;
> + const struct btf_type *t;
> + const struct btf *btf;
> + char *buf_start = buf;
> + const char *btf_type;
> + u64 flags = 0, mod;
> + s32 btf_id;
> +
> + if (check_pointer(&buf, end, ptr, spec))
> + return buf;
> +
> + if (check_pointer(&buf, end, bp->ptr, spec))
> + return buf;

> + while (isalnum(*fmt)) {
> + mod = btf_modifier_flag(*fmt);
> + if (!mod)
> + break;
> + flags |= mod;
> + fmt++;
> + }

Can't we have explicitly all handled flags here, like other extensions do?

> + btf = bpf_get_btf_vmlinux();
> + if (IS_ERR_OR_NULL(btf))
> + return ptr_to_id(buf, end, bp->ptr, spec);
> +
> + if (bp->type != NULL) {
> + btf_type = bp->type;
> +
> + if (strncmp(bp->type, "struct ", strlen("struct ")) == 0) {
> + btf_kind = BTF_KIND_STRUCT;
> + btf_type += strlen("struct ");
> + } else if (strncmp(btf_type, "union ", strlen("union ")) == 0) {
> + btf_kind = BTF_KIND_UNION;
> + btf_type += strlen("union ");
> + } else if (strncmp(btf_type, "enum ", strlen("enum ")) == 0) {
> + btf_kind = BTF_KIND_ENUM;
> + btf_type += strlen("enum ");
> + }

Can't you provide a simple structure and do this in a loop?
Or even something like match_[partial]string() to implement?

> + if (strlen(btf_type) == 0)

Interesting way of checking btf_type == '\0'.

> + return ptr_to_id(buf, end, bp->ptr, spec);
> +
> + /*
> + * Assume type specified is a typedef as there's not much
> + * benefit in specifying int types other than wasting time
> + * on BTF lookups; we optimize for the most useful path.
> + *
> + * Fall back to BTF_KIND_INT if this fails.
> + */
> + btf_id = btf_find_by_name_kind(btf, btf_type, btf_kind);
> + if (btf_id < 0)
> + btf_id = btf_find_by_name_kind(btf, btf_type,
> + BTF_KIND_INT);
> + } else if (bp->id > 0)
> + btf_id = bp->id;
> + else
> + return ptr_to_id(buf, end, bp->ptr, spec);
> +

> + if (btf_id > 0)
> + t = btf_type_by_id(btf, btf_id);
> + if (btf_id <= 0 || !t)
> + return ptr_to_id(buf, end, bp->ptr, spec);

This can be easily incorporated in previous conditional tree.

> + buf += btf_type_snprintf_show(btf, btf_id, bp->ptr, buf,
> + end - buf_start, flags);
> +
> + return widen_string(buf, buf - buf_start, end, spec);
> +}

--
With Best Regards,
Andy Shevchenko


2020-06-23 13:13:45

by Rasmus Villemoes

[permalink] [raw]
Subject: Re: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF

On 23/06/2020 14.07, Alan Maguire wrote:
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index fc8f03c..8f8f5d2 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -618,4 +618,20 @@ static inline void print_hex_dump_debug(const char *prefix_str, int prefix_type,
> #define print_hex_dump_bytes(prefix_str, prefix_type, buf, len) \
> print_hex_dump_debug(prefix_str, prefix_type, 16, 1, buf, len, true)
>
> +/**
> + * struct btf_ptr is used for %pT (typed pointer) display; the
> + * additional type string/BTF id are used to render the pointer
> + * data as the appropriate type.
> + */
> +struct btf_ptr {
> + void *ptr;
> + const char *type;
> + u32 id;
> +};
> +
> +#define BTF_PTR_TYPE(ptrval, typeval) \
> + (&((struct btf_ptr){.ptr = ptrval, .type = #typeval}))
> +
> +#define BTF_PTR_ID(ptrval, idval) \
> + (&((struct btf_ptr){.ptr = ptrval, .id = idval}))

Isn't there some better place to put this than printk.h? Anyway, you
probably want the ptr member to be "const void*", to avoid "... discards
const qualifier" warnings when somebody happens to have a "const struct
foobar *".

> #endif
> diff --git a/lib/vsprintf.c b/lib/vsprintf.c
> index 259e558..c0d209d 100644
> --- a/lib/vsprintf.c
> +++ b/lib/vsprintf.c
> @@ -44,6 +44,7 @@
> #ifdef CONFIG_BLOCK
> #include <linux/blkdev.h>
> #endif
> +#include <linux/btf.h>
>
> #include "../mm/internal.h" /* For the trace_print_flags arrays */
>
> @@ -2092,6 +2093,87 @@ char *fwnode_string(char *buf, char *end, struct fwnode_handle *fwnode,
> return widen_string(buf, buf - buf_start, end, spec);
> }
>
> +#define btf_modifier_flag(c) (c == 'c' ? BTF_SHOW_COMPACT : \
> + c == 'N' ? BTF_SHOW_NONAME : \
> + c == 'x' ? BTF_SHOW_PTR_RAW : \
> + c == 'u' ? BTF_SHOW_UNSAFE : \
> + c == '0' ? BTF_SHOW_ZERO : 0)
> +
> +static noinline_for_stack
> +char *btf_string(char *buf, char *end, void *ptr, struct printf_spec spec,
> + const char *fmt)
> +{
> + struct btf_ptr *bp = (struct btf_ptr *)ptr;
> + u8 btf_kind = BTF_KIND_TYPEDEF;
> + const struct btf_type *t;
> + const struct btf *btf;
> + char *buf_start = buf;
> + const char *btf_type;
> + u64 flags = 0, mod;
> + s32 btf_id;
> +
> + if (check_pointer(&buf, end, ptr, spec))
> + return buf;
> +
> + if (check_pointer(&buf, end, bp->ptr, spec))
> + return buf;
> +
> + while (isalnum(*fmt)) {
> + mod = btf_modifier_flag(*fmt);
> + if (!mod)
> + break;
> + flags |= mod;
> + fmt++;
> + }
> +
> + btf = bpf_get_btf_vmlinux();

AFAICT, this function is only compiled if CONFIG_BPF=y and
CONFIG_BPF_SYSCALL=y, and I don't see any static inline stub defined
anywhere. Have you built the kernel with one or both of those turned off?

Rasmus

2020-06-26 11:48:24

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF

On Tue 2020-06-23 13:07:07, Alan Maguire wrote:
> printk supports multiple pointer object type specifiers (printing
> netdev features etc). Extend this support using BTF to cover
> arbitrary types. "%pT" specifies the typed format, and the pointer
> argument is a "struct btf_ptr *" where struct btf_ptr is as follows:
>
> struct btf_ptr {
> void *ptr;
> const char *type;
> u32 id;
> };
>
> Either the "type" string ("struct sk_buff") or the BTF "id" can be
> used to identify the type to use in displaying the associated "ptr"
> value. A convenience function to create and point at the struct
> is provided:
>
> printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));
>
> When invoked, BTF information is used to traverse the sk_buff *
> and display it. Support is present for structs, unions, enums,
> typedefs and core types (though in the latter case there's not
> much value in using this feature of course).
>
> Default output is indented, but compact output can be specified
> via the 'c' option. Type names/member values can be suppressed
> using the 'N' option. Zero values are not displayed by default
> but can be using the '0' option. Pointer values are obfuscated
> unless the 'x' option is specified. As an example:
>
> struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
> pr_info("%pT", BTF_PTR_TYPE(skb, struct sk_buff));
>
> ...gives us:
>
> (struct sk_buff){
> .transport_header = (__u16)65535,
> .mac_header = (__u16)65535,
> .end = (sk_buff_data_t)192,
> .head = (unsigned char *)0x000000006b71155a,
> .data = (unsigned char *)0x000000006b71155a,
> .truesize = (unsigned int)768,
> .users = (refcount_t){
> .refs = (atomic_t){
> .counter = (int)1,
> },
> },
> .extensions = (struct skb_ext *)0x00000000f486a130,
> }
>
> printk output is truncated at 1024 bytes. For cases where overflow
> is likely, the compact/no type names display modes may be used.

Hmm, this scares me:

1. The long message and many lines are going to stretch printk
design in another dimensions.

2. vsprintf() is important for debugging the system. It has to be
stable. But the btf code is too complex.

I would strongly prefer to keep this outside vsprintf and printk.
Please, invert the logic and convert it into using separate printk()
call for each printed line.


More details:

Add 1: Long messages with many lines:

IMHO, all existing printk() users are far below this limit. And this is
even worse because there are many short lines. They would require
double space to add prefixes (loglevel, timestamp, caller id) when
printing to console.

You might argue that 1024bytes are enough for you. But for how long?

Now, we have huge troubles to make printk() lockless and thus more
reliable. There is no way to allocate any internal buffers
dynamically. People using kernel on small devices have problem
with large static buffers.

printk() is primary designed to print single line messages. There are
many use cases where many lines are needed and they are solved by
many separate printk() calls.


Add 2: Complex code:

vsprintf() is currently called in printk() under logbuf_lock. It
might block printk() on the entire system.

Most existing %p<modifier> handlers are implemented by relatively
simple routines inside lib/vsprinf.c. The other external routines
look simple as well.

btf looks like a huge beast to me. For example, probe_kernel_read()
prevented boot recently, see the commit 2ac5a3bf7042a1c4abb
("vsprintf: Do not break early boot with probing addresses").


Best Regards,
Petr

2020-06-26 12:31:07

by Alan Maguire

[permalink] [raw]
Subject: Re: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF


On Fri, 26 Jun 2020, Petr Mladek wrote:

> On Tue 2020-06-23 13:07:07, Alan Maguire wrote:
> > printk supports multiple pointer object type specifiers (printing
> > netdev features etc). Extend this support using BTF to cover
> > arbitrary types. "%pT" specifies the typed format, and the pointer
> > argument is a "struct btf_ptr *" where struct btf_ptr is as follows:
> >
> > struct btf_ptr {
> > void *ptr;
> > const char *type;
> > u32 id;
> > };
> >
> > Either the "type" string ("struct sk_buff") or the BTF "id" can be
> > used to identify the type to use in displaying the associated "ptr"
> > value. A convenience function to create and point at the struct
> > is provided:
> >
> > printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));
> >
> > When invoked, BTF information is used to traverse the sk_buff *
> > and display it. Support is present for structs, unions, enums,
> > typedefs and core types (though in the latter case there's not
> > much value in using this feature of course).
> >
> > Default output is indented, but compact output can be specified
> > via the 'c' option. Type names/member values can be suppressed
> > using the 'N' option. Zero values are not displayed by default
> > but can be using the '0' option. Pointer values are obfuscated
> > unless the 'x' option is specified. As an example:
> >
> > struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
> > pr_info("%pT", BTF_PTR_TYPE(skb, struct sk_buff));
> >
> > ...gives us:
> >
> > (struct sk_buff){
> > .transport_header = (__u16)65535,
> > .mac_header = (__u16)65535,
> > .end = (sk_buff_data_t)192,
> > .head = (unsigned char *)0x000000006b71155a,
> > .data = (unsigned char *)0x000000006b71155a,
> > .truesize = (unsigned int)768,
> > .users = (refcount_t){
> > .refs = (atomic_t){
> > .counter = (int)1,
> > },
> > },
> > .extensions = (struct skb_ext *)0x00000000f486a130,
> > }
> >
> > printk output is truncated at 1024 bytes. For cases where overflow
> > is likely, the compact/no type names display modes may be used.
>
> Hmm, this scares me:
>
> 1. The long message and many lines are going to stretch printk
> design in another dimensions.
>
> 2. vsprintf() is important for debugging the system. It has to be
> stable. But the btf code is too complex.
>

Right on both points, and there's no way around that really. Representing
even small data structures will stretch us to or beyond the 1024 byte
limit. This can be mitigated by using compact display mode and not
printing field names, but the output becomes hard to parse then.

I think a better approach might be to start small, adding the core
btf_show functionality to BPF, allowing consumers to use it there,
perhaps via a custom helper. In the current model bpf_trace_printk()
inherits the functionality to display data from core printk, so a
different approach would be needed there. Other consumers outside of BPF
could potentially avail of the show functionality directly via the btf_show
functions in the future, but at least it would have one consumer at the
outset, and wouldn't present problems like these for printk.

> I would strongly prefer to keep this outside vsprintf and printk.
> Please, invert the logic and convert it into using separate printk()
> call for each printed line.
>

I think the above is in line with what you're suggesting?

>
> More details:
>
> Add 1: Long messages with many lines:
>
> IMHO, all existing printk() users are far below this limit. And this is
> even worse because there are many short lines. They would require
> double space to add prefixes (loglevel, timestamp, caller id) when
> printing to console.
>
> You might argue that 1024bytes are enough for you. But for how long?
>
> Now, we have huge troubles to make printk() lockless and thus more
> reliable. There is no way to allocate any internal buffers
> dynamically. People using kernel on small devices have problem
> with large static buffers.
>
> printk() is primary designed to print single line messages. There are
> many use cases where many lines are needed and they are solved by
> many separate printk() calls.
>
>
> Add 2: Complex code:
>
> vsprintf() is currently called in printk() under logbuf_lock. It
> might block printk() on the entire system.
>
> Most existing %p<modifier> handlers are implemented by relatively
> simple routines inside lib/vsprinf.c. The other external routines
> look simple as well.
>
> btf looks like a huge beast to me. For example, probe_kernel_read()
> prevented boot recently, see the commit 2ac5a3bf7042a1c4abb
> ("vsprintf: Do not break early boot with probing addresses").
>
>

Yep, no way round this either. I'll try a different approach. Thanks for
taking a look!

Alan

> Best Regards,
> Petr
>

2020-06-29 19:03:53

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v3 bpf-next 4/8] printk: add type-printing %pT format specifier which uses BTF

On Fri 2020-06-26 12:37:19, Alan Maguire wrote:
>
> On Fri, 26 Jun 2020, Petr Mladek wrote:
>
> > On Tue 2020-06-23 13:07:07, Alan Maguire wrote:
> > >
> > > printk(KERN_INFO "%pT", BTF_PTR_TYPE(skb, struct sk_buff));
> > >
> > > struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
> > > pr_info("%pT", BTF_PTR_TYPE(skb, struct sk_buff));
> > >
> > > ...gives us:
> > >
> > > (struct sk_buff){
> > > .transport_header = (__u16)65535,
> > > .mac_header = (__u16)65535,
> > > .end = (sk_buff_data_t)192,
> > > .head = (unsigned char *)0x000000006b71155a,
> > > .data = (unsigned char *)0x000000006b71155a,
> > > .truesize = (unsigned int)768,
> > > .users = (refcount_t){
> > > .refs = (atomic_t){
> > > .counter = (int)1,
> > > },
> > > },
> > > .extensions = (struct skb_ext *)0x00000000f486a130,
> > > }
> > >
> > > printk output is truncated at 1024 bytes. For cases where overflow
> > > is likely, the compact/no type names display modes may be used.
> >
> > Hmm, this scares me:
> >
> > 1. The long message and many lines are going to stretch printk
> > design in another dimensions.
> >
> > 2. vsprintf() is important for debugging the system. It has to be
> > stable. But the btf code is too complex.
> >
>
> Right on both points, and there's no way around that really. Representing
> even small data structures will stretch us to or beyond the 1024 byte
> limit. This can be mitigated by using compact display mode and not
> printing field names, but the output becomes hard to parse then.
>
> I think a better approach might be to start small, adding the core
> btf_show functionality to BPF, allowing consumers to use it there,
> perhaps via a custom helper.

Sounds good to me.

> In the current model bpf_trace_printk() inherits the functionality
> to display data from core printk, so a different approach would
> be needed there.

BTW: Even the trace buffer has a limitation, see BUF_MAX_DATA_SIZE
in kernel/trace/ring_buffer.c. It is internally implemented as
a list of memory pages, see the comments above RB_BUFFER_OFF
definition.

It is typically 4k. I think that you might hit this limit as well.
We had to increase per-CPU buffers used by printk() in NMI context
because 4k was not enough for some backtraces.

So, using different approach would make sense even when using trace
buffer.

> Other consumers outside of BPF
> could potentially avail of the show functionality directly via the btf_show
> functions in the future, but at least it would have one consumer at the
> outset, and wouldn't present problems like these for printk.

Sounds good to me.

> > I would strongly prefer to keep this outside vsprintf and printk.
> > Please, invert the logic and convert it into using separate printk()
> > call for each printed line.
> >
>
> I think the above is in line with what you're suggesting?

Yes, as far as I understand it.

> Yep, no way round this either. I'll try a different approach. Thanks for
> taking a look!

Uff, thanks a lot for understanding. I hope that most of the code will
be reusable in some form.

Best Regards,
Petr