Bug 108654 - [CI][DRMTIP] igt@pm_rpm@* - dmesg-warn - *ERROR* DBus power enable timeout!
Summary: [CI][DRMTIP] igt@pm_rpm@* - dmesg-warn - *ERROR* DBus power enable timeout!
Status: NEW
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: XOrg git
Hardware: Other All
: highest normal
Assignee: Imre Deak
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
: 108756 (view as bug list)
Depends on:
Blocks:
 
Reported: 2018-11-05 09:14 UTC by Martin Peres
Modified: 2018-12-07 10:14 UTC (History)
3 users (show)

See Also:
i915 platform: ICL
i915 features: display/Other


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Peres 2018-11-05 09:14:52 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_136/fi-icl-u2/igt@pm_rpm@legacy-planes.html

<7> [181.072491] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [181.073073] [drm:intel_power_well_disable [i915]] disabling power well 1
<3> [181.073160] [drm:skl_update_crtcs [i915]] *ERROR* DBus power enable timeout!

<7> [193.976469] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 08
<4> [193.976552] ------------[ cut here ]------------
<4> [193.976562] Device suspended during HW access
<4> [193.976644] WARNING: CPU: 2 PID: 1148 at drivers/gpu/drm/i915/intel_drv.h:2098 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [193.976646] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec btusb btrtl btbcm snd_hwdep btintel cdc_ether snd_hda_core usbnet e1000e snd_pcm bluetooth mii ecdh_generic prime_numbers
<4> [193.976702] CPU: 2 PID: 1148 Comm: pm_rpm Tainted: G     U  W         4.19.0-gf311f120a0d9-drmtip_136+ #1
<4> [193.976705] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP TLC, BIOS ICLSFWR1.R00.2402.AD3.1810170014 10/17/2018
<4> [193.976748] RIP: 0010:gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [193.976751] Code: e8 57 e9 ff ff e9 86 fe ff ff 80 3d aa 2d 19 00 00 0f 85 14 fe ff ff 48 c7 c7 48 a3 52 c0 c6 05 96 2d 19 00 01 e8 c2 af c5 e8 <0f> 0b e9 fa fd ff ff e8 d6 c8 cd e8 85 c0 0f 85 5f ff ff ff 48 c7
<4> [193.976754] RSP: 0018:ffff9b03c069b9f8 EFLAGS: 00010282
<4> [193.976758] RAX: 0000000000000000 RBX: ffff88e2d3e00000 RCX: 0000000000000000
<4> [193.976760] RDX: 0000000000000007 RSI: ffffffffaa080e58 RDI: 00000000ffffffff
<4> [193.976762] RBP: 0000000000044fe8 R08: 0000000009d31acd R09: 0000000000000000
<4> [193.976764] R10: ffff88e2d56961b0 R11: 0000000000000000 R12: 0000000000000000
<4> [193.976767] R13: 0000000000000001 R14: ffff88e2d3e00000 R15: ffff88e2dad0efc8
<4> [193.976770] FS:  00007f08e0526980(0000) GS:ffff88e2eff00000(0000) knlGS:0000000000000000
<4> [193.976772] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [193.976774] CR2: 00007fbc59d6f000 CR3: 00000004a7cc4003 CR4: 0000000000760ee0
<4> [193.976776] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4> [193.976779] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4> [193.976781] PKRU: 55555554
<4> [193.976783] Call Trace:
<4> [193.976828]  icl_dbuf_slices_update+0x4f/0x170 [i915]
<4> [193.976900]  skl_update_crtcs+0x2ba/0x2e0 [i915]
<4> [193.976969]  intel_atomic_commit_tail+0x1e3/0xd10 [i915]
<4> [193.977031]  ? intel_atomic_commit_ready+0x3f/0x4c [i915]
<4> [193.977076]  ? __i915_sw_fence_complete+0x1a0/0x250 [i915]
<4> [193.977142]  intel_atomic_commit+0x244/0x330 [i915]
<4> [193.977154]  drm_atomic_helper_update_plane+0xeb/0x100
<4> [193.977165]  setplane_internal+0x97/0x190
<4> [193.977189]  drm_mode_setplane+0xcf/0x190
<4> [193.977197]  ? drm_mode_cursor_common+0x220/0x220
<4> [193.977197]  drm_ioctl_kernel+0x81/0xf0
<4> [193.977197]  drm_ioctl+0x2e6/0x3a0
<4> [193.977197]  ? drm_mode_cursor_common+0x220/0x220
<4> [193.977197]  do_vfs_ioctl+0xa0/0x6d0
<4> [193.977197]  ? __task_pid_nr_ns+0xb9/0x1f0
<4> [193.977197]  ksys_ioctl+0x35/0x60
<4> [193.977197]  __x64_sys_ioctl+0x11/0x20
<4> [193.977197]  do_syscall_64+0x55/0x190
<4> [193.977197]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [193.977197] RIP: 0033:0x7f08df7b05d7
<4> [193.977197] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
<4> [193.977197] RSP: 002b:00007fff8fc09d28 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [193.977197] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f08df7b05d7
<4> [193.977197] RDX: 00007fff8fc09d60 RSI: 00000000c03064b7 RDI: 0000000000000005
<4> [193.977197] RBP: 00007fff8fc09d60 R08: 0000000000000000 R09: 0000000000000001
<4> [193.977197] R10: 0000000000400000 R11: 0000000000000246 R12: 00000000c03064b7
<4> [193.977197] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
<4> [193.977197] irq event stamp: 230696
<4> [193.977197] hardirqs last  enabled at (230695): [<ffffffffa90fc06a>] console_unlock+0x3fa/0x5f0
<4> [193.977197] hardirqs last disabled at (230696): [<ffffffffa9001930>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [193.977197] softirqs last  enabled at (230606): [<ffffffffa9c00319>] __do_softirq+0x319/0x48e
<4> [193.977197] softirqs last disabled at (230583): [<ffffffffa9090329>] irq_exit+0xa9/0xc0
<4> [193.977197] WARNING: CPU: 2 PID: 1148 at drivers/gpu/drm/i915/intel_drv.h:2098 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [193.977197] ---[ end trace cecedd1d30fc6c74 ]---
Comment 1 Martin Peres 2018-11-05 09:17:39 UTC
Bumping the priority to high because this seems related to powerwells and DC states which are definitely important for our users.
Comment 3 Imre Deak 2018-11-05 15:57:06 UTC
We shouldn't touch the HW here, since the output is disabled. The HW update by set_plane is triggered since ddb.enabled_slices in dev_priv / intel_state is updated incorrectly.
Comment 4 Imre Deak 2018-11-30 15:19:27 UTC
*** Bug 108756 has been marked as a duplicate of this bug. ***
Comment 5 Imre Deak 2018-11-30 16:19:00 UTC
I was wondering how this can happen since we have all outputs disabled and
runtime suspended. Then by now icl_dbuf_disable() should have zeroed
dev_priv->wm.skl_hw.ddb.enabled_slices and skl_compute_ddb() copied this
0 to intel_state->wm_results.ddb.enabled_slices during the compute phase
of the problematic commit (since no crtcs are active this 0 should've
been kept as-is). Then here both hw_enabled_slices and required_slices
should be 0, but it's obviously not the case.

What could happen I think is that the store in icl_dbuf_disable() / icl_dbuf_enable() can race with the load in skl_compute_ddb(). So perhaps skl_compute_ddb() copied from dev_priv enabled_slices as 1 or 2 (the only values we compute during a commit), then icl_dbuf_disable() zeroed in a racy way enabled_slices in dev_priv and we get here required_slices being 1 or 2 and hw_enabled_slices being 0.

To fix the above I think we would need to do the following:
1. Do not update enabled_slices in icl_dbuf_enable() / icl_dbuf_disable()
   We instead depend on the DDB HW readout to set the correct initial value
   after module loading/resume and any following commit to update it if
   needed (based on new resolution etc.).

   After this we could still end up with stale values in
   wm.skl_hw.ddb.enabled_slices, for instance if it's 2 b/c of two pipes
   being enabled we wouldn't set it to 1 atm when disabling both pipes
   in the same atomic commit. So we'd also need the following 2 changes.

2. Force-enable only a single slice in icl_dbuf_enable() (as the spec
   requires) keeping the 2nd slice enabled only if BIOS has enabled it
   (DDB HW readout will set the correct enabled_slices afterwards).

3. Make sure we always compute the proper enabled_slices in the atomic
   state, by moving the calculation from intel_get_ddb_size() to
   earlier, performing it even if all crtcs are disabled.

Ville also noticed a related problem where we don't recalculate the slice count during a non-modeset commit, where a plane configuration change would require this (due to the changed pixel bandwidth).
Comment 6 Martin Peres 2018-12-03 14:30:36 UTC
Also seen in BAT: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5186_167/fi-icl-u3/igt@pm_rpm@basic-rte.html

<4> [359.043981] ------------[ cut here ]------------
<4> [359.043984] Device suspended during HW access
<4> [359.044079] WARNING: CPU: 0 PID: 2950 at drivers/gpu/drm/i915/intel_drv.h:2097 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [359.044083] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec btusb btrtl snd_hwdep btbcm btintel cdc_ether snd_hda_core usbnet e1000e snd_pcm mii bluetooth i2c_i801 ecdh_generic prime_numbers
<4> [359.044119] CPU: 0 PID: 2950 Comm: pm_rpm Tainted: G     U            4.20.0-rc3-g890ed44fe261-repeat_15+ #1
<4> [359.044124] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP TLC, BIOS ICLSFWR1.R00.2402.AD3.1810170014 10/17/2018
<4> [359.044189] RIP: 0010:gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [359.044194] Code: e8 57 e9 ff ff e9 86 fe ff ff 80 3d 6a 35 19 00 00 0f 85 14 fe ff ff 48 c7 c7 38 3e 7e c0 c6 05 56 35 19 00 01 e8 02 43 9a e0 <0f> 0b e9 fa fd ff ff e8 06 66 a2 e0 85 c0 0f 85 5f ff ff ff 48 c7
<4> [359.044198] RSP: 0018:ffffa67440dffa38 EFLAGS: 00010282
<4> [359.044204] RAX: 0000000000000000 RBX: ffff8f5b5b3a0000 RCX: 0000000000000000
<4> [359.044208] RDX: 0000000000000007 RSI: ffffffffa2087afb RDI: 00000000ffffffff
<4> [359.044211] RBP: 0000000000044fe8 R08: 000000004fd3a046 R09: 0000000000000000
<4> [359.044215] R10: ffff8f5b51a00d10 R11: 0000000000000000 R12: ffff8f5b5b3a04a0
<4> [359.044219] R13: 0000000000000001 R14: ffff8f5b5b3a0000 R15: ffff8f5b5ce78008
<4> [359.044224] FS:  00007f82d124f980(0000) GS:ffff8f5b6fe00000(0000) knlGS:0000000000000000
<4> [359.044228] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [359.044233] CR2: 00007fe4b86d0788 CR3: 00000004ab1d8002 CR4: 0000000000760ef0
<4> [359.044237] PKRU: 55555554
<4> [359.044242] Call Trace:
<4> [359.044312]  icl_dbuf_slices_update+0x55/0x160 [i915]
<4> [359.044386]  skl_update_crtcs+0x281/0x2b0 [i915]
<4> [359.044460]  intel_atomic_commit_tail+0x1e3/0xd20 [i915]
<4> [359.044527]  ? intel_atomic_commit_ready+0x3f/0x50 [i915]
<4> [359.044580]  ? __i915_sw_fence_complete+0x1a0/0x250 [i915]
<4> [359.044662]  intel_atomic_commit+0x244/0x330 [i915]
<4> [359.044676]  drm_atomic_helper_set_config+0x7b/0x90
<4> [359.044685]  drm_mode_setcrtc+0x195/0x6b0
<4> [359.044717]  ? drm_mode_getcrtc+0x180/0x180
<4> [359.044724]  drm_ioctl_kernel+0x81/0xf0
<4> [359.044736]  drm_ioctl+0x2de/0x390
<4> [359.044745]  ? drm_mode_getcrtc+0x180/0x180
<4> [359.044768]  do_vfs_ioctl+0xa0/0x6e0
<4> [359.044777]  ? __might_fault+0x39/0x90
<4> [359.044790]  ksys_ioctl+0x35/0x60
<4> [359.044800]  __x64_sys_ioctl+0x11/0x20
<4> [359.044806]  do_syscall_64+0x55/0x190
<4> [359.044815]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [359.044820] RIP: 0033:0x7f82d04d95d7
<4> [359.044826] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
<4> [359.044830] RSP: 002b:00007fffe394b328 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [359.044835] RAX: ffffffffffffffda RBX: 00007fffe394b360 RCX: 00007f82d04d95d7
<4> [359.044839] RDX: 00007fffe394b360 RSI: 00000000c06864a2 RDI: 0000000000000005
<4> [359.044843] RBP: 00007fffe394b360 R08: 0000000000000000 R09: 0000000000000000
<4> [359.044848] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000c06864a2
<4> [359.044851] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
<4> [359.044870] irq event stamp: 151080
<4> [359.044878] hardirqs last  enabled at (151079): [<ffffffffa10fef59>] console_unlock+0x3f9/0x5f0
<4> [359.044884] hardirqs last disabled at (151080): [<ffffffffa10019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [359.044890] softirqs last  enabled at (150974): [<ffffffffa1c0033a>] __do_softirq+0x33a/0x4b9
<4> [359.044897] softirqs last disabled at (150969): [<ffffffffa10929f9>] irq_exit+0xa9/0xc0
<4> [359.044964] WARNING: CPU: 0 PID: 2950 at drivers/gpu/drm/i915/intel_drv.h:2097 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [359.044968] ---[ end trace 56324727958c8cd9 ]---
Comment 7 Martin Peres 2018-12-03 14:32:28 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5186_224/fi-icl-u3/igt@pm_rpm@module-reload.html

<4> [408.963219] ------------[ cut here ]------------
<7> [408.966313] [drm:intel_runtime_suspend [i915]] Device suspended
<4> [408.966373] Device suspended during HW access
<4> [408.966426] WARNING: CPU: 0 PID: 3996 at drivers/gpu/drm/i915/intel_drv.h:2097 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [408.966428] Modules linked in: snd_hda_intel i915 vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic btusb btrtl btbcm x86_pkg_temp_thermal coretemp btintel snd_hda_codec crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hwdep snd_hda_core bluetooth snd_pcm cdc_ether usbnet mii e1000e ecdh_generic i2c_i801 prime_numbers [last unloaded: i915]
<4> [408.966449] CPU: 0 PID: 3996 Comm: pm_rpm Tainted: G     U            4.20.0-rc3-g890ed44fe261-repeat_15+ #1
<4> [408.966451] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP TLC, BIOS ICLSFWR1.R00.2402.AD3.1810170014 10/17/2018
<4> [408.966488] RIP: 0010:gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [408.966491] Code: e8 57 e9 ff ff e9 86 fe ff ff 80 3d 6a 35 19 00 00 0f 85 14 fe ff ff 48 c7 c7 38 de 84 c0 c6 05 56 35 19 00 01 e8 02 a3 93 d3 <0f> 0b e9 fa fd ff ff e8 06 c6 9b d3 85 c0 0f 85 5f ff ff ff 48 c7
<4> [408.966493] RSP: 0018:ffff97f0008b3a38 EFLAGS: 00010282
<4> [408.966496] RAX: 0000000000000000 RBX: ffff96bb1f960000 RCX: 0000000000000000
<4> [408.966498] RDX: 0000000000000007 RSI: ffffffff95087afb RDI: 00000000ffffffff
<4> [408.966500] RBP: 0000000000044fe8 R08: 0000000096bfd571 R09: 0000000000000000
<4> [408.966502] R10: ffff96bb5e5e2e10 R11: 0000000000000000 R12: ffff96bb1f9604a0
<4> [408.966504] R13: 0000000000000001 R14: ffff96bb1f960000 R15: ffff96bb55ab6678
<4> [408.966506] FS:  00007f1666ad4980(0000) GS:ffff96bb6fe00000(0000) knlGS:0000000000000000
<4> [408.966508] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [408.966510] CR2: 00007f8ec7ec8000 CR3: 000000049abf8003 CR4: 0000000000760ef0
<4> [408.966512] PKRU: 55555554
<4> [408.966514] Call Trace:
<4> [408.966544]  icl_dbuf_slices_update+0x55/0x160 [i915]
<4> [408.966584]  skl_update_crtcs+0x281/0x2b0 [i915]
<4> [408.966634]  intel_atomic_commit_tail+0x1e3/0xd20 [i915]
<4> [408.966671]  ? intel_atomic_commit_ready+0x3f/0x50 [i915]
<4> [408.966694]  ? __i915_sw_fence_complete+0x1a0/0x250 [i915]
<4> [408.966731]  intel_atomic_commit+0x244/0x330 [i915]
<4> [408.966741]  drm_atomic_helper_set_config+0x7b/0x90
<4> [408.966748]  drm_mode_setcrtc+0x195/0x6b0
<4> [408.966765]  ? drm_mode_getcrtc+0x180/0x180
<4> [408.966769]  drm_ioctl_kernel+0x81/0xf0
<4> [408.966775]  drm_ioctl+0x2de/0x390
<4> [408.966779]  ? drm_mode_getcrtc+0x180/0x180
<4> [408.966792]  do_vfs_ioctl+0xa0/0x6e0
<4> [408.966796]  ? lock_acquire+0xa6/0x1c0
<4> [408.966801]  ? __task_pid_nr_ns+0xb9/0x1f0
<4> [408.966807]  ksys_ioctl+0x35/0x60
<4> [408.966812]  __x64_sys_ioctl+0x11/0x20
<4> [408.966815]  do_syscall_64+0x55/0x190
<4> [408.966820]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [408.966823] RIP: 0033:0x7f1665d5e5d7
<4> [408.966826] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
<4> [408.966828] RSP: 002b:00007ffd64005188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [408.966831] RAX: ffffffffffffffda RBX: 00007ffd640051c0 RCX: 00007f1665d5e5d7
<4> [408.966833] RDX: 00007ffd640051c0 RSI: 00000000c06864a2 RDI: 0000000000000000
<4> [408.966835] RBP: 00007ffd640051c0 R08: 0000000000000000 R09: 0000000000000000
<4> [408.966837] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000c06864a2
<4> [408.966839] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
<4> [408.966849] irq event stamp: 1319552
<4> [408.966853] hardirqs last  enabled at (1319551): [<ffffffff940fef59>] console_unlock+0x3f9/0x5f0
<4> [408.966856] hardirqs last disabled at (1319552): [<ffffffff940019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [408.966859] softirqs last  enabled at (1319408): [<ffffffff94c0033a>] __do_softirq+0x33a/0x4b9
<4> [408.966862] softirqs last disabled at (1319399): [<ffffffff940929f9>] irq_exit+0xa9/0xc0
<4> [408.966897] WARNING: CPU: 0 PID: 3996 at drivers/gpu/drm/i915/intel_drv.h:2097 gen11_fwtable_read32+0x21e/0x260 [i915]
<4> [408.966899] ---[ end trace b2b7a32f26c769dd ]---
Comment 8 Martin Peres 2018-12-05 12:54:29 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5261/shard-iclb4/igt@pm_rpm@universal-planes.html

<4> [780.715455] ------------[ cut here ]------------
<4> [780.715460] RPM wakelock ref not held during HW access
<4> [780.715567] WARNING: CPU: 0 PID: 2964 at drivers/gpu/drm/i915/intel_drv.h:2128 gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [780.715572] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal coretemp snd_hda_intel crct10dif_pclmul crc32_pclmul snd_hda_codec ghash_clmulni_intel snd_hwdep cdc_ether snd_hda_core usbnet e1000e mii snd_pcm i2c_i801 prime_numbers
<4> [780.715608] CPU: 0 PID: 2964 Comm: pm_rpm Tainted: G     U            4.20.0-rc5-CI-CI_DRM_5261+ #1
<4> [780.715614] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP TLC, BIOS ICLSFWR1.R00.2402.AD3.1810170014 10/17/2018
<4> [780.715693] RIP: 0010:gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [780.715698] Code: e8 0f fa e2 e0 e9 0d ff ff ff 80 3d fe bf 19 00 00 0f 85 78 fe ff ff 48 c7 c7 98 60 2d a0 c6 05 ea bf 19 00 01 e8 88 4a eb e0 <0f> 0b e9 5e fe ff ff b9 01 00 00 00 ba 01 00 00 00 89 ee 48 89 df
<4> [780.715702] RSP: 0018:ffffc90000a17a10 EFLAGS: 00010286
<4> [780.715707] RAX: 0000000000000000 RBX: ffff888497bd0000 RCX: 0000000000000006
<4> [780.715711] RDX: 0000000000000006 RSI: ffffffff82129622 RDI: ffffffff820d7aa7
<4> [780.715715] RBP: 0000000000044fe8 R08: 00000000b3e1dae6 R09: 0000000000000000
<4> [780.715718] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
<4> [780.715723] R13: 0000000000000001 R14: ffff8884a597d3d8 R15: 0000000000000000
<4> [780.715728] FS:  00007f5081fd8980(0000) GS:ffff8884afe00000(0000) knlGS:0000000000000000
<4> [780.715733] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [780.715737] CR2: 00007f5081ee2000 CR3: 0000000498b24001 CR4: 0000000000760ef0
<4> [780.715742] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4> [780.715746] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4> [780.715750] PKRU: 55555554
<4> [780.715754] Call Trace:
<4> [780.715806]  icl_dbuf_slices_update+0xdf/0x160 [i915]
<4> [780.715871]  skl_update_crtcs+0x29c/0x2b0 [i915]
<4> [780.715938]  intel_atomic_commit_tail+0x1ea/0xd60 [i915]
<4> [780.716000]  ? intel_atomic_commit_ready+0x3f/0x50 [i915]
<4> [780.716038]  ? __i915_sw_fence_complete+0x1a0/0x250 [i915]
<4> [780.716102]  intel_atomic_commit+0x244/0x330 [i915]
<4> [780.716113]  drm_atomic_helper_update_plane+0xeb/0x100
<4> [780.716123]  setplane_internal+0x97/0x190
<4> [780.716143]  drm_mode_setplane+0xcf/0x190
<4> [780.716153]  ? drm_mode_cursor_common+0x220/0x220
<4> [780.716159]  drm_ioctl_kernel+0x81/0xf0
<4> [780.716168]  drm_ioctl+0x2de/0x390
<4> [780.716175]  ? drm_mode_cursor_common+0x220/0x220
<4> [780.716193]  do_vfs_ioctl+0xa0/0x6e0
<4> [780.716199]  ? lock_acquire+0xa6/0x1c0
<4> [780.716206]  ? __task_pid_nr_ns+0xb9/0x1f0
<4> [780.716214]  ksys_ioctl+0x35/0x60
<4> [780.716222]  __x64_sys_ioctl+0x11/0x20
<4> [780.716228]  do_syscall_64+0x55/0x190
<4> [780.716238]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [780.716244] RIP: 0033:0x7f50812615d7
<4> [780.716249] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
<4> [780.716252] RSP: 002b:00007ffd88fa4338 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [780.716256] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f50812615d7
<4> [780.716259] RDX: 00007ffd88fa4370 RSI: 00000000c03064b7 RDI: 0000000000000005
<4> [780.716262] RBP: 00007ffd88fa4370 R08: 0000000000000000 R09: 0000000000000001
<4> [780.716265] R10: 0000000000400000 R11: 0000000000000246 R12: 00000000c03064b7
<4> [780.716268] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
<4> [780.716282] irq event stamp: 253204
<4> [780.716288] hardirqs last  enabled at (253203): [<ffffffff810fc764>] vprintk_emit+0x124/0x320
<4> [780.716293] hardirqs last disabled at (253204): [<ffffffff810019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [780.716297] softirqs last  enabled at (253126): [<ffffffff81c0033a>] __do_softirq+0x33a/0x4b9
<4> [780.716303] softirqs last disabled at (253119): [<ffffffff8108e6a9>] irq_exit+0xa9/0xc0
<4> [780.716361] WARNING: CPU: 0 PID: 2964 at drivers/gpu/drm/i915/intel_drv.h:2128 gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [780.716364] ---[ end trace ad71a8b88380193b ]---
Comment 9 Martin Peres 2018-12-07 10:14:00 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5272/shard-iclb7/igt@pm_rpm@legacy-planes.html

<4> [783.701792] ------------[ cut here ]------------
<4> [783.701795] RPM wakelock ref not held during HW access
<4> [783.701852] WARNING: CPU: 0 PID: 4145 at drivers/gpu/drm/i915/intel_drv.h:2128 gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [783.701854] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal i915 coretemp crct10dif_pclmul crc32_pclmul snd_hda_intel cdc_ether snd_hda_codec snd_hwdep usbnet ghash_clmulni_intel mii snd_hda_core e1000e snd_pcm i2c_i801 prime_numbers [last unloaded: vgem]
<4> [783.701872] CPU: 0 PID: 4145 Comm: pm_rpm Tainted: G     U            4.20.0-rc5-CI-CI_DRM_5272+ #1
<4> [783.701875] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP, BIOS ICLSFWR1.R00.2402.AD3.1810170014 10/17/2018
<4> [783.701917] RIP: 0010:gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [783.701921] Code: e8 ef e9 de e0 e9 0d ff ff ff 80 3d de bf 19 00 00 0f 85 78 fe ff ff 48 c7 c7 90 70 31 a0 c6 05 ca bf 19 00 01 e8 68 3a e7 e0 <0f> 0b e9 5e fe ff ff b9 01 00 00 00 ba 01 00 00 00 89 ee 48 89 df
<4> [783.701923] RSP: 0018:ffffc9000062ba10 EFLAGS: 00010286
<4> [783.701926] RAX: 0000000000000000 RBX: ffff88849eac0000 RCX: 0000000000000006
<4> [783.701929] RDX: 0000000000000006 RSI: ffffffff821298aa RDI: ffffffff820d7ca7
<4> [783.701931] RBP: 0000000000044fe8 R08: 00000000afec3fc3 R09: 0000000000000000
<4> [783.701933] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
<4> [783.701936] R13: 0000000000000001 R14: ffff8884908fa548 R15: 0000000000000000
<4> [783.701939] FS:  00007f98bd7c9980(0000) GS:ffff8884afe00000(0000) knlGS:0000000000000000
<4> [783.701941] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [783.701944] CR2: 00007f80d801d000 CR3: 000000044ea2c005 CR4: 0000000000760ef0
<4> [783.701946] PKRU: 55555554
<4> [783.701947] Call Trace:
<4> [783.701987]  icl_dbuf_slices_update+0xdf/0x160 [i915]
<4> [783.702033]  skl_update_crtcs+0x29c/0x2b0 [i915]
<4> [783.702082]  intel_atomic_commit_tail+0x1ea/0xd70 [i915]
<4> [783.702128]  ? intel_atomic_commit_ready+0x3f/0x50 [i915]
<4> [783.702157]  ? __i915_sw_fence_complete+0x1a0/0x250 [i915]
<4> [783.702203]  intel_atomic_commit+0x244/0x330 [i915]
<4> [783.702211]  drm_atomic_helper_update_plane+0xeb/0x100
<4> [783.702219]  setplane_internal+0x97/0x190
<4> [783.702233]  drm_mode_setplane+0xcf/0x190
<4> [783.702240]  ? drm_mode_cursor_common+0x220/0x220
<4> [783.702244]  drm_ioctl_kernel+0x81/0xf0
<4> [783.702251]  drm_ioctl+0x2de/0x390
<4> [783.702256]  ? drm_mode_cursor_common+0x220/0x220
<4> [783.702269]  do_vfs_ioctl+0xa0/0x6e0
<4> [783.702274]  ? lock_acquire+0xa6/0x1c0
<4> [783.702278]  ? __task_pid_nr_ns+0xb9/0x1f0
<4> [783.702284]  ksys_ioctl+0x35/0x60
<4> [783.702289]  __x64_sys_ioctl+0x11/0x20
<4> [783.702293]  do_syscall_64+0x55/0x190
<4> [783.702298]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [783.702301] RIP: 0033:0x7f98bca535d7
<4> [783.702304] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
<4> [783.702307] RSP: 002b:00007fff878179a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4> [783.702310] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f98bca535d7
<4> [783.702312] RDX: 00007fff878179e0 RSI: 00000000c03064b7 RDI: 0000000000000005
<4> [783.702314] RBP: 00007fff878179e0 R08: 0000000000000000 R09: 0000000000000001
<4> [783.702316] R10: 0000000000400000 R11: 0000000000000246 R12: 00000000c03064b7
<4> [783.702318] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
<4> [783.702329] irq event stamp: 100046
<4> [783.702333] hardirqs last  enabled at (100045): [<ffffffff810fc764>] vprintk_emit+0x124/0x320
<4> [783.702336] hardirqs last disabled at (100046): [<ffffffff810019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [783.702339] softirqs last  enabled at (99968): [<ffffffff81c0033a>] __do_softirq+0x33a/0x4b9
<4> [783.702343] softirqs last disabled at (99933): [<ffffffff8108e6a9>] irq_exit+0xa9/0xc0
<4> [783.702384] WARNING: CPU: 0 PID: 4145 at drivers/gpu/drm/i915/intel_drv.h:2128 gen11_fwtable_read32+0x1c8/0x260 [i915]
<4> [783.702386] ---[ end trace 346b1910a3fff3c5 ]---


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.