| Message ID | 20170221091350.14605-3-tvrtko.ursulin@linux.intel.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Tue, Feb 21, 2017 at 09:13:45AM +0000, Tvrtko Ursulin wrote: > From: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > > Provide the same information as the other request event classes. > > v2: Pass in flags so we can properly report the blocking status. > (Chris Wilson) > > v3: Log hex with 0x prefix for clarity. > > Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > --- > drivers/gpu/drm/i915/i915_gem_request.c | 2 +- > drivers/gpu/drm/i915/i915_trace.h | 21 +++++++++++++-------- > 2 files changed, 14 insertions(+), 9 deletions(-) > > diff --git a/drivers/gpu/drm/i915/i915_gem_request.c b/drivers/gpu/drm/i915/i915_gem_request.c > index a5fac40d2a4f..543cef57972b 100644 > --- a/drivers/gpu/drm/i915/i915_gem_request.c > +++ b/drivers/gpu/drm/i915/i915_gem_request.c > @@ -1092,7 +1092,7 @@ long i915_wait_request(struct drm_i915_gem_request *req, > if (!timeout) > return -ETIME; > > - trace_i915_gem_request_wait_begin(req); > + trace_i915_gem_request_wait_begin(req, flags); > > if (!i915_sw_fence_done(&req->execute)) { > timeout = __i915_request_wait_for_execute(req, flags, timeout); > diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h > index d9ade8c38f92..916aadbb5389 100644 > --- a/drivers/gpu/drm/i915/i915_trace.h > +++ b/drivers/gpu/drm/i915/i915_trace.h > @@ -508,13 +508,16 @@ DEFINE_EVENT(i915_gem_request, i915_gem_request_complete, > ); > > TRACE_EVENT(i915_gem_request_wait_begin, > - TP_PROTO(struct drm_i915_gem_request *req), > - TP_ARGS(req), > + TP_PROTO(struct drm_i915_gem_request *req, unsigned int flags), > + TP_ARGS(req, flags), > > TP_STRUCT__entry( > __field(u32, dev) > __field(u32, ring) > + __field(u32, ctx) > __field(u32, seqno) > + __field(u32, global) > + __field(unsigned int, flags) > __field(bool, blocking) > ), > > @@ -527,14 +530,16 @@ TRACE_EVENT(i915_gem_request_wait_begin, > TP_fast_assign( > __entry->dev = req->i915->drm.primary->index; > __entry->ring = req->engine->id; > - __entry->seqno = req->global_seqno; > - __entry->blocking = > - mutex_is_locked(&req->i915->drm.struct_mutex); > + __entry->ctx = req->ctx->hw_id; > + __entry->seqno = req->fence.seqno; > + __entry->global = req->global_seqno; > + __entry->flags = flags; > + __entry->blocking = flags & I915_WAIT_LOCKED; > ), > > - TP_printk("dev=%u, ring=%u, seqno=%u, blocking=%s", > - __entry->dev, __entry->ring, > - __entry->seqno, __entry->blocking ? "yes (NB)" : "no") > + TP_printk("dev=%u, ring=%u, ctx=%u, seqno=%u, global=%u, blocking=%u, flags=0x%x", > + __entry->dev, __entry->ring, __entry->ctx, __entry->seqno, > + __entry->global, __entry->blocking, __entry->flags) We don't need to store bool blocking, we can just pluck it out of flags in the printk. Hmm. How should we handle global changing value in the course of the wait? -Chris
On 21/02/2017 09:50, Chris Wilson wrote: > On Tue, Feb 21, 2017 at 09:13:45AM +0000, Tvrtko Ursulin wrote: >> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com> >> >> Provide the same information as the other request event classes. >> >> v2: Pass in flags so we can properly report the blocking status. >> (Chris Wilson) >> >> v3: Log hex with 0x prefix for clarity. >> >> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com> >> --- >> drivers/gpu/drm/i915/i915_gem_request.c | 2 +- >> drivers/gpu/drm/i915/i915_trace.h | 21 ++++++++++++-------- >> 2 files changed, 14 insertions(+), 9 deletions(-) >> >> diff --git a/drivers/gpu/drm/i915/i915_gem_request.c b/drivers/gpu/drm/i915/i915_gem_request.c >> index a5fac40d2a4f..543cef57972b 100644 >> --- a/drivers/gpu/drm/i915/i915_gem_request.c >> +++ b/drivers/gpu/drm/i915/i915_gem_request.c >> @@ -1092,7 +1092,7 @@ long i915_wait_request(struct drm_i915_gem_request *req, >> if (!timeout) >> return -ETIME; >> >> - trace_i915_gem_request_wait_begin(req); >> + trace_i915_gem_request_wait_begin(req, flags); >> >> if (!i915_sw_fence_done(&req->execute)) { >> timeout = __i915_request_wait_for_execute(req, flags, timeout); >> diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h >> index d9ade8c38f92..916aadbb5389 100644 >> --- a/drivers/gpu/drm/i915/i915_trace.h >> +++ b/drivers/gpu/drm/i915/i915_trace.h >> @@ -508,13 +508,16 @@ DEFINE_EVENT(i915_gem_request, i915_gem_request_complete, >> ); >> >> TRACE_EVENT(i915_gem_request_wait_begin, >> - TP_PROTO(struct drm_i915_gem_request *req), >> - TP_ARGS(req), >> + TP_PROTO(struct drm_i915_gem_request *req, unsigned int flags), >> + TP_ARGS(req, flags), >> >> TP_STRUCT__entry( >> __field(u32, dev) >> __field(u32, ring) >> + __field(u32, ctx) >> __field(u32, seqno) >> + __field(u32, global) >> + __field(unsigned int, flags) >> __field(bool, blocking) >> ), >> >> @@ -527,14 +530,16 @@ TRACE_EVENT(i915_gem_request_wait_begin, >> TP_fast_assign( >> __entry->dev = req->i915->drm.primary->index; >> __entry->ring = req->engine->id; >> - __entry->seqno = req->global_seqno; >> - __entry->blocking = >> - mutex_is_locked(&req->i915->drm.struct_mutex); >> + __entry->ctx = req->ctx->hw_id; >> + __entry->seqno = req->fence.seqno; >> + __entry->global = req->global_seqno; >> + __entry->flags = flags; >> + __entry->blocking = flags & I915_WAIT_LOCKED; >> ), >> >> - TP_printk("dev=%u, ring=%u, seqno=%u, blocking=%s", >> - __entry->dev, __entry->ring, >> - __entry->seqno, __entry->blocking ? "yes (NB)" : "no") >> + TP_printk("dev=%u, ring=%u, ctx=%u, seqno=%u, global=%u, blocking=%u, flags=0x%x", >> + __entry->dev, __entry->ring, __entry->ctx, __entry->seqno, >> + __entry->global, __entry->blocking, __entry->flags) > > We don't need to store bool blocking, we can just pluck it out of flags > in the printk. Ok. > Hmm. How should we handle global changing value in the course of the > wait? How would you do that? It will get logged at the end of the wait and ctx/ring/seqno can be used as an unique identifier to match the two ends. Regards, Tvrtko
On Tue, Feb 21, 2017 at 10:10:09AM +0000, Tvrtko Ursulin wrote: > > On 21/02/2017 09:50, Chris Wilson wrote: > >Hmm. How should we handle global changing value in the course of the > >wait? > > How would you do that? It will get logged at the end of the wait and > ctx/ring/seqno can be used as an unique identifier to match the two > ends. I was wondering what value global had in the early tracepoint. It tells us if the wait begins before the request was executed. Then at the end, you can see if it was interrupted by seeing if global changed. It will definitely help in the trivial cases of reading through the logs and tieing the waits to the execution - I just forsee some confusion occasionally :) -Chris
diff --git a/drivers/gpu/drm/i915/i915_gem_request.c b/drivers/gpu/drm/i915/i915_gem_request.c index a5fac40d2a4f..543cef57972b 100644 --- a/drivers/gpu/drm/i915/i915_gem_request.c +++ b/drivers/gpu/drm/i915/i915_gem_request.c @@ -1092,7 +1092,7 @@ long i915_wait_request(struct drm_i915_gem_request *req, if (!timeout) return -ETIME; - trace_i915_gem_request_wait_begin(req); + trace_i915_gem_request_wait_begin(req, flags); if (!i915_sw_fence_done(&req->execute)) { timeout = __i915_request_wait_for_execute(req, flags, timeout); diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h index d9ade8c38f92..916aadbb5389 100644 --- a/drivers/gpu/drm/i915/i915_trace.h +++ b/drivers/gpu/drm/i915/i915_trace.h @@ -508,13 +508,16 @@ DEFINE_EVENT(i915_gem_request, i915_gem_request_complete, ); TRACE_EVENT(i915_gem_request_wait_begin, - TP_PROTO(struct drm_i915_gem_request *req), - TP_ARGS(req), + TP_PROTO(struct drm_i915_gem_request *req, unsigned int flags), + TP_ARGS(req, flags), TP_STRUCT__entry( __field(u32, dev) __field(u32, ring) + __field(u32, ctx) __field(u32, seqno) + __field(u32, global) + __field(unsigned int, flags) __field(bool, blocking) ), @@ -527,14 +530,16 @@ TRACE_EVENT(i915_gem_request_wait_begin, TP_fast_assign( __entry->dev = req->i915->drm.primary->index; __entry->ring = req->engine->id; - __entry->seqno = req->global_seqno; - __entry->blocking = - mutex_is_locked(&req->i915->drm.struct_mutex); + __entry->ctx = req->ctx->hw_id; + __entry->seqno = req->fence.seqno; + __entry->global = req->global_seqno; + __entry->flags = flags; + __entry->blocking = flags & I915_WAIT_LOCKED; ), - TP_printk("dev=%u, ring=%u, seqno=%u, blocking=%s", - __entry->dev, __entry->ring, - __entry->seqno, __entry->blocking ? "yes (NB)" : "no") + TP_printk("dev=%u, ring=%u, ctx=%u, seqno=%u, global=%u, blocking=%u, flags=0x%x", + __entry->dev, __entry->ring, __entry->ctx, __entry->seqno, + __entry->global, __entry->blocking, __entry->flags) ); DEFINE_EVENT(i915_gem_request, i915_gem_request_wait_end,