Bug 112364 - [CI][DRMTIP]igt@perf@gen8-unprivileged-single-ctx-counters - timeout - INFO: task kworker/0:1:12 blocked for more than 61 seconds.
Summary: [CI][DRMTIP]igt@perf@gen8-unprivileged-single-ctx-counters - timeout - INFO: ...
Status: RESOLVED DUPLICATE of bug 111732
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: not set not set
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-11-21 08:24 UTC by Lakshmi
Modified: 2019-11-22 00:34 UTC (History)
1 user (show)

See Also:
i915 platform: KBL
i915 features: GEM/Other


Attachments

Description Lakshmi 2019-11-21 08:24:35 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_407/fi-kbl-soraka/igt@perf@gen8-unprivileged-single-ctx-counters.html
<3> [371.526846] INFO: task kworker/0:1:12 blocked for more than 61 seconds.
<3> [371.527085]       Tainted: G     U  W         5.4.0-rc8-ga8ea5fe36a5e-drmtip_407+ #1
<3> [371.527229] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6> [371.527374] kworker/0:1     D12920    12      2 0x80004000
<6> [371.527690] Workqueue: events retire_work_handler [i915]
<4> [371.527918] Call Trace:
<4> [371.527999]  ? __schedule+0x2f1/0x810
<4> [371.528079]  schedule+0x34/0xc0
<4> [371.528112]  schedule_preempt_disabled+0xf/0x20
<4> [371.528133]  __mutex_lock+0x286/0x9d0
<4> [371.528493]  ? intel_context_unpin+0x54/0x100 [i915]
<4> [371.528873]  ? intel_context_unpin+0x54/0x100 [i915]
<4> [371.528996]  ? refcount_inc_checked+0x5/0x30
<4> [371.529305]  intel_context_unpin+0x54/0x100 [i915]
<4> [371.529748]  i915_request_retire+0x343/0x8c0 [i915]
<4> [371.530255]  intel_gt_retire_requests_timeout+0x156/0x530 [i915]
<4> [371.530651]  retire_work_handler+0x12/0x40 [i915]
<4> [371.530794]  process_one_work+0x26a/0x620
<4> [371.530875]  worker_thread+0x37/0x380
<4> [371.530923]  ? process_one_work+0x620/0x620
<4> [371.530946]  kthread+0x119/0x130
<4> [371.530974]  ? kthread_park+0x80/0x80
<4> [371.531019]  ret_from_fork+0x3a/0x50
<3> [371.531142] INFO: task kworker/0:2:187 blocked for more than 61 seconds.
<3> [371.531377]       Tainted: G     U  W         5.4.0-rc8-ga8ea5fe36a5e-drmtip_407+ #1
<3> [371.531757] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6> [371.532025] kworker/0:2     D13944   187      2 0x80004000
<6> [371.532378] Workqueue: events heartbeat [i915]
<4> [371.532409] Call Trace:
<4> [371.532465]  ? __schedule+0x2f1/0x810
<4> [371.532538]  schedule+0x34/0xc0
<4> [371.532570]  schedule_preempt_disabled+0xf/0x20
<4> [371.532591]  __mutex_lock+0x286/0x9d0
<4> [371.533029]  ? heartbeat+0x3f7/0x5f0 [i915]
<4> [371.533407]  ? heartbeat+0x3f7/0x5f0 [i915]
<4> [371.533725]  heartbeat+0x3f7/0x5f0 [i915]
<4> [371.533917]  process_one_work+0x26a/0x620
<4> [371.533999]  worker_thread+0x37/0x380
<4> [371.534047]  ? process_one_work+0x620/0x620
<4> [371.534070]  kthread+0x119/0x130
<4> [371.534097]  ? kthread_park+0x80/0x80
<4> [371.534148]  ret_from_fork+0x3a/0x50
<4> [371.534283] 
Showing all locks held in the system:
<4> [371.534310] 4 locks held by kworker/0:1/12:
<4> [371.534327]  #0: ffff938bfa08f528 ((wq_completion)events){+.+.}, at: process_one_work+0x1de/0x620
<4> [371.534379]  #1: ffffa5610007fe78 ((work_completion)(&(&gt->requests.retire_work)->work)){+.+.}, at: process_one_work+0x1de/0x620
<4> [371.534425]  #2: ffff938be0040e70 (&timeline->mutex){+.+.}, at: intel_gt_retire_requests_timeout+0xc5/0x530 [i915]
<4> [371.534906]  #3: ffff938bdffec128 (&ce->pin_mutex/1){+.+.}, at: intel_context_unpin+0x54/0x100 [i915]
<4> [371.535280] 1 lock held by khungtaskd/34:
<4> [371.535299]  #0: ffffffff85448220 (rcu_read_lock){....}, at: debug_show_all_locks+0xe/0x1a0
<4> [371.535356] 3 locks held by kworker/0:2/187:
<4> [371.535372]  #0: ffff938bfa08f528 ((wq_completion)events){+.+.}, at: process_one_work+0x1de/0x620
<4> [371.535411]  #1: ffffa56100617e78 ((work_completion)(&(&engine->heartbeat.work)->work)){+.+.}, at: process_one_work+0x1de/0x620
<4> [371.535468]  #2: ffff938bf050a070 (&kernel#2){+.+.}, at: heartbeat+0x3f7/0x5f0 [i915]
<4> [371.535908] 3 locks held by kworker/1:2H/193:
<4> [371.535931] 1 lock held by in:imklog/343:
<4> [371.535948]  #0: ffff938bd336aea0 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x3a/0x50
<4> [371.535996] 3 locks held by rs:main Q:Reg/344:
<4> [371.536025] 5 locks held by dmesg/1039:
<4> [371.536045] 5 locks held by perf/1186:
<4> [371.536061]  #0: ffff938be6ddba80 (&perf->lock){+.+.}, at: i915_perf_release+0x20/0x40 [i915]
<4> [371.536505]  #1: ffff938be0d32878 (&ctx->engines_mutex){+.+.}, at: lrc_configure_all_contexts+0x26b/0x880 [i915]
<4> [371.537072]  #2: ffff938bdffec128 (&ce->pin_mutex){+.+.}, at: lrc_configure_all_contexts+0x2d7/0x880 [i915]
<4> [371.537516]  #3: ffff938bf050a070 (&kernel#2){+.+.}, at: i915_request_create+0x16/0x1b0 [i915]
<4> [371.538048]  #4: ffff938be0040e70 (&timeline->mutex/1){+.+.}, at: intel_context_prepare_remote_request+0x3f/0x180 [i915]
<4> [371.538414] 
<4> [371.538439] =============================================
Comment 1 CI Bug Log 2019-11-21 08:25:37 UTC
The CI Bug Log issue associated to this bug has been updated.

