Adding printk for syscall tracepoints for the tp_printk work.

Signed-off-by: Jeff Xie <xiehuan09@gmail.com>
---
 kernel/trace/trace_syscalls.c | 25 +++++++++++++++++++++++++
 1 file changed, 25 insertions(+)

diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index f755bde42fd0..9798122166d3 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -290,6 +290,25 @@ static int __init syscall_enter_define_fields(struct trace_event_call *call)
 	return ret;
 }
 
+static void syscall_output_printk(struct trace_entry *ent,
+		struct trace_event_file *trace_file, struct trace_array *tr)
+{
+	unsigned long flags;
+	struct trace_iterator *iter = tracepoint_print_iter;
+	struct trace_event *event = &trace_file->event_call->event;
+
+	spin_lock_irqsave(&tracepoint_iter_lock, flags);
+
+	trace_seq_init(&iter->seq);
+	iter->ent = ent;
+	iter->tr = tr;
+	event->funcs->trace(iter, 0, event);
+	trace_seq_putc(&iter->seq, 0);
+	pr_info("%s", iter->seq.buffer);
+
+	spin_unlock_irqrestore(&tracepoint_iter_lock, flags);
+}
+
 static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
 {
 	struct trace_array *tr = data;
@@ -333,6 +352,9 @@ static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
 	syscall_get_arguments(current, regs, args);
 	memcpy(entry->args, args, sizeof(unsigned long) * sys_data->nb_args);
 
+	if (static_key_false(&tracepoint_printk_key.key))
+		syscall_output_printk(&entry->ent, trace_file, tr);
+
 	event_trigger_unlock_commit(trace_file, buffer, event, entry,
 				    trace_ctx);
 }
@@ -376,6 +398,9 @@ static void ftrace_syscall_exit(void *data, struct pt_regs *regs, long ret)
 	entry->nr = syscall_nr;
 	entry->ret = syscall_get_return_value(current, regs);
 
+	if (static_key_false(&tracepoint_printk_key.key))
+		syscall_output_printk(&entry->ent, trace_file, tr);
+
 	event_trigger_unlock_commit(trace_file, buffer, event, entry,
 				    trace_ctx);
 }
-- 
2.25.1

On Wed, 30 Mar 2022 00:39:31 +0800
Jeff Xie <xiehuan09@gmail.com> wrote:

First, patch 1 and 2 can be folded into this patch. Making something
"available for future use" is not a reason to break up patches. It will not
help in bisecting, and its not something to be backported.

Next, the tracing subsystem follows the "Capitalize first letter" for
subjects:

 "tracing: Make tp_printk work on syscall tracepoints"

> Adding printk for syscall tracepoints for the tp_printk work.

Need to add much more content to the above. Your cover letter would work.

    Currently the tp_printk option has no effect on syscall tracepoint.
    When adding the kernel option parameter tp_printk, then:

    echo 1 > /sys/kernel/debug/tracing/events/syscalls/enable

    When running any application, no trace information is printed on the
    terminal.

    Now added printk for syscall tracepoints.

As commit logs should be self explanatory per commit. The cover letter was,
but this patch was lacking.


> 
> Signed-off-by: Jeff Xie <xiehuan09@gmail.com>
> ---
>  kernel/trace/trace_syscalls.c | 25 +++++++++++++++++++++++++
>  1 file changed, 25 insertions(+)
> 
> diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> index f755bde42fd0..9798122166d3 100644
> --- a/kernel/trace/trace_syscalls.c
> +++ b/kernel/trace/trace_syscalls.c
> @@ -290,6 +290,25 @@ static int __init syscall_enter_define_fields(struct trace_event_call *call)
>  	return ret;
>  }
>  
> +static void syscall_output_printk(struct trace_entry *ent,
> +		struct trace_event_file *trace_file, struct trace_array *tr)
> +{
> +	unsigned long flags;
> +	struct trace_iterator *iter = tracepoint_print_iter;
> +	struct trace_event *event = &trace_file->event_call->event;
> +
> +	spin_lock_irqsave(&tracepoint_iter_lock, flags);
> +
> +	trace_seq_init(&iter->seq);
> +	iter->ent = ent;
> +	iter->tr = tr;
> +	event->funcs->trace(iter, 0, event);
> +	trace_seq_putc(&iter->seq, 0);
> +	pr_info("%s", iter->seq.buffer);
> +
> +	spin_unlock_irqrestore(&tracepoint_iter_lock, flags);
> +}
> +
>  static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
>  {
>  	struct trace_array *tr = data;
> @@ -333,6 +352,9 @@ static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
>  	syscall_get_arguments(current, regs, args);
>  	memcpy(entry->args, args, sizeof(unsigned long) * sys_data->nb_args);
>  
> +	if (static_key_false(&tracepoint_printk_key.key))
> +		syscall_output_printk(&entry->ent, trace_file, tr);
> +
>  	event_trigger_unlock_commit(trace_file, buffer, event, entry,
>  				    trace_ctx);


>  }
> @@ -376,6 +398,9 @@ static void ftrace_syscall_exit(void *data, struct pt_regs *regs, long ret)
>  	entry->nr = syscall_nr;
>  	entry->ret = syscall_get_return_value(current, regs);
>  
> +	if (static_key_false(&tracepoint_printk_key.key))
> +		syscall_output_printk(&entry->ent, trace_file, tr);
> +

