diff mbox

[2/2] drm/i915: Include completed status in HW request tracepoints

Message ID 20180501151309.10787-2-chris@chris-wilson.co.uk (mailing list archive)
State New, archived
Headers show

Commit Message

Chris Wilson May 1, 2018, 3:13 p.m. UTC
Include a bool to show whether the request is complete in every
tracepoint. This especially helps when tracing the flow of requests
through the HW.

v2: Limit to in/out HW events, not all general request tracepoints.

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
---
 drivers/gpu/drm/i915/i915_trace.h           | 17 +++++++++++------
 drivers/gpu/drm/i915/intel_guc_submission.c |  2 +-
 drivers/gpu/drm/i915/intel_lrc.c            |  2 +-
 3 files changed, 13 insertions(+), 8 deletions(-)

Comments

Tvrtko Ursulin May 1, 2018, 3:26 p.m. UTC | #1
On 01/05/2018 16:13, Chris Wilson wrote:
> Include a bool to show whether the request is complete in every
> tracepoint. This especially helps when tracing the flow of requests
> through the HW.
> 
> v2: Limit to in/out HW events, not all general request tracepoints.
> 
> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> ---
>   drivers/gpu/drm/i915/i915_trace.h           | 17 +++++++++++------
>   drivers/gpu/drm/i915/intel_guc_submission.c |  2 +-
>   drivers/gpu/drm/i915/intel_lrc.c            |  2 +-
>   3 files changed, 13 insertions(+), 8 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h
> index 408827bf5d96..66956af25da3 100644
> --- a/drivers/gpu/drm/i915/i915_trace.h
> +++ b/drivers/gpu/drm/i915/i915_trace.h
> @@ -691,6 +691,8 @@ DECLARE_EVENT_CLASS(i915_request_hw,
>   				     __field(u32, seqno)
>   				     __field(u32, global_seqno)
>   				     __field(u32, port)
> +				     __field(u32, prio)
> +				     __field(u32, completed)
>   				    ),
>   
>   		    TP_fast_assign(
> @@ -701,12 +703,15 @@ DECLARE_EVENT_CLASS(i915_request_hw,
>   				   __entry->seqno = rq->fence.seqno;
>   				   __entry->global_seqno = rq->global_seqno;
>   				   __entry->port = port;
> +				   __entry->prio = rq->sched.attr.priority;
> +				   __entry->completed = i915_request_completed(rq);
>   				  ),
>   
> -		    TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, global=%u, port=%u",
> +		    TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, prio=%u, global=%u, port=%u, completed?=%d",
>   			      __entry->dev, __entry->hw_id, __entry->ring,
> -			      __entry->ctx, __entry->seqno,
> -			      __entry->global_seqno, __entry->port)
> +			      __entry->ctx, __entry->seqno, __entry->prio,
> +			      __entry->global_seqno, __entry->port,
> +			      __entry->completed)
>   );
>   
>   DEFINE_EVENT(i915_request_hw, i915_request_in,
> @@ -714,9 +719,9 @@ DEFINE_EVENT(i915_request_hw, i915_request_in,
>   	     TP_ARGS(rq, port)
>   );
>   
> -DEFINE_EVENT(i915_request, i915_request_out,
> -	     TP_PROTO(struct i915_request *rq),
> -	     TP_ARGS(rq)
> +DEFINE_EVENT(i915_request_hw, i915_request_out,
> +	     TP_PROTO(struct i915_request *rq, unsigned int port),
> +	     TP_ARGS(rq, port)
>   );
>   #else
>   #if !defined(TRACE_HEADER_MULTI_READ)
> diff --git a/drivers/gpu/drm/i915/intel_guc_submission.c b/drivers/gpu/drm/i915/intel_guc_submission.c
> index c6bb5bebddfc..bd440687892a 100644
> --- a/drivers/gpu/drm/i915/intel_guc_submission.c
> +++ b/drivers/gpu/drm/i915/intel_guc_submission.c
> @@ -762,7 +762,7 @@ static void guc_submission_tasklet(unsigned long data)
>   
>   	rq = port_request(port);
>   	while (rq && i915_request_completed(rq)) {
> -		trace_i915_request_out(rq);
> +		trace_i915_request_out(rq, 0);
>   		i915_request_put(rq);
>   
>   		port = execlists_port_complete(execlists, port);
> diff --git a/drivers/gpu/drm/i915/intel_lrc.c b/drivers/gpu/drm/i915/intel_lrc.c
> index ffc74f562f77..396d9596d0aa 100644
> --- a/drivers/gpu/drm/i915/intel_lrc.c
> +++ b/drivers/gpu/drm/i915/intel_lrc.c
> @@ -402,7 +402,7 @@ execlists_context_schedule_out(struct i915_request *rq, unsigned long status)
>   {
>   	intel_engine_context_out(rq->engine);
>   	execlists_context_status_change(rq, status);
> -	trace_i915_request_out(rq);
> +	trace_i915_request_out(rq, 0);
>   }
>   
>   static void
> 

Another one! :) For simplicity:

Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Regards,

Tvrtko
Tvrtko Ursulin May 1, 2018, 3:41 p.m. UTC | #2
On 01/05/2018 16:26, Tvrtko Ursulin wrote:
> 
> On 01/05/2018 16:13, Chris Wilson wrote:
>> Include a bool to show whether the request is complete in every
>> tracepoint. This especially helps when tracing the flow of requests
>> through the HW.
>>
>> v2: Limit to in/out HW events, not all general request tracepoints.
>>
>> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
>> ---
>>   drivers/gpu/drm/i915/i915_trace.h           | 17 +++++++++++------
>>   drivers/gpu/drm/i915/intel_guc_submission.c |  2 +-
>>   drivers/gpu/drm/i915/intel_lrc.c            |  2 +-
>>   3 files changed, 13 insertions(+), 8 deletions(-)
>>
>> diff --git a/drivers/gpu/drm/i915/i915_trace.h 
>> b/drivers/gpu/drm/i915/i915_trace.h
>> index 408827bf5d96..66956af25da3 100644
>> --- a/drivers/gpu/drm/i915/i915_trace.h
>> +++ b/drivers/gpu/drm/i915/i915_trace.h
>> @@ -691,6 +691,8 @@ DECLARE_EVENT_CLASS(i915_request_hw,
>>                        __field(u32, seqno)
>>                        __field(u32, global_seqno)
>>                        __field(u32, port)
>> +                     __field(u32, prio)
>> +                     __field(u32, completed)
>>                       ),
>>               TP_fast_assign(
>> @@ -701,12 +703,15 @@ DECLARE_EVENT_CLASS(i915_request_hw,
>>                      __entry->seqno = rq->fence.seqno;
>>                      __entry->global_seqno = rq->global_seqno;
>>                      __entry->port = port;
>> +                   __entry->prio = rq->sched.attr.priority;
>> +                   __entry->completed = i915_request_completed(rq);
>>                     ),
>> -            TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, 
>> global=%u, port=%u",
>> +            TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, 
>> prio=%u, global=%u, port=%u, completed?=%d",
>>                     __entry->dev, __entry->hw_id, __entry->ring,
>> -                  __entry->ctx, __entry->seqno,
>> -                  __entry->global_seqno, __entry->port)
>> +                  __entry->ctx, __entry->seqno, __entry->prio,
>> +                  __entry->global_seqno, __entry->port,
>> +                  __entry->completed)
>>   );
>>   DEFINE_EVENT(i915_request_hw, i915_request_in,
>> @@ -714,9 +719,9 @@ DEFINE_EVENT(i915_request_hw, i915_request_in,
>>            TP_ARGS(rq, port)
>>   );
>> -DEFINE_EVENT(i915_request, i915_request_out,
>> -         TP_PROTO(struct i915_request *rq),
>> -         TP_ARGS(rq)
>> +DEFINE_EVENT(i915_request_hw, i915_request_out,
>> +         TP_PROTO(struct i915_request *rq, unsigned int port),
>> +         TP_ARGS(rq, port)
>>   );
>>   #else
>>   #if !defined(TRACE_HEADER_MULTI_READ)
>> diff --git a/drivers/gpu/drm/i915/intel_guc_submission.c 
>> b/drivers/gpu/drm/i915/intel_guc_submission.c
>> index c6bb5bebddfc..bd440687892a 100644
>> --- a/drivers/gpu/drm/i915/intel_guc_submission.c
>> +++ b/drivers/gpu/drm/i915/intel_guc_submission.c
>> @@ -762,7 +762,7 @@ static void guc_submission_tasklet(unsigned long 
>> data)
>>       rq = port_request(port);
>>       while (rq && i915_request_completed(rq)) {
>> -        trace_i915_request_out(rq);
>> +        trace_i915_request_out(rq, 0);
>>           i915_request_put(rq);
>>           port = execlists_port_complete(execlists, port);
>> diff --git a/drivers/gpu/drm/i915/intel_lrc.c 
>> b/drivers/gpu/drm/i915/intel_lrc.c
>> index ffc74f562f77..396d9596d0aa 100644
>> --- a/drivers/gpu/drm/i915/intel_lrc.c
>> +++ b/drivers/gpu/drm/i915/intel_lrc.c
>> @@ -402,7 +402,7 @@ execlists_context_schedule_out(struct i915_request 
>> *rq, unsigned long status)
>>   {
>>       intel_engine_context_out(rq->engine);
>>       execlists_context_status_change(rq, status);
>> -    trace_i915_request_out(rq);
>> +    trace_i915_request_out(rq, 0);
>>   }
>>   static void
>>
> 
> Another one! :) For simplicity:
> 
> Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Well actually on a second thought I think it would be tidier to define 
in and out separately so not to pollute the logs with pointless fields. 
If you are busy I am happy to do that.

Regards,

Tvrtko
Chris Wilson May 1, 2018, 3:43 p.m. UTC | #3
Quoting Tvrtko Ursulin (2018-05-01 16:41:15)
> 
> On 01/05/2018 16:26, Tvrtko Ursulin wrote:
> > 
> > On 01/05/2018 16:13, Chris Wilson wrote:
> >> Include a bool to show whether the request is complete in every
> >> tracepoint. This especially helps when tracing the flow of requests
> >> through the HW.
> >>
> >> v2: Limit to in/out HW events, not all general request tracepoints.
> >>
> >> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> >> ---
> >>   drivers/gpu/drm/i915/i915_trace.h           | 17 +++++++++++------
> >>   drivers/gpu/drm/i915/intel_guc_submission.c |  2 +-
> >>   drivers/gpu/drm/i915/intel_lrc.c            |  2 +-
> >>   3 files changed, 13 insertions(+), 8 deletions(-)
> >>
> >> diff --git a/drivers/gpu/drm/i915/i915_trace.h 
> >> b/drivers/gpu/drm/i915/i915_trace.h
> >> index 408827bf5d96..66956af25da3 100644
> >> --- a/drivers/gpu/drm/i915/i915_trace.h
> >> +++ b/drivers/gpu/drm/i915/i915_trace.h
> >> @@ -691,6 +691,8 @@ DECLARE_EVENT_CLASS(i915_request_hw,
> >>                        __field(u32, seqno)
> >>                        __field(u32, global_seqno)
> >>                        __field(u32, port)
> >> +                     __field(u32, prio)
> >> +                     __field(u32, completed)
> >>                       ),
> >>               TP_fast_assign(
> >> @@ -701,12 +703,15 @@ DECLARE_EVENT_CLASS(i915_request_hw,
> >>                      __entry->seqno = rq->fence.seqno;
> >>                      __entry->global_seqno = rq->global_seqno;
> >>                      __entry->port = port;
> >> +                   __entry->prio = rq->sched.attr.priority;
> >> +                   __entry->completed = i915_request_completed(rq);
> >>                     ),
> >> -            TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, 
> >> global=%u, port=%u",
> >> +            TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, 
> >> prio=%u, global=%u, port=%u, completed?=%d",
> >>                     __entry->dev, __entry->hw_id, __entry->ring,
> >> -                  __entry->ctx, __entry->seqno,
> >> -                  __entry->global_seqno, __entry->port)
> >> +                  __entry->ctx, __entry->seqno, __entry->prio,
> >> +                  __entry->global_seqno, __entry->port,
> >> +                  __entry->completed)
> >>   );
> >>   DEFINE_EVENT(i915_request_hw, i915_request_in,
> >> @@ -714,9 +719,9 @@ DEFINE_EVENT(i915_request_hw, i915_request_in,
> >>            TP_ARGS(rq, port)
> >>   );
> >> -DEFINE_EVENT(i915_request, i915_request_out,
> >> -         TP_PROTO(struct i915_request *rq),
> >> -         TP_ARGS(rq)
> >> +DEFINE_EVENT(i915_request_hw, i915_request_out,
> >> +         TP_PROTO(struct i915_request *rq, unsigned int port),
> >> +         TP_ARGS(rq, port)
> >>   );
> >>   #else
> >>   #if !defined(TRACE_HEADER_MULTI_READ)
> >> diff --git a/drivers/gpu/drm/i915/intel_guc_submission.c 
> >> b/drivers/gpu/drm/i915/intel_guc_submission.c
> >> index c6bb5bebddfc..bd440687892a 100644
> >> --- a/drivers/gpu/drm/i915/intel_guc_submission.c
> >> +++ b/drivers/gpu/drm/i915/intel_guc_submission.c
> >> @@ -762,7 +762,7 @@ static void guc_submission_tasklet(unsigned long 
> >> data)
> >>       rq = port_request(port);
> >>       while (rq && i915_request_completed(rq)) {
> >> -        trace_i915_request_out(rq);
> >> +        trace_i915_request_out(rq, 0);
> >>           i915_request_put(rq);
> >>           port = execlists_port_complete(execlists, port);
> >> diff --git a/drivers/gpu/drm/i915/intel_lrc.c 
> >> b/drivers/gpu/drm/i915/intel_lrc.c
> >> index ffc74f562f77..396d9596d0aa 100644
> >> --- a/drivers/gpu/drm/i915/intel_lrc.c
> >> +++ b/drivers/gpu/drm/i915/intel_lrc.c
> >> @@ -402,7 +402,7 @@ execlists_context_schedule_out(struct i915_request 
> >> *rq, unsigned long status)
> >>   {
> >>       intel_engine_context_out(rq->engine);
> >>       execlists_context_status_change(rq, status);
> >> -    trace_i915_request_out(rq);
> >> +    trace_i915_request_out(rq, 0);
> >>   }
> >>   static void
> >>
> > 
> > Another one! :) For simplicity:
> > 
> > Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> 
> Well actually on a second thought I think it would be tidier to define 
> in and out separately so not to pollute the logs with pointless fields. 
> If you are busy I am happy to do that.

If your fingers are on the keyboard already, go for it.
-Chris
kernel test robot May 1, 2018, 4:05 p.m. UTC | #4
Hi Chris,

Thank you for the patch! Yet something to improve:

[auto build test ERROR on drm-intel/for-linux-next]
[also build test ERROR on next-20180501]
[cannot apply to v4.17-rc3]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Chris-Wilson/drm-i915-execlists-Emit-i915_trace_request_out-for-preemption/20180501-233343
base:   git://anongit.freedesktop.org/drm-intel for-linux-next
config: x86_64-randconfig-x011-201817 (attached as .config)
compiler: gcc-7 (Debian 7.3.0-16) 7.3.0
reproduce:
        # save the attached .config to linux build tree
        make ARCH=x86_64 

All errors (new ones prefixed by >>):

   drivers/gpu/drm/i915/intel_lrc.c: In function 'execlists_context_schedule_out':
>> drivers/gpu/drm/i915/intel_lrc.c:404:2: error: too many arguments to function 'trace_i915_request_out'
     trace_i915_request_out(rq, 0);
     ^~~~~~~~~~~~~~~~~~~~~~
   In file included from drivers/gpu/drm/i915/i915_drv.h:2668:0,
                    from drivers/gpu/drm/i915/intel_lrc.c:138:
   drivers/gpu/drm/i915/i915_trace.h:744:1: note: declared here
    trace_i915_request_out(struct i915_request *rq)
    ^~~~~~~~~~~~~~~~~~~~~~
--
   drivers/gpu/drm/i915/intel_guc_submission.c: In function 'guc_submission_tasklet':
>> drivers/gpu/drm/i915/intel_guc_submission.c:763:3: error: too many arguments to function 'trace_i915_request_out'
      trace_i915_request_out(rq, 0);
      ^~~~~~~~~~~~~~~~~~~~~~
   In file included from drivers/gpu/drm/i915/i915_drv.h:2668:0,
                    from drivers/gpu/drm/i915/intel_guc_submission.c:30:
   drivers/gpu/drm/i915/i915_trace.h:744:1: note: declared here
    trace_i915_request_out(struct i915_request *rq)
    ^~~~~~~~~~~~~~~~~~~~~~

vim +/trace_i915_request_out +404 drivers/gpu/drm/i915/intel_lrc.c

   398	
   399	static inline void
   400	execlists_context_schedule_out(struct i915_request *rq, unsigned long status)
   401	{
   402		intel_engine_context_out(rq->engine);
   403		execlists_context_status_change(rq, status);
 > 404		trace_i915_request_out(rq, 0);
   405	}
   406	

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation
diff mbox

Patch

diff --git a/drivers/gpu/drm/i915/i915_trace.h b/drivers/gpu/drm/i915/i915_trace.h
index 408827bf5d96..66956af25da3 100644
--- a/drivers/gpu/drm/i915/i915_trace.h
+++ b/drivers/gpu/drm/i915/i915_trace.h
@@ -691,6 +691,8 @@  DECLARE_EVENT_CLASS(i915_request_hw,
 				     __field(u32, seqno)
 				     __field(u32, global_seqno)
 				     __field(u32, port)
+				     __field(u32, prio)
+				     __field(u32, completed)
 				    ),
 
 		    TP_fast_assign(
@@ -701,12 +703,15 @@  DECLARE_EVENT_CLASS(i915_request_hw,
 				   __entry->seqno = rq->fence.seqno;
 				   __entry->global_seqno = rq->global_seqno;
 				   __entry->port = port;
+				   __entry->prio = rq->sched.attr.priority;
+				   __entry->completed = i915_request_completed(rq);
 				  ),
 
-		    TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, global=%u, port=%u",
+		    TP_printk("dev=%u, hw_id=%u, ring=%u, ctx=%u, seqno=%u, prio=%u, global=%u, port=%u, completed?=%d",
 			      __entry->dev, __entry->hw_id, __entry->ring,
-			      __entry->ctx, __entry->seqno,
-			      __entry->global_seqno, __entry->port)
+			      __entry->ctx, __entry->seqno, __entry->prio,
+			      __entry->global_seqno, __entry->port,
+			      __entry->completed)
 );
 
 DEFINE_EVENT(i915_request_hw, i915_request_in,
@@ -714,9 +719,9 @@  DEFINE_EVENT(i915_request_hw, i915_request_in,
 	     TP_ARGS(rq, port)
 );
 
-DEFINE_EVENT(i915_request, i915_request_out,
-	     TP_PROTO(struct i915_request *rq),
-	     TP_ARGS(rq)
+DEFINE_EVENT(i915_request_hw, i915_request_out,
+	     TP_PROTO(struct i915_request *rq, unsigned int port),
+	     TP_ARGS(rq, port)
 );
 #else
 #if !defined(TRACE_HEADER_MULTI_READ)
diff --git a/drivers/gpu/drm/i915/intel_guc_submission.c b/drivers/gpu/drm/i915/intel_guc_submission.c
index c6bb5bebddfc..bd440687892a 100644
--- a/drivers/gpu/drm/i915/intel_guc_submission.c
+++ b/drivers/gpu/drm/i915/intel_guc_submission.c
@@ -762,7 +762,7 @@  static void guc_submission_tasklet(unsigned long data)
 
 	rq = port_request(port);
 	while (rq && i915_request_completed(rq)) {
-		trace_i915_request_out(rq);
+		trace_i915_request_out(rq, 0);
 		i915_request_put(rq);
 
 		port = execlists_port_complete(execlists, port);
diff --git a/drivers/gpu/drm/i915/intel_lrc.c b/drivers/gpu/drm/i915/intel_lrc.c
index ffc74f562f77..396d9596d0aa 100644
--- a/drivers/gpu/drm/i915/intel_lrc.c
+++ b/drivers/gpu/drm/i915/intel_lrc.c
@@ -402,7 +402,7 @@  execlists_context_schedule_out(struct i915_request *rq, unsigned long status)
 {
 	intel_engine_context_out(rq->engine);
 	execlists_context_status_change(rq, status);
-	trace_i915_request_out(rq);
+	trace_i915_request_out(rq, 0);
 }
 
 static void