| Message ID | 20180328173959.23948-1-tvrtko.ursulin@linux.intel.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
Quoting Tvrtko Ursulin (2018-03-28 18:39:59) > From: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > > Some messages are using %d and some %x which creates confusion while > reading the traces. > > I also added: > > 1. Fence context/seqno to elsp traces - so it is easier to correlate > events. > > 2. New GEM_TRACE logging to port and request cancellation sites. > > Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > --- > Crystal ball says I'll be removing everything other than the seqno format > consolidation in v2. :) > --- > drivers/gpu/drm/i915/intel_lrc.c | 27 ++++++++++++++++++++++----- > 1 file changed, 22 insertions(+), 5 deletions(-) > > diff --git a/drivers/gpu/drm/i915/intel_lrc.c b/drivers/gpu/drm/i915/intel_lrc.c > index fe520c4dd999..c5e8526a2025 100644 > --- a/drivers/gpu/drm/i915/intel_lrc.c > +++ b/drivers/gpu/drm/i915/intel_lrc.c > @@ -454,10 +454,12 @@ static void execlists_submit_ports(struct intel_engine_cs *engine) > desc = execlists_update_context(rq); > GEM_DEBUG_EXEC(port[n].context_id = upper_32_bits(desc)); > > - GEM_TRACE("%s in[%d]: ctx=%d.%d, seqno=%x, prio=%d\n", > + GEM_TRACE("%s in[%d]: ctx=%d.%d, seqno=%d (fence %llx:%d), prio=%d\n", > engine->name, n, > port[n].context_id, count, > rq->global_seqno, > + rq->fence.context, > + rq->fence.seqno, > rq_prio(rq)); > } else { > GEM_BUG_ON(!n); > @@ -727,6 +729,10 @@ execlists_cancel_port_requests(struct intel_engine_execlists * const execlists) > while (num_ports-- && port_isset(port)) { > struct i915_request *rq = port_request(port); > > + GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n", > + rq->engine->name, port - execlists->port, > + rq->fence.context, rq->fence.seqno, rq->global_seqno); > + > GEM_BUG_ON(!execlists->active); > intel_engine_context_out(rq->engine); > > @@ -802,7 +808,8 @@ static void execlists_cancel_requests(struct intel_engine_cs *engine) > struct rb_node *rb; > unsigned long flags; > > - GEM_TRACE("%s\n", engine->name); > + GEM_TRACE("%s, hws global %d\n", > + engine->name, intel_engine_get_seqno(engine)); I've been suggesting switching over to current=%d for hws global. Maybe "breadcrumb=%d"? Just something that is unambiguous. > * Before we call engine->cancel_requests(), we should have exclusive > @@ -829,8 +836,12 @@ static void execlists_cancel_requests(struct intel_engine_cs *engine) > /* Mark all executing requests as skipped. */ > list_for_each_entry(rq, &engine->timeline->requests, link) { > GEM_BUG_ON(!rq->global_seqno); > - if (!i915_request_completed(rq)) > + if (!i915_request_completed(rq)) { > + GEM_TRACE("%s eio %llx:%d [global %d]\n", > + rq->engine->name, rq->fence.context, > + rq->fence.seqno, rq->global_seqno); > dma_fence_set_error(&rq->fence, -EIO); > + } > } I've been using global_seqno=%d elsewhere. So pick one, and we'll be consistent! I promise this time. Well, at least until I forget in the morning. So "fence=%llx:%d, global_seqno=%d (current=%d)" e.g. https://patchwork.freedesktop.org/patch/213307/ -Chris
Hi Tvrtko,
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-20180329]
[cannot apply to v4.16-rc7]
[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/Tvrtko-Ursulin/drm-i915-execlists-Consistent-seqno-reporting-in-GEM_TRACE/20180330-120802
base: git://anongit.freedesktop.org/drm-intel for-linux-next
config: i386-randconfig-x0-03302126 (attached as .config)
compiler: gcc-5 (Debian 5.5.0-3) 5.4.1 20171010
reproduce:
# save the attached .config to linux build tree
make ARCH=i386
All errors (new ones prefixed by >>):
In file included from include/linux/interrupt.h:6:0,
from drivers/gpu//drm/i915/intel_lrc.c:134:
drivers/gpu//drm/i915/intel_lrc.c: In function 'execlists_cancel_port_requests':
>> drivers/gpu//drm/i915/intel_lrc.c:730:13: error: format '%lu' expects argument of type 'long unsigned int', but argument 3 has type 'int' [-Werror=format=]
GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n",
^
include/linux/kernel.h:635:33: note: in definition of macro '__trace_printk_check_format'
____trace_printk_check_format(fmt, ##args); \
^
include/linux/kernel.h:672:3: note: in expansion of macro 'do_trace_printk'
do_trace_printk(fmt, ##__VA_ARGS__); \
^
drivers/gpu//drm/i915/i915_gem.h:55:24: note: in expansion of macro 'trace_printk'
#define GEM_TRACE(...) trace_printk(__VA_ARGS__)
^
drivers/gpu//drm/i915/intel_lrc.c:730:3: note: in expansion of macro 'GEM_TRACE'
GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n",
^
drivers/gpu//drm/i915/intel_lrc.c:730:13: error: format '%lu' expects argument of type 'long unsigned int', but argument 4 has type 'int' [-Werror=format=]
GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n",
^
include/linux/kernel.h:688:29: note: in definition of macro 'do_trace_printk'
__trace_printk(_THIS_IP_, fmt, ##args); \
^
drivers/gpu//drm/i915/i915_gem.h:55:24: note: in expansion of macro 'trace_printk'
#define GEM_TRACE(...) trace_printk(__VA_ARGS__)
^
drivers/gpu//drm/i915/intel_lrc.c:730:3: note: in expansion of macro 'GEM_TRACE'
GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n",
^
cc1: all warnings being treated as errors
vim +730 drivers/gpu//drm/i915/intel_lrc.c
720
721 void
722 execlists_cancel_port_requests(struct intel_engine_execlists * const execlists)
723 {
724 struct execlist_port *port = execlists->port;
725 unsigned int num_ports = execlists_num_ports(execlists);
726
727 while (num_ports-- && port_isset(port)) {
728 struct i915_request *rq = port_request(port);
729
> 730 GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n",
731 rq->engine->name, port - execlists->port,
732 rq->fence.context, rq->fence.seqno, rq->global_seqno);
733
734 GEM_BUG_ON(!execlists->active);
735 intel_engine_context_out(rq->engine);
736
737 execlists_context_status_change(rq,
738 i915_request_completed(rq) ?
739 INTEL_CONTEXT_SCHEDULE_OUT :
740 INTEL_CONTEXT_SCHEDULE_PREEMPTED);
741
742 i915_request_put(rq);
743
744 memset(port, 0, sizeof(*port));
745 port++;
746 }
747 }
748
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all Intel Corporation
diff --git a/drivers/gpu/drm/i915/intel_lrc.c b/drivers/gpu/drm/i915/intel_lrc.c index fe520c4dd999..c5e8526a2025 100644 --- a/drivers/gpu/drm/i915/intel_lrc.c +++ b/drivers/gpu/drm/i915/intel_lrc.c @@ -454,10 +454,12 @@ static void execlists_submit_ports(struct intel_engine_cs *engine) desc = execlists_update_context(rq); GEM_DEBUG_EXEC(port[n].context_id = upper_32_bits(desc)); - GEM_TRACE("%s in[%d]: ctx=%d.%d, seqno=%x, prio=%d\n", + GEM_TRACE("%s in[%d]: ctx=%d.%d, seqno=%d (fence %llx:%d), prio=%d\n", engine->name, n, port[n].context_id, count, rq->global_seqno, + rq->fence.context, + rq->fence.seqno, rq_prio(rq)); } else { GEM_BUG_ON(!n); @@ -727,6 +729,10 @@ execlists_cancel_port_requests(struct intel_engine_execlists * const execlists) while (num_ports-- && port_isset(port)) { struct i915_request *rq = port_request(port); + GEM_TRACE("%s:port%lu cancel %llx:%d [global %d]\n", + rq->engine->name, port - execlists->port, + rq->fence.context, rq->fence.seqno, rq->global_seqno); + GEM_BUG_ON(!execlists->active); intel_engine_context_out(rq->engine); @@ -802,7 +808,8 @@ static void execlists_cancel_requests(struct intel_engine_cs *engine) struct rb_node *rb; unsigned long flags; - GEM_TRACE("%s\n", engine->name); + GEM_TRACE("%s, hws global %d\n", + engine->name, intel_engine_get_seqno(engine)); /* * Before we call engine->cancel_requests(), we should have exclusive @@ -829,8 +836,12 @@ static void execlists_cancel_requests(struct intel_engine_cs *engine) /* Mark all executing requests as skipped. */ list_for_each_entry(rq, &engine->timeline->requests, link) { GEM_BUG_ON(!rq->global_seqno); - if (!i915_request_completed(rq)) + if (!i915_request_completed(rq)) { + GEM_TRACE("%s eio %llx:%d [global %d]\n", + rq->engine->name, rq->fence.context, + rq->fence.seqno, rq->global_seqno); dma_fence_set_error(&rq->fence, -EIO); + } } /* Flush the queued requests to the timeline list (for retiring). */ @@ -839,6 +850,10 @@ static void execlists_cancel_requests(struct intel_engine_cs *engine) struct i915_priolist *p = to_priolist(rb); list_for_each_entry_safe(rq, rn, &p->requests, priotree.link) { + GEM_TRACE("%s submit-eio %llx:%d [global %d]\n", + rq->engine->name, rq->fence.context, + rq->fence.seqno, rq->global_seqno); + INIT_LIST_HEAD(&rq->priotree.link); dma_fence_set_error(&rq->fence, -EIO); @@ -999,10 +1014,12 @@ static void execlists_submission_tasklet(unsigned long data) EXECLISTS_ACTIVE_USER)); rq = port_unpack(port, &count); - GEM_TRACE("%s out[0]: ctx=%d.%d, seqno=%x, prio=%d\n", + GEM_TRACE("%s out[0]: ctx=%d.%d, seqno=%d (fence %llx:%d), prio=%d\n", engine->name, port->context_id, count, rq ? rq->global_seqno : 0, + rq ? rq->fence.context : 0, + rq ? rq->fence.seqno : 0, rq ? rq_prio(rq) : 0); /* Check the context/desc id for this event matches */ @@ -1706,7 +1723,7 @@ static void reset_common_ring(struct intel_engine_cs *engine, struct intel_context *ce; unsigned long flags; - GEM_TRACE("%s seqno=%x\n", + GEM_TRACE("%s seqno=%d\n", engine->name, request ? request->global_seqno : 0); /* See execlists_cancel_requests() for the irq/spinlock split. */