Instead of reimplementing the logic, just convert the syscall code to use,
trace_event_buffer_reserve() and trace_event_buffer_commit(), and then you
not only get tp_printk() for syscalls, but also other features as well.

-- Steve


>  	event_trigger_unlock_commit(trace_file, buffer, event, entry,
>  				    trace_ctx);
>  }

Hi steve,

On Sat, Apr 9, 2022 at 5:18 AM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Wed, 30 Mar 2022 00:39:31 +0800
> Jeff Xie <xiehuan09@gmail.com> wrote:
>
> First, patch 1 and 2 can be folded into this patch. Making something
> "available for future use" is not a reason to break up patches. It will not
> help in bisecting, and its not something to be backported.
>
> Next, the tracing subsystem follows the "Capitalize first letter" for
> subjects:
>
>  "tracing: Make tp_printk work on syscall tracepoints"
>
> > Adding printk for syscall tracepoints for the tp_printk work.
>
> Need to add much more content to the above. Your cover letter would work.
>
>     Currently the tp_printk option has no effect on syscall tracepoint.
>     When adding the kernel option parameter tp_printk, then:
>
>     echo 1 > /sys/kernel/debug/tracing/events/syscalls/enable
>
>     When running any application, no trace information is printed on the
>     terminal.
>
>     Now added printk for syscall tracepoints.
>
> As commit logs should be self explanatory per commit. The cover letter was,
> but this patch was lacking.

Thanks a lot for these detailed suggestions.

>
> >
> > Signed-off-by: Jeff Xie <xiehuan09@gmail.com>
> > ---
> >  kernel/trace/trace_syscalls.c | 25 +++++++++++++++++++++++++
> >  1 file changed, 25 insertions(+)
> >
> > diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> > index f755bde42fd0..9798122166d3 100644
> > --- a/kernel/trace/trace_syscalls.c
> > +++ b/kernel/trace/trace_syscalls.c
> > @@ -290,6 +290,25 @@ static int __init syscall_enter_define_fields(struct trace_event_call *call)
> >       return ret;
> >  }
> >
> > +static void syscall_output_printk(struct trace_entry *ent,
> > +             struct trace_event_file *trace_file, struct trace_array *tr)
> > +{
> > +     unsigned long flags;
> > +     struct trace_iterator *iter = tracepoint_print_iter;
> > +     struct trace_event *event = &trace_file->event_call->event;
> > +
> > +     spin_lock_irqsave(&tracepoint_iter_lock, flags);
> > +
> > +     trace_seq_init(&iter->seq);
> > +     iter->ent = ent;
> > +     iter->tr = tr;
> > +     event->funcs->trace(iter, 0, event);
> > +     trace_seq_putc(&iter->seq, 0);
> > +     pr_info("%s", iter->seq.buffer);
> > +
> > +     spin_unlock_irqrestore(&tracepoint_iter_lock, flags);
> > +}
> > +
> >  static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
> >  {
> >       struct trace_array *tr = data;
> > @@ -333,6 +352,9 @@ static void ftrace_syscall_enter(void *data, struct pt_regs *regs, long id)
> >       syscall_get_arguments(current, regs, args);
> >       memcpy(entry->args, args, sizeof(unsigned long) * sys_data->nb_args);
> >
> > +     if (static_key_false(&tracepoint_printk_key.key))
> > +             syscall_output_printk(&entry->ent, trace_file, tr);
> > +
> >       event_trigger_unlock_commit(trace_file, buffer, event, entry,
> >                                   trace_ctx);
>
>
> >  }
> > @@ -376,6 +398,9 @@ static void ftrace_syscall_exit(void *data, struct pt_regs *regs, long ret)
> >       entry->nr = syscall_nr;
> >       entry->ret = syscall_get_return_value(current, regs);
> >
> > +     if (static_key_false(&tracepoint_printk_key.key))
> > +             syscall_output_printk(&entry->ent, trace_file, tr);
> > +
>
> Instead of reimplementing the logic, just convert the syscall code to use,
> trace_event_buffer_reserve() and trace_event_buffer_commit(), and then you
> not only get tp_printk() for syscalls, but also other features as well.

Thanks, I will prepare the V2.

> -- Steve
>
>
> >       event_trigger_unlock_commit(trace_file, buffer, event, entry,
> >                                   trace_ctx);
> >  }
>
---
JeffXie