linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] tracing: Allow for max buffer data size trace_marker writes
@ 2023-12-09 22:50 Steven Rostedt
  2023-12-10 14:09 ` Mathieu Desnoyers
  0 siblings, 1 reply; 7+ messages in thread
From: Steven Rostedt @ 2023-12-09 22:50 UTC (permalink / raw)
  To: LKML, Linux Trace Kernel
  Cc: Masami Hiramatsu, Mark Rutland, Mathieu Desnoyers

From: "Steven Rostedt (Google)" <rostedt@goodmis.org>

Allow a trace write to be as big as the ring buffer tracing data will
allow. Currently, it only allows writes of 1KB in size, but there's no
reason that it cannot allow what the ring buffer can hold.

Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
[
   Depends on: https://lore.kernel.org/linux-trace-kernel/20231209170139.33c1b452@gandalf.local.home/
]
 include/linux/ring_buffer.h |  1 +
 kernel/trace/ring_buffer.c  | 12 ++++++++++++
 kernel/trace/trace.c        | 28 +++++++++++++++++++++-------
 3 files changed, 34 insertions(+), 7 deletions(-)

diff --git a/include/linux/ring_buffer.h b/include/linux/ring_buffer.h
index 782e14f62201..b1b03b2c0f08 100644
--- a/include/linux/ring_buffer.h
+++ b/include/linux/ring_buffer.h
@@ -141,6 +141,7 @@ int ring_buffer_iter_empty(struct ring_buffer_iter *iter);
 bool ring_buffer_iter_dropped(struct ring_buffer_iter *iter);
 
 unsigned long ring_buffer_size(struct trace_buffer *buffer, int cpu);
+unsigned long ring_buffer_max_event_size(struct trace_buffer *buffer);
 
 void ring_buffer_reset_cpu(struct trace_buffer *buffer, int cpu);
 void ring_buffer_reset_online_cpus(struct trace_buffer *buffer);
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 8da1320df51d..3a5026702179 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -5254,6 +5254,18 @@ unsigned long ring_buffer_size(struct trace_buffer *buffer, int cpu)
 }
 EXPORT_SYMBOL_GPL(ring_buffer_size);
 
+/**
+ * ring_buffer_max_event_size - return the max data size of an event
+ * @buffer: The ring buffer.
+ *
+ * Returns the maximum size an event can be.
+ */
+unsigned long ring_buffer_max_event_size(struct trace_buffer *buffer)
+{
+	return BUF_MAX_EVENT_SIZE;
+}
+EXPORT_SYMBOL_GPL(ring_buffer_max_event_size);
+
 static void rb_clear_buffer_page(struct buffer_page *page)
 {
 	local_set(&page->write, 0);
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 49f388e4fa1d..83393c65ec71 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -7272,6 +7272,7 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 	enum event_trigger_type tt = ETT_NONE;
 	struct trace_buffer *buffer;
 	struct print_entry *entry;
+	int meta_size;
 	ssize_t written;
 	int size;
 	int len;
@@ -7286,12 +7287,9 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 	if (!(tr->trace_flags & TRACE_ITER_MARKERS))
 		return -EINVAL;
 
-	if (cnt > TRACE_BUF_SIZE)
-		cnt = TRACE_BUF_SIZE;
-
-	BUILD_BUG_ON(TRACE_BUF_SIZE >= PAGE_SIZE);
-
-	size = sizeof(*entry) + cnt + 2; /* add '\0' and possible '\n' */
+	meta_size = sizeof(*entry) + 2;  /* add '\0' and possible '\n' */
+ again:
+	size = cnt + meta_size;
 
 	/* If less than "<faulted>", then make sure we can still add that */
 	if (cnt < FAULTED_SIZE)
@@ -7300,9 +7298,25 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 	buffer = tr->array_buffer.buffer;
 	event = __trace_buffer_lock_reserve(buffer, TRACE_PRINT, size,
 					    tracing_gen_ctx());
-	if (unlikely(!event))
+	if (unlikely(!event)) {
+		/*
+		 * If the size was greated than what was allowed, then
+		 * make it smaller and try again.
+		 */
+		if (size > ring_buffer_max_event_size(buffer)) {
+			/* cnt < FAULTED size should never be bigger than max */
+			if (WARN_ON_ONCE(cnt < FAULTED_SIZE))
+				return -EBADF;
+			cnt = ring_buffer_max_event_size(buffer) - meta_size;
+			/* The above should only happen once */
+			if (WARN_ON_ONCE(cnt + meta_size == size))
+				return -EBADF;
+			goto again;
+		}
+
 		/* Ring buffer disabled, return as if not open for write */
 		return -EBADF;
+	}
 
 	entry = ring_buffer_event_data(event);
 	entry->ip = _THIS_IP_;
-- 
2.42.0


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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-09 22:50 [PATCH] tracing: Allow for max buffer data size trace_marker writes Steven Rostedt
@ 2023-12-10 14:09 ` Mathieu Desnoyers
  2023-12-10 15:30   ` Steven Rostedt
  0 siblings, 1 reply; 7+ messages in thread
From: Mathieu Desnoyers @ 2023-12-10 14:09 UTC (permalink / raw)
  To: Steven Rostedt, LKML, Linux Trace Kernel; +Cc: Masami Hiramatsu, Mark Rutland

On 2023-12-09 17:50, Steven Rostedt wrote:
> From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
> 
> Allow a trace write to be as big as the ring buffer tracing data will
> allow. Currently, it only allows writes of 1KB in size, but there's no
> reason that it cannot allow what the ring buffer can hold.

I would expect the tests under tools/testing/selftests/ftrace/* to
be affected by those changes. If they are not, then it's a hole in
the test coverage and should be taken care of as this behavior is
modified.

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
https://www.efficios.com


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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-10 14:09 ` Mathieu Desnoyers
@ 2023-12-10 15:30   ` Steven Rostedt
  2023-12-10 16:07     ` Mathieu Desnoyers
  0 siblings, 1 reply; 7+ messages in thread