### New filters associated

* KBL: igt@perf@gen8-unprivileged-single-ctx-counters - timeout - INFO: task kworker/0:1:12 blocked for more than 61 seconds.
  - https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_407/fi-kbl-soraka/igt@perf@gen8-unprivileged-single-ctx-counters.html
Comment 2 Chris Wilson 2019-11-21 08:27:10 UTC
I've seen this in a bug before and speculated upon the probable mutex inversion.
Comment 3 Lakshmi 2019-11-21 09:12:20 UTC
(In reply to Chris Wilson from comment #2)
> I've seen this in a bug before and speculated upon the probable mutex
> inversion.

Is this the one Bug 111732?
Comment 4 CI Bug Log 2019-11-21 09:15:39 UTC
A CI Bug Log filter associated to this bug has been updated:

{- KBL: igt@perf@gen8-unprivileged-single-ctx-counters - timeout - INFO: task kworker/0:1:12 blocked for more than 61 seconds. -}
{+ KBL: igt@perf@gen8-unprivileged-single-ctx-counters - timeout/incomplete - INFO: task kworker/0:1:12 blocked for more than 61 seconds. +}

New failures caught by the filter:

  * https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_405/fi-kbl-soraka/igt@perf@gen8-unprivileged-single-ctx-counters.html
Comment 5 Chris Wilson 2019-11-22 00:34:07 UTC

*** This bug has been marked as a duplicate of bug 111732 ***


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.