| Message ID | edc9697b5140015b15c96cc1b505b3c53169e634.1440482404.git.panand@redhat.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Tue, 25 Aug 2015 11:34:19 +0530 Pratyush Anand <panand@redhat.com> 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 <panand@redhat.com> > Cc: Steven Rostedt <rostedt@goodmis.org> Acked-by: Steven Rostedt <rostedt@goodmis.org> -- 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 */ > -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Tue, 25 Aug 2015 11:34:19 +0530 Pratyush Anand <panand@redhat.com> 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 <panand@redhat.com> > Cc: Steven Rostedt <rostedt@goodmis.org> > --- > 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 */ >
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 <panand@redhat.com> 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 -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Wed, 26 Aug 2015 17:22:25 +0530 Pratyush Anand <panand@redhat.com> 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 <panand@redhat.com> 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.
On 26/08/2015:08:01:21 AM, Jeff Layton wrote: > On Wed, 26 Aug 2015 17:22:25 +0530 > Pratyush Anand <panand@redhat.com> 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 <panand@redhat.com> 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 -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
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 */
`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 <panand@redhat.com> Cc: Steven Rostedt <rostedt@goodmis.org> --- include/trace/events/sunrpc.h | 21 ++++++++++++++++----- 1 file changed, 16 insertions(+), 5 deletions(-)