[Intel-gfx] [PATCH 3/8] drm/i915/tracepoints: Tidy i915_gem_request_wait_begin

[Tvrtko Ursulin]

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 at 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 at 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