From: Steven Rostedt @ 2023-12-10 15:30 UTC (permalink / raw)
  To: Mathieu Desnoyers
  Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mark Rutland

On Sun, 10 Dec 2023 09:09:06 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> On 2023-12-09 17:50, Steven Rostedt wrote:
> > From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
> > 
> > Allow a trace write to be as big as the ring buffer tracing data will
> > allow. Currently, it only allows writes of 1KB in size, but there's no
> > reason that it cannot allow what the ring buffer can hold.  
> 
> I would expect the tests under tools/testing/selftests/ftrace/* to
> be affected by those changes. If they are not, then it's a hole in
> the test coverage and should be taken care of as this behavior is
> modified.
> 

Before this change we had:

~# echo -n '12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
 7890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
 4567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
 1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567
 89012345678901234567890123456789012345678901234567890123456789012345678901234' > /sys/kernel/tracing/trace_marker

~# cat /sys/kernel/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 4/4   #P:8
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
           <...>-2129    [007] ..... 246786.691139: tracing_mark_write: 12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
 78901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
           <...>-2129    [007] ..... 246786.691144: tracing_mark_write: 56789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
 12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
           <...>-2129    [007] ..... 246786.691145: tracing_mark_write: 90123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
 56789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012
           <...>-2129    [007] ..... 246786.691147: tracing_mark_write: 34567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
 90123456789012345678901234567890123456789012345678901234


After, we now have:

~# cat /sys/kernel/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 2/2   #P:8
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
            bash-13057   [006] ..... 44212.619656: tracing_mark_write: 123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567
 8901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
 5678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901
 2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
 90123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
            bash-13057   [006] ..... 44212.619688: tracing_mark_write: 78901234

It just allows more to be written in one go.

I don't see why the tests need to cover this or detect this change.

-- Steve

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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-10 15:30   ` Steven Rostedt
@ 2023-12-10 16:07     ` Mathieu Desnoyers
  2023-12-10 16:38       ` Steven Rostedt
  0 siblings, 1 reply; 7+ messages in thread
From: Mathieu Desnoyers @ 2023-12-10 16:07 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mark Rutland

On 2023-12-10 10:30, Steven Rostedt wrote:
> On Sun, 10 Dec 2023 09:09:06 -0500
> Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> 
>> On 2023-12-09 17:50, Steven Rostedt wrote:
>>> From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
>>>
>>> Allow a trace write to be as big as the ring buffer tracing data will
>>> allow. Currently, it only allows writes of 1KB in size, but there's no
>>> reason that it cannot allow what the ring buffer can hold.
>>
>> I would expect the tests under tools/testing/selftests/ftrace/* to
>> be affected by those changes. If they are not, then it's a hole in
>> the test coverage and should be taken care of as this behavior is
>> modified.
>>
> 
> Before this change we had:
> 
> ~# echo -n '12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
>   7890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
>   4567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
>   1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567
>   89012345678901234567890123456789012345678901234567890123456789012345678901234' > /sys/kernel/tracing/trace_marker
> 
> ~# cat /sys/kernel/tracing/trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 4/4   #P:8
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>             <...>-2129    [007] ..... 246786.691139: tracing_mark_write: 12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
>   78901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
>             <...>-2129    [007] ..... 246786.691144: tracing_mark_write: 56789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890
>   12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
>             <...>-2129    [007] ..... 246786.691145: tracing_mark_write: 90123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
>   56789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012
>             <...>-2129    [007] ..... 246786.691147: tracing_mark_write: 34567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
>   90123456789012345678901234567890123456789012345678901234
> 
> 
> After, we now have:
> 
> ~# cat /sys/kernel/tracing/trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 2/2   #P:8
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>              bash-13057   [006] ..... 44212.619656: tracing_mark_write: 123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567
>   8901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234
>   5678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901
>   2345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678
>   90123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
>              bash-13057   [006] ..... 44212.619688: tracing_mark_write: 78901234
> 
> It just allows more to be written in one go.
> 
> I don't see why the tests need to cover this or detect this change.

If the purpose of this change is to ensure that the entire
trace marker payload is shown within a single event, then
there should be a test which exercises this, and which
validates that the end result is that the entire payload
is indeed shown within a single event record.

Otherwise there is no permanent validation that this change
indeed does what it is intended to do, so it can regress
at any time without any test noticing it.

Thanks,

Mathieu

> 
> -- Steve

-- 
Mathieu Desnoyers
EfficiOS Inc.
https://www.efficios.com


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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-10 16:07     ` Mathieu Desnoyers
@ 2023-12-10 16:38       ` Steven Rostedt
  2023-12-10 17:28         ` Mathieu Desnoyers
  0 siblings, 1 reply; 7+ messages in thread
From: Steven Rostedt @ 2023-12-10 16:38 UTC (permalink / raw)
  To: Mathieu Desnoyers
  Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mark Rutland

On Sun, 10 Dec 2023 11:07:22 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> > It just allows more to be written in one go.
> > 
> > I don't see why the tests need to cover this or detect this change.  
> 
> If the purpose of this change is to ensure that the entire
> trace marker payload is shown within a single event, then
> there should be a test which exercises this, and which
> validates that the end result is that the entire payload
> is indeed shown within a single event record.

No, the purpose of the change is not to do that, because there can always
be a bigger trace marker write than a single event can hold. This is the
way it has always worked. This is an optimization or "enhancement". The 1KB
restriction was actually because of a previous implementation years ago
(before selftests even existed) that wrote into a temp buffer before
copying into the ring buffer. But since we now can copy directly into the
ring buffer, there's no reason not to use the maximum that the ring buffer
can accept.

> 
> Otherwise there is no permanent validation that this change
> indeed does what it is intended to do, so it can regress
> at any time without any test noticing it.

What regress? The amount of a trace_marker write that can make it into a
the buffer in one go? Now, I agree that we should have a test to make sure
that all of the trace marker write gets into the buffer. But it's always
been allowed to break up that write however it wanted to.

Note, because different architectures have different page sizes, how much
that can make it in one go is architecture dependent. So you can have a
"regression" by simply running your application on a different architecture.

Again, it's not a requirement, it's just an enhancement.

-- Steve

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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-10 16:38       ` Steven Rostedt
@ 2023-12-10 17:28         ` Mathieu Desnoyers
  2023-12-10 17:59           ` Steven Rostedt
  0 siblings, 1 reply; 7+ messages in thread
From: Mathieu Desnoyers @ 2023-12-10 17:28 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mark Rutland

On 2023-12-10 11:38, Steven Rostedt wrote:
> On Sun, 10 Dec 2023 11:07:22 -0500
> Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> 
>>> It just allows more to be written in one go.
>>>
>>> I don't see why the tests need to cover this or detect this change.
>>
>> If the purpose of this change is to ensure that the entire
>> trace marker payload is shown within a single event, then
>> there should be a test which exercises this, and which
>> validates that the end result is that the entire payload
>> is indeed shown within a single event record.
> 
> No, the purpose of the change is not to do that, because there can always
> be a bigger trace marker write than a single event can hold. This is the
> way it has always worked. This is an optimization or "enhancement". The 1KB
> restriction was actually because of a previous implementation years ago
> (before selftests even existed) that wrote into a temp buffer before
> copying into the ring buffer. But since we now can copy directly into the
> ring buffer, there's no reason not to use the maximum that the ring buffer
> can accept.

My point is that the difference between the new "enhanced" behavior
and the previous behavior is not tested for.

> 
>>
>> Otherwise there is no permanent validation that this change
>> indeed does what it is intended to do, so it can regress
>> at any time without any test noticing it.
> 
> What regress? The amount of a trace_marker write that can make it into a
> the buffer in one go? Now, I agree that we should have a test to make sure
> that all of the trace marker write gets into the buffer.

Yes. This is pretty much my point.


> But it's always
> been allowed to break up that write however it wanted to.

And the enhanced behavior extends the amount of data that can get
written into a single sub-buffer, and this is not tested.

> 
> Note, because different architectures have different page sizes, how much
> that can make it in one go is architecture dependent. So you can have a
> "regression" by simply running your application on a different architecture.

Which is why in the following patches you have expressing the subbuffer
size as bytes rather than pages is important at the ABI level. It
facilitates portability of tests, and decreases documentation / user
burden.

> Again, it's not a requirement, it's just an enhancement.

How does this have anything to do with dispensing from testing the
new behavior ? If the new behavior has a bug that causes it to
silently truncate the trace marker payloads, how do you catch it
with the current tests ?

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
https://www.efficios.com


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

* Re: [PATCH] tracing: Allow for max buffer data size trace_marker writes
  2023-12-10 17:28         ` Mathieu Desnoyers
@ 2023-12-10 17:59           ` Steven Rostedt
  0 siblings, 0 replies; 7+ messages in thread
From: Steven Rostedt @ 2023-12-10 17:59 UTC (permalink / raw)
  To: Mathieu Desnoyers
  Cc: LKML, Linux Trace Kernel, Masami Hiramatsu, Mark Rutland

On Sun, 10 Dec 2023 12:28:32 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> > Again, it's not a requirement, it's just an enhancement.  
> 
> How does this have anything to do with dispensing from testing the
> new behavior ? If the new behavior has a bug that causes it to
> silently truncate the trace marker payloads, how do you catch it
> with the current tests ?

I'm not disagreeing with you, but honestly, writing tests that can be
submitted, take up time I simply do not have. So it's either I get this
working and manually test it, or not apply it at all. This was a simple
change which is why I added it. The tests will take much longer to
write than the enhancement itself.

If someone wants to submit patches that test this further, I'd be more
than happy to apply them!

It may be several more months before I get the time to work on this any
further, and there's still several other features that are in my queue
to apply, where some of them will be affected by these changes.

Right now I'm just focused on that any of these changes do not cause
regressions in the workflow that others have. The trace_marker usage
that I've ever seen has been simple writes that are never more than a
couple of hundred bytes. The main reason I added this change was to
be able to test the subbuffer change. Otherwise I would never had made
this change.

Adding more tests is on my todo list, and not just for this, but for
other features. I do have a bunch of tests I run locally that are not
upsteam, but they are mostly hacks that require a lot of clean up
before being added to selftests.

-- Steve

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

end of thread, other threads:[~2023-12-10 18:15 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-12-09 22:50 [PATCH] tracing: Allow for max buffer data size trace_marker writes Steven Rostedt
2023-12-10 14:09 ` Mathieu Desnoyers
2023-12-10 15:30   ` Steven Rostedt
2023-12-10 16:07     ` Mathieu Desnoyers
2023-12-10 16:38       ` Steven Rostedt
2023-12-10 17:28         ` Mathieu Desnoyers
2023-12-10 17:59           ` Steven Rostedt

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).