[PATCH v3 3/4] drm/sched: cleanup gpu_scheduler trace events

[Steven Rostedt]

On Thu, 6 Jun 2024 15:06:24 +0200
Pierre-Eric Pelloux-Prayer <pierre-eric.pelloux-prayer at amd.com> wrote:

> Print identifiers instead of pointers:
> * "fence=%p" is replaced by "fence=(context:%llu, seqno:%lld)" to have a
> coherent way to print the fence. A possible follow up change would be
> to use the same format in traces/../dma-fence.h.
> * "entity=%p" is removed because the fence's context is already an
> identifier of the job owner.
> 
> Signed-off-by: Pierre-Eric Pelloux-Prayer <pierre-eric.pelloux-prayer at amd.com>
> ---
>  .../gpu/drm/scheduler/gpu_scheduler_trace.h   | 27 ++++++++++---------
>  1 file changed, 15 insertions(+), 12 deletions(-)
> 
> diff --git a/drivers/gpu/drm/scheduler/gpu_scheduler_trace.h b/drivers/gpu/drm/scheduler/gpu_scheduler_trace.h
> index 0a19c121bda5..2d7f2252eb5d 100644
> --- a/drivers/gpu/drm/scheduler/gpu_scheduler_trace.h
> +++ b/drivers/gpu/drm/scheduler/gpu_scheduler_trace.h
> @@ -58,9 +58,9 @@ DECLARE_EVENT_CLASS(drm_sched_job,
>  				   &sched_job->sched->credit_count);
>  			   __entry->dev_index = sched_job->sched->dev->primary->index;
>  			   ),
> -	    TP_printk("entity=%p, id=%llu, fence=%p, ring=%s, job count:%u, hw job count:%d",
> -		      __entry->entity, __entry->id,
> -		      __entry->fence, __get_str(name),
> +	    TP_printk("id=%llu, fence=(context:%llu, seqno:%lld), ring=%s, job count:%u, hw job count:%d",
> +		      __entry->id,
> +		      __entry->fence->context, __entry->fence->seqno, __get_str(name),
>  		      __entry->job_count, __entry->hw_job_count)
>  );
>  
> @@ -72,9 +72,9 @@ DEFINE_EVENT(drm_sched_job, drm_sched_job,
>  DEFINE_EVENT_PRINT(drm_sched_job, drm_run_job,
>  	    TP_PROTO(struct drm_sched_job *sched_job, struct drm_sched_entity *entity),
>  	    TP_ARGS(sched_job, entity),
> -	    TP_printk("dev_index=%d entity=%p id=%llu, fence=%p, ring=%s, job count:%u, hw job count:%d",
> -		      __entry->dev_index, __entry->entity, __entry->id,
> -		      __entry->fence, __get_str(name),
> +	    TP_printk("dev_index=%d id=%llu, fence=(context:%llu, seqno:%lld), ring=%s, job count:%u, hw job count:%d",
> +		      __entry->dev_index, __entry->id,
> +		      __entry->fence->context, __entry->fence->seqno, __get_str(name),
>  		      __entry->job_count, __entry->hw_job_count)

NACK!

You can't dereference pointers from TP_printk(). This is called seconds,
minutes, hours, even days or months after that pointer was assigned. How do
you know that pointer still points to anything?

-- Steve


>  );
>  
> @@ -88,7 +88,8 @@ TRACE_EVENT(drm_sched_process_job,
>  	    TP_fast_assign(
>  		    __entry->fence = &fence->finished;
>  		    ),
> -	    TP_printk("fence=%p signaled", __entry->fence)
> +	    TP_printk("fence=(context:%llu, seqno:%lld) signaled",
> +		      __entry->fence->context, __entry->fence->seqno)
>  );
>  
>  TRACE_EVENT(drm_sched_job_wait_dep,
> @@ -96,23 +97,25 @@ TRACE_EVENT(drm_sched_job_wait_dep,
>  	    TP_ARGS(sched_job, fence),
>  	    TP_STRUCT__entry(
>  			     __string(name, sched_job->sched->name)
> +			     __field(uint64_t, fence_context)
>  			     __field(uint64_t, id)
>  			     __field(struct dma_fence *, fence)
>  			     __field(uint64_t, ctx)
> -			     __field(unsigned, seqno)
> +			     __field(uint64_t, seqno)
>  			     ),
>  
>  	    TP_fast_assign(
>  			   __assign_str(name);
> +			   /* Store the hw exec fence context. */
> +			   __entry->fence_context = sched_job->entity->fence_context + 1;
>  			   __entry->id = sched_job->id;
>  			   __entry->fence = fence;
>  			   __entry->ctx = fence->context;
>  			   __entry->seqno = fence->seqno;
>  			   ),
> -	    TP_printk("job ring=%s, id=%llu, depends fence=%p, context=%llu, seq=%u",
> -		      __get_str(name), __entry->id,
> -		      __entry->fence, __entry->ctx,
> -		      __entry->seqno)
> +	    TP_printk("job ring=%s, fence_context=%llu, id=%llu, depends fence=(context:%llu, seqno:%lld)",
> +		      __get_str(name), __entry->fence_context, __entry->id,
> +		      __entry->ctx, __entry->seqno)
>  );
>  
>  #endif