On 02/26/2016 07:55 AM, John Harrison wrote:
> On 23/02/2016 20:42, Jesse Barnes wrote:
>> On 02/18/2016 06:27 AM, [email protected] wrote:
>>> From: John Harrison <[email protected]>
>>>
>>> Added trace points to the scheduler to track all the various events,
>>> node state transitions and other interesting things that occur.
>>>
>>> v2: Updated for new request completion tracking implementation.
>>>
>>> v3: Updated for changes to node kill code.
>>>
>>> v4: Wrapped some long lines to keep the style checker happy.
>>>
>>> For: VIZ-1587
>>> Signed-off-by: John Harrison <[email protected]>
>>> ---
>>>   drivers/gpu/drm/i915/i915_gem_execbuffer.c |   2 +
>>>   drivers/gpu/drm/i915/i915_scheduler.c      |  26 ++++
>>>   drivers/gpu/drm/i915/i915_trace.h          | 196 
>>> +++++++++++++++++++++++++++++
>>>   drivers/gpu/drm/i915/intel_lrc.c           |   2 +
>>>   4 files changed, 226 insertions(+)
>>>
>>> diff --git a/drivers/gpu/drm/i915/i915_gem_execbuffer.c 
>>> b/drivers/gpu/drm/i915/i915_gem_execbuffer.c
>>> index b9ad0fd..d4de8c7 100644
>>> --- a/drivers/gpu/drm/i915/i915_gem_execbuffer.c
>>> +++ b/drivers/gpu/drm/i915/i915_gem_execbuffer.c
>>> @@ -1272,6 +1272,8 @@ i915_gem_ringbuffer_submission(struct 
>>> i915_execbuffer_params *params,
>>>         i915_gem_execbuffer_move_to_active(vmas, params->request);
>>>   +    trace_i915_gem_ring_queue(ring, params);
>>> +
>>>       qe = container_of(params, typeof(*qe), params);
>>>       ret = i915_scheduler_queue_execbuffer(qe);
>>>       if (ret)
>>> diff --git a/drivers/gpu/drm/i915/i915_scheduler.c 
>>> b/drivers/gpu/drm/i915/i915_scheduler.c
>>> index 47d7de4..e56ce08 100644
>>> --- a/drivers/gpu/drm/i915/i915_scheduler.c
>>> +++ b/drivers/gpu/drm/i915/i915_scheduler.c
>>> @@ -88,6 +88,8 @@ static void i915_scheduler_node_requeue(struct 
>>> i915_scheduler_queue_entry *node)
>>>       /* Seqno will be reassigned on relaunch */
>>>       node->params.request->seqno = 0;
>>>       node->status = i915_sqs_queued;
>>> +    trace_i915_scheduler_unfly(node->params.ring, node);
>>> +    trace_i915_scheduler_node_state_change(node->params.ring, node);
>>>   }
>>>     /*
>>> @@ -99,7 +101,11 @@ static void i915_scheduler_node_kill(struct 
>>> i915_scheduler_queue_entry *node)
>>>       WARN_ON(!node);
>>>       WARN_ON(I915_SQS_IS_COMPLETE(node));
>>>   +    if (I915_SQS_IS_FLYING(node))
>>> +        trace_i915_scheduler_unfly(node->params.ring, node);
>>> +
>>>       node->status = i915_sqs_dead;
>>> +    trace_i915_scheduler_node_state_change(node->params.ring, node);
>>>   }
>>>     /* Mark a node as in flight on the hardware. */
>>> @@ -124,6 +130,9 @@ static int i915_scheduler_node_fly(struct 
>>> i915_scheduler_queue_entry *node)
>>>         node->status = i915_sqs_flying;
>>>   +    trace_i915_scheduler_fly(ring, node);
>>> +    trace_i915_scheduler_node_state_change(ring, node);
>>> +
>>>       if (!(scheduler->flags[ring->id] & i915_sf_interrupts_enabled)) {
>>>           bool success = true;
>>>   @@ -280,6 +289,8 @@ static int 
>>> i915_scheduler_pop_from_queue_locked(struct intel_engine_cs *ring,
>>>           INIT_LIST_HEAD(&best->link);
>>>           best->status  = i915_sqs_popped;
>>>   +        trace_i915_scheduler_node_state_change(ring, best);
>>> +
>>>           ret = 0;
>>>       } else {
>>>           /* Can only get here if:
>>> @@ -297,6 +308,8 @@ static int i915_scheduler_pop_from_queue_locked(struct 
>>> intel_engine_cs *ring,
>>>           }
>>>       }
>>>   +    trace_i915_scheduler_pop_from_queue(ring, best);
>>> +
>>>       *pop_node = best;
>>>       return ret;
>>>   }
>>> @@ -506,6 +519,8 @@ static int 
>>> i915_scheduler_queue_execbuffer_bypass(struct i915_scheduler_queue_en
>>>       struct i915_scheduler *scheduler = dev_priv->scheduler;
>>>       int ret;
>>>   +    trace_i915_scheduler_queue(qe->params.ring, qe);
>>> +
>>>       intel_ring_reserved_space_cancel(qe->params.request->ringbuf);
>>>         scheduler->flags[qe->params.ring->id] |= i915_sf_submitting;
>>> @@ -628,6 +643,9 @@ int i915_scheduler_queue_execbuffer(struct 
>>> i915_scheduler_queue_entry *qe)
>>>       not_flying = i915_scheduler_count_flying(scheduler, ring) <
>>>                            scheduler->min_flying;
>>>   +    trace_i915_scheduler_queue(ring, node);
>>> +    trace_i915_scheduler_node_state_change(ring, node);
>>> +
>>>       spin_unlock_irq(&scheduler->lock);
>>>         if (not_flying)
>>> @@ -657,6 +675,8 @@ bool i915_scheduler_notify_request(struct 
>>> drm_i915_gem_request *req)
>>>       struct i915_scheduler_queue_entry *node = req->scheduler_qe;
>>>       unsigned long flags;
>>>   +    trace_i915_scheduler_landing(req);
>>> +
>>>       if (!node)
>>>           return false;
>>>   @@ -670,6 +690,8 @@ bool i915_scheduler_notify_request(struct 
>>> drm_i915_gem_request *req)
>>>       else
>>>           node->status = i915_sqs_complete;
>>>   +    trace_i915_scheduler_node_state_change(req->ring, node);
>>> +
>>>       spin_unlock_irqrestore(&scheduler->lock, flags);
>>>         return true;
>>> @@ -877,6 +899,8 @@ static bool i915_scheduler_remove(struct i915_scheduler 
>>> *scheduler,
>>>       /* Launch more packets now? */
>>>       do_submit = (queued > 0) && (flying < scheduler->min_flying);
>>>   +    trace_i915_scheduler_remove(ring, min_seqno, do_submit);
>>> +
>>>       spin_unlock_irq(&scheduler->lock);
>>>         return do_submit;
>>> @@ -912,6 +936,8 @@ static void i915_scheduler_process_work(struct 
>>> intel_engine_cs *ring)
>>>           node = list_first_entry(&remove, typeof(*node), link);
>>>           list_del(&node->link);
>>>   +        trace_i915_scheduler_destroy(ring, node);
>>> +
>>>           /* Free up all the DRM references */
>>>           i915_scheduler_clean_node(node);
>>>   diff --git a/drivers/gpu/drm/i915/i915_trace.h 
>>> b/drivers/gpu/drm/i915/i915_trace.h
>>> index 455c215..c3c4e58 100644
>>> --- a/drivers/gpu/drm/i915/i915_trace.h
>>> +++ b/drivers/gpu/drm/i915/i915_trace.h
>>> @@ -9,6 +9,7 @@
>>>   #include "i915_drv.h"
>>>   #include "intel_drv.h"
>>>   #include "intel_ringbuffer.h"
>>> +#include "i915_scheduler.h"
>>>     #undef TRACE_SYSTEM
>>>   #define TRACE_SYSTEM i915
>>> @@ -826,6 +827,201 @@ TRACE_EVENT(switch_mm,
>>>             __entry->dev, __entry->ring, __entry->to, __entry->vm)
>>>   );
>>>   +TRACE_EVENT(i915_scheduler_queue,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno = node ? node->params.request->seqno : 0;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_fly,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno = node ? node->params.request->seqno : 0;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_unfly,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno = node ? node->params.request->seqno : 0;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_landing,
>>> +        TP_PROTO(struct drm_i915_gem_request *req),
>>> +        TP_ARGS(req),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 __field(u32, status)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring   = req->ring->id;
>>> +               __entry->uniq   = req->uniq;
>>> +               __entry->seqno  = req->seqno;
>>> +               __entry->status = req->scheduler_qe ?
>>> +                        req->scheduler_qe->status : ~0U;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d, status=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno,
>>> +              __entry->status)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_remove,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             u32 min_seqno, bool do_submit),
>>> +        TP_ARGS(ring, min_seqno, do_submit),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, min_seqno)
>>> +                 __field(bool, do_submit)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring      = ring->id;
>>> +               __entry->min_seqno = min_seqno;
>>> +               __entry->do_submit = do_submit;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, min_seqno = %d, do_submit=%d",
>>> +              __entry->ring, __entry->min_seqno, __entry->do_submit)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_destroy,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno = node ? node->params.request->seqno : 0;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_pop_from_queue,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno = node ? node->params.request->seqno : 0;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_scheduler_node_state_change,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_scheduler_queue_entry *node),
>>> +        TP_ARGS(ring, node),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 __field(u32, status)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring   = ring->id;
>>> +               __entry->uniq   = node ? node->params.request->uniq  : 0;
>>> +               __entry->seqno  = node->params.request->seqno;
>>> +               __entry->status = node->status;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d, status=%d",
>>> +              __entry->ring, __entry->uniq, __entry->seqno,
>>> +              __entry->status)
>>> +);
>>> +
>>> +TRACE_EVENT(i915_gem_ring_queue,
>>> +        TP_PROTO(struct intel_engine_cs *ring,
>>> +             struct i915_execbuffer_params *params),
>>> +        TP_ARGS(ring, params),
>>> +
>>> +        TP_STRUCT__entry(
>>> +                 __field(u32, ring)
>>> +                 __field(u32, uniq)
>>> +                 __field(u32, seqno)
>>> +                 ),
>>> +
>>> +        TP_fast_assign(
>>> +               __entry->ring  = ring->id;
>>> +               __entry->uniq  = params->request->uniq;
>>> +               __entry->seqno = params->request->seqno;
>>> +               ),
>>> +
>>> +        TP_printk("ring=%d, uniq=%d, seqno=%d", __entry->ring,
>>> +              __entry->uniq, __entry->seqno)
>>> +);
>>> +
>>>   #endif /* _I915_TRACE_H_ */
>>>     /* This part must be outside protection */
>>> diff --git a/drivers/gpu/drm/i915/intel_lrc.c 
>>> b/drivers/gpu/drm/i915/intel_lrc.c
>>> index 9c7a79a..2b9f49c 100644
>>> --- a/drivers/gpu/drm/i915/intel_lrc.c
>>> +++ b/drivers/gpu/drm/i915/intel_lrc.c
>>> @@ -954,6 +954,8 @@ int intel_execlists_submission(struct 
>>> i915_execbuffer_params *params,
>>>         i915_gem_execbuffer_move_to_active(vmas, params->request);
>>>   +    trace_i915_gem_ring_queue(ring, params);
>>> +
>>>       qe = container_of(params, typeof(*qe), params);
>>>       ret = i915_scheduler_queue_execbuffer(qe);
>>>       if (ret)
>>>
>> Oops, forgot to ask if there are any tools for igt that make use of these, 
>> e.g. some kind of scheduler top util that looks for bubbles or starved 
>> batches or something.
> Nothing at the moment. They have been used to debug issues by looking through 
> trace logs. Also the validation team have tests that hook in to the various 
> trace points to verify the internal operation of the scheduler and other 
> parts of the i915 driver.

Nice.  I wasn't asking because it's a blocker or anything, just curious.

Thanks,
Jesse

_______________________________________________
Intel-gfx mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Reply via email to