Skip to content

Commit 043477b

Browse files
mikuintmikuint
committed
drm/i915: Print error state times relative to capture
Using plain jiffies in error state output makes the output time differences relative to the current system time. This is wrong as it makes output time differences dependent of when the error state is printed rather than when it is captured. Store capture jiffies into error state and use it when outputting the state to fix time differences output. v2: use engine timestamp as epoch, output formatting (Chris) v3: pass epoch to print_engine/request (Chris) Cc: Chris Wilson <chris@chris-wilson.co.uk> Signed-off-by: Mika Kuoppala <mika.kuoppala@linux.intel.com> Reviewed-by: Chris Wilson <chris@chris-wilson.co.uk> Link: https://patchwork.freedesktop.org/patch/msgid/20180430075259.4476-1-mika.kuoppala@linux.intel.com
1 parent c5ce3b8 commit 043477b

File tree

2 files changed

+40
-9
lines changed

2 files changed

+40
-9
lines changed

‎drivers/gpu/drm/i915/i915_gpu_error.c

Lines changed: 38 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -404,15 +404,16 @@ static const char *bannable(const struct drm_i915_error_context *ctx)
404404

405405
static void error_print_request(struct drm_i915_error_state_buf *m,
406406
const char *prefix,
407-
const struct drm_i915_error_request *erq)
407+
const struct drm_i915_error_request *erq,
408+
const unsigned long epoch)
408409
{
409410
if (!erq->seqno)
410411
return;
411412

412-
err_printf(m, "%s pid %d, ban score %d, seqno %8x:%08x, prio %d, emitted %dms ago, head %08x, tail %08x\n",
413+
err_printf(m, "%s pid %d, ban score %d, seqno %8x:%08x, prio %d, emitted %dms, head %08x, tail %08x\n",
413414
prefix, erq->pid, erq->ban_score,
414415
erq->context, erq->seqno, erq->sched_attr.priority,
415-
jiffies_to_msecs(jiffies - erq->jiffies),
416+
jiffies_to_msecs(erq->jiffies - epoch),
416417
erq->head, erq->tail);
417418
}
418419

@@ -427,7 +428,8 @@ static void error_print_context(struct drm_i915_error_state_buf *m,
427428
}
428429

429430
static void error_print_engine(struct drm_i915_error_state_buf *m,
430-
const struct drm_i915_error_engine *ee)
431+
const struct drm_i915_error_engine *ee,
432+
const unsigned long epoch)
431433
{
432434
int n;
433435

@@ -497,14 +499,15 @@ static void error_print_engine(struct drm_i915_error_state_buf *m,
497499
err_printf(m, " hangcheck stall: %s\n", yesno(ee->hangcheck_stalled));
498500
err_printf(m, " hangcheck action: %s\n",
499501
hangcheck_action_to_str(ee->hangcheck_action));
500-
err_printf(m, " hangcheck action timestamp: %lu, %u ms ago\n",
502+
err_printf(m, " hangcheck action timestamp: %dms (%lu%s)\n",
503+
jiffies_to_msecs(ee->hangcheck_timestamp - epoch),
501504
ee->hangcheck_timestamp,
502-
jiffies_to_msecs(jiffies - ee->hangcheck_timestamp));
505+
ee->hangcheck_timestamp == epoch ? "; epoch" : "");
503506
err_printf(m, " engine reset count: %u\n", ee->reset_count);
504507

505508
for (n = 0; n < ee->num_ports; n++) {
506509
err_printf(m, " ELSP[%d]:", n);
507-
error_print_request(m, " ", &ee->execlist[n]);
510+
error_print_request(m, " ", &ee->execlist[n], epoch);
508511
}
509512

510513
error_print_context(m, " Active context: ", &ee->context);
@@ -650,6 +653,11 @@ int i915_error_state_to_str(struct drm_i915_error_state_buf *m,
650653
ts = ktime_to_timespec64(error->uptime);
651654
err_printf(m, "Uptime: %lld s %ld us\n",
652655
(s64)ts.tv_sec, ts.tv_nsec / NSEC_PER_USEC);
656+
err_printf(m, "Epoch: %lu jiffies (%u HZ)\n", error->epoch, HZ);
657+
err_printf(m, "Capture: %lu jiffies; %d ms ago, %d ms after epoch\n",
658+
error->capture,
659+
jiffies_to_msecs(jiffies - error->capture),
660+
jiffies_to_msecs(error->capture - error->epoch));
653661

654662
for (i = 0; i < ARRAY_SIZE(error->engine); i++) {
655663
if (error->engine[i].hangcheck_stalled &&
@@ -710,7 +718,7 @@ int i915_error_state_to_str(struct drm_i915_error_state_buf *m,
710718

711719
for (i = 0; i < ARRAY_SIZE(error->engine); i++) {
712720
if (error->engine[i].engine_id != -1)
713-
error_print_engine(m, &error->engine[i]);
721+
error_print_engine(m, &error->engine[i], error->epoch);
714722
}
715723

716724
for (i = 0; i < ARRAY_SIZE(error->active_vm); i++) {
@@ -769,7 +777,9 @@ int i915_error_state_to_str(struct drm_i915_error_state_buf *m,
769777
dev_priv->engine[i]->name,
770778
ee->num_requests);
771779
for (j = 0; j < ee->num_requests; j++)
772-
error_print_request(m, " ", &ee->requests[j]);
780+
error_print_request(m, " ",
781+
&ee->requests[j],
782+
error->epoch);
773783
}
774784

775785
if (IS_ERR(ee->waiters)) {
@@ -1736,6 +1746,22 @@ static void capture_params(struct i915_gpu_state *error)
17361746
#undef DUP
17371747
}
17381748

1749+
static unsigned long capture_find_epoch(const struct i915_gpu_state *error)
1750+
{
1751+
unsigned long epoch = error->capture;
1752+
int i;
1753+
1754+
for (i = 0; i < ARRAY_SIZE(error->engine); i++) {
1755+
const struct drm_i915_error_engine *ee = &error->engine[i];
1756+
1757+
if (ee->hangcheck_stalled &&
1758+
time_before(ee->hangcheck_timestamp, epoch))
1759+
epoch = ee->hangcheck_timestamp;
1760+
}
1761+
1762+
return epoch;
1763+
}
1764+
17391765
static int capture(void *data)
17401766
{
17411767
struct i915_gpu_state *error = data;
@@ -1744,6 +1770,7 @@ static int capture(void *data)
17441770
error->boottime = ktime_get_boottime();
17451771
error->uptime = ktime_sub(ktime_get(),
17461772
error->i915->gt.last_init_time);
1773+
error->capture = jiffies;
17471774

17481775
capture_params(error);
17491776
capture_gen_state(error);
@@ -1757,6 +1784,8 @@ static int capture(void *data)
17571784
error->overlay = intel_overlay_capture_error_state(error->i915);
17581785
error->display = intel_display_capture_error_state(error->i915);
17591786

1787+
error->epoch = capture_find_epoch(error);
1788+
17601789
return 0;
17611790
}
17621791

‎drivers/gpu/drm/i915/i915_gpu_error.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,8 @@ struct i915_gpu_state {
3131
ktime_t time;
3232
ktime_t boottime;
3333
ktime_t uptime;
34+
unsigned long capture;
35+
unsigned long epoch;
3436

3537
struct drm_i915_private *i915;
3638

0 commit comments

Comments
 (0)