`perf stat -e sunrpc:svc_xprt_do_enqueue true` results in
Warning: unknown op '->'
Warning: [sunrpc:svc_xprt_do_enqueue] unknown op '->'
Similar warning for svc_handle_xprt as well.
Actually TP_printk() should never dereference an address saved in the ring
buffer that points somewhere in the kernel. There's no guarantee that that
object still exists (with the exception of static strings).
Therefore change all the arguments for TP_printk(), so that it references
values existing in the ring buffer only.
While doing that, also fix another possible bug when argument xprt could be
NULL and TP_fast_assign() tries to access it's elements.
Signed-off-by: Pratyush Anand <[email protected]>
Cc: Steven Rostedt <[email protected]>
---
include/trace/events/sunrpc.h | 21 ++++++++++++++++-----
1 file changed, 16 insertions(+), 5 deletions(-)
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index fd1a02cb3c82..937e482d80e9 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -529,18 +529,24 @@ TRACE_EVENT(svc_xprt_do_enqueue,
TP_STRUCT__entry(
__field(struct svc_xprt *, xprt)
+ __field(struct sockaddr *, addr)
__field(struct svc_rqst *, rqst)
+ __field(int, pid)
+ __field(unsigned long, flags)
),
TP_fast_assign(
__entry->xprt = xprt;
+ __entry->addr =
+ xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
__entry->rqst = rqst;
+ __entry->pid = rqst? rqst->rq_task->pid : 0;
+ __entry->flags = xprt ? xprt->xpt_flags : 0;
),
TP_printk("xprt=0x%p addr=%pIScp pid=%d flags=%s", __entry->xprt,
- (struct sockaddr *)&__entry->xprt->xpt_remote,
- __entry->rqst ? __entry->rqst->rq_task->pid : 0,
- show_svc_xprt_flags(__entry->xprt->xpt_flags))
+ __entry->addr, __entry->pid,
+ show_svc_xprt_flags(__entry->flags))
);
TRACE_EVENT(svc_xprt_dequeue,
@@ -589,16 +595,21 @@ TRACE_EVENT(svc_handle_xprt,
TP_STRUCT__entry(
__field(struct svc_xprt *, xprt)
__field(int, len)
+ __field(struct sockaddr *, addr)
+ __field(unsigned long, flags)
),
TP_fast_assign(
__entry->xprt = xprt;
+ __entry->addr =
+ xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
__entry->len = len;
+ __entry->flags = xprt ? xprt->xpt_flags : 0;
),
TP_printk("xprt=0x%p addr=%pIScp len=%d flags=%s", __entry->xprt,
- (struct sockaddr *)&__entry->xprt->xpt_remote, __entry->len,
- show_svc_xprt_flags(__entry->xprt->xpt_flags))
+ __entry->addr, __entry->len,
+ show_svc_xprt_flags(__entry->flags))
);
#endif /* _TRACE_SUNRPC_H */
--
2.4.3
On Tue, 25 Aug 2015 11:34:19 +0530
Pratyush Anand <[email protected]> wrote:
> `perf stat -e sunrpc:svc_xprt_do_enqueue true` results in
>
> Warning: unknown op '->'
> Warning: [sunrpc:svc_xprt_do_enqueue] unknown op '->'
>
> Similar warning for svc_handle_xprt as well.
>
> Actually TP_printk() should never dereference an address saved in the ring
> buffer that points somewhere in the kernel. There's no guarantee that that
> object still exists (with the exception of static strings).
Right, that is very dangerous. It has caused kernel panics in the past.
>
> Therefore change all the arguments for TP_printk(), so that it references
> values existing in the ring buffer only.
>
> While doing that, also fix another possible bug when argument xprt could be
> NULL and TP_fast_assign() tries to access it's elements.
>
> Signed-off-by: Pratyush Anand <[email protected]>
> Cc: Steven Rostedt <[email protected]>
Acked-by: Steven Rostedt <[email protected]>
-- Steve
> ---
> include/trace/events/sunrpc.h | 21 ++++++++++++++++-----
> 1 file changed, 16 insertions(+), 5 deletions(-)
>
> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
> index fd1a02cb3c82..937e482d80e9 100644
> --- a/include/trace/events/sunrpc.h
> +++ b/include/trace/events/sunrpc.h
> @@ -529,18 +529,24 @@ TRACE_EVENT(svc_xprt_do_enqueue,
>
> TP_STRUCT__entry(
> __field(struct svc_xprt *, xprt)
> + __field(struct sockaddr *, addr)
> __field(struct svc_rqst *, rqst)
> + __field(int, pid)
> + __field(unsigned long, flags)
> ),
>
> TP_fast_assign(
> __entry->xprt = xprt;
> + __entry->addr =
> + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
> __entry->rqst = rqst;
> + __entry->pid = rqst? rqst->rq_task->pid : 0;
> + __entry->flags = xprt ? xprt->xpt_flags : 0;
> ),
>
> TP_printk("xprt=0x%p addr=%pIScp pid=%d flags=%s", __entry->xprt,
> - (struct sockaddr *)&__entry->xprt->xpt_remote,
> - __entry->rqst ? __entry->rqst->rq_task->pid : 0,
> - show_svc_xprt_flags(__entry->xprt->xpt_flags))
> + __entry->addr, __entry->pid,
> + show_svc_xprt_flags(__entry->flags))
> );
>
> TRACE_EVENT(svc_xprt_dequeue,
> @@ -589,16 +595,21 @@ TRACE_EVENT(svc_handle_xprt,
> TP_STRUCT__entry(
> __field(struct svc_xprt *, xprt)
> __field(int, len)
> + __field(struct sockaddr *, addr)
> + __field(unsigned long, flags)
> ),
>
> TP_fast_assign(
> __entry->xprt = xprt;
> + __entry->addr =
> + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
> __entry->len = len;
> + __entry->flags = xprt ? xprt->xpt_flags : 0;
> ),
>
> TP_printk("xprt=0x%p addr=%pIScp len=%d flags=%s", __entry->xprt,
> - (struct sockaddr *)&__entry->xprt->xpt_remote, __entry->len,
> - show_svc_xprt_flags(__entry->xprt->xpt_flags))
> + __entry->addr, __entry->len,
> + show_svc_xprt_flags(__entry->flags))
> );
> #endif /* _TRACE_SUNRPC_H */
>
On Tue, 25 Aug 2015 11:34:19 +0530
Pratyush Anand <[email protected]> wrote:
> `perf stat -e sunrpc:svc_xprt_do_enqueue true` results in
>
> Warning: unknown op '->'
> Warning: [sunrpc:svc_xprt_do_enqueue] unknown op '->'
>
> Similar warning for svc_handle_xprt as well.
>
> Actually TP_printk() should never dereference an address saved in the ring
> buffer that points somewhere in the kernel. There's no guarantee that that
> object still exists (with the exception of static strings).
>
> Therefore change all the arguments for TP_printk(), so that it references
> values existing in the ring buffer only.
>
> While doing that, also fix another possible bug when argument xprt could be
> NULL and TP_fast_assign() tries to access it's elements.
>
> Signed-off-by: Pratyush Anand <[email protected]>
> Cc: Steven Rostedt <[email protected]>
> ---
> include/trace/events/sunrpc.h | 21 ++++++++++++++++-----
> 1 file changed, 16 insertions(+), 5 deletions(-)
>
> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
> index fd1a02cb3c82..937e482d80e9 100644
> --- a/include/trace/events/sunrpc.h
> +++ b/include/trace/events/sunrpc.h
> @@ -529,18 +529,24 @@ TRACE_EVENT(svc_xprt_do_enqueue,
>
> TP_STRUCT__entry(
> __field(struct svc_xprt *, xprt)
> + __field(struct sockaddr *, addr)
> __field(struct svc_rqst *, rqst)
> + __field(int, pid)
> + __field(unsigned long, flags)
> ),
>
> TP_fast_assign(
> __entry->xprt = xprt;
> + __entry->addr =
> + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
I don't get it. It's not safe to save a pointer to xprt and dereference
that in a tracepoint (and I understand why that is), but it is safe to
save a pointer to a structure embedded inside of xprt? Shouldn't you be
saving a copy of the entire sockaddr struct instead?
Ahh, ok -- I think I see the confusion. %pIScp does not print the
address of the sockaddr, but instead dereferences the pointer and
prints it as a formatted address string. See pointer() in
lib/vsprintf.c. You do want to save off a copy of the structure instead.
> __entry->rqst = rqst;
> + __entry->pid = rqst? rqst->rq_task->pid : 0;
> + __entry->flags = xprt ? xprt->xpt_flags : 0;
> ),
>
> TP_printk("xprt=0x%p addr=%pIScp pid=%d flags=%s",
> __entry->xprt,
> - (struct sockaddr *)&__entry->xprt->xpt_remote,
> - __entry->rqst ? __entry->rqst->rq_task->pid : 0,
> - show_svc_xprt_flags(__entry->xprt->xpt_flags))
> + __entry->addr, __entry->pid,
> + show_svc_xprt_flags(__entry->flags))
> );
>
> TRACE_EVENT(svc_xprt_dequeue,
> @@ -589,16 +595,21 @@ TRACE_EVENT(svc_handle_xprt,
> TP_STRUCT__entry(
> __field(struct svc_xprt *, xprt)
> __field(int, len)
> + __field(struct sockaddr *, addr)
> + __field(unsigned long, flags)
> ),
>
> TP_fast_assign(
> __entry->xprt = xprt;
> + __entry->addr =
> + xprt ? (struct sockaddr
> *)&xprt->xpt_remote : NULL; __entry->len = len;
> + __entry->flags = xprt ? xprt->xpt_flags : 0;
> ),
>
> TP_printk("xprt=0x%p addr=%pIScp len=%d flags=%s",
> __entry->xprt,
> - (struct sockaddr *)&__entry->xprt->xpt_remote,
> __entry->len,
> - show_svc_xprt_flags(__entry->xprt->xpt_flags))
> + __entry->addr, __entry->len,
> + show_svc_xprt_flags(__entry->flags))
> );
> #endif /* _TRACE_SUNRPC_H */
>
--
Jeff Layton <[email protected]>
Hi Jeff,
Thanks for your review comments.
On 26/08/2015:06:31:03 AM, Jeff Layton wrote:
> On Tue, 25 Aug 2015 11:34:19 +0530
> Pratyush Anand <[email protected]> wrote:
> > TP_fast_assign(
> > __entry->xprt = xprt;
> > + __entry->addr =
> > + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
>
> I don't get it. It's not safe to save a pointer to xprt and dereference
> that in a tracepoint (and I understand why that is), but it is safe to
> save a pointer to a structure embedded inside of xprt? Shouldn't you be
> saving a copy of the entire sockaddr struct instead?
As far as "saving of a pointer to a structure embedded inside of xprt" is
concerned, I do not see any issue.
Its your take that what you want to print as your tracepoint print output. I
might be missing something.. However, I do not see any value addition in
printing address of a structure(located in ring buffer) where xprt->xpt_remote
has been copied.
>
> Ahh, ok -- I think I see the confusion. %pIScp does not print the
> address of the sockaddr, but instead dereferences the pointer and
> prints it as a formatted address string. See pointer() in
> lib/vsprintf.c. You do want to save off a copy of the structure instead.
In my opinion, saving of structure would only be necessary if you want to access
element of the structure xprt->xpt_remote.
~Pratyush
On Wed, 26 Aug 2015 17:22:25 +0530
Pratyush Anand <[email protected]> wrote:
> Hi Jeff,
>
> Thanks for your review comments.
>
> On 26/08/2015:06:31:03 AM, Jeff Layton wrote:
> > On Tue, 25 Aug 2015 11:34:19 +0530
> > Pratyush Anand <[email protected]> wrote:
> > > TP_fast_assign(
> > > __entry->xprt = xprt;
> > > + __entry->addr =
> > > + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
> >
> > I don't get it. It's not safe to save a pointer to xprt and dereference
> > that in a tracepoint (and I understand why that is), but it is safe to
> > save a pointer to a structure embedded inside of xprt? Shouldn't you be
> > saving a copy of the entire sockaddr struct instead?
>
> As far as "saving of a pointer to a structure embedded inside of xprt" is
> concerned, I do not see any issue.
>
> Its your take that what you want to print as your tracepoint print output. I
> might be missing something.. However, I do not see any value addition in
> printing address of a structure(located in ring buffer) where xprt->xpt_remote
> has been copied.
>
> >
> > Ahh, ok -- I think I see the confusion. %pIScp does not print the
> > address of the sockaddr, but instead dereferences the pointer and
> > prints it as a formatted address string. See pointer() in
> > lib/vsprintf.c. You do want to save off a copy of the structure instead.
>
> In my opinion, saving of structure would only be necessary if you want to access
> element of the structure xprt->xpt_remote.
>
> ~Pratyush
That's exactly what %pI does. Look at the pointer() function.
For this tracepoint, we want to print out the address of the remote end
of the socket. That's saved in xprt->xpt_remote.
%pIScp doesn't print the pointer's address. It dereferences that
pointer and formats and prints the socket address that it points to. If
you pass a NULL pointer into anything that uses %pI, it's going to oops.
--
Jeff Layton <[email protected]>
On 26/08/2015:08:01:21 AM, Jeff Layton wrote:
> On Wed, 26 Aug 2015 17:22:25 +0530
> Pratyush Anand <[email protected]> wrote:
>
> > Hi Jeff,
> >
> > Thanks for your review comments.
> >
> > On 26/08/2015:06:31:03 AM, Jeff Layton wrote:
> > > On Tue, 25 Aug 2015 11:34:19 +0530
> > > Pratyush Anand <[email protected]> wrote:
> > > > TP_fast_assign(
> > > > __entry->xprt = xprt;
> > > > + __entry->addr =
> > > > + xprt ? (struct sockaddr *)&xprt->xpt_remote : NULL;
> > >
> > > I don't get it. It's not safe to save a pointer to xprt and dereference
> > > that in a tracepoint (and I understand why that is), but it is safe to
> > > save a pointer to a structure embedded inside of xprt? Shouldn't you be
> > > saving a copy of the entire sockaddr struct instead?
> >
> > As far as "saving of a pointer to a structure embedded inside of xprt" is
> > concerned, I do not see any issue.
> >
> > Its your take that what you want to print as your tracepoint print output. I
> > might be missing something.. However, I do not see any value addition in
> > printing address of a structure(located in ring buffer) where xprt->xpt_remote
> > has been copied.
> >
> > >
> > > Ahh, ok -- I think I see the confusion. %pIScp does not print the
> > > address of the sockaddr, but instead dereferences the pointer and
> > > prints it as a formatted address string. See pointer() in
> > > lib/vsprintf.c. You do want to save off a copy of the structure instead.
> >
> > In my opinion, saving of structure would only be necessary if you want to access
> > element of the structure xprt->xpt_remote.
> >
> > ~Pratyush
>
> That's exactly what %pI does. Look at the pointer() function.
My bad..am a slow learner :(
Will send V2. Thanks for explaining.
~Pratyush