Bug 65197

Summary: [HSW Bisected]<3>[drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
Product: DRI Reporter: lu hua <huax.lu>
Component: DRM/IntelAssignee: Daniel Vetter <daniel>
Status: CLOSED FIXED QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: major    
Priority: high CC: yangweix.shui
Version: unspecified   
Hardware: All   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:
Attachments:
Description Flags
drop the WARN none

Description lu hua 2013-05-31 03:01:24 UTC 
System Environment:
--------------------------
Arch:           x86_64
Platform:       Haswell
Kernel: (drm-intel-next-queued)c886979ca47fcdcec95a288c8f119510b1be5469

Bug detailed description:
-------------------------
Run ./drm_vma_limiter_cached , dmesg has [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted.
When run following cases, also have this issue:
igt/drm_vma_limiter_gtt
igt/gem_cpu_concurrent_blit/gpu-read-after-write
igt/gem_cpu_concurrent_blit/overwrite-source
igt/gem_cpu_reloc
igt/gem_cs_prefetch
igt/gem_cs_tlb/blt
igt/gem_cs_tlb/bsd
igt/gem_cs_tlb/render
igt/gem_ctx_bad_exec
igt/gem_ctx_basic
igt/gem_ctx_exec
igt/gem_double_irq_loop
igt/gem_dummy_reloc_loop/blt
igt/gem_dummy_reloc_loop/bsd
igt/gem_dummy_reloc_loop/mixed
igt/gem_dummy_reloc_loop/render
igt/gem_exec_bad_domains/cpu-domain
igt/gem_exec_bad_domains/double-write-domain
igt/gem_exec_bad_domains/gtt-domain
igt/gem_exec_bad_domains/invalid-gpu-domain
igt/gem_exec_big
igt/gem_exec_blt
igt/gem_exec_lut_handle
igt/gem_exec_nop/blt
igt/gem_exec_nop/bsd
igt/gem_exec_nop/render
igt/gem_fenced_exec_thrash
igt/gem_fence_thrash/bo-write-verify-none
igt/gem_fence_thrash/bo-write-verify-x
igt/gem_flink/basic
igt/gem_flink/double-flink
igt/gem_flink/flink-lifetime
igt/gem_gtt_concurrent_blit/early-read
igt/gem_gtt_concurrent_blit/overwrite-source
igt/gem_hangcheck_forcewake
igt/gem_largeobject
igt/gem_linear_blits
igt/gem_lut_handle
igt/gem_mmap_gtt/write
igt/gem_mmap_offset_exhaustion
igt/gem_partial_pwrite_pread/reads
igt/gem_partial_pwrite_pread/writes
igt/gem_partial_pwrite_pread/writes-after-reads
igt/gem_pin
igt/gem_pipe_control_store_loop
igt/gem_pwrite
igt/gem_reg_read
igt/gem_reloc_vs_gpu
igt/gem_render_linear_blits
igt/gem_render_tiled_blits
igt/gem_ringfill/blitter
igt/gem_ringfill/render
igt/gem_ring_sync_loop
igt/gem_seqno_wrap
igt/gem_set_tiling_vs_blt/tiled-to-tiled
igt/gem_set_tiling_vs_blt/tiled-to-untiled
igt/gem_set_tiling_vs_blt/untiled-to-tiled
igt/gem_storedw_batches_loop
igt/gem_storedw_loop_blt
igt/gem_storedw_loop_bsd
igt/gem_storedw_loop_render
igt/gem_tiled_blits
igt/gem_tiled_fence_blits
igt/gem_tiled_partial_pwrite_pread/reads
igt/gem_tiled_partial_pwrite_pread/writes
igt/gem_tiled_partial_pwrite_pread/writes-after-reads
igt/gem_tiled_pread
igt/gem_tiled_swapping
igt/gem_tiling_max_stride
igt/gem_unfence_active_buffers
igt/gem_unref_active_buffers
igt/gem_wait_render_timeout
igt/getstats
igt/kms_flip/delayed-flip-vs-dpms
igt/kms_flip/delayed-flip-vs-panning
igt/kms_flip/flip-vs-absolute-wf_vblank
igt/kms_flip/flip-vs-dpms
igt/kms_flip/flip-vs-dpms-off-vs-modeset
igt/kms_flip/flip-vs-modeset
igt/kms_flip/plain-flip-fb-recreate
igt/kms_flip/single-buffer-flip-vs-dpms-off-vs-modeset
igt/kms_flip/wf_vblank-vs-dpms
igt/kms_flip/wf_vblank-vs-modeset
igt/module_reload
igt/prime_self_import/with_two_bos
igt/testdisplay

Bisect shows:
22aae764a3fa21ee502b99e8986cb4e49ec14cfe is the first bad commit
commit 22aae764a3fa21ee502b99e8986cb4e49ec14cfe
Author:     Ben Widawsky <ben@bwidawsk.net>
AuthorDate: Tue May 28 19:22:24 2013 -0700
Commit:     Daniel Vetter <daniel.vetter@ffwll.ch>
CommitDate: Wed May 29 21:19:11 2013 +0200

    drm/i915: Create a more generic pm handler for hsw+

    HSW has some special requirements for the VEBOX. Splitting out the
    interrupt handler will make the code a bit nicer and less error prone
    when we begin to handle those.

    The slight functional change in this patch (queueing work while holding
    the spinlock) is intentional as it makes a subsequent patch a bit nicer.
    The change should also only effect HSW platforms.

    Reviewed-by: Damien Lespiau <damien.lespiau@intel.com>
    Signed-off-by: Ben Widawsky <ben@bwidawsk.net>
    [danvet: move the queue_work out of the spinlock again.]
    Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

dmesg:
[   37.719785] [drm:i915_driver_open],
[   37.719797] [drm:intel_crtc_set_config], [CRTC:3] [NOFB]
[   37.719801] [drm:intel_crtc_set_config], [CRTC:5] [NOFB]
[   37.719802] [drm:intel_crtc_set_config], [CRTC:7] [NOFB]
[   37.719805] [drm:i915_driver_open],
[   37.719832] [drm:i915_getparam], Unknown parameter 22
[   37.719946] [drm:i915_getparam], Unknown parameter 22
[   37.804527] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.315209] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.347630] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.412516] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.509595] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.574380] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.671577] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.736392] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.833891] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.931013] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   38.995697] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.028196] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.093471] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.190957] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.255942] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.353898] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.418944] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.451447] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.516462] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.613935] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.678898] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.776729] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.841703] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.906728] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   39.918886] [drm:intel_crtc_set_config], [CRTC:3] [NOFB]
[   39.918891] [drm:intel_crtc_set_config], [CRTC:5] [NOFB]
[   39.918893] [drm:intel_crtc_set_config], [CRTC:7] [NOFB]
[   39.918915] [drm:i915_driver_open],
[   39.918919] [drm:intel_crtc_set_config], [CRTC:3] [NOFB]
[   39.918920] [drm:intel_crtc_set_config], [CRTC:5] [NOFB]
[   39.918921] [drm:intel_crtc_set_config], [CRTC:7] [NOFB]
[   39.918924] [drm:i915_driver_open],
[   39.918949] [drm:i915_getparam], Unknown parameter 22
[   40.288303] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   40.288353] [drm:intel_crtc_set_config], [CRTC:3] [NOFB]
[   40.288355] [drm:intel_crtc_set_config], [CRTC:5] [NOFB]
[   40.288357] [drm:intel_crtc_set_config], [CRTC:7] [NOFB]
[   42.715457] [drm:hsw_pm_irq_handler] *ERROR* Unexpected PM interrupted
[   62.124839] NET: Registered protocol family 10

Reproduce steps:
----------------
1. ./drm_vma_limiter_cached
2. dmesg -r | egrep "<[1-6]>" |grep drm
Comment 1 lu hua 2013-05-31 03:31:27 UTC 
It happens on drm-intel-next-queued kernel, and works well on drm-intel-fixes kernel.
Comment 2 Daniel Vetter 2013-05-31 07:12:54 UTC 
Created attachment 80082 [details] [review]
drop the WARN
Comment 3 lu hua 2013-06-03 01:51:38 UTC 
Fixed.
Comment 4 lu hua 2013-06-03 01:52:31 UTC 
Verified.Fixed.
Comment 5 Gordon Jin 2013-07-03 01:52:12 UTC 
(correct for credit)
Comment 6 Jari Tahvanainen 2017-08-14 10:36:12 UTC 
Closing old Verified+Fixed.

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.