Bug 103520 - [IGT] kms_pipe_crc_basic fails due to PM early wake event detected.
Summary: [IGT] kms_pipe_crc_basic fails due to PM early wake event detected.
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: unspecified
Hardware: Other All
: high critical
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
Depends on:
Blocks:
 
Reported: 2017-10-30 20:17 UTC by Elizabeth
Modified: 2018-01-05 17:08 UTC (History)
2 users (show)

See Also:
i915 platform: IVB
i915 features: power/runtime PM


Attachments
dmesg_log_ivb (740.11 KB, text/plain)
2017-10-30 20:17 UTC, Elizabeth
no flags Details
output_suspend-read-crc-pipe-A (12.61 KB, text/plain)
2017-10-30 20:25 UTC, Elizabeth
no flags Details

Description Elizabeth 2017-10-30 20:17:23 UTC
Created attachment 135169 [details]
dmesg_log_ivb

On IVB, when I try kms_pipe_crc_basic@suspend-read-crc-pipe-[A/B/C] twice, the second time the test fail due to: 

[16688.382233] pci_pm_suspend(): hcd_pci_suspend+0x0/0x30 returns -16
[16688.382247] dpm_run_callback(): pci_pm_suspend+0x0/0x140 returns -16
[16688.382252] PM: Device 0000:00:1d.0 failed to suspend async: error -16
[16688.550517] hp_wmi: Unknown event_id - 14 - 0x0
[16688.815267] PM: Some devices failed to suspend, or early wake event detected

It will work the third time, fail the forth and so on...

Assertion given is:

(kms_pipe_crc_basic:8202) igt-core-WARNING: [cmd] rtcwake: write error
(kms_pipe_crc_basic:8202) igt-aux-CRITICAL: Test assertion failure function suspend_via_rtcwake, file igt_aux.c:809:
(kms_pipe_crc_basic:8202) igt-aux-CRITICAL: Failed assertion: ret == 0
(kms_pipe_crc_basic:8202) igt-aux-CRITICAL: rtcwake failed with 1
Check dmesg for further details.

