BPF Archive on lore.kernel.org
 help / color / Atom feed
* [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper
@ 2021-04-19 15:52 Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf Florent Revest
                   ` (6 more replies)
  0 siblings, 7 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

We have a usecase where we want to audit symbol names (if available) in
callback registration hooks. (ex: fentry/nf_register_net_hook)

A few months back, I proposed a bpf_kallsyms_lookup series but it was
decided in the reviews that a more generic helper, bpf_snprintf, would
be more useful.

This series implements the helper according to the feedback received in
https://lore.kernel.org/bpf/20201126165748.1748417-1-revest@google.com/T/#u

- A new arg type guarantees the NULL-termination of string arguments and
  lets us pass format strings in only one arg
- A new helper is implemented using that guarantee. Because the format
  string is known at verification time, the format string validation is
  done by the verifier
- To implement a series of tests for bpf_snprintf, the logic for
  marshalling variadic args in a fixed-size array is reworked as per:
https://lore.kernel.org/bpf/20210310015455.1095207-1-revest@chromium.org/T/#u

---
Changes in v5:
- Fixed the bpf_printf_buf_used counter logic in try_get_fmt_tmp_buf
- Added a couple of extra incorrect specifiers tests
- Call test_snprintf_single__destroy unconditionally
- Fixed a C++-style comment

---
Changes in v4:
- Moved bpf_snprintf, bpf_printf_prepare and bpf_printf_cleanup to
  kernel/bpf/helpers.c so that they get built without CONFIG_BPF_EVENTS
- Added negative test cases (various invalid format strings)
- Renamed put_fmt_tmp_buf() as bpf_printf_cleanup()
- Fixed a mistake that caused temporary buffers to be unconditionally
  freed in bpf_printf_prepare
- Fixed a mistake that caused missing 0 character to be ignored
- Fixed a warning about integer to pointer conversion
- Misc cleanups

---
Changes in v3:
- Simplified temporary buffer acquisition with try_get_fmt_tmp_buf()
- Made zero-termination check more consistent
- Allowed NULL output_buffer
- Simplified the BPF_CAST_FMT_ARG macro
- Three new test cases: number padding, simple string with no arg and
  string length extraction only with a NULL output buffer
- Clarified helper's description for edge cases (eg: str_size == 0)
- Lots of cosmetic changes

---
Changes in v2:
- Extracted the format validation/argument sanitization in a generic way
  for all printf-like helpers.
- bpf_snprintf's str_size can now be 0
- bpf_snprintf is now exposed to all BPF program types
- We now preempt_disable when using a per-cpu temporary buffer
- Addressed a few cosmetic changes

Florent Revest (6):
  bpf: Factorize bpf_trace_printk and bpf_seq_printf
  bpf: Add a ARG_PTR_TO_CONST_STR argument type
  bpf: Add a bpf_snprintf helper
  libbpf: Initialize the bpf_seq_printf parameters array field by field
  libbpf: Introduce a BPF_SNPRINTF helper macro
  selftests/bpf: Add a series of tests for bpf_snprintf

 include/linux/bpf.h                           |  22 ++
 include/uapi/linux/bpf.h                      |  28 ++
 kernel/bpf/helpers.c                          | 306 ++++++++++++++
 kernel/bpf/verifier.c                         |  82 ++++
 kernel/trace/bpf_trace.c                      | 373 ++----------------
 tools/include/uapi/linux/bpf.h                |  28 ++
 tools/lib/bpf/bpf_tracing.h                   |  58 ++-
 .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++
 .../selftests/bpf/progs/test_snprintf.c       |  73 ++++
 .../bpf/progs/test_snprintf_single.c          |  20 +
 10 files changed, 770 insertions(+), 345 deletions(-)
 create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
 create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
 create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c

-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type Florent Revest
                   ` (5 subsequent siblings)
  6 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

Two helpers (trace_printk and seq_printf) have very similar
implementations of format string parsing and a third one is coming
(snprintf). To avoid code duplication and make the code easier to
maintain, this moves the operations associated with format string
parsing (validation and argument sanitization) into one generic
function.

The implementation of the two existing helpers already drifted quite a
bit so unifying them entailed a lot of changes:

- bpf_trace_printk always expected fmt[fmt_size] to be the terminating
  NULL character, this is no longer true, the first 0 is terminating.
- bpf_trace_printk now supports %% (which produces the percentage char).
- bpf_trace_printk now skips width formating fields.
- bpf_trace_printk now supports the X modifier (capital hexadecimal).
- bpf_trace_printk now supports %pK, %px, %pB, %pi4, %pI4, %pi6 and %pI6
- argument casting on 32 bit has been simplified into one macro and
  using an enum instead of obscure int increments.

- bpf_seq_printf now uses bpf_trace_copy_string instead of
  strncpy_from_kernel_nofault and handles the %pks %pus specifiers.
- bpf_seq_printf now prints longs correctly on 32 bit architectures.

- both were changed to use a global per-cpu tmp buffer instead of one
  stack buffer for trace_printk and 6 small buffers for seq_printf.
- to avoid per-cpu buffer usage conflict, these helpers disable
  preemption while the per-cpu buffer is in use.
- both helpers now support the %ps and %pS specifiers to print symbols.

The implementation is also moved from bpf_trace.c to helpers.c because
the upcoming bpf_snprintf helper will be made available to all BPF
programs and will need it.

Signed-off-by: Florent Revest <revest@chromium.org>
---
 include/linux/bpf.h      |  20 +++
 kernel/bpf/helpers.c     | 256 +++++++++++++++++++++++++++
 kernel/trace/bpf_trace.c | 371 ++++-----------------------------------
 3 files changed, 313 insertions(+), 334 deletions(-)

diff --git a/include/linux/bpf.h b/include/linux/bpf.h
index ff8cd68c01b3..77d1d8c65b81 100644
--- a/include/linux/bpf.h
+++ b/include/linux/bpf.h
@@ -2077,4 +2077,24 @@ int bpf_arch_text_poke(void *ip, enum bpf_text_poke_type t,
 struct btf_id_set;
 bool btf_id_set_contains(const struct btf_id_set *set, u32 id);
 
+enum bpf_printf_mod_type {
+	BPF_PRINTF_INT,
+	BPF_PRINTF_LONG,
+	BPF_PRINTF_LONG_LONG,
+};
+
+/* Workaround for getting va_list handling working with different argument type
+ * combinations generically for 32 and 64 bit archs.
+ */
+#define BPF_CAST_FMT_ARG(arg_nb, args, mod)				\
+	(mod[arg_nb] == BPF_PRINTF_LONG_LONG ||				\
+	 (mod[arg_nb] == BPF_PRINTF_LONG && __BITS_PER_LONG == 64)	\
+	  ? (u64)args[arg_nb]						\
+	  : (u32)args[arg_nb])
+
+int bpf_printf_prepare(char *fmt, u32 fmt_size, const u64 *raw_args,
+		       u64 *final_args, enum bpf_printf_mod_type *mod,
+		       u32 num_args);
+void bpf_printf_cleanup(void);
+
 #endif /* _LINUX_BPF_H */
diff --git a/kernel/bpf/helpers.c b/kernel/bpf/helpers.c
index f306611c4ddf..9ca57eb1fc0d 100644
--- a/kernel/bpf/helpers.c
+++ b/kernel/bpf/helpers.c
@@ -669,6 +669,262 @@ const struct bpf_func_proto bpf_this_cpu_ptr_proto = {
 	.arg1_type	= ARG_PTR_TO_PERCPU_BTF_ID,
 };
 
+static int bpf_trace_copy_string(char *buf, void *unsafe_ptr, char fmt_ptype,
+		size_t bufsz)
+{
+	void __user *user_ptr = (__force void __user *)unsafe_ptr;
+
+	buf[0] = 0;
+
+	switch (fmt_ptype) {
+	case 's':
+#ifdef CONFIG_ARCH_HAS_NON_OVERLAPPING_ADDRESS_SPACE
+		if ((unsigned long)unsafe_ptr < TASK_SIZE)
+			return strncpy_from_user_nofault(buf, user_ptr, bufsz);
+		fallthrough;
+#endif
+	case 'k':
+		return strncpy_from_kernel_nofault(buf, unsafe_ptr, bufsz);
+	case 'u':
+		return strncpy_from_user_nofault(buf, user_ptr, bufsz);
+	}
+
+	return -EINVAL;
+}
+
+/* Per-cpu temp buffers which can be used by printf-like helpers for %s or %p
+ */
+#define MAX_PRINTF_BUF_LEN	512
+
+struct bpf_printf_buf {
+	char tmp_buf[MAX_PRINTF_BUF_LEN];
+};
+static DEFINE_PER_CPU(struct bpf_printf_buf, bpf_printf_buf);
+static DEFINE_PER_CPU(int, bpf_printf_buf_used);
+
+static int try_get_fmt_tmp_buf(char **tmp_buf)
+{
+	struct bpf_printf_buf *bufs;
+	int used;
+
+	if (*tmp_buf)
+		return 0;
+
+	preempt_disable();
+	used = this_cpu_inc_return(bpf_printf_buf_used);
+	if (WARN_ON_ONCE(used > 1)) {
+		this_cpu_dec(bpf_printf_buf_used);
+		preempt_enable();
+		return -EBUSY;
+	}
+	bufs = this_cpu_ptr(&bpf_printf_buf);
+	*tmp_buf = bufs->tmp_buf;
+
+	return 0;
+}
+
+void bpf_printf_cleanup(void)
+{
+	if (this_cpu_read(bpf_printf_buf_used)) {
+		this_cpu_dec(bpf_printf_buf_used);
+		preempt_enable();
+	}
+}
+
+/*
+ * bpf_parse_fmt_str - Generic pass on format strings for printf-like helpers
+ *
+ * Returns a negative value if fmt is an invalid format string or 0 otherwise.
+ *
+ * This can be used in two ways:
+ * - Format string verification only: when final_args and mod are NULL
+ * - Arguments preparation: in addition to the above verification, it writes in
+ *   final_args a copy of raw_args where pointers from BPF have been sanitized
+ *   into pointers safe to use by snprintf. This also writes in the mod array
+ *   the size requirement of each argument, usable by BPF_CAST_FMT_ARG for ex.
+ *
+ * In argument preparation mode, if 0 is returned, safe temporary buffers are
+ * allocated and bpf_printf_cleanup should be called to free them after use.
+ */
+int bpf_printf_prepare(char *fmt, u32 fmt_size, const u64 *raw_args,
+			u64 *final_args, enum bpf_printf_mod_type *mod,
+			u32 num_args)
+{
+	char *unsafe_ptr = NULL, *tmp_buf = NULL, *fmt_end;
+	size_t tmp_buf_len = MAX_PRINTF_BUF_LEN;
+	int err, i, num_spec = 0, copy_size;
+	enum bpf_printf_mod_type cur_mod;
+	u64 cur_arg;
+	char fmt_ptype;
+
+	if (!!final_args != !!mod)
+		return -EINVAL;
+
+	fmt_end = strnchr(fmt, fmt_size, 0);
+	if (!fmt_end)
+		return -EINVAL;
+	fmt_size = fmt_end - fmt;
+
+	for (i = 0; i < fmt_size; i++) {
+		if ((!isprint(fmt[i]) && !isspace(fmt[i])) || !isascii(fmt[i])) {
+			err = -EINVAL;
+			goto cleanup;
+		}
+
+		if (fmt[i] != '%')
+			continue;
+
+		if (fmt[i + 1] == '%') {
+			i++;
+			continue;
+		}
+
+		if (num_spec >= num_args) {
+			err = -EINVAL;
+			goto cleanup;
+		}
+
+		/* The string is zero-terminated so if fmt[i] != 0, we can
+		 * always access fmt[i + 1], in the worst case it will be a 0
+		 */
+		i++;
+
+		/* skip optional "[0 +-][num]" width formatting field */
+		while (fmt[i] == '0' || fmt[i] == '+'  || fmt[i] == '-' ||
+		       fmt[i] == ' ')
+			i++;
+		if (fmt[i] >= '1' && fmt[i] <= '9') {
+			i++;
+			while (fmt[i] >= '0' && fmt[i] <= '9')
+				i++;
+		}
+
+		if (fmt[i] == 'p') {
+			cur_mod = BPF_PRINTF_LONG;
+
+			if ((fmt[i + 1] == 'k' || fmt[i + 1] == 'u') &&
+			    fmt[i + 2] == 's') {
+				fmt_ptype = fmt[i + 1];
+				i += 2;
+				goto fmt_str;
+			}
+
+			if (fmt[i + 1] == 0 || isspace(fmt[i + 1]) ||
+			    ispunct(fmt[i + 1]) || fmt[i + 1] == 'K' ||
+			    fmt[i + 1] == 'x' || fmt[i + 1] == 'B' ||
+			    fmt[i + 1] == 's' || fmt[i + 1] == 'S') {
+				/* just kernel pointers */
+				if (final_args)
+					cur_arg = raw_args[num_spec];
+				goto fmt_next;
+			}
+
+			/* only support "%pI4", "%pi4", "%pI6" and "%pi6". */
+			if ((fmt[i + 1] != 'i' && fmt[i + 1] != 'I') ||
+			    (fmt[i + 2] != '4' && fmt[i + 2] != '6')) {
+				err = -EINVAL;
+				goto cleanup;
+			}
+
+			i += 2;
+			if (!final_args)
+				goto fmt_next;
+
+			if (try_get_fmt_tmp_buf(&tmp_buf)) {
+				err = -EBUSY;
+				goto out;
+			}
+
+			copy_size = (fmt[i + 2] == '4') ? 4 : 16;
+			if (tmp_buf_len < copy_size) {
+				err = -ENOSPC;
+				goto cleanup;
+			}
+
+			unsafe_ptr = (char *)(long)raw_args[num_spec];
+			err = copy_from_kernel_nofault(tmp_buf, unsafe_ptr,
+						       copy_size);
+			if (err < 0)
+				memset(tmp_buf, 0, copy_size);
+			cur_arg = (u64)(long)tmp_buf;
+			tmp_buf += copy_size;
+			tmp_buf_len -= copy_size;
+
+			goto fmt_next;
+		} else if (fmt[i] == 's') {
+			cur_mod = BPF_PRINTF_LONG;
+			fmt_ptype = fmt[i];
+fmt_str:
+			if (fmt[i + 1] != 0 &&
+			    !isspace(fmt[i + 1]) &&
+			    !ispunct(fmt[i + 1])) {
+				err = -EINVAL;
+				goto cleanup;
+			}
+
+			if (!final_args)
+				goto fmt_next;
+
+			if (try_get_fmt_tmp_buf(&tmp_buf)) {
+				err = -EBUSY;
+				goto out;
+			}
+
+			if (!tmp_buf_len) {
+				err = -ENOSPC;
+				goto cleanup;
+			}
+
+			unsafe_ptr = (char *)(long)raw_args[num_spec];
+			err = bpf_trace_copy_string(tmp_buf, unsafe_ptr,
+						    fmt_ptype, tmp_buf_len);
+			if (err < 0) {
+				tmp_buf[0] = '\0';
+				err = 1;
+			}
+
+			cur_arg = (u64)(long)tmp_buf;
+			tmp_buf += err;
+			tmp_buf_len -= err;
+
+			goto fmt_next;
+		}
+
+		cur_mod = BPF_PRINTF_INT;
+
+		if (fmt[i] == 'l') {
+			cur_mod = BPF_PRINTF_LONG;
+			i++;
+		}
+		if (fmt[i] == 'l') {
+			cur_mod = BPF_PRINTF_LONG_LONG;
+			i++;
+		}
+
+		if (fmt[i] != 'i' && fmt[i] != 'd' && fmt[i] != 'u' &&
+		    fmt[i] != 'x' && fmt[i] != 'X') {
+			err = -EINVAL;
+			goto cleanup;
+		}
+
+		if (final_args)
+			cur_arg = raw_args[num_spec];
+fmt_next:
+		if (final_args) {
+			mod[num_spec] = cur_mod;
+			final_args[num_spec] = cur_arg;
+		}
+		num_spec++;
+	}
+
+	err = 0;
+cleanup:
+	if (err)
+		bpf_printf_cleanup();
+out:
+	return err;
+}
+
 const struct bpf_func_proto bpf_get_current_task_proto __weak;
 const struct bpf_func_proto bpf_probe_read_user_proto __weak;
 const struct bpf_func_proto bpf_probe_read_user_str_proto __weak;
diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
index 0d23755c2747..a13f8644b357 100644
--- a/kernel/trace/bpf_trace.c
+++ b/kernel/trace/bpf_trace.c
@@ -372,188 +372,38 @@ static const struct bpf_func_proto *bpf_get_probe_write_proto(void)
 	return &bpf_probe_write_user_proto;
 }
 
-static void bpf_trace_copy_string(char *buf, void *unsafe_ptr, char fmt_ptype,
-		size_t bufsz)
-{
-	void __user *user_ptr = (__force void __user *)unsafe_ptr;
-
-	buf[0] = 0;
-
-	switch (fmt_ptype) {
-	case 's':
-#ifdef CONFIG_ARCH_HAS_NON_OVERLAPPING_ADDRESS_SPACE
-		if ((unsigned long)unsafe_ptr < TASK_SIZE) {
-			strncpy_from_user_nofault(buf, user_ptr, bufsz);
-			break;
-		}
-		fallthrough;
-#endif
-	case 'k':
-		strncpy_from_kernel_nofault(buf, unsafe_ptr, bufsz);
-		break;
-	case 'u':
-		strncpy_from_user_nofault(buf, user_ptr, bufsz);
-		break;
-	}
-}
-
 static DEFINE_RAW_SPINLOCK(trace_printk_lock);
 
-#define BPF_TRACE_PRINTK_SIZE   1024
+#define MAX_TRACE_PRINTK_VARARGS	3
+#define BPF_TRACE_PRINTK_SIZE		1024
 
-static __printf(1, 0) int bpf_do_trace_printk(const char *fmt, ...)
+BPF_CALL_5(bpf_trace_printk, char *, fmt, u32, fmt_size, u64, arg1,
+	   u64, arg2, u64, arg3)
 {
+	u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
+	enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
 	static char buf[BPF_TRACE_PRINTK_SIZE];
 	unsigned long flags;
-	va_list ap;
 	int ret;
 
-	raw_spin_lock_irqsave(&trace_printk_lock, flags);
-	va_start(ap, fmt);
-	ret = vsnprintf(buf, sizeof(buf), fmt, ap);
-	va_end(ap);
-	/* vsnprintf() will not append null for zero-length strings */
+	ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
+				 MAX_TRACE_PRINTK_VARARGS);
+	if (ret < 0)
+		return ret;
+
+	ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
+		BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
+	/* snprintf() will not append null for zero-length strings */
 	if (ret == 0)
 		buf[0] = '\0';
+
+	raw_spin_lock_irqsave(&trace_printk_lock, flags);
 	trace_bpf_trace_printk(buf);
 	raw_spin_unlock_irqrestore(&trace_printk_lock, flags);
 
-	return ret;
-}
-
-/*
- * Only limited trace_printk() conversion specifiers allowed:
- * %d %i %u %x %ld %li %lu %lx %lld %lli %llu %llx %p %pB %pks %pus %s
- */
-BPF_CALL_5(bpf_trace_printk, char *, fmt, u32, fmt_size, u64, arg1,
-	   u64, arg2, u64, arg3)
-{
-	int i, mod[3] = {}, fmt_cnt = 0;
-	char buf[64], fmt_ptype;
-	void *unsafe_ptr = NULL;
-	bool str_seen = false;
+	bpf_printf_cleanup();
 
-	/*
-	 * bpf_check()->check_func_arg()->check_stack_boundary()
-	 * guarantees that fmt points to bpf program stack,
-	 * fmt_size bytes of it were initialized and fmt_size > 0
-	 */
-	if (fmt[--fmt_size] != 0)
-		return -EINVAL;
-
-	/* check format string for allowed specifiers */
-	for (i = 0; i < fmt_size; i++) {
-		if ((!isprint(fmt[i]) && !isspace(fmt[i])) || !isascii(fmt[i]))
-			return -EINVAL;
-
-		if (fmt[i] != '%')
-			continue;
-
-		if (fmt_cnt >= 3)
-			return -EINVAL;
-
-		/* fmt[i] != 0 && fmt[last] == 0, so we can access fmt[i + 1] */
-		i++;
-		if (fmt[i] == 'l') {
-			mod[fmt_cnt]++;
-			i++;
-		} else if (fmt[i] == 'p') {
-			mod[fmt_cnt]++;
-			if ((fmt[i + 1] == 'k' ||
-			     fmt[i + 1] == 'u') &&
-			    fmt[i + 2] == 's') {
-				fmt_ptype = fmt[i + 1];
-				i += 2;
-				goto fmt_str;
-			}
-
-			if (fmt[i + 1] == 'B') {
-				i++;
-				goto fmt_next;
-			}
-
-			/* disallow any further format extensions */
-			if (fmt[i + 1] != 0 &&
-			    !isspace(fmt[i + 1]) &&
-			    !ispunct(fmt[i + 1]))
-				return -EINVAL;
-
-			goto fmt_next;
-		} else if (fmt[i] == 's') {
-			mod[fmt_cnt]++;
-			fmt_ptype = fmt[i];
-fmt_str:
-			if (str_seen)
-				/* allow only one '%s' per fmt string */
-				return -EINVAL;
-			str_seen = true;
-
-			if (fmt[i + 1] != 0 &&
-			    !isspace(fmt[i + 1]) &&
-			    !ispunct(fmt[i + 1]))
-				return -EINVAL;
-
-			switch (fmt_cnt) {
-			case 0:
-				unsafe_ptr = (void *)(long)arg1;
-				arg1 = (long)buf;
-				break;
-			case 1:
-				unsafe_ptr = (void *)(long)arg2;
-				arg2 = (long)buf;
-				break;
-			case 2:
-				unsafe_ptr = (void *)(long)arg3;
-				arg3 = (long)buf;
-				break;
-			}
-
-			bpf_trace_copy_string(buf, unsafe_ptr, fmt_ptype,
-					sizeof(buf));
-			goto fmt_next;
-		}
-
-		if (fmt[i] == 'l') {
-			mod[fmt_cnt]++;
-			i++;
-		}
-
-		if (fmt[i] != 'i' && fmt[i] != 'd' &&
-		    fmt[i] != 'u' && fmt[i] != 'x')
-			return -EINVAL;
-fmt_next:
-		fmt_cnt++;
-	}
-
-/* Horrid workaround for getting va_list handling working with different
- * argument type combinations generically for 32 and 64 bit archs.
- */
-#define __BPF_TP_EMIT()	__BPF_ARG3_TP()
-#define __BPF_TP(...)							\
-	bpf_do_trace_printk(fmt, ##__VA_ARGS__)
-
-#define __BPF_ARG1_TP(...)						\
-	((mod[0] == 2 || (mod[0] == 1 && __BITS_PER_LONG == 64))	\
-	  ? __BPF_TP(arg1, ##__VA_ARGS__)				\
-	  : ((mod[0] == 1 || (mod[0] == 0 && __BITS_PER_LONG == 32))	\
-	      ? __BPF_TP((long)arg1, ##__VA_ARGS__)			\
-	      : __BPF_TP((u32)arg1, ##__VA_ARGS__)))
-
-#define __BPF_ARG2_TP(...)						\
-	((mod[1] == 2 || (mod[1] == 1 && __BITS_PER_LONG == 64))	\
-	  ? __BPF_ARG1_TP(arg2, ##__VA_ARGS__)				\
-	  : ((mod[1] == 1 || (mod[1] == 0 && __BITS_PER_LONG == 32))	\
-	      ? __BPF_ARG1_TP((long)arg2, ##__VA_ARGS__)		\
-	      : __BPF_ARG1_TP((u32)arg2, ##__VA_ARGS__)))
-
-#define __BPF_ARG3_TP(...)						\
-	((mod[2] == 2 || (mod[2] == 1 && __BITS_PER_LONG == 64))	\
-	  ? __BPF_ARG2_TP(arg3, ##__VA_ARGS__)				\
-	  : ((mod[2] == 1 || (mod[2] == 0 && __BITS_PER_LONG == 32))	\
-	      ? __BPF_ARG2_TP((long)arg3, ##__VA_ARGS__)		\
-	      : __BPF_ARG2_TP((u32)arg3, ##__VA_ARGS__)))
-
-	return __BPF_TP_EMIT();
+	return ret;
 }
 
 static const struct bpf_func_proto bpf_trace_printk_proto = {
@@ -581,184 +431,37 @@ const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
 }
 
 #define MAX_SEQ_PRINTF_VARARGS		12
-#define MAX_SEQ_PRINTF_MAX_MEMCPY	6
-#define MAX_SEQ_PRINTF_STR_LEN		128
-
-struct bpf_seq_printf_buf {
-	char buf[MAX_SEQ_PRINTF_MAX_MEMCPY][MAX_SEQ_PRINTF_STR_LEN];
-};
-static DEFINE_PER_CPU(struct bpf_seq_printf_buf, bpf_seq_printf_buf);
-static DEFINE_PER_CPU(int, bpf_seq_printf_buf_used);
 
 BPF_CALL_5(bpf_seq_printf, struct seq_file *, m, char *, fmt, u32, fmt_size,
 	   const void *, data, u32, data_len)
 {
-	int err = -EINVAL, fmt_cnt = 0, memcpy_cnt = 0;
-	int i, buf_used, copy_size, num_args;
-	u64 params[MAX_SEQ_PRINTF_VARARGS];
-	struct bpf_seq_printf_buf *bufs;
-	const u64 *args = data;
-
-	buf_used = this_cpu_inc_return(bpf_seq_printf_buf_used);
-	if (WARN_ON_ONCE(buf_used > 1)) {
-		err = -EBUSY;
-		goto out;
-	}
-
-	bufs = this_cpu_ptr(&bpf_seq_printf_buf);
-
-	/*
-	 * bpf_check()->check_func_arg()->check_stack_boundary()
-	 * guarantees that fmt points to bpf program stack,
-	 * fmt_size bytes of it were initialized and fmt_size > 0
-	 */
-	if (fmt[--fmt_size] != 0)
-		goto out;
-
-	if (data_len & 7)
-		goto out;
-
-	for (i = 0; i < fmt_size; i++) {
-		if (fmt[i] == '%') {
-			if (fmt[i + 1] == '%')
-				i++;
-			else if (!data || !data_len)
-				goto out;
-		}
-	}
+	enum bpf_printf_mod_type mod[MAX_SEQ_PRINTF_VARARGS];
+	u64 args[MAX_SEQ_PRINTF_VARARGS];
+	int err, num_args;
 
+	if (data_len & 7 || data_len > MAX_SEQ_PRINTF_VARARGS * 8 ||
+	    (data_len && !data))
+		return -EINVAL;
 	num_args = data_len / 8;
 
-	/* check format string for allowed specifiers */
-	for (i = 0; i < fmt_size; i++) {
-		/* only printable ascii for now. */
-		if ((!isprint(fmt[i]) && !isspace(fmt[i])) || !isascii(fmt[i])) {
-			err = -EINVAL;
-			goto out;
-		}
-
-		if (fmt[i] != '%')
-			continue;
-
-		if (fmt[i + 1] == '%') {
-			i++;
-			continue;
-		}
-
-		if (fmt_cnt >= MAX_SEQ_PRINTF_VARARGS) {
-			err = -E2BIG;
-			goto out;
-		}
-
-		if (fmt_cnt >= num_args) {
-			err = -EINVAL;
-			goto out;
-		}
-
-		/* fmt[i] != 0 && fmt[last] == 0, so we can access fmt[i + 1] */
-		i++;
-
-		/* skip optional "[0 +-][num]" width formating field */
-		while (fmt[i] == '0' || fmt[i] == '+'  || fmt[i] == '-' ||
-		       fmt[i] == ' ')
-			i++;
-		if (fmt[i] >= '1' && fmt[i] <= '9') {
-			i++;
-			while (fmt[i] >= '0' && fmt[i] <= '9')
-				i++;
-		}
-
-		if (fmt[i] == 's') {
-			void *unsafe_ptr;
-
-			/* try our best to copy */
-			if (memcpy_cnt >= MAX_SEQ_PRINTF_MAX_MEMCPY) {
-				err = -E2BIG;
-				goto out;
-			}
-
-			unsafe_ptr = (void *)(long)args[fmt_cnt];
-			err = strncpy_from_kernel_nofault(bufs->buf[memcpy_cnt],
-					unsafe_ptr, MAX_SEQ_PRINTF_STR_LEN);
-			if (err < 0)
-				bufs->buf[memcpy_cnt][0] = '\0';
-			params[fmt_cnt] = (u64)(long)bufs->buf[memcpy_cnt];
-
-			fmt_cnt++;
-			memcpy_cnt++;
-			continue;
-		}
-
-		if (fmt[i] == 'p') {
-			if (fmt[i + 1] == 0 ||
-			    fmt[i + 1] == 'K' ||
-			    fmt[i + 1] == 'x' ||
-			    fmt[i + 1] == 'B') {
-				/* just kernel pointers */
-				params[fmt_cnt] = args[fmt_cnt];
-				fmt_cnt++;
-				continue;
-			}
-
-			/* only support "%pI4", "%pi4", "%pI6" and "%pi6". */
-			if (fmt[i + 1] != 'i' && fmt[i + 1] != 'I') {
-				err = -EINVAL;
-				goto out;
-			}
-			if (fmt[i + 2] != '4' && fmt[i + 2] != '6') {
-				err = -EINVAL;
-				goto out;
-			}
-
-			if (memcpy_cnt >= MAX_SEQ_PRINTF_MAX_MEMCPY) {
-				err = -E2BIG;
-				goto out;
-			}
-
-
-			copy_size = (fmt[i + 2] == '4') ? 4 : 16;
-
-			err = copy_from_kernel_nofault(bufs->buf[memcpy_cnt],
-						(void *) (long) args[fmt_cnt],
-						copy_size);
-			if (err < 0)
-				memset(bufs->buf[memcpy_cnt], 0, copy_size);
-			params[fmt_cnt] = (u64)(long)bufs->buf[memcpy_cnt];
-
-			i += 2;
-			fmt_cnt++;
-			memcpy_cnt++;
-			continue;
-		}
-
-		if (fmt[i] == 'l') {
-			i++;
-			if (fmt[i] == 'l')
-				i++;
-		}
-
-		if (fmt[i] != 'i' && fmt[i] != 'd' &&
-		    fmt[i] != 'u' && fmt[i] != 'x' &&
-		    fmt[i] != 'X') {
-			err = -EINVAL;
-			goto out;
-		}
-
-		params[fmt_cnt] = args[fmt_cnt];
-		fmt_cnt++;
-	}
+	err = bpf_printf_prepare(fmt, fmt_size, data, args, mod, num_args);
+	if (err < 0)
+		return err;
 
 	/* Maximumly we can have MAX_SEQ_PRINTF_VARARGS parameter, just give
 	 * all of them to seq_printf().
 	 */
-	seq_printf(m, fmt, params[0], params[1], params[2], params[3],
-		   params[4], params[5], params[6], params[7], params[8],
-		   params[9], params[10], params[11]);
+	seq_printf(m, fmt, BPF_CAST_FMT_ARG(0, args, mod),
+		BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod),
+		BPF_CAST_FMT_ARG(3, args, mod), BPF_CAST_FMT_ARG(4, args, mod),
+		BPF_CAST_FMT_ARG(5, args, mod), BPF_CAST_FMT_ARG(6, args, mod),
+		BPF_CAST_FMT_ARG(7, args, mod), BPF_CAST_FMT_ARG(8, args, mod),
+		BPF_CAST_FMT_ARG(9, args, mod), BPF_CAST_FMT_ARG(10, args, mod),
+		BPF_CAST_FMT_ARG(11, args, mod));
 
-	err = seq_has_overflowed(m) ? -EOVERFLOW : 0;
-out:
-	this_cpu_dec(bpf_seq_printf_buf_used);
-	return err;
+	bpf_printf_cleanup();
+
+	return seq_has_overflowed(m) ? -EOVERFLOW : 0;
 }
 
 BTF_ID_LIST_SINGLE(btf_seq_file_ids, struct, seq_file)
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-19 22:54   ` Alexei Starovoitov
  2021-04-19 15:52 ` [PATCH bpf-next v5 3/6] bpf: Add a bpf_snprintf helper Florent Revest
                   ` (4 subsequent siblings)
  6 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

This type provides the guarantee that an argument is going to be a const
pointer to somewhere in a read-only map value. It also checks that this
pointer is followed by a zero character before the end of the map value.

Signed-off-by: Florent Revest <revest@chromium.org>
Acked-by: Andrii Nakryiko <andrii@kernel.org>
---
 include/linux/bpf.h   |  1 +
 kernel/bpf/verifier.c | 41 +++++++++++++++++++++++++++++++++++++++++
 2 files changed, 42 insertions(+)

diff --git a/include/linux/bpf.h b/include/linux/bpf.h
index 77d1d8c65b81..c160526fc8bf 100644
--- a/include/linux/bpf.h
+++ b/include/linux/bpf.h
@@ -309,6 +309,7 @@ enum bpf_arg_type {
 	ARG_PTR_TO_PERCPU_BTF_ID,	/* pointer to in-kernel percpu type */
 	ARG_PTR_TO_FUNC,	/* pointer to a bpf program function */
 	ARG_PTR_TO_STACK_OR_NULL,	/* pointer to stack or NULL */
+	ARG_PTR_TO_CONST_STR,	/* pointer to a null terminated read-only string */
 	__BPF_ARG_TYPE_MAX,
 };
 
diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index 852541a435ef..5f46dd6f3383 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -4787,6 +4787,7 @@ static const struct bpf_reg_types spin_lock_types = { .types = { PTR_TO_MAP_VALU
 static const struct bpf_reg_types percpu_btf_ptr_types = { .types = { PTR_TO_PERCPU_BTF_ID } };
 static const struct bpf_reg_types func_ptr_types = { .types = { PTR_TO_FUNC } };
 static const struct bpf_reg_types stack_ptr_types = { .types = { PTR_TO_STACK } };
+static const struct bpf_reg_types const_str_ptr_types = { .types = { PTR_TO_MAP_VALUE } };
 
 static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
 	[ARG_PTR_TO_MAP_KEY]		= &map_key_value_types,
@@ -4817,6 +4818,7 @@ static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
 	[ARG_PTR_TO_PERCPU_BTF_ID]	= &percpu_btf_ptr_types,
 	[ARG_PTR_TO_FUNC]		= &func_ptr_types,
 	[ARG_PTR_TO_STACK_OR_NULL]	= &stack_ptr_types,
+	[ARG_PTR_TO_CONST_STR]		= &const_str_ptr_types,
 };
 
 static int check_reg_type(struct bpf_verifier_env *env, u32 regno,
@@ -5067,6 +5069,45 @@ static int check_func_arg(struct bpf_verifier_env *env, u32 arg,
 		if (err)
 			return err;
 		err = check_ptr_alignment(env, reg, 0, size, true);
+	} else if (arg_type == ARG_PTR_TO_CONST_STR) {
+		struct bpf_map *map = reg->map_ptr;
+		int map_off;
+		u64 map_addr;
+		char *str_ptr;
+
+		if (reg->type != PTR_TO_MAP_VALUE || !map ||
+		    !bpf_map_is_rdonly(map)) {
+			verbose(env, "R%d does not point to a readonly map'\n", regno);
+			return -EACCES;
+		}
+
+		if (!tnum_is_const(reg->var_off)) {
+			verbose(env, "R%d is not a constant address'\n", regno);
+			return -EACCES;
+		}
+
+		if (!map->ops->map_direct_value_addr) {
+			verbose(env, "no direct value access support for this map type\n");
+			return -EACCES;
+		}
+
+		err = check_map_access(env, regno, reg->off,
+				       map->value_size - reg->off, false);
+		if (err)
+			return err;
+
+		map_off = reg->off + reg->var_off.value;
+		err = map->ops->map_direct_value_addr(map, &map_addr, map_off);
+		if (err) {
+			verbose(env, "direct value access on string failed\n");
+			return err;
+		}
+
+		str_ptr = (char *)(long)(map_addr);
+		if (!strnchr(str_ptr + map_off, map->value_size - map_off, 0)) {
+			verbose(env, "string is not zero-terminated\n");
+			return -EINVAL;
+		}
 	}
 
 	return err;
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 3/6] bpf: Add a bpf_snprintf helper
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 4/6] libbpf: Initialize the bpf_seq_printf parameters array field by field Florent Revest
                   ` (3 subsequent siblings)
  6 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

The implementation takes inspiration from the existing bpf_trace_printk
helper but there are a few differences:

To allow for a large number of format-specifiers, parameters are
provided in an array, like in bpf_seq_printf.

Because the output string takes two arguments and the array of
parameters also takes two arguments, the format string needs to fit in
one argument. Thankfully, ARG_PTR_TO_CONST_STR is guaranteed to point to
a zero-terminated read-only map so we don't need a format string length
arg.

Because the format-string is known at verification time, we also do
a first pass of format string validation in the verifier logic. This
makes debugging easier.

Signed-off-by: Florent Revest <revest@chromium.org>
Acked-by: Andrii Nakryiko <andrii@kernel.org>
---
 include/linux/bpf.h            |  1 +
 include/uapi/linux/bpf.h       | 28 +++++++++++++++++++
 kernel/bpf/helpers.c           | 50 ++++++++++++++++++++++++++++++++++
 kernel/bpf/verifier.c          | 41 ++++++++++++++++++++++++++++
 kernel/trace/bpf_trace.c       |  2 ++
 tools/include/uapi/linux/bpf.h | 28 +++++++++++++++++++
 6 files changed, 150 insertions(+)

diff --git a/include/linux/bpf.h b/include/linux/bpf.h
index c160526fc8bf..f8a45f109e96 100644
--- a/include/linux/bpf.h
+++ b/include/linux/bpf.h
@@ -1953,6 +1953,7 @@ extern const struct bpf_func_proto bpf_skc_to_tcp_request_sock_proto;
 extern const struct bpf_func_proto bpf_skc_to_udp6_sock_proto;
 extern const struct bpf_func_proto bpf_copy_from_user_proto;
 extern const struct bpf_func_proto bpf_snprintf_btf_proto;
+extern const struct bpf_func_proto bpf_snprintf_proto;
 extern const struct bpf_func_proto bpf_per_cpu_ptr_proto;
 extern const struct bpf_func_proto bpf_this_cpu_ptr_proto;
 extern const struct bpf_func_proto bpf_ktime_get_coarse_ns_proto;
diff --git a/include/uapi/linux/bpf.h b/include/uapi/linux/bpf.h
index df164a44bb41..ec6d85a81744 100644
--- a/include/uapi/linux/bpf.h
+++ b/include/uapi/linux/bpf.h
@@ -4708,6 +4708,33 @@ union bpf_attr {
  *	Return
  *		The number of traversed map elements for success, **-EINVAL** for
  *		invalid **flags**.
+ *
+ * long bpf_snprintf(char *str, u32 str_size, const char *fmt, u64 *data, u32 data_len)
+ *	Description
+ *		Outputs a string into the **str** buffer of size **str_size**
+ *		based on a format string stored in a read-only map pointed by
+ *		**fmt**.
+ *
+ *		Each format specifier in **fmt** corresponds to one u64 element
+ *		in the **data** array. For strings and pointers where pointees
+ *		are accessed, only the pointer values are stored in the *data*
+ *		array. The *data_len* is the size of *data* in bytes.
+ *
+ *		Formats **%s** and **%p{i,I}{4,6}** require to read kernel
+ *		memory. Reading kernel memory may fail due to either invalid
+ *		address or valid address but requiring a major memory fault. If
+ *		reading kernel memory fails, the string for **%s** will be an
+ *		empty string, and the ip address for **%p{i,I}{4,6}** will be 0.
+ *		Not returning error to bpf program is consistent with what
+ *		**bpf_trace_printk**\ () does for now.
+ *
+ *	Return
+ *		The strictly positive length of the formatted string, including
+ *		the trailing zero character. If the return value is greater than
+ *		**str_size**, **str** contains a truncated string, guaranteed to
+ *		be zero-terminated except when **str_size** is 0.
+ *
+ *		Or **-EBUSY** if the per-CPU memory copy buffer is busy.
  */
 #define __BPF_FUNC_MAPPER(FN)		\
 	FN(unspec),			\
@@ -4875,6 +4902,7 @@ union bpf_attr {
 	FN(sock_from_file),		\
 	FN(check_mtu),			\
 	FN(for_each_map_elem),		\
+	FN(snprintf),			\
 	/* */
 
 /* integer value in 'imm' field of BPF_CALL instruction selects which helper
diff --git a/kernel/bpf/helpers.c b/kernel/bpf/helpers.c
index 9ca57eb1fc0d..85b26ca5aacd 100644
--- a/kernel/bpf/helpers.c
+++ b/kernel/bpf/helpers.c
@@ -925,6 +925,54 @@ int bpf_printf_prepare(char *fmt, u32 fmt_size, const u64 *raw_args,
 	return err;
 }
 
+#define MAX_SNPRINTF_VARARGS		12
+
+BPF_CALL_5(bpf_snprintf, char *, str, u32, str_size, char *, fmt,
+	   const void *, data, u32, data_len)
+{
+	enum bpf_printf_mod_type mod[MAX_SNPRINTF_VARARGS];
+	u64 args[MAX_SNPRINTF_VARARGS];
+	int err, num_args;
+
+	if (data_len % 8 || data_len > MAX_SNPRINTF_VARARGS * 8 ||
+	    (data_len && !data))
+		return -EINVAL;
+	num_args = data_len / 8;
+
+	/* ARG_PTR_TO_CONST_STR guarantees that fmt is zero-terminated so we
+	 * can safely give an unbounded size.
+	 */
+	err = bpf_printf_prepare(fmt, UINT_MAX, data, args, mod, num_args);
+	if (err < 0)
+		return err;
+
+	/* Maximumly we can have MAX_SNPRINTF_VARARGS parameters, just give
+	 * all of them to snprintf().
+	 */
+	err = snprintf(str, str_size, fmt, BPF_CAST_FMT_ARG(0, args, mod),
+		BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod),
+		BPF_CAST_FMT_ARG(3, args, mod), BPF_CAST_FMT_ARG(4, args, mod),
+		BPF_CAST_FMT_ARG(5, args, mod), BPF_CAST_FMT_ARG(6, args, mod),
+		BPF_CAST_FMT_ARG(7, args, mod), BPF_CAST_FMT_ARG(8, args, mod),
+		BPF_CAST_FMT_ARG(9, args, mod), BPF_CAST_FMT_ARG(10, args, mod),
+		BPF_CAST_FMT_ARG(11, args, mod));
+
+	bpf_printf_cleanup();
+
+	return err + 1;
+}
+
+const struct bpf_func_proto bpf_snprintf_proto = {
+	.func		= bpf_snprintf,
+	.gpl_only	= true,
+	.ret_type	= RET_INTEGER,
+	.arg1_type	= ARG_PTR_TO_MEM_OR_NULL,
+	.arg2_type	= ARG_CONST_SIZE_OR_ZERO,
+	.arg3_type	= ARG_PTR_TO_CONST_STR,
+	.arg4_type	= ARG_PTR_TO_MEM_OR_NULL,
+	.arg5_type	= ARG_CONST_SIZE_OR_ZERO,
+};
+
 const struct bpf_func_proto bpf_get_current_task_proto __weak;
 const struct bpf_func_proto bpf_probe_read_user_proto __weak;
 const struct bpf_func_proto bpf_probe_read_user_str_proto __weak;
@@ -1013,6 +1061,8 @@ bpf_base_func_proto(enum bpf_func_id func_id)
 		return &bpf_probe_read_kernel_str_proto;
 	case BPF_FUNC_snprintf_btf:
 		return &bpf_snprintf_btf_proto;
+	case BPF_FUNC_snprintf:
+		return &bpf_snprintf_proto;
 	default:
 		return NULL;
 	}
diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index 5f46dd6f3383..994ef36c5f60 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -5918,6 +5918,41 @@ static int check_reference_leak(struct bpf_verifier_env *env)
 	return state->acquired_refs ? -EINVAL : 0;
 }
 
+static int check_bpf_snprintf_call(struct bpf_verifier_env *env,
+				   struct bpf_reg_state *regs)
+{
+	struct bpf_reg_state *fmt_reg = &regs[BPF_REG_3];
+	struct bpf_reg_state *data_len_reg = &regs[BPF_REG_5];
+	struct bpf_map *fmt_map = fmt_reg->map_ptr;
+	int err, fmt_map_off, num_args;
+	u64 fmt_addr;
+	char *fmt;
+
+	/* data must be an array of u64 */
+	if (data_len_reg->var_off.value % 8)
+		return -EINVAL;
+	num_args = data_len_reg->var_off.value / 8;
+
+	/* fmt being ARG_PTR_TO_CONST_STR guarantees that var_off is const
+	 * and map_direct_value_addr is set.
+	 */
+	fmt_map_off = fmt_reg->off + fmt_reg->var_off.value;
+	err = fmt_map->ops->map_direct_value_addr(fmt_map, &fmt_addr,
+						  fmt_map_off);
+	if (err)
+		return err;
+	fmt = (char *)(long)fmt_addr + fmt_map_off;
+
+	/* We are also guaranteed that fmt+fmt_map_off is NULL terminated, we
+	 * can focus on validating the format specifiers.
+	 */
+	err = bpf_printf_prepare(fmt, UINT_MAX, NULL, NULL, NULL, num_args);
+	if (err < 0)
+		verbose(env, "Invalid format string\n");
+
+	return err;
+}
+
 static int check_helper_call(struct bpf_verifier_env *env, struct bpf_insn *insn,
 			     int *insn_idx_p)
 {
@@ -6032,6 +6067,12 @@ static int check_helper_call(struct bpf_verifier_env *env, struct bpf_insn *insn
 			return -EINVAL;
 	}
 
+	if (func_id == BPF_FUNC_snprintf) {
+		err = check_bpf_snprintf_call(env, regs);
+		if (err < 0)
+			return err;
+	}
+
 	/* reset caller saved regs */
 	for (i = 0; i < CALLER_SAVED_REGS; i++) {
 		mark_reg_not_init(env, regs, caller_saved[i]);
diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
index a13f8644b357..2a8bcdc927c7 100644
--- a/kernel/trace/bpf_trace.c
+++ b/kernel/trace/bpf_trace.c
@@ -1076,6 +1076,8 @@ bpf_tracing_func_proto(enum bpf_func_id func_id, const struct bpf_prog *prog)
 		return &bpf_task_storage_delete_proto;
 	case BPF_FUNC_for_each_map_elem:
 		return &bpf_for_each_map_elem_proto;
+	case BPF_FUNC_snprintf:
+		return &bpf_snprintf_proto;
 	default:
 		return NULL;
 	}
diff --git a/tools/include/uapi/linux/bpf.h b/tools/include/uapi/linux/bpf.h
index df164a44bb41..ec6d85a81744 100644
--- a/tools/include/uapi/linux/bpf.h
+++ b/tools/include/uapi/linux/bpf.h
@@ -4708,6 +4708,33 @@ union bpf_attr {
  *	Return
  *		The number of traversed map elements for success, **-EINVAL** for
  *		invalid **flags**.
+ *
+ * long bpf_snprintf(char *str, u32 str_size, const char *fmt, u64 *data, u32 data_len)
+ *	Description
+ *		Outputs a string into the **str** buffer of size **str_size**
+ *		based on a format string stored in a read-only map pointed by
+ *		**fmt**.
+ *
+ *		Each format specifier in **fmt** corresponds to one u64 element
+ *		in the **data** array. For strings and pointers where pointees
+ *		are accessed, only the pointer values are stored in the *data*
+ *		array. The *data_len* is the size of *data* in bytes.
+ *
+ *		Formats **%s** and **%p{i,I}{4,6}** require to read kernel
+ *		memory. Reading kernel memory may fail due to either invalid
+ *		address or valid address but requiring a major memory fault. If
+ *		reading kernel memory fails, the string for **%s** will be an
+ *		empty string, and the ip address for **%p{i,I}{4,6}** will be 0.
+ *		Not returning error to bpf program is consistent with what
+ *		**bpf_trace_printk**\ () does for now.
+ *
+ *	Return
+ *		The strictly positive length of the formatted string, including
+ *		the trailing zero character. If the return value is greater than
+ *		**str_size**, **str** contains a truncated string, guaranteed to
+ *		be zero-terminated except when **str_size** is 0.
+ *
+ *		Or **-EBUSY** if the per-CPU memory copy buffer is busy.
  */
 #define __BPF_FUNC_MAPPER(FN)		\
 	FN(unspec),			\
@@ -4875,6 +4902,7 @@ union bpf_attr {
 	FN(sock_from_file),		\
 	FN(check_mtu),			\
 	FN(for_each_map_elem),		\
+	FN(snprintf),			\
 	/* */
 
 /* integer value in 'imm' field of BPF_CALL instruction selects which helper
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 4/6] libbpf: Initialize the bpf_seq_printf parameters array field by field
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
                   ` (2 preceding siblings ...)
  2021-04-19 15:52 ` [PATCH bpf-next v5 3/6] bpf: Add a bpf_snprintf helper Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 5/6] libbpf: Introduce a BPF_SNPRINTF helper macro Florent Revest
                   ` (2 subsequent siblings)
  6 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

When initializing the __param array with a one liner, if all args are
const, the initial array value will be placed in the rodata section but
because libbpf does not support relocation in the rodata section, any
pointer in this array will stay NULL.

Fixes: c09add2fbc5a ("tools/libbpf: Add bpf_iter support")
Signed-off-by: Florent Revest <revest@chromium.org>
Acked-by: Andrii Nakryiko <andrii@kernel.org>
---
 tools/lib/bpf/bpf_tracing.h | 40 +++++++++++++++++++++++++++----------
 1 file changed, 29 insertions(+), 11 deletions(-)

diff --git a/tools/lib/bpf/bpf_tracing.h b/tools/lib/bpf/bpf_tracing.h
index f9ef37707888..1c2e91ee041d 100644
--- a/tools/lib/bpf/bpf_tracing.h
+++ b/tools/lib/bpf/bpf_tracing.h
@@ -413,20 +413,38 @@ typeof(name(0)) name(struct pt_regs *ctx)				    \
 }									    \
 static __always_inline typeof(name(0)) ____##name(struct pt_regs *ctx, ##args)
 
+#define ___bpf_fill0(arr, p, x) do {} while (0)
+#define ___bpf_fill1(arr, p, x) arr[p] = x
+#define ___bpf_fill2(arr, p, x, args...) arr[p] = x; ___bpf_fill1(arr, p + 1, args)
+#define ___bpf_fill3(arr, p, x, args...) arr[p] = x; ___bpf_fill2(arr, p + 1, args)
+#define ___bpf_fill4(arr, p, x, args...) arr[p] = x; ___bpf_fill3(arr, p + 1, args)
+#define ___bpf_fill5(arr, p, x, args...) arr[p] = x; ___bpf_fill4(arr, p + 1, args)
+#define ___bpf_fill6(arr, p, x, args...) arr[p] = x; ___bpf_fill5(arr, p + 1, args)
+#define ___bpf_fill7(arr, p, x, args...) arr[p] = x; ___bpf_fill6(arr, p + 1, args)
+#define ___bpf_fill8(arr, p, x, args...) arr[p] = x; ___bpf_fill7(arr, p + 1, args)
+#define ___bpf_fill9(arr, p, x, args...) arr[p] = x; ___bpf_fill8(arr, p + 1, args)
+#define ___bpf_fill10(arr, p, x, args...) arr[p] = x; ___bpf_fill9(arr, p + 1, args)
+#define ___bpf_fill11(arr, p, x, args...) arr[p] = x; ___bpf_fill10(arr, p + 1, args)
+#define ___bpf_fill12(arr, p, x, args...) arr[p] = x; ___bpf_fill11(arr, p + 1, args)
+#define ___bpf_fill(arr, args...) \
+	___bpf_apply(___bpf_fill, ___bpf_narg(args))(arr, 0, args)
+
 /*
  * BPF_SEQ_PRINTF to wrap bpf_seq_printf to-be-printed values
  * in a structure.
  */
-#define BPF_SEQ_PRINTF(seq, fmt, args...)				    \
-	({								    \
-		_Pragma("GCC diagnostic push")				    \
-		_Pragma("GCC diagnostic ignored \"-Wint-conversion\"")	    \
-		static const char ___fmt[] = fmt;			    \
-		unsigned long long ___param[] = { args };		    \
-		_Pragma("GCC diagnostic pop")				    \
-		int ___ret = bpf_seq_printf(seq, ___fmt, sizeof(___fmt),    \
-					    ___param, sizeof(___param));    \
-		___ret;							    \
-	})
+#define BPF_SEQ_PRINTF(seq, fmt, args...)			\
+({								\
+	static const char ___fmt[] = fmt;			\
+	unsigned long long ___param[___bpf_narg(args)];		\
+								\
+	_Pragma("GCC diagnostic push")				\
+	_Pragma("GCC diagnostic ignored \"-Wint-conversion\"")	\
+	___bpf_fill(___param, args);				\
+	_Pragma("GCC diagnostic pop")				\
+								\
+	bpf_seq_printf(seq, ___fmt, sizeof(___fmt),		\
+		       ___param, sizeof(___param));		\
+})
 
 #endif
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 5/6] libbpf: Introduce a BPF_SNPRINTF helper macro
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
                   ` (3 preceding siblings ...)
  2021-04-19 15:52 ` [PATCH bpf-next v5 4/6] libbpf: Initialize the bpf_seq_printf parameters array field by field Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-19 15:52 ` [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf Florent Revest
  2021-04-19 19:33 ` [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Andrii Nakryiko
  6 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

Similarly to BPF_SEQ_PRINTF, this macro turns variadic arguments into an
array of u64, making it more natural to call the bpf_snprintf helper.

Signed-off-by: Florent Revest <revest@chromium.org>
Acked-by: Andrii Nakryiko <andrii@kernel.org>
---
 tools/lib/bpf/bpf_tracing.h | 18 ++++++++++++++++++
 1 file changed, 18 insertions(+)

diff --git a/tools/lib/bpf/bpf_tracing.h b/tools/lib/bpf/bpf_tracing.h
index 1c2e91ee041d..8c954ebc0c7c 100644
--- a/tools/lib/bpf/bpf_tracing.h
+++ b/tools/lib/bpf/bpf_tracing.h
@@ -447,4 +447,22 @@ static __always_inline typeof(name(0)) ____##name(struct pt_regs *ctx, ##args)
 		       ___param, sizeof(___param));		\
 })
 
+/*
+ * BPF_SNPRINTF wraps the bpf_snprintf helper with variadic arguments instead of
+ * an array of u64.
+ */
+#define BPF_SNPRINTF(out, out_size, fmt, args...)		\
+({								\
+	static const char ___fmt[] = fmt;			\
+	unsigned long long ___param[___bpf_narg(args)];		\
+								\
+	_Pragma("GCC diagnostic push")				\
+	_Pragma("GCC diagnostic ignored \"-Wint-conversion\"")	\
+	___bpf_fill(___param, args);				\
+	_Pragma("GCC diagnostic pop")				\
+								\
+	bpf_snprintf(out, out_size, ___fmt,			\
+		     ___param, sizeof(___param));		\
+})
+
 #endif
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
                   ` (4 preceding siblings ...)
  2021-04-19 15:52 ` [PATCH bpf-next v5 5/6] libbpf: Introduce a BPF_SNPRINTF helper macro Florent Revest
@ 2021-04-19 15:52 ` Florent Revest
  2021-04-23 22:38   ` Andrii Nakryiko
  2021-04-19 19:33 ` [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Andrii Nakryiko
  6 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-19 15:52 UTC (permalink / raw)
  To: bpf
  Cc: ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel,
	Florent Revest

The "positive" part tests all format specifiers when things go well.

The "negative" part makes sure that incorrect format strings fail at
load time.

Signed-off-by: Florent Revest <revest@chromium.org>
---
 .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
 .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
 .../bpf/progs/test_snprintf_single.c          |  20 +++
 3 files changed, 218 insertions(+)
 create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
 create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
 create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c

diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
new file mode 100644
index 000000000000..a958c22aec75
--- /dev/null
+++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
@@ -0,0 +1,125 @@
+// SPDX-License-Identifier: GPL-2.0
+/* Copyright (c) 2021 Google LLC. */
+
+#include <test_progs.h>
+#include "test_snprintf.skel.h"
+#include "test_snprintf_single.skel.h"
+
+#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
+#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
+
+#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
+#define EXP_IP_RET   sizeof(EXP_IP_OUT)
+
+/* The third specifier, %pB, depends on compiler inlining so don't check it */
+#define EXP_SYM_OUT  "schedule schedule+0x0/"
+#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
+
+/* The third specifier, %p, is a hashed pointer which changes on every reboot */
+#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
+#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
+
+#define EXP_STR_OUT  "str1 longstr"
+#define EXP_STR_RET  sizeof(EXP_STR_OUT)
+
+#define EXP_OVER_OUT "%over"
+#define EXP_OVER_RET 10
+
+#define EXP_PAD_OUT "    4 000"
+#define EXP_PAD_RET 900007
+
+#define EXP_NO_ARG_OUT "simple case"
+#define EXP_NO_ARG_RET 12
+
+#define EXP_NO_BUF_RET 29
+
+void test_snprintf_positive(void)
+{
+	char exp_addr_out[] = EXP_ADDR_OUT;
+	char exp_sym_out[]  = EXP_SYM_OUT;
+	struct test_snprintf *skel;
+
+	skel = test_snprintf__open_and_load();
+	if (!ASSERT_OK_PTR(skel, "skel_open"))
+		return;
+
+	if (!ASSERT_OK(test_snprintf__attach(skel), "skel_attach"))
+		goto cleanup;
+
+	/* trigger tracepoint */
+	usleep(1);
+
+	ASSERT_STREQ(skel->bss->num_out, EXP_NUM_OUT, "num_out");
+	ASSERT_EQ(skel->bss->num_ret, EXP_NUM_RET, "num_ret");
+
+	ASSERT_STREQ(skel->bss->ip_out, EXP_IP_OUT, "ip_out");
+	ASSERT_EQ(skel->bss->ip_ret, EXP_IP_RET, "ip_ret");
+
+	ASSERT_OK(memcmp(skel->bss->sym_out, exp_sym_out,
+			 sizeof(exp_sym_out) - 1), "sym_out");
+	ASSERT_LT(MIN_SYM_RET, skel->bss->sym_ret, "sym_ret");
+
+	ASSERT_OK(memcmp(skel->bss->addr_out, exp_addr_out,
+			 sizeof(exp_addr_out) - 1), "addr_out");
+	ASSERT_EQ(skel->bss->addr_ret, EXP_ADDR_RET, "addr_ret");
+
+	ASSERT_STREQ(skel->bss->str_out, EXP_STR_OUT, "str_out");
+	ASSERT_EQ(skel->bss->str_ret, EXP_STR_RET, "str_ret");
+
+	ASSERT_STREQ(skel->bss->over_out, EXP_OVER_OUT, "over_out");
+	ASSERT_EQ(skel->bss->over_ret, EXP_OVER_RET, "over_ret");
+
+	ASSERT_STREQ(skel->bss->pad_out, EXP_PAD_OUT, "pad_out");
+	ASSERT_EQ(skel->bss->pad_ret, EXP_PAD_RET, "pad_ret");
+
+	ASSERT_STREQ(skel->bss->noarg_out, EXP_NO_ARG_OUT, "no_arg_out");
+	ASSERT_EQ(skel->bss->noarg_ret, EXP_NO_ARG_RET, "no_arg_ret");
+
+	ASSERT_EQ(skel->bss->nobuf_ret, EXP_NO_BUF_RET, "no_buf_ret");
+
+cleanup:
+	test_snprintf__destroy(skel);
+}
+
+#define min(a, b) ((a) < (b) ? (a) : (b))
+
+/* Loads an eBPF object calling bpf_snprintf with up to 10 characters of fmt */
+static int load_single_snprintf(char *fmt)
+{
+	struct test_snprintf_single *skel;
+	int ret;
+
+	skel = test_snprintf_single__open();
+	if (!skel)
+		return -EINVAL;
+
+	memcpy(skel->rodata->fmt, fmt, min(strlen(fmt) + 1, 10));
+
+	ret = test_snprintf_single__load(skel);
+	test_snprintf_single__destroy(skel);
+
+	return ret;
+}
+
+void test_snprintf_negative(void)
+{
+	ASSERT_OK(load_single_snprintf("valid %d"), "valid usage");
+
+	ASSERT_ERR(load_single_snprintf("0123456789"), "no terminating zero");
+	ASSERT_ERR(load_single_snprintf("%d %d"), "too many specifiers");
+	ASSERT_ERR(load_single_snprintf("%pi5"), "invalid specifier 1");
+	ASSERT_ERR(load_single_snprintf("%a"), "invalid specifier 2");
+	ASSERT_ERR(load_single_snprintf("%"), "invalid specifier 3");
+	ASSERT_ERR(load_single_snprintf("%12345678"), "invalid specifier 4");
+	ASSERT_ERR(load_single_snprintf("%--------"), "invalid specifier 5");
+	ASSERT_ERR(load_single_snprintf("\x80"), "non ascii character");
+	ASSERT_ERR(load_single_snprintf("\x1"), "non printable character");
+}
+
+void test_snprintf(void)
+{
+	if (test__start_subtest("snprintf_positive"))
+		test_snprintf_positive();
+	if (test__start_subtest("snprintf_negative"))
+		test_snprintf_negative();
+}
diff --git a/tools/testing/selftests/bpf/progs/test_snprintf.c b/tools/testing/selftests/bpf/progs/test_snprintf.c
new file mode 100644
index 000000000000..951a0301c553
--- /dev/null
+++ b/tools/testing/selftests/bpf/progs/test_snprintf.c
@@ -0,0 +1,73 @@
+// SPDX-License-Identifier: GPL-2.0
+/* Copyright (c) 2021 Google LLC. */
+
+#include <linux/bpf.h>
+#include <bpf/bpf_helpers.h>
+#include <bpf/bpf_tracing.h>
+
+char num_out[64] = {};
+long num_ret = 0;
+
+char ip_out[64] = {};
+long ip_ret = 0;
+
+char sym_out[64] = {};
+long sym_ret = 0;
+
+char addr_out[64] = {};
+long addr_ret = 0;
+
+char str_out[64] = {};
+long str_ret = 0;
+
+char over_out[6] = {};
+long over_ret = 0;
+
+char pad_out[10] = {};
+long pad_ret = 0;
+
+char noarg_out[64] = {};
+long noarg_ret = 0;
+
+long nobuf_ret = 0;
+
+extern const void schedule __ksym;
+
+SEC("raw_tp/sys_enter")
+int handler(const void *ctx)
+{
+	/* Convenient values to pretty-print */
+	const __u8 ex_ipv4[] = {127, 0, 0, 1};
+	const __u8 ex_ipv6[] = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1};
+	static const char str1[] = "str1";
+	static const char longstr[] = "longstr";
+
+	/* Integer types */
+	num_ret  = BPF_SNPRINTF(num_out, sizeof(num_out),
+				"%d %u %x %li %llu %lX",
+				-8, 9, 150, -424242, 1337, 0xDABBAD00);
+	/* IP addresses */
+	ip_ret   = BPF_SNPRINTF(ip_out, sizeof(ip_out), "%pi4 %pI6",
+				&ex_ipv4, &ex_ipv6);
+	/* Symbol lookup formatting */
+	sym_ret  = BPF_SNPRINTF(sym_out,  sizeof(sym_out), "%ps %pS %pB",
+				&schedule, &schedule, &schedule);
+	/* Kernel pointers */
+	addr_ret = BPF_SNPRINTF(addr_out, sizeof(addr_out), "%pK %px %p",
+				0, 0xFFFF00000ADD4E55, 0xFFFF00000ADD4E55);
+	/* Strings embedding */
+	str_ret  = BPF_SNPRINTF(str_out, sizeof(str_out), "%s %+05s",
+				str1, longstr);
+	/* Overflow */
+	over_ret = BPF_SNPRINTF(over_out, sizeof(over_out), "%%overflow");
+	/* Padding of fixed width numbers */
+	pad_ret = BPF_SNPRINTF(pad_out, sizeof(pad_out), "%5d %0900000X", 4, 4);
+	/* No args */
+	noarg_ret = BPF_SNPRINTF(noarg_out, sizeof(noarg_out), "simple case");
+	/* No buffer */
+	nobuf_ret = BPF_SNPRINTF(NULL, 0, "only interested in length %d", 60);
+
+	return 0;
+}
+
+char _license[] SEC("license") = "GPL";
diff --git a/tools/testing/selftests/bpf/progs/test_snprintf_single.c b/tools/testing/selftests/bpf/progs/test_snprintf_single.c
new file mode 100644
index 000000000000..402adaf344f9
--- /dev/null
+++ b/tools/testing/selftests/bpf/progs/test_snprintf_single.c
@@ -0,0 +1,20 @@
+// SPDX-License-Identifier: GPL-2.0
+/* Copyright (c) 2021 Google LLC. */
+
+#include <linux/bpf.h>
+#include <bpf/bpf_helpers.h>
+
+/* The format string is filled from the userspace such that loading fails */
+static const char fmt[10];
+
+SEC("raw_tp/sys_enter")
+int handler(const void *ctx)
+{
+	unsigned long long arg = 42;
+
+	bpf_snprintf(NULL, 0, fmt, &arg, sizeof(arg));
+
+	return 0;
+}
+
+char _license[] SEC("license") = "GPL";
-- 
2.31.1.368.gbe11c130af-goog


^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper
  2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
                   ` (5 preceding siblings ...)
  2021-04-19 15:52 ` [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf Florent Revest
@ 2021-04-19 19:33 ` Andrii Nakryiko
  2021-04-20 12:02   ` Florent Revest
  6 siblings, 1 reply; 23+ messages in thread
From: Andrii Nakryiko @ 2021-04-19 19:33 UTC (permalink / raw)
  To: Florent Revest
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
>
> We have a usecase where we want to audit symbol names (if available) in
> callback registration hooks. (ex: fentry/nf_register_net_hook)
>
> A few months back, I proposed a bpf_kallsyms_lookup series but it was
> decided in the reviews that a more generic helper, bpf_snprintf, would
> be more useful.
>
> This series implements the helper according to the feedback received in
> https://lore.kernel.org/bpf/20201126165748.1748417-1-revest@google.com/T/#u
>
> - A new arg type guarantees the NULL-termination of string arguments and
>   lets us pass format strings in only one arg
> - A new helper is implemented using that guarantee. Because the format
>   string is known at verification time, the format string validation is
>   done by the verifier
> - To implement a series of tests for bpf_snprintf, the logic for
>   marshalling variadic args in a fixed-size array is reworked as per:
> https://lore.kernel.org/bpf/20210310015455.1095207-1-revest@chromium.org/T/#u
>
> ---
> Changes in v5:
> - Fixed the bpf_printf_buf_used counter logic in try_get_fmt_tmp_buf
> - Added a couple of extra incorrect specifiers tests
> - Call test_snprintf_single__destroy unconditionally
> - Fixed a C++-style comment
>
> ---
> Changes in v4:
> - Moved bpf_snprintf, bpf_printf_prepare and bpf_printf_cleanup to
>   kernel/bpf/helpers.c so that they get built without CONFIG_BPF_EVENTS
> - Added negative test cases (various invalid format strings)
> - Renamed put_fmt_tmp_buf() as bpf_printf_cleanup()
> - Fixed a mistake that caused temporary buffers to be unconditionally
>   freed in bpf_printf_prepare
> - Fixed a mistake that caused missing 0 character to be ignored
> - Fixed a warning about integer to pointer conversion
> - Misc cleanups
>
> ---
> Changes in v3:
> - Simplified temporary buffer acquisition with try_get_fmt_tmp_buf()
> - Made zero-termination check more consistent
> - Allowed NULL output_buffer
> - Simplified the BPF_CAST_FMT_ARG macro
> - Three new test cases: number padding, simple string with no arg and
>   string length extraction only with a NULL output buffer
> - Clarified helper's description for edge cases (eg: str_size == 0)
> - Lots of cosmetic changes
>
> ---
> Changes in v2:
> - Extracted the format validation/argument sanitization in a generic way
>   for all printf-like helpers.
> - bpf_snprintf's str_size can now be 0
> - bpf_snprintf is now exposed to all BPF program types
> - We now preempt_disable when using a per-cpu temporary buffer
> - Addressed a few cosmetic changes
>
> Florent Revest (6):
>   bpf: Factorize bpf_trace_printk and bpf_seq_printf
>   bpf: Add a ARG_PTR_TO_CONST_STR argument type
>   bpf: Add a bpf_snprintf helper
>   libbpf: Initialize the bpf_seq_printf parameters array field by field
>   libbpf: Introduce a BPF_SNPRINTF helper macro
>   selftests/bpf: Add a series of tests for bpf_snprintf
>
>  include/linux/bpf.h                           |  22 ++
>  include/uapi/linux/bpf.h                      |  28 ++
>  kernel/bpf/helpers.c                          | 306 ++++++++++++++
>  kernel/bpf/verifier.c                         |  82 ++++
>  kernel/trace/bpf_trace.c                      | 373 ++----------------
>  tools/include/uapi/linux/bpf.h                |  28 ++
>  tools/lib/bpf/bpf_tracing.h                   |  58 ++-
>  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++
>  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++
>  .../bpf/progs/test_snprintf_single.c          |  20 +
>  10 files changed, 770 insertions(+), 345 deletions(-)
>  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
>
> --
> 2.31.1.368.gbe11c130af-goog
>

Looks great, thank you!

For the series:

Acked-by: Andrii Nakryiko <andrii@kernel.org>

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type
  2021-04-19 15:52 ` [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type Florent Revest
@ 2021-04-19 22:54   ` Alexei Starovoitov
  2021-04-20 12:35     ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Alexei Starovoitov @ 2021-04-19 22:54 UTC (permalink / raw)
  To: Florent Revest
  Cc: bpf, ast, daniel, andrii, yhs, kpsingh, jackmanb, linux-kernel

On Mon, Apr 19, 2021 at 05:52:39PM +0200, Florent Revest wrote:
> This type provides the guarantee that an argument is going to be a const
> pointer to somewhere in a read-only map value. It also checks that this
> pointer is followed by a zero character before the end of the map value.
> 
> Signed-off-by: Florent Revest <revest@chromium.org>
> Acked-by: Andrii Nakryiko <andrii@kernel.org>
> ---
>  include/linux/bpf.h   |  1 +
>  kernel/bpf/verifier.c | 41 +++++++++++++++++++++++++++++++++++++++++
>  2 files changed, 42 insertions(+)
> 
> diff --git a/include/linux/bpf.h b/include/linux/bpf.h
> index 77d1d8c65b81..c160526fc8bf 100644
> --- a/include/linux/bpf.h
> +++ b/include/linux/bpf.h
> @@ -309,6 +309,7 @@ enum bpf_arg_type {
>  	ARG_PTR_TO_PERCPU_BTF_ID,	/* pointer to in-kernel percpu type */
>  	ARG_PTR_TO_FUNC,	/* pointer to a bpf program function */
>  	ARG_PTR_TO_STACK_OR_NULL,	/* pointer to stack or NULL */
> +	ARG_PTR_TO_CONST_STR,	/* pointer to a null terminated read-only string */
>  	__BPF_ARG_TYPE_MAX,
>  };
>  
> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> index 852541a435ef..5f46dd6f3383 100644
> --- a/kernel/bpf/verifier.c
> +++ b/kernel/bpf/verifier.c
> @@ -4787,6 +4787,7 @@ static const struct bpf_reg_types spin_lock_types = { .types = { PTR_TO_MAP_VALU
>  static const struct bpf_reg_types percpu_btf_ptr_types = { .types = { PTR_TO_PERCPU_BTF_ID } };
>  static const struct bpf_reg_types func_ptr_types = { .types = { PTR_TO_FUNC } };
>  static const struct bpf_reg_types stack_ptr_types = { .types = { PTR_TO_STACK } };
> +static const struct bpf_reg_types const_str_ptr_types = { .types = { PTR_TO_MAP_VALUE } };
>  
>  static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
>  	[ARG_PTR_TO_MAP_KEY]		= &map_key_value_types,
> @@ -4817,6 +4818,7 @@ static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
>  	[ARG_PTR_TO_PERCPU_BTF_ID]	= &percpu_btf_ptr_types,
>  	[ARG_PTR_TO_FUNC]		= &func_ptr_types,
>  	[ARG_PTR_TO_STACK_OR_NULL]	= &stack_ptr_types,
> +	[ARG_PTR_TO_CONST_STR]		= &const_str_ptr_types,
>  };
>  
>  static int check_reg_type(struct bpf_verifier_env *env, u32 regno,
> @@ -5067,6 +5069,45 @@ static int check_func_arg(struct bpf_verifier_env *env, u32 arg,
>  		if (err)
>  			return err;
>  		err = check_ptr_alignment(env, reg, 0, size, true);
> +	} else if (arg_type == ARG_PTR_TO_CONST_STR) {
> +		struct bpf_map *map = reg->map_ptr;
> +		int map_off;
> +		u64 map_addr;
> +		char *str_ptr;
> +
> +		if (reg->type != PTR_TO_MAP_VALUE || !map ||

I think the 'type' check is redundant,
since check_reg_type() did it via compatible_reg_types.
If so it's probably better to remove it here ?

'!map' looks unnecessary. Can it ever happen? If yes, it's a verifier bug.
For example in check_mem_access() we just deref reg->map_ptr without checking
which, I think, is correct.

> +		    !bpf_map_is_rdonly(map)) {

This check is needed, of course.

> +			verbose(env, "R%d does not point to a readonly map'\n", regno);
> +			return -EACCES;
> +		}
> +
> +		if (!tnum_is_const(reg->var_off)) {
> +			verbose(env, "R%d is not a constant address'\n", regno);
> +			return -EACCES;
> +		}
> +
> +		if (!map->ops->map_direct_value_addr) {
> +			verbose(env, "no direct value access support for this map type\n");
> +			return -EACCES;
> +		}
> +
> +		err = check_map_access(env, regno, reg->off,
> +				       map->value_size - reg->off, false);
> +		if (err)
> +			return err;
> +
> +		map_off = reg->off + reg->var_off.value;
> +		err = map->ops->map_direct_value_addr(map, &map_addr, map_off);
> +		if (err) {

since the code checks it here the same check in check_bpf_snprintf_call() should
probably do:
 if (err) {
   verbose("verifier bug\n");
   return -EFAULT;
 }

instead of just "return err;"
?

> +			verbose(env, "direct value access on string failed\n");

I think the message doesn't tell users much, but they probably should never
see it unless they try to do lookup from readonly array with
more than one element.
So I guess it's fine to keep this one as-is. Just flagging.

Anyway the whole set looks great, so I've applied to bpf-next.
Thanks!

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper
  2021-04-19 19:33 ` [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Andrii Nakryiko
@ 2021-04-20 12:02   ` Florent Revest
  0 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-20 12:02 UTC (permalink / raw)
  To: Andrii Nakryiko
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Mon, Apr 19, 2021 at 9:34 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> >
> > We have a usecase where we want to audit symbol names (if available) in
> > callback registration hooks. (ex: fentry/nf_register_net_hook)
> >
> > A few months back, I proposed a bpf_kallsyms_lookup series but it was
> > decided in the reviews that a more generic helper, bpf_snprintf, would
> > be more useful.
> >
> > This series implements the helper according to the feedback received in
> > https://lore.kernel.org/bpf/20201126165748.1748417-1-revest@google.com/T/#u
> >
> > - A new arg type guarantees the NULL-termination of string arguments and
> >   lets us pass format strings in only one arg
> > - A new helper is implemented using that guarantee. Because the format
> >   string is known at verification time, the format string validation is
> >   done by the verifier
> > - To implement a series of tests for bpf_snprintf, the logic for
> >   marshalling variadic args in a fixed-size array is reworked as per:
> > https://lore.kernel.org/bpf/20210310015455.1095207-1-revest@chromium.org/T/#u
> >
> > ---
> > Changes in v5:
> > - Fixed the bpf_printf_buf_used counter logic in try_get_fmt_tmp_buf
> > - Added a couple of extra incorrect specifiers tests
> > - Call test_snprintf_single__destroy unconditionally
> > - Fixed a C++-style comment
> >
> > ---
> > Changes in v4:
> > - Moved bpf_snprintf, bpf_printf_prepare and bpf_printf_cleanup to
> >   kernel/bpf/helpers.c so that they get built without CONFIG_BPF_EVENTS
> > - Added negative test cases (various invalid format strings)
> > - Renamed put_fmt_tmp_buf() as bpf_printf_cleanup()
> > - Fixed a mistake that caused temporary buffers to be unconditionally
> >   freed in bpf_printf_prepare
> > - Fixed a mistake that caused missing 0 character to be ignored
> > - Fixed a warning about integer to pointer conversion
> > - Misc cleanups
> >
> > ---
> > Changes in v3:
> > - Simplified temporary buffer acquisition with try_get_fmt_tmp_buf()
> > - Made zero-termination check more consistent
> > - Allowed NULL output_buffer
> > - Simplified the BPF_CAST_FMT_ARG macro
> > - Three new test cases: number padding, simple string with no arg and
> >   string length extraction only with a NULL output buffer
> > - Clarified helper's description for edge cases (eg: str_size == 0)
> > - Lots of cosmetic changes
> >
> > ---
> > Changes in v2:
> > - Extracted the format validation/argument sanitization in a generic way
> >   for all printf-like helpers.
> > - bpf_snprintf's str_size can now be 0
> > - bpf_snprintf is now exposed to all BPF program types
> > - We now preempt_disable when using a per-cpu temporary buffer
> > - Addressed a few cosmetic changes
> >
> > Florent Revest (6):
> >   bpf: Factorize bpf_trace_printk and bpf_seq_printf
> >   bpf: Add a ARG_PTR_TO_CONST_STR argument type
> >   bpf: Add a bpf_snprintf helper
> >   libbpf: Initialize the bpf_seq_printf parameters array field by field
> >   libbpf: Introduce a BPF_SNPRINTF helper macro
> >   selftests/bpf: Add a series of tests for bpf_snprintf
> >
> >  include/linux/bpf.h                           |  22 ++
> >  include/uapi/linux/bpf.h                      |  28 ++
> >  kernel/bpf/helpers.c                          | 306 ++++++++++++++
> >  kernel/bpf/verifier.c                         |  82 ++++
> >  kernel/trace/bpf_trace.c                      | 373 ++----------------
> >  tools/include/uapi/linux/bpf.h                |  28 ++
> >  tools/lib/bpf/bpf_tracing.h                   |  58 ++-
> >  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++
> >  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++
> >  .../bpf/progs/test_snprintf_single.c          |  20 +
> >  10 files changed, 770 insertions(+), 345 deletions(-)
> >  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> >
> > --
> > 2.31.1.368.gbe11c130af-goog
> >
>
> Looks great, thank you!
>
> For the series:
>
> Acked-by: Andrii Nakryiko <andrii@kernel.org>

Thank you for the all the fast and in-depth reviews Andrii! :)

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type
  2021-04-19 22:54   ` Alexei Starovoitov
@ 2021-04-20 12:35     ` Florent Revest
  2021-04-20 15:23       ` Alexei Starovoitov
  0 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-20 12:35 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Tue, Apr 20, 2021 at 12:54 AM Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Mon, Apr 19, 2021 at 05:52:39PM +0200, Florent Revest wrote:
> > This type provides the guarantee that an argument is going to be a const
> > pointer to somewhere in a read-only map value. It also checks that this
> > pointer is followed by a zero character before the end of the map value.
> >
> > Signed-off-by: Florent Revest <revest@chromium.org>
> > Acked-by: Andrii Nakryiko <andrii@kernel.org>
> > ---
> >  include/linux/bpf.h   |  1 +
> >  kernel/bpf/verifier.c | 41 +++++++++++++++++++++++++++++++++++++++++
> >  2 files changed, 42 insertions(+)
> >
> > diff --git a/include/linux/bpf.h b/include/linux/bpf.h
> > index 77d1d8c65b81..c160526fc8bf 100644
> > --- a/include/linux/bpf.h
> > +++ b/include/linux/bpf.h
> > @@ -309,6 +309,7 @@ enum bpf_arg_type {
> >       ARG_PTR_TO_PERCPU_BTF_ID,       /* pointer to in-kernel percpu type */
> >       ARG_PTR_TO_FUNC,        /* pointer to a bpf program function */
> >       ARG_PTR_TO_STACK_OR_NULL,       /* pointer to stack or NULL */
> > +     ARG_PTR_TO_CONST_STR,   /* pointer to a null terminated read-only string */
> >       __BPF_ARG_TYPE_MAX,
> >  };
> >
> > diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> > index 852541a435ef..5f46dd6f3383 100644
> > --- a/kernel/bpf/verifier.c
> > +++ b/kernel/bpf/verifier.c
> > @@ -4787,6 +4787,7 @@ static const struct bpf_reg_types spin_lock_types = { .types = { PTR_TO_MAP_VALU
> >  static const struct bpf_reg_types percpu_btf_ptr_types = { .types = { PTR_TO_PERCPU_BTF_ID } };
> >  static const struct bpf_reg_types func_ptr_types = { .types = { PTR_TO_FUNC } };
> >  static const struct bpf_reg_types stack_ptr_types = { .types = { PTR_TO_STACK } };
> > +static const struct bpf_reg_types const_str_ptr_types = { .types = { PTR_TO_MAP_VALUE } };
> >
> >  static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> >       [ARG_PTR_TO_MAP_KEY]            = &map_key_value_types,
> > @@ -4817,6 +4818,7 @@ static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> >       [ARG_PTR_TO_PERCPU_BTF_ID]      = &percpu_btf_ptr_types,
> >       [ARG_PTR_TO_FUNC]               = &func_ptr_types,
> >       [ARG_PTR_TO_STACK_OR_NULL]      = &stack_ptr_types,
> > +     [ARG_PTR_TO_CONST_STR]          = &const_str_ptr_types,
> >  };
> >
> >  static int check_reg_type(struct bpf_verifier_env *env, u32 regno,
> > @@ -5067,6 +5069,45 @@ static int check_func_arg(struct bpf_verifier_env *env, u32 arg,
> >               if (err)
> >                       return err;
> >               err = check_ptr_alignment(env, reg, 0, size, true);
> > +     } else if (arg_type == ARG_PTR_TO_CONST_STR) {
> > +             struct bpf_map *map = reg->map_ptr;
> > +             int map_off;
> > +             u64 map_addr;
> > +             char *str_ptr;
> > +
> > +             if (reg->type != PTR_TO_MAP_VALUE || !map ||
>
> I think the 'type' check is redundant,
> since check_reg_type() did it via compatible_reg_types.
> If so it's probably better to remove it here ?
>
> '!map' looks unnecessary. Can it ever happen? If yes, it's a verifier bug.
> For example in check_mem_access() we just deref reg->map_ptr without checking
> which, I think, is correct.

I agree with all of the above. I only thought it's better to be safe
than sorry but if you'd like I could follow up with a patch that
removes some checks?

> > +                 !bpf_map_is_rdonly(map)) {
>
> This check is needed, of course.
>
> > +                     verbose(env, "R%d does not point to a readonly map'\n", regno);
> > +                     return -EACCES;
> > +             }
> > +
> > +             if (!tnum_is_const(reg->var_off)) {
> > +                     verbose(env, "R%d is not a constant address'\n", regno);
> > +                     return -EACCES;
> > +             }
> > +
> > +             if (!map->ops->map_direct_value_addr) {
> > +                     verbose(env, "no direct value access support for this map type\n");
> > +                     return -EACCES;
> > +             }
> > +
> > +             err = check_map_access(env, regno, reg->off,
> > +                                    map->value_size - reg->off, false);
> > +             if (err)
> > +                     return err;
> > +
> > +             map_off = reg->off + reg->var_off.value;
> > +             err = map->ops->map_direct_value_addr(map, &map_addr, map_off);
> > +             if (err) {
>
> since the code checks it here the same check in check_bpf_snprintf_call() should
> probably do:
>  if (err) {
>    verbose("verifier bug\n");
>    return -EFAULT;
>  }
>
> instead of just "return err;"
> ?

Sure, does not hurt. I can also follow up with a patch unless if you
prefer doing it yourself.

> > +                     verbose(env, "direct value access on string failed\n");
>
> I think the message doesn't tell users much, but they probably should never
> see it unless they try to do lookup from readonly array with
> more than one element.
> So I guess it's fine to keep this one as-is. Just flagging.

Ack

> Anyway the whole set looks great, so I've applied to bpf-next.
> Thanks!

Thank you :D

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type
  2021-04-20 12:35     ` Florent Revest
@ 2021-04-20 15:23       ` Alexei Starovoitov
  2021-04-22  8:41         ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Alexei Starovoitov @ 2021-04-20 15:23 UTC (permalink / raw)
  To: Florent Revest
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Tue, Apr 20, 2021 at 5:35 AM Florent Revest <revest@chromium.org> wrote:
>
> On Tue, Apr 20, 2021 at 12:54 AM Alexei Starovoitov
> <alexei.starovoitov@gmail.com> wrote:
> >
> > On Mon, Apr 19, 2021 at 05:52:39PM +0200, Florent Revest wrote:
> > > This type provides the guarantee that an argument is going to be a const
> > > pointer to somewhere in a read-only map value. It also checks that this
> > > pointer is followed by a zero character before the end of the map value.
> > >
> > > Signed-off-by: Florent Revest <revest@chromium.org>
> > > Acked-by: Andrii Nakryiko <andrii@kernel.org>
> > > ---
> > >  include/linux/bpf.h   |  1 +
> > >  kernel/bpf/verifier.c | 41 +++++++++++++++++++++++++++++++++++++++++
> > >  2 files changed, 42 insertions(+)
> > >
> > > diff --git a/include/linux/bpf.h b/include/linux/bpf.h
> > > index 77d1d8c65b81..c160526fc8bf 100644
> > > --- a/include/linux/bpf.h
> > > +++ b/include/linux/bpf.h
> > > @@ -309,6 +309,7 @@ enum bpf_arg_type {
> > >       ARG_PTR_TO_PERCPU_BTF_ID,       /* pointer to in-kernel percpu type */
> > >       ARG_PTR_TO_FUNC,        /* pointer to a bpf program function */
> > >       ARG_PTR_TO_STACK_OR_NULL,       /* pointer to stack or NULL */
> > > +     ARG_PTR_TO_CONST_STR,   /* pointer to a null terminated read-only string */
> > >       __BPF_ARG_TYPE_MAX,
> > >  };
> > >
> > > diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> > > index 852541a435ef..5f46dd6f3383 100644
> > > --- a/kernel/bpf/verifier.c
> > > +++ b/kernel/bpf/verifier.c
> > > @@ -4787,6 +4787,7 @@ static const struct bpf_reg_types spin_lock_types = { .types = { PTR_TO_MAP_VALU
> > >  static const struct bpf_reg_types percpu_btf_ptr_types = { .types = { PTR_TO_PERCPU_BTF_ID } };
> > >  static const struct bpf_reg_types func_ptr_types = { .types = { PTR_TO_FUNC } };
> > >  static const struct bpf_reg_types stack_ptr_types = { .types = { PTR_TO_STACK } };
> > > +static const struct bpf_reg_types const_str_ptr_types = { .types = { PTR_TO_MAP_VALUE } };
> > >
> > >  static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> > >       [ARG_PTR_TO_MAP_KEY]            = &map_key_value_types,
> > > @@ -4817,6 +4818,7 @@ static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> > >       [ARG_PTR_TO_PERCPU_BTF_ID]      = &percpu_btf_ptr_types,
> > >       [ARG_PTR_TO_FUNC]               = &func_ptr_types,
> > >       [ARG_PTR_TO_STACK_OR_NULL]      = &stack_ptr_types,
> > > +     [ARG_PTR_TO_CONST_STR]          = &const_str_ptr_types,
> > >  };
> > >
> > >  static int check_reg_type(struct bpf_verifier_env *env, u32 regno,
> > > @@ -5067,6 +5069,45 @@ static int check_func_arg(struct bpf_verifier_env *env, u32 arg,
> > >               if (err)
> > >                       return err;
> > >               err = check_ptr_alignment(env, reg, 0, size, true);
> > > +     } else if (arg_type == ARG_PTR_TO_CONST_STR) {
> > > +             struct bpf_map *map = reg->map_ptr;
> > > +             int map_off;
> > > +             u64 map_addr;
> > > +             char *str_ptr;
> > > +
> > > +             if (reg->type != PTR_TO_MAP_VALUE || !map ||
> >
> > I think the 'type' check is redundant,
> > since check_reg_type() did it via compatible_reg_types.
> > If so it's probably better to remove it here ?
> >
> > '!map' looks unnecessary. Can it ever happen? If yes, it's a verifier bug.
> > For example in check_mem_access() we just deref reg->map_ptr without checking
> > which, I think, is correct.
>
> I agree with all of the above. I only thought it's better to be safe
> than sorry but if you'd like I could follow up with a patch that
> removes some checks?
...
> Sure, does not hurt. I can also follow up with a patch unless if you
> prefer doing it yourself.

Please send a follow up patch.
I consider this kind of "safe than sorry" to be defensive programming that
promotes less-thinking-is-fine-because-its-faster-to-code style.
I'm sure you've seen my rants against defensive programming in the past :)

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type
  2021-04-20 15:23       ` Alexei Starovoitov
@ 2021-04-22  8:41         ` Florent Revest
  0 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-04-22  8:41 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Tue, Apr 20, 2021 at 5:23 PM Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Tue, Apr 20, 2021 at 5:35 AM Florent Revest <revest@chromium.org> wrote:
> >
> > On Tue, Apr 20, 2021 at 12:54 AM Alexei Starovoitov
> > <alexei.starovoitov@gmail.com> wrote:
> > >
> > > On Mon, Apr 19, 2021 at 05:52:39PM +0200, Florent Revest wrote:
> > > > This type provides the guarantee that an argument is going to be a const
> > > > pointer to somewhere in a read-only map value. It also checks that this
> > > > pointer is followed by a zero character before the end of the map value.
> > > >
> > > > Signed-off-by: Florent Revest <revest@chromium.org>
> > > > Acked-by: Andrii Nakryiko <andrii@kernel.org>
> > > > ---
> > > >  include/linux/bpf.h   |  1 +
> > > >  kernel/bpf/verifier.c | 41 +++++++++++++++++++++++++++++++++++++++++
> > > >  2 files changed, 42 insertions(+)
> > > >
> > > > diff --git a/include/linux/bpf.h b/include/linux/bpf.h
> > > > index 77d1d8c65b81..c160526fc8bf 100644
> > > > --- a/include/linux/bpf.h
> > > > +++ b/include/linux/bpf.h
> > > > @@ -309,6 +309,7 @@ enum bpf_arg_type {
> > > >       ARG_PTR_TO_PERCPU_BTF_ID,       /* pointer to in-kernel percpu type */
> > > >       ARG_PTR_TO_FUNC,        /* pointer to a bpf program function */
> > > >       ARG_PTR_TO_STACK_OR_NULL,       /* pointer to stack or NULL */
> > > > +     ARG_PTR_TO_CONST_STR,   /* pointer to a null terminated read-only string */
> > > >       __BPF_ARG_TYPE_MAX,
> > > >  };
> > > >
> > > > diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> > > > index 852541a435ef..5f46dd6f3383 100644
> > > > --- a/kernel/bpf/verifier.c
> > > > +++ b/kernel/bpf/verifier.c
> > > > @@ -4787,6 +4787,7 @@ static const struct bpf_reg_types spin_lock_types = { .types = { PTR_TO_MAP_VALU
> > > >  static const struct bpf_reg_types percpu_btf_ptr_types = { .types = { PTR_TO_PERCPU_BTF_ID } };
> > > >  static const struct bpf_reg_types func_ptr_types = { .types = { PTR_TO_FUNC } };
> > > >  static const struct bpf_reg_types stack_ptr_types = { .types = { PTR_TO_STACK } };
> > > > +static const struct bpf_reg_types const_str_ptr_types = { .types = { PTR_TO_MAP_VALUE } };
> > > >
> > > >  static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> > > >       [ARG_PTR_TO_MAP_KEY]            = &map_key_value_types,
> > > > @@ -4817,6 +4818,7 @@ static const struct bpf_reg_types *compatible_reg_types[__BPF_ARG_TYPE_MAX] = {
> > > >       [ARG_PTR_TO_PERCPU_BTF_ID]      = &percpu_btf_ptr_types,
> > > >       [ARG_PTR_TO_FUNC]               = &func_ptr_types,
> > > >       [ARG_PTR_TO_STACK_OR_NULL]      = &stack_ptr_types,
> > > > +     [ARG_PTR_TO_CONST_STR]          = &const_str_ptr_types,
> > > >  };
> > > >
> > > >  static int check_reg_type(struct bpf_verifier_env *env, u32 regno,
> > > > @@ -5067,6 +5069,45 @@ static int check_func_arg(struct bpf_verifier_env *env, u32 arg,
> > > >               if (err)
> > > >                       return err;
> > > >               err = check_ptr_alignment(env, reg, 0, size, true);
> > > > +     } else if (arg_type == ARG_PTR_TO_CONST_STR) {
> > > > +             struct bpf_map *map = reg->map_ptr;
> > > > +             int map_off;
> > > > +             u64 map_addr;
> > > > +             char *str_ptr;
> > > > +
> > > > +             if (reg->type != PTR_TO_MAP_VALUE || !map ||
> > >
> > > I think the 'type' check is redundant,
> > > since check_reg_type() did it via compatible_reg_types.
> > > If so it's probably better to remove it here ?
> > >
> > > '!map' looks unnecessary. Can it ever happen? If yes, it's a verifier bug.
> > > For example in check_mem_access() we just deref reg->map_ptr without checking
> > > which, I think, is correct.
> >
> > I agree with all of the above. I only thought it's better to be safe
> > than sorry but if you'd like I could follow up with a patch that
> > removes some checks?
> ...
> > Sure, does not hurt. I can also follow up with a patch unless if you
> > prefer doing it yourself.
>
> Please send a follow up patch.

Okay, doing that today :)

> I consider this kind of "safe than sorry" to be defensive programming that
> promotes less-thinking-is-fine-because-its-faster-to-code style.

Fair

> I'm sure you've seen my rants against defensive programming in the past :)

Ahah, I haven't yet but I surely don't want to make you rant again ;)

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-19 15:52 ` [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf Florent Revest
@ 2021-04-23 22:38   ` Andrii Nakryiko
  2021-04-26 10:10     ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Andrii Nakryiko @ 2021-04-23 22:38 UTC (permalink / raw)
  To: Florent Revest
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
>
> The "positive" part tests all format specifiers when things go well.
>
> The "negative" part makes sure that incorrect format strings fail at
> load time.
>
> Signed-off-by: Florent Revest <revest@chromium.org>
> ---
>  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
>  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
>  .../bpf/progs/test_snprintf_single.c          |  20 +++
>  3 files changed, 218 insertions(+)
>  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
>
> diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> new file mode 100644
> index 000000000000..a958c22aec75
> --- /dev/null
> +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> @@ -0,0 +1,125 @@
> +// SPDX-License-Identifier: GPL-2.0
> +/* Copyright (c) 2021 Google LLC. */
> +
> +#include <test_progs.h>
> +#include "test_snprintf.skel.h"
> +#include "test_snprintf_single.skel.h"
> +
> +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> +
> +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> +
> +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> +
> +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> +
> +#define EXP_STR_OUT  "str1 longstr"
> +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> +
> +#define EXP_OVER_OUT "%over"
> +#define EXP_OVER_RET 10
> +
> +#define EXP_PAD_OUT "    4 000"

Roughly 50% of the time I get failure for this test case:

test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
0000' != expected '    4 000'

Re-running this test case immediately passes. Running again most
probably fails. Please take a look.

> +#define EXP_PAD_RET 900007
> +
> +#define EXP_NO_ARG_OUT "simple case"
> +#define EXP_NO_ARG_RET 12
> +
> +#define EXP_NO_BUF_RET 29
> +

[...]

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-23 22:38   ` Andrii Nakryiko
@ 2021-04-26 10:10     ` Florent Revest
  2021-04-26 16:19       ` Andrii Nakryiko
  0 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-26 10:10 UTC (permalink / raw)
  To: Andrii Nakryiko
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> >
> > The "positive" part tests all format specifiers when things go well.
> >
> > The "negative" part makes sure that incorrect format strings fail at
> > load time.
> >
> > Signed-off-by: Florent Revest <revest@chromium.org>
> > ---
> >  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
> >  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
> >  .../bpf/progs/test_snprintf_single.c          |  20 +++
> >  3 files changed, 218 insertions(+)
> >  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> >
> > diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > new file mode 100644
> > index 000000000000..a958c22aec75
> > --- /dev/null
> > +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > @@ -0,0 +1,125 @@
> > +// SPDX-License-Identifier: GPL-2.0
> > +/* Copyright (c) 2021 Google LLC. */
> > +
> > +#include <test_progs.h>
> > +#include "test_snprintf.skel.h"
> > +#include "test_snprintf_single.skel.h"
> > +
> > +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> > +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> > +
> > +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> > +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> > +
> > +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> > +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> > +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> > +
> > +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> > +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> > +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> > +
> > +#define EXP_STR_OUT  "str1 longstr"
> > +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> > +
> > +#define EXP_OVER_OUT "%over"
> > +#define EXP_OVER_RET 10
> > +
> > +#define EXP_PAD_OUT "    4 000"
>
> Roughly 50% of the time I get failure for this test case:
>
> test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
> 0000' != expected '    4 000'
>
> Re-running this test case immediately passes. Running again most
> probably fails. Please take a look.

Do you have more information on how to reproduce this ?
I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:

#!/bin/sh
for i in `seq 1000`
do
  ./test_progs -t snprintf
  if [ $? -ne 0 ];
  then
    echo FAILURE
    exit 1
  fi
done

The thousand executions passed.

This is a bit concerning because your unexpected_pad_out seems to have
an extra '0' so it ends up with strlen(pad_out)=11 but
sizeof(pad_out)=10. The actual string writing is not really done by
our helper code but by the snprintf implementation (str and str_size
are only given to snprintf()) so I'd expect the truncation to work
well there. I'm a bit puzzled

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-26 10:10     ` Florent Revest
@ 2021-04-26 16:19       ` Andrii Nakryiko
  2021-04-26 21:08         ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Andrii Nakryiko @ 2021-04-26 16:19 UTC (permalink / raw)
  To: Florent Revest
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Mon, Apr 26, 2021 at 3:10 AM Florent Revest <revest@chromium.org> wrote:
>
> On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
> <andrii.nakryiko@gmail.com> wrote:
> >
> > On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> > >
> > > The "positive" part tests all format specifiers when things go well.
> > >
> > > The "negative" part makes sure that incorrect format strings fail at
> > > load time.
> > >
> > > Signed-off-by: Florent Revest <revest@chromium.org>
> > > ---
> > >  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
> > >  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
> > >  .../bpf/progs/test_snprintf_single.c          |  20 +++
> > >  3 files changed, 218 insertions(+)
> > >  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> > >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> > >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> > >
> > > diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > > new file mode 100644
> > > index 000000000000..a958c22aec75
> > > --- /dev/null
> > > +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > > @@ -0,0 +1,125 @@
> > > +// SPDX-License-Identifier: GPL-2.0
> > > +/* Copyright (c) 2021 Google LLC. */
> > > +
> > > +#include <test_progs.h>
> > > +#include "test_snprintf.skel.h"
> > > +#include "test_snprintf_single.skel.h"
> > > +
> > > +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> > > +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> > > +
> > > +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> > > +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> > > +
> > > +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> > > +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> > > +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> > > +
> > > +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> > > +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> > > +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> > > +
> > > +#define EXP_STR_OUT  "str1 longstr"
> > > +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> > > +
> > > +#define EXP_OVER_OUT "%over"
> > > +#define EXP_OVER_RET 10
> > > +
> > > +#define EXP_PAD_OUT "    4 000"
> >
> > Roughly 50% of the time I get failure for this test case:
> >
> > test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
> > 0000' != expected '    4 000'
> >
> > Re-running this test case immediately passes. Running again most
> > probably fails. Please take a look.
>
> Do you have more information on how to reproduce this ?
> I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:
>
> #!/bin/sh
> for i in `seq 1000`
> do
>   ./test_progs -t snprintf
>   if [ $? -ne 0 ];
>   then
>     echo FAILURE
>     exit 1
>   fi
> done
>
> The thousand executions passed.
>
> This is a bit concerning because your unexpected_pad_out seems to have
> an extra '0' so it ends up with strlen(pad_out)=11 but
> sizeof(pad_out)=10. The actual string writing is not really done by
> our helper code but by the snprintf implementation (str and str_size
> are only given to snprintf()) so I'd expect the truncation to work
> well there. I'm a bit puzzled

I'm puzzled too, have no idea. I also can't repro this with vmtest.sh.
But I can quite reliably reproduce with my local ArchLinux-based qemu
image with different config (see [0] for config itself). So please try
with my config and see if that helps to repro. If not, I'll have to
debug it on my own later.

  [0] https://gist.github.com/anakryiko/4b6ae21680842bdeacca8fa99d378048

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-26 16:19       ` Andrii Nakryiko
@ 2021-04-26 21:08         ` Florent Revest
  2021-04-27  6:35           ` Rasmus Villemoes
  0 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-26 21:08 UTC (permalink / raw)
  To: Andrii Nakryiko
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On Mon, Apr 26, 2021 at 6:19 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Mon, Apr 26, 2021 at 3:10 AM Florent Revest <revest@chromium.org> wrote:
> >
> > On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
> > <andrii.nakryiko@gmail.com> wrote:
> > >
> > > On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> > > >
> > > > The "positive" part tests all format specifiers when things go well.
> > > >
> > > > The "negative" part makes sure that incorrect format strings fail at
> > > > load time.
> > > >
> > > > Signed-off-by: Florent Revest <revest@chromium.org>
> > > > ---
> > > >  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
> > > >  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
> > > >  .../bpf/progs/test_snprintf_single.c          |  20 +++
> > > >  3 files changed, 218 insertions(+)
> > > >  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> > > >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> > > >  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> > > >
> > > > diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > > > new file mode 100644
> > > > index 000000000000..a958c22aec75
> > > > --- /dev/null
> > > > +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > > > @@ -0,0 +1,125 @@
> > > > +// SPDX-License-Identifier: GPL-2.0
> > > > +/* Copyright (c) 2021 Google LLC. */
> > > > +
> > > > +#include <test_progs.h>
> > > > +#include "test_snprintf.skel.h"
> > > > +#include "test_snprintf_single.skel.h"
> > > > +
> > > > +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> > > > +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> > > > +
> > > > +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> > > > +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> > > > +
> > > > +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> > > > +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> > > > +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> > > > +
> > > > +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> > > > +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> > > > +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> > > > +
> > > > +#define EXP_STR_OUT  "str1 longstr"
> > > > +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> > > > +
> > > > +#define EXP_OVER_OUT "%over"
> > > > +#define EXP_OVER_RET 10
> > > > +
> > > > +#define EXP_PAD_OUT "    4 000"
> > >
> > > Roughly 50% of the time I get failure for this test case:
> > >
> > > test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
> > > 0000' != expected '    4 000'
> > >
> > > Re-running this test case immediately passes. Running again most
> > > probably fails. Please take a look.
> >
> > Do you have more information on how to reproduce this ?
> > I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:
> >
> > #!/bin/sh
> > for i in `seq 1000`
> > do
> >   ./test_progs -t snprintf
> >   if [ $? -ne 0 ];
> >   then
> >     echo FAILURE
> >     exit 1
> >   fi
> > done
> >
> > The thousand executions passed.
> >
> > This is a bit concerning because your unexpected_pad_out seems to have
> > an extra '0' so it ends up with strlen(pad_out)=11 but
> > sizeof(pad_out)=10. The actual string writing is not really done by
> > our helper code but by the snprintf implementation (str and str_size
> > are only given to snprintf()) so I'd expect the truncation to work
> > well there. I'm a bit puzzled
>
> I'm puzzled too, have no idea. I also can't repro this with vmtest.sh.
> But I can quite reliably reproduce with my local ArchLinux-based qemu
> image with different config (see [0] for config itself). So please try
> with my config and see if that helps to repro. If not, I'll have to
> debug it on my own later.
>
>   [0] https://gist.github.com/anakryiko/4b6ae21680842bdeacca8fa99d378048

I tried that config on the same commit 87bd9e602 (bpf-next/master)
with my debian-based qemu image and I still can't reproduce the issue
:| If I can be of any help let me know, I'd be happy to help

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-26 21:08         ` Florent Revest
@ 2021-04-27  6:35           ` Rasmus Villemoes
  2021-04-27  9:50             ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Rasmus Villemoes @ 2021-04-27  6:35 UTC (permalink / raw)
  To: Florent Revest, Andrii Nakryiko
  Cc: bpf, Alexei Starovoitov, Daniel Borkmann, Andrii Nakryiko,
	Yonghong Song, KP Singh, Brendan Jackman, open list

On 26/04/2021 23.08, Florent Revest wrote:
> On Mon, Apr 26, 2021 at 6:19 PM Andrii Nakryiko
> <andrii.nakryiko@gmail.com> wrote:
>>
>> On Mon, Apr 26, 2021 at 3:10 AM Florent Revest <revest@chromium.org> wrote:
>>>
>>> On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
>>> <andrii.nakryiko@gmail.com> wrote:
>>>>
>>>> On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
>>>>>
>>>>> The "positive" part tests all format specifiers when things go well.
>>>>>
>>>>> The "negative" part makes sure that incorrect format strings fail at
>>>>> load time.
>>>>>
>>>>> Signed-off-by: Florent Revest <revest@chromium.org>
>>>>> ---
>>>>>  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
>>>>>  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
>>>>>  .../bpf/progs/test_snprintf_single.c          |  20 +++
>>>>>  3 files changed, 218 insertions(+)
>>>>>  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
>>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
>>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
>>>>>
>>>>> diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
>>>>> new file mode 100644
>>>>> index 000000000000..a958c22aec75
>>>>> --- /dev/null
>>>>> +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
>>>>> @@ -0,0 +1,125 @@
>>>>> +// SPDX-License-Identifier: GPL-2.0
>>>>> +/* Copyright (c) 2021 Google LLC. */
>>>>> +
>>>>> +#include <test_progs.h>
>>>>> +#include "test_snprintf.skel.h"
>>>>> +#include "test_snprintf_single.skel.h"
>>>>> +
>>>>> +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
>>>>> +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
>>>>> +
>>>>> +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
>>>>> +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
>>>>> +
>>>>> +/* The third specifier, %pB, depends on compiler inlining so don't check it */
>>>>> +#define EXP_SYM_OUT  "schedule schedule+0x0/"
>>>>> +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
>>>>> +
>>>>> +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
>>>>> +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
>>>>> +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
>>>>> +
>>>>> +#define EXP_STR_OUT  "str1 longstr"
>>>>> +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
>>>>> +
>>>>> +#define EXP_OVER_OUT "%over"
>>>>> +#define EXP_OVER_RET 10
>>>>> +
>>>>> +#define EXP_PAD_OUT "    4 000"
>>>>
>>>> Roughly 50% of the time I get failure for this test case:
>>>>
>>>> test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
>>>> 0000' != expected '    4 000'
>>>>
>>>> Re-running this test case immediately passes. Running again most
>>>> probably fails. Please take a look.
>>>
>>> Do you have more information on how to reproduce this ?
>>> I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:
>>>
>>> #!/bin/sh
>>> for i in `seq 1000`
>>> do
>>>   ./test_progs -t snprintf
>>>   if [ $? -ne 0 ];
>>>   then
>>>     echo FAILURE
>>>     exit 1
>>>   fi
>>> done
>>>
>>> The thousand executions passed.
>>>
>>> This is a bit concerning because your unexpected_pad_out seems to have
>>> an extra '0' so it ends up with strlen(pad_out)=11 but
>>> sizeof(pad_out)=10. The actual string writing is not really done by
>>> our helper code but by the snprintf implementation (str and str_size
>>> are only given to snprintf()) so I'd expect the truncation to work
>>> well there. I'm a bit puzzled
>>
>> I'm puzzled too, have no idea. I also can't repro this with vmtest.sh.
>> But I can quite reliably reproduce with my local ArchLinux-based qemu
>> image with different config (see [0] for config itself). So please try
>> with my config and see if that helps to repro. If not, I'll have to
>> debug it on my own later.
>>
>>   [0] https://gist.github.com/anakryiko/4b6ae21680842bdeacca8fa99d378048
> 
> I tried that config on the same commit 87bd9e602 (bpf-next/master)
> with my debian-based qemu image and I still can't reproduce the issue
> :| If I can be of any help let me know, I'd be happy to help
> 

It's not really clear to me if this is before or after the rewrite to
use bprintf, but regardless, in those two patches this caught my attention:

 	u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
-	enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
+	u32 *bin_args;
 	static char buf[BPF_TRACE_PRINTK_SIZE];
 	unsigned long flags;
 	int ret;

-	ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
-				 MAX_TRACE_PRINTK_VARARGS);
+	ret = bpf_bprintf_prepare(fmt, fmt_size, args, &bin_args,
+				  MAX_TRACE_PRINTK_VARARGS);
 	if (ret < 0)
 		return ret;

-	ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
-		BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
-	/* snprintf() will not append null for zero-length strings */
-	if (ret == 0)
-		buf[0] = '\0';
+	ret = bstr_printf(buf, sizeof(buf), fmt, bin_args);

 	raw_spin_lock_irqsave(&trace_printk_lock, flags);
 	trace_bpf_trace_printk(buf);
 	raw_spin_unlock_irqrestore(&trace_printk_lock, flags);

Why isn't the write to buf[] protected by that spinlock? Or put another
way, what protects buf[] from concurrent writes?

Probably the test cases are not run in parallel, but this is the kind of
thing that would give those symptoms.

Rasmus

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-27  6:35           ` Rasmus Villemoes
@ 2021-04-27  9:50             ` Florent Revest
  2021-04-27 18:03               ` Andrii Nakryiko
  0 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-27  9:50 UTC (permalink / raw)
  To: Rasmus Villemoes
  Cc: Andrii Nakryiko, bpf, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Yonghong Song, KP Singh, Brendan Jackman,
	open list

On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
<linux@rasmusvillemoes.dk> wrote:
>
> On 26/04/2021 23.08, Florent Revest wrote:
> > On Mon, Apr 26, 2021 at 6:19 PM Andrii Nakryiko
> > <andrii.nakryiko@gmail.com> wrote:
> >>
> >> On Mon, Apr 26, 2021 at 3:10 AM Florent Revest <revest@chromium.org> wrote:
> >>>
> >>> On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
> >>> <andrii.nakryiko@gmail.com> wrote:
> >>>>
> >>>> On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> >>>>>
> >>>>> The "positive" part tests all format specifiers when things go well.
> >>>>>
> >>>>> The "negative" part makes sure that incorrect format strings fail at
> >>>>> load time.
> >>>>>
> >>>>> Signed-off-by: Florent Revest <revest@chromium.org>
> >>>>> ---
> >>>>>  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
> >>>>>  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
> >>>>>  .../bpf/progs/test_snprintf_single.c          |  20 +++
> >>>>>  3 files changed, 218 insertions(+)
> >>>>>  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> >>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> >>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> >>>>>
> >>>>> diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> >>>>> new file mode 100644
> >>>>> index 000000000000..a958c22aec75
> >>>>> --- /dev/null
> >>>>> +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> >>>>> @@ -0,0 +1,125 @@
> >>>>> +// SPDX-License-Identifier: GPL-2.0
> >>>>> +/* Copyright (c) 2021 Google LLC. */
> >>>>> +
> >>>>> +#include <test_progs.h>
> >>>>> +#include "test_snprintf.skel.h"
> >>>>> +#include "test_snprintf_single.skel.h"
> >>>>> +
> >>>>> +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> >>>>> +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> >>>>> +
> >>>>> +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> >>>>> +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> >>>>> +
> >>>>> +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> >>>>> +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> >>>>> +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> >>>>> +
> >>>>> +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> >>>>> +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> >>>>> +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> >>>>> +
> >>>>> +#define EXP_STR_OUT  "str1 longstr"
> >>>>> +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> >>>>> +
> >>>>> +#define EXP_OVER_OUT "%over"
> >>>>> +#define EXP_OVER_RET 10
> >>>>> +
> >>>>> +#define EXP_PAD_OUT "    4 000"
> >>>>
> >>>> Roughly 50% of the time I get failure for this test case:
> >>>>
> >>>> test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
> >>>> 0000' != expected '    4 000'
> >>>>
> >>>> Re-running this test case immediately passes. Running again most
> >>>> probably fails. Please take a look.
> >>>
> >>> Do you have more information on how to reproduce this ?
> >>> I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:
> >>>
> >>> #!/bin/sh
> >>> for i in `seq 1000`
> >>> do
> >>>   ./test_progs -t snprintf
> >>>   if [ $? -ne 0 ];
> >>>   then
> >>>     echo FAILURE
> >>>     exit 1
> >>>   fi
> >>> done
> >>>
> >>> The thousand executions passed.
> >>>
> >>> This is a bit concerning because your unexpected_pad_out seems to have
> >>> an extra '0' so it ends up with strlen(pad_out)=11 but
> >>> sizeof(pad_out)=10. The actual string writing is not really done by
> >>> our helper code but by the snprintf implementation (str and str_size
> >>> are only given to snprintf()) so I'd expect the truncation to work
> >>> well there. I'm a bit puzzled
> >>
> >> I'm puzzled too, have no idea. I also can't repro this with vmtest.sh.
> >> But I can quite reliably reproduce with my local ArchLinux-based qemu
> >> image with different config (see [0] for config itself). So please try
> >> with my config and see if that helps to repro. If not, I'll have to
> >> debug it on my own later.
> >>
> >>   [0] https://gist.github.com/anakryiko/4b6ae21680842bdeacca8fa99d378048
> >
> > I tried that config on the same commit 87bd9e602 (bpf-next/master)
> > with my debian-based qemu image and I still can't reproduce the issue
> > :| If I can be of any help let me know, I'd be happy to help
> >
>
> It's not really clear to me if this is before or after the rewrite to
> use bprintf, but regardless, in those two patches this caught my attention:

I tried to reproduce Andrii's bug both before and after the bprintf
rewrite but I think he meant before.

>         u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
> -       enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
> +       u32 *bin_args;
>         static char buf[BPF_TRACE_PRINTK_SIZE];
>         unsigned long flags;
>         int ret;
>
> -       ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
> -                                MAX_TRACE_PRINTK_VARARGS);
> +       ret = bpf_bprintf_prepare(fmt, fmt_size, args, &bin_args,
> +                                 MAX_TRACE_PRINTK_VARARGS);
>         if (ret < 0)
>                 return ret;
>
> -       ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
> -               BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
> -       /* snprintf() will not append null for zero-length strings */
> -       if (ret == 0)
> -               buf[0] = '\0';
> +       ret = bstr_printf(buf, sizeof(buf), fmt, bin_args);
>
>         raw_spin_lock_irqsave(&trace_printk_lock, flags);
>         trace_bpf_trace_printk(buf);
>         raw_spin_unlock_irqrestore(&trace_printk_lock, flags);
>
> Why isn't the write to buf[] protected by that spinlock? Or put another
> way, what protects buf[] from concurrent writes?

You're right, that is a bug, I missed that buf was static and thought
it was just on the stack. That snprintf call should be after the
raw_spin_lock_irqsave. I'll send a patch. Thank you Rasmus. (before my
snprintf series, there was a vsprintf after the raw_spin_lock_irqsave)

> Probably the test cases are not run in parallel, but this is the kind of
> thing that would give those symptoms.

I think it's a separate issue from what Andrii reported though because
the flaky test exercises the bpf_snprintf helper and this buf spinlock
bug you just found only affects the bpf_trace_printk helper.

That being said, it does smell a little bit like a concurrency issue
too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
attaches to all syscall entries and most likely gets executed many
more times than necessary and probably on parallel CPUs. The "pad_out"
buffer they write to is unique and not locked so maybe the test's
userspace reads pad_out while another CPU is writing on it and if the
string output goes through a stage where it is "    4 0000" before
being "    4 000", we might read at the wrong time. That being said, I
would find it weird that this happens as much as 50% of the time and
always specifically on that test case.

Andrii could you maybe try changing the prog type to
"tp/syscalls/sys_enter_nanosleep" on the machine where you can
reproduce this bug ?

> Rasmus

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-27  9:50             ` Florent Revest
@ 2021-04-27 18:03               ` Andrii Nakryiko
  2021-04-28 14:59                 ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Andrii Nakryiko @ 2021-04-27 18:03 UTC (permalink / raw)
  To: Florent Revest
  Cc: Rasmus Villemoes, bpf, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Yonghong Song, KP Singh, Brendan Jackman,
	open list

On Tue, Apr 27, 2021 at 2:51 AM Florent Revest <revest@chromium.org> wrote:
>
> On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
> <linux@rasmusvillemoes.dk> wrote:
> >
> > On 26/04/2021 23.08, Florent Revest wrote:
> > > On Mon, Apr 26, 2021 at 6:19 PM Andrii Nakryiko
> > > <andrii.nakryiko@gmail.com> wrote:
> > >>
> > >> On Mon, Apr 26, 2021 at 3:10 AM Florent Revest <revest@chromium.org> wrote:
> > >>>
> > >>> On Sat, Apr 24, 2021 at 12:38 AM Andrii Nakryiko
> > >>> <andrii.nakryiko@gmail.com> wrote:
> > >>>>
> > >>>> On Mon, Apr 19, 2021 at 8:52 AM Florent Revest <revest@chromium.org> wrote:
> > >>>>>
> > >>>>> The "positive" part tests all format specifiers when things go well.
> > >>>>>
> > >>>>> The "negative" part makes sure that incorrect format strings fail at
> > >>>>> load time.
> > >>>>>
> > >>>>> Signed-off-by: Florent Revest <revest@chromium.org>
> > >>>>> ---
> > >>>>>  .../selftests/bpf/prog_tests/snprintf.c       | 125 ++++++++++++++++++
> > >>>>>  .../selftests/bpf/progs/test_snprintf.c       |  73 ++++++++++
> > >>>>>  .../bpf/progs/test_snprintf_single.c          |  20 +++
> > >>>>>  3 files changed, 218 insertions(+)
> > >>>>>  create mode 100644 tools/testing/selftests/bpf/prog_tests/snprintf.c
> > >>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf.c
> > >>>>>  create mode 100644 tools/testing/selftests/bpf/progs/test_snprintf_single.c
> > >>>>>
> > >>>>> diff --git a/tools/testing/selftests/bpf/prog_tests/snprintf.c b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > >>>>> new file mode 100644
> > >>>>> index 000000000000..a958c22aec75
> > >>>>> --- /dev/null
> > >>>>> +++ b/tools/testing/selftests/bpf/prog_tests/snprintf.c
> > >>>>> @@ -0,0 +1,125 @@
> > >>>>> +// SPDX-License-Identifier: GPL-2.0
> > >>>>> +/* Copyright (c) 2021 Google LLC. */
> > >>>>> +
> > >>>>> +#include <test_progs.h>
> > >>>>> +#include "test_snprintf.skel.h"
> > >>>>> +#include "test_snprintf_single.skel.h"
> > >>>>> +
> > >>>>> +#define EXP_NUM_OUT  "-8 9 96 -424242 1337 DABBAD00"
> > >>>>> +#define EXP_NUM_RET  sizeof(EXP_NUM_OUT)
> > >>>>> +
> > >>>>> +#define EXP_IP_OUT   "127.000.000.001 0000:0000:0000:0000:0000:0000:0000:0001"
> > >>>>> +#define EXP_IP_RET   sizeof(EXP_IP_OUT)
> > >>>>> +
> > >>>>> +/* The third specifier, %pB, depends on compiler inlining so don't check it */
> > >>>>> +#define EXP_SYM_OUT  "schedule schedule+0x0/"
> > >>>>> +#define MIN_SYM_RET  sizeof(EXP_SYM_OUT)
> > >>>>> +
> > >>>>> +/* The third specifier, %p, is a hashed pointer which changes on every reboot */
> > >>>>> +#define EXP_ADDR_OUT "0000000000000000 ffff00000add4e55 "
> > >>>>> +#define EXP_ADDR_RET sizeof(EXP_ADDR_OUT "unknownhashedptr")
> > >>>>> +
> > >>>>> +#define EXP_STR_OUT  "str1 longstr"
> > >>>>> +#define EXP_STR_RET  sizeof(EXP_STR_OUT)
> > >>>>> +
> > >>>>> +#define EXP_OVER_OUT "%over"
> > >>>>> +#define EXP_OVER_RET 10
> > >>>>> +
> > >>>>> +#define EXP_PAD_OUT "    4 000"
> > >>>>
> > >>>> Roughly 50% of the time I get failure for this test case:
> > >>>>
> > >>>> test_snprintf_positive:FAIL:pad_out unexpected pad_out: actual '    4
> > >>>> 0000' != expected '    4 000'
> > >>>>
> > >>>> Re-running this test case immediately passes. Running again most
> > >>>> probably fails. Please take a look.
> > >>>
> > >>> Do you have more information on how to reproduce this ?
> > >>> I spinned up a VM at 87bd9e602 with ./vmtest -s and then run this script:
> > >>>
> > >>> #!/bin/sh
> > >>> for i in `seq 1000`
> > >>> do
> > >>>   ./test_progs -t snprintf
> > >>>   if [ $? -ne 0 ];
> > >>>   then
> > >>>     echo FAILURE
> > >>>     exit 1
> > >>>   fi
> > >>> done
> > >>>
> > >>> The thousand executions passed.
> > >>>
> > >>> This is a bit concerning because your unexpected_pad_out seems to have
> > >>> an extra '0' so it ends up with strlen(pad_out)=11 but
> > >>> sizeof(pad_out)=10. The actual string writing is not really done by
> > >>> our helper code but by the snprintf implementation (str and str_size
> > >>> are only given to snprintf()) so I'd expect the truncation to work
> > >>> well there. I'm a bit puzzled
> > >>
> > >> I'm puzzled too, have no idea. I also can't repro this with vmtest.sh.
> > >> But I can quite reliably reproduce with my local ArchLinux-based qemu
> > >> image with different config (see [0] for config itself). So please try
> > >> with my config and see if that helps to repro. If not, I'll have to
> > >> debug it on my own later.
> > >>
> > >>   [0] https://gist.github.com/anakryiko/4b6ae21680842bdeacca8fa99d378048
> > >
> > > I tried that config on the same commit 87bd9e602 (bpf-next/master)
> > > with my debian-based qemu image and I still can't reproduce the issue
> > > :| If I can be of any help let me know, I'd be happy to help
> > >
> >
> > It's not really clear to me if this is before or after the rewrite to
> > use bprintf, but regardless, in those two patches this caught my attention:
>
> I tried to reproduce Andrii's bug both before and after the bprintf
> rewrite but I think he meant before.

I'm running on the latest bpf-next master, but I don't think it's
related to bprintf change.

>
> >         u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
> > -       enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
> > +       u32 *bin_args;
> >         static char buf[BPF_TRACE_PRINTK_SIZE];
> >         unsigned long flags;
> >         int ret;
> >
> > -       ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
> > -                                MAX_TRACE_PRINTK_VARARGS);
> > +       ret = bpf_bprintf_prepare(fmt, fmt_size, args, &bin_args,
> > +                                 MAX_TRACE_PRINTK_VARARGS);
> >         if (ret < 0)
> >                 return ret;
> >
> > -       ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
> > -               BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
> > -       /* snprintf() will not append null for zero-length strings */
> > -       if (ret == 0)
> > -               buf[0] = '\0';
> > +       ret = bstr_printf(buf, sizeof(buf), fmt, bin_args);
> >
> >         raw_spin_lock_irqsave(&trace_printk_lock, flags);
> >         trace_bpf_trace_printk(buf);
> >         raw_spin_unlock_irqrestore(&trace_printk_lock, flags);
> >
> > Why isn't the write to buf[] protected by that spinlock? Or put another
> > way, what protects buf[] from concurrent writes?
>
> You're right, that is a bug, I missed that buf was static and thought
> it was just on the stack. That snprintf call should be after the
> raw_spin_lock_irqsave. I'll send a patch. Thank you Rasmus. (before my
> snprintf series, there was a vsprintf after the raw_spin_lock_irqsave)

Can you please also clean up unnecessary ()s you added in at least a
few places. Thanks.

>
> > Probably the test cases are not run in parallel, but this is the kind of
> > thing that would give those symptoms.
>
> I think it's a separate issue from what Andrii reported though because
> the flaky test exercises the bpf_snprintf helper and this buf spinlock
> bug you just found only affects the bpf_trace_printk helper.
>
> That being said, it does smell a little bit like a concurrency issue
> too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
> attaches to all syscall entries and most likely gets executed many
> more times than necessary and probably on parallel CPUs. The "pad_out"
> buffer they write to is unique and not locked so maybe the test's
> userspace reads pad_out while another CPU is writing on it and if the
> string output goes through a stage where it is "    4 0000" before
> being "    4 000", we might read at the wrong time. That being said, I
> would find it weird that this happens as much as 50% of the time and
> always specifically on that test case.
>
> Andrii could you maybe try changing the prog type to
> "tp/syscalls/sys_enter_nanosleep" on the machine where you can
> reproduce this bug ?

Yes, it helps. I can't repro it easily anymore. I think the right fix,
though, should be to filter by tid, not change the tracepoint.

I think what's happening is we see the string right before bstr_printf
does zero-termination with end[-1] = '\0'; So in some cases we see
truncated string, in others we see untruncated one.

>
> > Rasmus

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-27 18:03               ` Andrii Nakryiko
@ 2021-04-28 14:59                 ` Florent Revest
  2021-05-05  6:55                   ` Rasmus Villemoes
  0 siblings, 1 reply; 23+ messages in thread
From: Florent Revest @ 2021-04-28 14:59 UTC (permalink / raw)
  To: Andrii Nakryiko
  Cc: Rasmus Villemoes, bpf, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Yonghong Song, KP Singh, Brendan Jackman,
	open list

On Tue, Apr 27, 2021 at 8:03 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Tue, Apr 27, 2021 at 2:51 AM Florent Revest <revest@chromium.org> wrote:
> >
> > On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
> > <linux@rasmusvillemoes.dk> wrote:
> > >         u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
> > > -       enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
> > > +       u32 *bin_args;
> > >         static char buf[BPF_TRACE_PRINTK_SIZE];
> > >         unsigned long flags;
> > >         int ret;
> > >
> > > -       ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
> > > -                                MAX_TRACE_PRINTK_VARARGS);
> > > +       ret = bpf_bprintf_prepare(fmt, fmt_size, args, &bin_args,
> > > +                                 MAX_TRACE_PRINTK_VARARGS);
> > >         if (ret < 0)
> > >                 return ret;
> > >
> > > -       ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
> > > -               BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
> > > -       /* snprintf() will not append null for zero-length strings */
> > > -       if (ret == 0)
> > > -               buf[0] = '\0';
> > > +       ret = bstr_printf(buf, sizeof(buf), fmt, bin_args);
> > >
> > >         raw_spin_lock_irqsave(&trace_printk_lock, flags);
> > >         trace_bpf_trace_printk(buf);
> > >         raw_spin_unlock_irqrestore(&trace_printk_lock, flags);
> > >
> > > Why isn't the write to buf[] protected by that spinlock? Or put another
> > > way, what protects buf[] from concurrent writes?
> >
> > You're right, that is a bug, I missed that buf was static and thought
> > it was just on the stack. That snprintf call should be after the
> > raw_spin_lock_irqsave. I'll send a patch. Thank you Rasmus. (before my
> > snprintf series, there was a vsprintf after the raw_spin_lock_irqsave)

Solved now

> Can you please also clean up unnecessary ()s you added in at least a
> few places. Thanks.

Alexei said he took care of this .:)

> > > Probably the test cases are not run in parallel, but this is the kind of
> > > thing that would give those symptoms.
> >
> > I think it's a separate issue from what Andrii reported though because
> > the flaky test exercises the bpf_snprintf helper and this buf spinlock
> > bug you just found only affects the bpf_trace_printk helper.
> >
> > That being said, it does smell a little bit like a concurrency issue
> > too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
> > attaches to all syscall entries and most likely gets executed many
> > more times than necessary and probably on parallel CPUs. The "pad_out"
> > buffer they write to is unique and not locked so maybe the test's
> > userspace reads pad_out while another CPU is writing on it and if the
> > string output goes through a stage where it is "    4 0000" before
> > being "    4 000", we might read at the wrong time. That being said, I
> > would find it weird that this happens as much as 50% of the time and
> > always specifically on that test case.
> >
> > Andrii could you maybe try changing the prog type to
> > "tp/syscalls/sys_enter_nanosleep" on the machine where you can
> > reproduce this bug ?
>
> Yes, it helps. I can't repro it easily anymore.

Good, so it does sound like a concurrency issue indeed

> I think the right fix, though, should be to filter by tid, not change the tracepoint.

Agreed, I'll send a patch for that today. :)

> I think what's happening is we see the string right before bstr_printf
> does zero-termination with end[-1] = '\0'; So in some cases we see
> truncated string, in others we see untruncated one.

Makes sense but I still wonder why it happens so often (50% of the
time is really a lot) and why it is consistently that one test case
that fails and not the "overflow" case for example. But I'm confident
that this is not a bug in the helper now and that the tid filter will
fix the test.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-04-28 14:59                 ` Florent Revest
@ 2021-05-05  6:55                   ` Rasmus Villemoes
  2021-05-05 14:25                     ` Florent Revest
  0 siblings, 1 reply; 23+ messages in thread
From: Rasmus Villemoes @ 2021-05-05  6:55 UTC (permalink / raw)
  To: Florent Revest, Andrii Nakryiko
  Cc: Rasmus Villemoes, bpf, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Yonghong Song, KP Singh, Brendan Jackman,
	open list

On 28/04/2021 16.59, Florent Revest wrote:
> On Tue, Apr 27, 2021 at 8:03 PM Andrii Nakryiko
> <andrii.nakryiko@gmail.com> wrote:
>>
>> On Tue, Apr 27, 2021 at 2:51 AM Florent Revest <revest@chromium.org> wrote:
>>>
>>> On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
>>> <linux@rasmusvillemoes.dk> wrote:
>>>>         u64 args[MAX_TRACE_PRINTK_VARARGS] = { arg1, arg2, arg3 };
>>>> -       enum bpf_printf_mod_type mod[MAX_TRACE_PRINTK_VARARGS];
>>>> +       u32 *bin_args;
>>>>         static char buf[BPF_TRACE_PRINTK_SIZE];
>>>>         unsigned long flags;
>>>>         int ret;
>>>>
>>>> -       ret = bpf_printf_prepare(fmt, fmt_size, args, args, mod,
>>>> -                                MAX_TRACE_PRINTK_VARARGS);
>>>> +       ret = bpf_bprintf_prepare(fmt, fmt_size, args, &bin_args,
>>>> +                                 MAX_TRACE_PRINTK_VARARGS);
>>>>         if (ret < 0)
>>>>                 return ret;
>>>>
>>>> -       ret = snprintf(buf, sizeof(buf), fmt, BPF_CAST_FMT_ARG(0, args, mod),
>>>> -               BPF_CAST_FMT_ARG(1, args, mod), BPF_CAST_FMT_ARG(2, args, mod));
>>>> -       /* snprintf() will not append null for zero-length strings */
>>>> -       if (ret == 0)
>>>> -               buf[0] = '\0';
>>>> +       ret = bstr_printf(buf, sizeof(buf), fmt, bin_args);
>>>>
>>>>         raw_spin_lock_irqsave(&trace_printk_lock, flags);
>>>>         trace_bpf_trace_printk(buf);
>>>>         raw_spin_unlock_irqrestore(&trace_printk_lock, flags);
>>>>
>>>> Why isn't the write to buf[] protected by that spinlock? Or put another
>>>> way, what protects buf[] from concurrent writes?
>>>
>>> You're right, that is a bug, I missed that buf was static and thought
>>> it was just on the stack. That snprintf call should be after the
>>> raw_spin_lock_irqsave. I'll send a patch. Thank you Rasmus. (before my
>>> snprintf series, there was a vsprintf after the raw_spin_lock_irqsave)
> 
> Solved now
> 
>> Can you please also clean up unnecessary ()s you added in at least a
>> few places. Thanks.
> 
> Alexei said he took care of this .:)
> 
>>>> Probably the test cases are not run in parallel, but this is the kind of
>>>> thing that would give those symptoms.
>>>
>>> I think it's a separate issue from what Andrii reported though because
>>> the flaky test exercises the bpf_snprintf helper and this buf spinlock
>>> bug you just found only affects the bpf_trace_printk helper.
>>>
>>> That being said, it does smell a little bit like a concurrency issue
>>> too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
>>> attaches to all syscall entries and most likely gets executed many
>>> more times than necessary and probably on parallel CPUs. The "pad_out"
>>> buffer they write to is unique and not locked so maybe the test's
>>> userspace reads pad_out while another CPU is writing on it and if the
>>> string output goes through a stage where it is "    4 0000" before
>>> being "    4 000", we might read at the wrong time. That being said, I
>>> would find it weird that this happens as much as 50% of the time and
>>> always specifically on that test case.
>>>
>>> Andrii could you maybe try changing the prog type to
>>> "tp/syscalls/sys_enter_nanosleep" on the machine where you can
>>> reproduce this bug ?
>>
>> Yes, it helps. I can't repro it easily anymore.
> 
> Good, so it does sound like a concurrency issue indeed
> 
>> I think the right fix, though, should be to filter by tid, not change the tracepoint.
> 
> Agreed, I'll send a patch for that today. :)
> 
>> I think what's happening is we see the string right before bstr_printf
>> does zero-termination with end[-1] = '\0'; So in some cases we see
>> truncated string, in others we see untruncated one.
> 
> Makes sense but I still wonder why it happens so often (50% of the
> time is really a lot) and why it is consistently that one test case
> that fails and not the "overflow" case for example. But I'm confident
> that this is not a bug in the helper now and that the tid filter will
> fix the test.
> 

If the caller, or one of its sibling threads, inspects the buffer before
(v)snprintf has returned it's very obviously a bug in the caller. As for
why that particular case exposes the race: It seems to be the only one
that "expects" an insanely long result, and it takes a very very long
time (several cycles per byte I'd assume) for the vsnprintf code to very
carefully go through the

  if (buf < end)
     *buf = /* '0' or ' ' or whatever it is it is emitting here */
  buf++;

900k times. So there's simply a very large window where the buffer
contents is "    4 0000" while number() is still 'emitting' 0s until
control returns to vsnprintf() which does that final end[-1] = '\0'.

Rasmus


^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
  2021-05-05  6:55                   ` Rasmus Villemoes
@ 2021-05-05 14:25                     ` Florent Revest
  0 siblings, 0 replies; 23+ messages in thread
From: Florent Revest @ 2021-05-05 14:25 UTC (permalink / raw)
  To: Rasmus Villemoes
  Cc: Andrii Nakryiko, bpf, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Yonghong Song, KP Singh, Brendan Jackman,
	open list

On Wed, May 5, 2021 at 8:55 AM Rasmus Villemoes
<linux@rasmusvillemoes.dk> wrote:
>
> On 28/04/2021 16.59, Florent Revest wrote:
> > On Tue, Apr 27, 2021 at 8:03 PM Andrii Nakryiko
> > <andrii.nakryiko@gmail.com> wrote:
> >>
> >> On Tue, Apr 27, 2021 at 2:51 AM Florent Revest <revest@chromium.org> wrote:
> >>>
> >>> On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
> >>> <linux@rasmusvillemoes.dk> wrote:
> >>>> Probably the test cases are not run in parallel, but this is the kind of
> >>>> thing that would give those symptoms.
> >>>
> >>> I think it's a separate issue from what Andrii reported though because
> >>> the flaky test exercises the bpf_snprintf helper and this buf spinlock
> >>> bug you just found only affects the bpf_trace_printk helper.
> >>>
> >>> That being said, it does smell a little bit like a concurrency issue
> >>> too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
> >>> attaches to all syscall entries and most likely gets executed many
> >>> more times than necessary and probably on parallel CPUs. The "pad_out"
> >>> buffer they write to is unique and not locked so maybe the test's
> >>> userspace reads pad_out while another CPU is writing on it and if the
> >>> string output goes through a stage where it is "    4 0000" before
> >>> being "    4 000", we might read at the wrong time. That being said, I
> >>> would find it weird that this happens as much as 50% of the time and
> >>> always specifically on that test case.
> >>>
> >>> Andrii could you maybe try changing the prog type to
> >>> "tp/syscalls/sys_enter_nanosleep" on the machine where you can
> >>> reproduce this bug ?
> >>
> >> Yes, it helps. I can't repro it easily anymore.
> >
> > Good, so it does sound like a concurrency issue indeed
> >
> >> I think the right fix, though, should be to filter by tid, not change the tracepoint.
> >
> > Agreed, I'll send a patch for that today. :)
> >
> >> I think what's happening is we see the string right before bstr_printf
> >> does zero-termination with end[-1] = '\0'; So in some cases we see
> >> truncated string, in others we see untruncated one.
> >
> > Makes sense but I still wonder why it happens so often (50% of the
> > time is really a lot) and why it is consistently that one test case
> > that fails and not the "overflow" case for example. But I'm confident
> > that this is not a bug in the helper now and that the tid filter will
> > fix the test.
> >
>
> If the caller, or one of its sibling threads, inspects the buffer before
> (v)snprintf has returned it's very obviously a bug in the caller. As for

Absolutely

> why that particular case exposes the race: It seems to be the only one
> that "expects" an insanely long result, and it takes a very very long
> time (several cycles per byte I'd assume) for the vsnprintf code to very
> carefully go through the
>
>   if (buf < end)
>      *buf = /* '0' or ' ' or whatever it is it is emitting here */
>   buf++;
>
> 900k times. So there's simply a very large window where the buffer
> contents is "    4 0000" while number() is still 'emitting' 0s until
> control returns to vsnprintf() which does that final end[-1] = '\0'.

Aaah, of course, it makes complete sense! :) Thank you Rasmus

^ permalink raw reply	[flat|nested] 23+ messages in thread

end of thread, back to index

Thread overview: 23+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type Florent Revest
2021-04-19 22:54   ` Alexei Starovoitov
2021-04-20 12:35     ` Florent Revest
2021-04-20 15:23       ` Alexei Starovoitov
2021-04-22  8:41         ` Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 3/6] bpf: Add a bpf_snprintf helper Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 4/6] libbpf: Initialize the bpf_seq_printf parameters array field by field Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 5/6] libbpf: Introduce a BPF_SNPRINTF helper macro Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf Florent Revest
2021-04-23 22:38   ` Andrii Nakryiko
2021-04-26 10:10     ` Florent Revest
2021-04-26 16:19       ` Andrii Nakryiko
2021-04-26 21:08         ` Florent Revest
2021-04-27  6:35           ` Rasmus Villemoes
2021-04-27  9:50             ` Florent Revest
2021-04-27 18:03               ` Andrii Nakryiko
2021-04-28 14:59                 ` Florent Revest
2021-05-05  6:55                   ` Rasmus Villemoes
2021-05-05 14:25                     ` Florent Revest
2021-04-19 19:33 ` [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Andrii Nakryiko
2021-04-20 12:02   ` Florent Revest

BPF Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/bpf/0 bpf/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 bpf bpf/ https://lore.kernel.org/bpf \
		bpf@vger.kernel.org
	public-inbox-index bpf

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.bpf


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git