Re: [Intel-gfx] [PATCH 1/4] drm/i915: Add request cancel low level trace point

From: Tvrtko Ursulin <tvrtko.ursulin@linux.intel.com>
To: Matthew Brost <matthew.brost@intel.com>
Cc: intel-gfx@lists.freedesktop.org, dri-devel@lists.freedesktop.org
Subject: Re: [Intel-gfx] [PATCH 1/4] drm/i915: Add request cancel low level trace point
Date: Wed, 26 Jan 2022 10:29:21 +0000	[thread overview]
Message-ID: <abc9273c-4054-3c09-f584-22dcf33a34e6@linux.intel.com> (raw)
In-Reply-To: <20220125163911.GA20056@jons-linux-dev-box>

On 25/01/2022 16:39, Matthew Brost wrote:
> On Tue, Jan 25, 2022 at 12:27:43PM +0000, Tvrtko Ursulin wrote:
>>
>> On 24/01/2022 15:01, Matthew Brost wrote:
>>> Add request cancel trace point guarded by
>>> CONFIG_DRM_I915_LOW_LEVEL_TRACEPOINT.
>>
>> Okay-ish I guess (There is pr_notice with the only real caller, but I
>> suppose you want it for selftests? Oh yes, why is missing from the commit
>> message.), but I'd emit it from i915_request_cancel since that's what the
>> tracepoint is called so it fits.
>>
> 
> I had this tracepoint at one point but somehow during the upstreaming it
> got lost. Noticed when debugging the below issue this tracepoint wasn't
> present, so I brought it back in.
> 
> I generally use low level tracepoints for debug, so a pr_notice doesn't
> really help there.
> 
> Link: https://gitlab.freedesktop.org/drm/intel/-/issues/4960

This was a GuC backend bug right? And log shows this:

<7> [275.431050] [drm:eb_lookup_vmas [i915]] EINVAL at eb_validate_vma:514
<5> [295.433920] Fence expiration time out i915-0000:03:00.0:kms_vblank[1038]:2!
<3> [332.736763] INFO: task kworker/2:1:55 blocked for more than 30 seconds.

So pr_notice worked. I am not opposed to the tracepoint just put a solid why in the commit message and if the tracepoint is called i915_request_cancel it should be emitted from i915_request_cancel().

Regards,

Tvrtko

> 
> Matt
> 
>> Regards,
>>
>> Tvrtko
>>
>>> Signed-off-by: Matthew Brost <matthew.brost@intel.com>
>>> ---
>>>    drivers/gpu/drm/i915/gt/intel_context.h |  1 +
>>>    drivers/gpu/drm/i915/i915_trace.h       | 10 ++++++++++
>>>    2 files changed, 11 insertions(+)
>>>
>>> diff --git a/drivers/gpu/drm/i915/gt/intel_context.h b/drivers/gpu/drm/i915/gt/intel_context.h
>>> index d8c74bbf9aae2..3aed4d77f116c 100644
>>> --- a/drivers/gpu/drm/i915/gt/intel_context.h
>>> +++ b/drivers/gpu/drm/i915/gt/intel_context.h
>>> @@ -124,6 +124,7 @@ intel_context_is_pinned(struct intel_context *ce)
>>>    static inline void intel_context_cancel_request(struct intel_context *ce,
>>>    						struct i915_request *rq)
>>>    {
>>> +	trace_i915_request_cancel(rq);
>>>    	GEM_BUG_ON(!ce->ops->cancel_request);
>>>    	return ce->ops->cancel_request(ce, rq);
>>>    }
>>> diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h
>>> index 37b5c9e9d260e..d0a11a8bb0ca3 100644
>>> --- a/drivers/gpu/drm/i915/i915_trace.h
>>> +++ b/drivers/gpu/drm/i915/i915_trace.h
>>> @@ -324,6 +324,11 @@ DEFINE_EVENT(i915_request, i915_request_add,
>>>    );
>>>    #if defined(CONFIG_DRM_I915_LOW_LEVEL_TRACEPOINTS)
>>> +DEFINE_EVENT(i915_request, i915_request_cancel,
>>> +	     TP_PROTO(struct i915_request *rq),
>>> +	     TP_ARGS(rq)
>>> +);
>>> +
>>>    DEFINE_EVENT(i915_request, i915_request_guc_submit,
>>>    	     TP_PROTO(struct i915_request *rq),
>>>    	     TP_ARGS(rq)
>>> @@ -497,6 +502,11 @@ DEFINE_EVENT(intel_context, intel_context_do_unpin,
>>>    #else
>>>    #if !defined(TRACE_HEADER_MULTI_READ)
>>> +static inline void
>>> +trace_i915_request_cancel(struct i915_request *rq)
>>> +{
>>> +}
>>> +
>>>    static inline void
>>>    trace_i915_request_guc_submit(struct i915_request *rq)
>>>    {
>>>