With IGT-Version: 1.20-g1fc4de1 (x86_64) (Linux: 4.14.0-rc6-drm-intel-qa-ww44-commit-2badde8+ x86_64)
Comment 1 Elizabeth 2017-10-30 20:25:11 UTC
Created attachment 135170 [details]
output_suspend-read-crc-pipe-A
Comment 2 Elizabeth 2017-11-13 22:24:28 UTC
Still present with IGT-Version: 1.20-gf370d59 (x86_64) (Linux: 4.14.0-rc8-drm-intel-qa-ww46-commit-9a81c14+ x86_64)
Comment 3 krisman 2017-11-14 00:34:26 UTC
(In reply to Elizabeth from comment #0)
> Created attachment 135169 [details]
> dmesg_log_ivb
> 
> On IVB, when I try kms_pipe_crc_basic@suspend-read-crc-pipe-[A/B/C] twice,
> the second time the test fail due to: 
> 
> [16688.382233] pci_pm_suspend(): hcd_pci_suspend+0x0/0x30 returns -16

If I'm not mistaken, that is from USB.  Do you have any gadgets connected to the box?  Try unplugging those prior to running the test.  Looks like you have a misbehaving gadget.
Comment 4 Elizabeth 2017-11-16 20:09:52 UTC
(In reply to krisman from comment #3)
> (In reply to Elizabeth from comment #0)
> >
> If I'm not mistaken, that is from USB.  Do you have any gadgets connected to
> the box?  Try unplugging those prior to running the test.  Looks like you
> have a misbehaving gadget.
Sorry for the delay, I tested without anything besides Ethernet cable connected to the laptop. I tried with and without external monitor connected, and result keeps being the same, once pass, twice fails with PM error message each time it fails.

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
IGT-Version: 1.20-g88d6550 (x86_64) (Linux: 4.14.0-drm-intel-qa-ww46-commit-1fc4fe8+ x86_64)
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 16 07:20:01 2017
(kms_pipe_crc_basic:3923) igt-core-WARNING: [cmd] rtcwake: write error
(kms_pipe_crc_basic:3923) igt-aux-CRITICAL: Test assertion failure function suspend_via_rtcwake, file igt_aux.c:809:
(kms_pipe_crc_basic:3923) igt-aux-CRITICAL: Failed assertion: ret == 0
(kms_pipe_crc_basic:3923) igt-aux-CRITICAL: rtcwake failed with 1
Check dmesg for further details.
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [igt_system_suspend_autoresume+0x5ae]
  #2 [<unknown>+0x5ae]
  #3 [<unknown>+0x5ae]
Subtest suspend-read-crc-pipe-A failed.

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
IGT-Version: 1.20-g88d6550 (x86_64) (Linux: 4.14.0-drm-intel-qa-ww46-commit-1fc4fe8+ x86_64)
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 16 07:20:08 2017
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
Subtest suspend-read-crc-pipe-A: SUCCESS (4.138s)

$ : dmesg | grep PM:
[   42.019984] PM: suspend entry (deep)
[   42.019986] PM: Syncing filesystems ... done.
[   42.120102] PM: Device 0000:00:1d.0 failed to suspend async: error -16
[   42.570211] PM: Some devices failed to suspend, or early wake event detected
[   43.011696] PM: suspend exit
[   48.781766] PM: suspend entry (deep)
[   48.781769] PM: Syncing filesystems ... done.
[   49.416702] PM: Saving platform NVS memory
[   49.484019] PM: Restoring platform NVS memory
[   50.880846] PM: suspend exit
Comment 5 krisman 2017-11-27 09:06:34 UTC
(In reply to Elizabeth from comment #4)
> (In reply to krisman from comment #3)
> > (In reply to Elizabeth from comment #0)
> > >
> > If I'm not mistaken, that is from USB.  Do you have any gadgets connected to
> > the box?  Try unplugging those prior to running the test.  Looks like you
> > have a misbehaving gadget.
> Sorry for the delay, I tested without anything besides Ethernet cable
> connected to the laptop. I tried with and without external monitor
> connected, and result keeps being the same, once pass, twice fails with PM
> error message each time it fails.
> 
> $ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
> IGT-Version: 1.20-g88d6550 (x86_64) (Linux:
> 4.14.0-drm-intel-qa-ww46-commit-1fc4fe8+ x86_64)
> suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
> [cmd] rtcwake: assuming RTC uses UTC ...
> rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 16 07:20:01 2017
> (kms_pipe_crc_basic:3923) igt-core-WARNING: [cmd] rtcwake: write error
> (kms_pipe_crc_basic:3923) igt-aux-CRITICAL: Test assertion failure function
> suspend_via_rtcwake, file igt_aux.c:809:
> (kms_pipe_crc_basic:3923) igt-aux-CRITICAL: Failed assertion: ret == 0
> (kms_pipe_crc_basic:3923) igt-aux-CRITICAL: rtcwake failed with 1
> Check dmesg for further details.
> Stack trace:
>   #0 [__igt_fail_assert+0x101]
>   #1 [igt_system_suspend_autoresume+0x5ae]
>   #2 [<unknown>+0x5ae]
>   #3 [<unknown>+0x5ae]
> Subtest suspend-read-crc-pipe-A failed.
> 
> $ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
> IGT-Version: 1.20-g88d6550 (x86_64) (Linux:
> 4.14.0-drm-intel-qa-ww46-commit-1fc4fe8+ x86_64)
> suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
> [cmd] rtcwake: assuming RTC uses UTC ...
> rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 16 07:20:08 2017
> suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
> suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
> Subtest suspend-read-crc-pipe-A: SUCCESS (4.138s)
> 
> $ : dmesg | grep PM:
> [   42.019984] PM: suspend entry (deep)
> [   42.019986] PM: Syncing filesystems ... done.
> [   42.120102] PM: Device 0000:00:1d.0 failed to suspend async: error -16
> [   42.570211] PM: Some devices failed to suspend, or early wake event
> detected
> [   43.011696] PM: suspend exit
> [   48.781766] PM: suspend entry (deep)
> [   48.781769] PM: Syncing filesystems ... done.
> [   49.416702] PM: Saving platform NVS memory
> [   49.484019] PM: Restoring platform NVS memory
> [   50.880846] PM: suspend exit

I would suggest enabling dyn_dbg for xhci and trying again.  Since this is not graphics related, what is the procedure?  should we create a bug in kernel.org?
Comment 6 Elizabeth 2017-11-30 16:03:39 UTC
(In reply to krisman from comment #5)
>...
Can't reproduce issue anymore since commit: 

commit 79ca54cbfbc7aae4090d6ded6af6348f8654322d
Author:     Chris Wilson <chris@chris-wilson.co.uk>
AuthorDate: Fri Nov 24 12:20:21 2017 +0000
Commit:     Chris Wilson <chris@chris-wilson.co.uk>
CommitDate: Fri Nov 24 12:20:21 2017 +0000

    drm-tip: 2017y-11m-24d-12h-19m-52s UTC integration manifest

No HW changes were done.

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:10:04 2017
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
Subtest suspend-read-crc-pipe-A: SUCCESS (4.121s)

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-A
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:10:33 2017
suspend-read-crc-pipe-A: Testing connector LVDS-1 using pipe A
suspend-read-crc-pipe-A: Testing connector VGA-1 using pipe A
suspend-read-crc-pipe-A: Testing connector DP-3 using pipe A
Subtest suspend-read-crc-pipe-A: SUCCESS (4.107s)

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-B
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-B: Testing connector LVDS-1 using pipe B
suspend-read-crc-pipe-B: Testing connector VGA-1 using pipe B
suspend-read-crc-pipe-B: Testing connector DP-3 using pipe B
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:11:03 2017
suspend-read-crc-pipe-B: Testing connector LVDS-1 using pipe B
suspend-read-crc-pipe-B: Testing connector VGA-1 using pipe B
suspend-read-crc-pipe-B: Testing connector DP-3 using pipe B
Subtest suspend-read-crc-pipe-B: SUCCESS (4.609s)

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-B
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-B: Testing connector LVDS-1 using pipe B
suspend-read-crc-pipe-B: Testing connector VGA-1 using pipe B
suspend-read-crc-pipe-B: Testing connector DP-3 using pipe B
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:11:43 2017
suspend-read-crc-pipe-B: Testing connector LVDS-1 using pipe B
suspend-read-crc-pipe-B: Testing connector VGA-1 using pipe B
suspend-read-crc-pipe-B: Testing connector DP-3 using pipe B
Subtest suspend-read-crc-pipe-B: SUCCESS (4.852s)

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-C
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-C: Testing connector LVDS-1 using pipe C
suspend-read-crc-pipe-C: Testing connector VGA-1 using pipe C
suspend-read-crc-pipe-C: Testing connector DP-3 using pipe C
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:12:16 2017
suspend-read-crc-pipe-C: Testing connector LVDS-1 using pipe C
suspend-read-crc-pipe-C: Testing connector VGA-1 using pipe C
suspend-read-crc-pipe-C: Testing connector DP-3 using pipe C
Subtest suspend-read-crc-pipe-C: SUCCESS (4.685s)

$ : sudo -E ./kms_pipe_crc_basic --r suspend-read-crc-pipe-C
IGT-Version: 1.20-gac6739b (x86_64) (Linux: 4.15.0-rc1-drm-intel-qa-ww48-commit-6d6c48b+ x86_64)
suspend-read-crc-pipe-C: Testing connector LVDS-1 using pipe C
suspend-read-crc-pipe-C: Testing connector VGA-1 using pipe C
suspend-read-crc-pipe-C: Testing connector DP-3 using pipe C
[cmd] rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Thu Nov 30 05:12:48 2017
suspend-read-crc-pipe-C: Testing connector LVDS-1 using pipe C
suspend-read-crc-pipe-C: Testing connector VGA-1 using pipe C
suspend-read-crc-pipe-C: Testing connector DP-3 using pipe C
Subtest suspend-read-crc-pipe-C: SUCCESS (4.921s)

$ : dmesg | grep PM:
[ 6707.869600] PM: suspend entry (deep)
[ 6707.869605] PM: Syncing filesystems ... done.
[ 6708.578279] PM: Saving platform NVS memory
[ 6708.641679] PM: Restoring platform NVS memory
[ 6710.001727] PM: suspend exit


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.