* [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
@ 2018-03-28 17:39 Tvrtko Ursulin
2018-03-28 17:53 ` Chris Wilson
` (3 more replies)
0 siblings, 4 replies; 5+ messages in thread
From: Tvrtko Ursulin @ 2018-03-28 17:39 UTC (permalink / raw)
To: Intel-gfx
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));
/*
* 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. */
--
2.14.1
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
2018-03-28 17:39 [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE Tvrtko Ursulin
@ 2018-03-28 17:53 ` Chris Wilson
2018-03-28 18:24 ` ✓ Fi.CI.BAT: success for " Patchwork
` (2 subsequent siblings)
3 siblings, 0 replies; 5+ messages in thread
From: Chris Wilson @ 2018-03-28 17:53 UTC (permalink / raw)
To: Tvrtko Ursulin, Intel-gfx
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
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 5+ messages in thread
* ✓ Fi.CI.BAT: success for drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
2018-03-28 17:39 [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE Tvrtko Ursulin
2018-03-28 17:53 ` Chris Wilson
@ 2018-03-28 18:24 ` Patchwork
2018-03-29 0:30 ` ✗ Fi.CI.IGT: failure " Patchwork
2018-03-30 14:59 ` [PATCH] " kbuild test robot
3 siblings, 0 replies; 5+ messages in thread
From: Patchwork @ 2018-03-28 18:24 UTC (permalink / raw)
To: Tvrtko Ursulin; +Cc: intel-gfx
== Series Details ==
Series: drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
URL : https://patchwork.freedesktop.org/series/40821/
State : success
== Summary ==
Series 40821v1 drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
https://patchwork.freedesktop.org/api/1.0/series/40821/revisions/1/mbox/
Warning: Kernel 32bit buildtest failed
https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8518/build_32bit.log
---- Known issues:
Test drv_module_reload:
Subgroup basic-reload-inject:
pass -> INCOMPLETE (fi-cnl-y3) fdo#105777
Test kms_pipe_crc_basic:
Subgroup suspend-read-crc-pipe-c:
pass -> DMESG-WARN (fi-cnl-y3) fdo#104951
fdo#105777 https://bugs.freedesktop.org/show_bug.cgi?id=105777
fdo#104951 https://bugs.freedesktop.org/show_bug.cgi?id=104951
fi-bdw-5557u total:285 pass:264 dwarn:0 dfail:0 fail:0 skip:21 time:432s
fi-bdw-gvtdvm total:285 pass:261 dwarn:0 dfail:0 fail:0 skip:24 time:444s
fi-blb-e6850 total:285 pass:220 dwarn:1 dfail:0 fail:0 skip:64 time:383s
fi-bsw-n3050 total:285 pass:239 dwarn:0 dfail:0 fail:0 skip:46 time:536s
fi-bwr-2160 total:285 pass:180 dwarn:0 dfail:0 fail:0 skip:105 time:296s
fi-bxt-dsi total:285 pass:255 dwarn:0 dfail:0 fail:0 skip:30 time:521s
fi-bxt-j4205 total:285 pass:256 dwarn:0 dfail:0 fail:0 skip:29 time:511s
fi-byt-j1900 total:285 pass:250 dwarn:0 dfail:0 fail:0 skip:35 time:518s
fi-byt-n2820 total:285 pass:246 dwarn:0 dfail:0 fail:0 skip:39 time:504s
fi-cfl-8700k total:285 pass:257 dwarn:0 dfail:0 fail:0 skip:28 time:411s
fi-cfl-s3 total:285 pass:259 dwarn:0 dfail:0 fail:0 skip:26 time:564s
fi-cfl-u total:285 pass:259 dwarn:0 dfail:0 fail:0 skip:26 time:510s
fi-cnl-y3 total:284 pass:257 dwarn:1 dfail:0 fail:0 skip:25
fi-elk-e7500 total:285 pass:225 dwarn:1 dfail:0 fail:0 skip:59 time:419s
fi-gdg-551 total:285 pass:176 dwarn:0 dfail:0 fail:1 skip:108 time:314s
fi-glk-1 total:285 pass:257 dwarn:0 dfail:0 fail:0 skip:28 time:539s
fi-hsw-4770 total:285 pass:258 dwarn:0 dfail:0 fail:0 skip:27 time:406s
fi-ilk-650 total:285 pass:225 dwarn:0 dfail:0 fail:0 skip:60 time:422s
fi-ivb-3520m total:285 pass:256 dwarn:0 dfail:0 fail:0 skip:29 time:469s
fi-ivb-3770 total:285 pass:252 dwarn:0 dfail:0 fail:0 skip:33 time:435s
fi-kbl-7500u total:285 pass:260 dwarn:1 dfail:0 fail:0 skip:24 time:469s
fi-kbl-7567u total:285 pass:265 dwarn:0 dfail:0 fail:0 skip:20 time:464s
fi-kbl-r total:285 pass:258 dwarn:0 dfail:0 fail:0 skip:27 time:509s
fi-pnv-d510 total:285 pass:219 dwarn:1 dfail:0 fail:0 skip:65 time:666s
fi-skl-6260u total:285 pass:265 dwarn:0 dfail:0 fail:0 skip:20 time:440s
fi-skl-6600u total:285 pass:258 dwarn:0 dfail:0 fail:0 skip:27 time:540s
fi-skl-6700k2 total:285 pass:261 dwarn:0 dfail:0 fail:0 skip:24 time:505s
fi-skl-6770hq total:285 pass:265 dwarn:0 dfail:0 fail:0 skip:20 time:506s
fi-skl-guc total:285 pass:257 dwarn:0 dfail:0 fail:0 skip:28 time:426s
fi-skl-gvtdvm total:285 pass:262 dwarn:0 dfail:0 fail:0 skip:23 time:445s
fi-snb-2520m total:285 pass:245 dwarn:0 dfail:0 fail:0 skip:40 time:577s
fi-snb-2600 total:285 pass:245 dwarn:0 dfail:0 fail:0 skip:40 time:396s
Blacklisted hosts:
fi-cnl-psr total:285 pass:256 dwarn:3 dfail:0 fail:0 skip:26 time:519s
fi-glk-j4005 failed to collect. IGT log at Patchwork_8518/fi-glk-j4005/run0.log
1a854db0e982d1d8caaaaec519ab789bd6ca28ea drm-tip: 2018y-03m-28d-16h-19m-39s UTC integration manifest
ec687c517727 drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
== Logs ==
For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8518/issues.html
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 5+ messages in thread
* ✗ Fi.CI.IGT: failure for drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
2018-03-28 17:39 [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE Tvrtko Ursulin
2018-03-28 17:53 ` Chris Wilson
2018-03-28 18:24 ` ✓ Fi.CI.BAT: success for " Patchwork
@ 2018-03-29 0:30 ` Patchwork
2018-03-30 14:59 ` [PATCH] " kbuild test robot
3 siblings, 0 replies; 5+ messages in thread
From: Patchwork @ 2018-03-29 0:30 UTC (permalink / raw)
To: Tvrtko Ursulin; +Cc: intel-gfx
== Series Details ==
Series: drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
URL : https://patchwork.freedesktop.org/series/40821/
State : failure
== Summary ==
---- Possible new issues:
Test drv_selftest:
Subgroup live_hangcheck:
pass -> DMESG-FAIL (shard-apl)
Test kms_draw_crc:
Subgroup draw-method-xrgb8888-mmap-wc-xtiled:
skip -> PASS (shard-snb)
---- Known issues:
Test kms_flip:
Subgroup 2x-dpms-vs-vblank-race:
pass -> FAIL (shard-hsw) fdo#103060
Subgroup 2x-flip-vs-expired-vblank-interruptible:
fail -> PASS (shard-hsw) fdo#102887
Subgroup 2x-plain-flip-ts-check-interruptible:
pass -> FAIL (shard-hsw) fdo#100368 +1
Test kms_sysfs_edid_timing:
warn -> PASS (shard-apl) fdo#100047
fdo#103060 https://bugs.freedesktop.org/show_bug.cgi?id=103060
fdo#102887 https://bugs.freedesktop.org/show_bug.cgi?id=102887
fdo#100368 https://bugs.freedesktop.org/show_bug.cgi?id=100368
fdo#100047 https://bugs.freedesktop.org/show_bug.cgi?id=100047
shard-apl total:3495 pass:1831 dwarn:1 dfail:1 fail:7 skip:1655 time:12801s
shard-hsw total:3495 pass:1781 dwarn:1 dfail:0 fail:3 skip:1709 time:11425s
shard-snb total:3495 pass:1375 dwarn:1 dfail:0 fail:2 skip:2117 time:6955s
Blacklisted hosts:
shard-kbl total:3495 pass:1940 dwarn:17 dfail:1 fail:7 skip:1530 time:9233s
== Logs ==
For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8518/shards.html
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE
2018-03-28 17:39 [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE Tvrtko Ursulin
` (2 preceding siblings ...)
2018-03-29 0:30 ` ✗ Fi.CI.IGT: failure " Patchwork
@ 2018-03-30 14:59 ` kbuild test robot
3 siblings, 0 replies; 5+ messages in thread
From: kbuild test robot @ 2018-03-30 14:59 UTC (permalink / raw)
To: Tvrtko Ursulin; +Cc: Intel-gfx, kbuild-all
[-- Attachment #1: Type: text/plain, Size: 3722 bytes --]
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
[-- Attachment #2: .config.gz --]
[-- Type: application/gzip, Size: 30404 bytes --]
[-- Attachment #3: Type: text/plain, Size: 160 bytes --]
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2018-03-30 15:00 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-03-28 17:39 [PATCH] drm/i915/execlists: Consistent seqno reporting in GEM_TRACE Tvrtko Ursulin
2018-03-28 17:53 ` Chris Wilson
2018-03-28 18:24 ` ✓ Fi.CI.BAT: success for " Patchwork
2018-03-29 0:30 ` ✗ Fi.CI.IGT: failure " Patchwork
2018-03-30 14:59 ` [PATCH] " kbuild test robot
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.