Bug 97564

Summary: [IVB] [IGT] pm_rps / waitboost produces a Test assertion failure
Product: DRI Reporter: Luis Botello <luis.botello.ortega>
Component: DRM/IntelAssignee: Intel GFX Bugs mailing list <intel-gfx-bugs>
Status: CLOSED WORKSFORME QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: normal    
Priority: medium CC: intel-gfx-bugs
Version: XOrg git   
Hardware: x86-64 (AMD64)   
OS: Linux (All)   
Whiteboard:
i915 platform: IVB i915 features: GEM/Other

Description Luis Botello 2016-09-01 18:21:57 UTC 
Description:
======================================
pm_rps / waitboost causes Test assertion Failure:
Test assertion failure function waitboost, file pm_rps.c:615:
CRITICAL: Failed assertion: boost_freqs[CUR] == boost_freqs[MAX]
CRITICAL: error: 350 != 1150
Issue is seen on 7 / 10 times.

Steps to reproduce:
======================================
#./pm_rps --run-subtest waitboost --debug

Software Configuration:
======================================
Bios: BH7710H.86A.0096.2012.1012.1645
Linux distribution: Ubuntu 16.04 64 bits
Kernel: 4.8.0-rc4 f4f46e5 from http://cgit.freedesktop.org/drm-intel/
{color:grey} commit f4f46e5544894b2198cdfd5a226ee587d9834cc4}}
 Author: Daniel Vetter <daniel.vetter@ffwll.ch>
 Date:   Mon Aug 29 16:09:42 2016 +0200
 drm-intel-nightly: 2016y-08m-29d-14h-09m-23s UTC integration manifest{color}
ibdrm-2.4.70-2 b214b05 from git://anongit.freedesktop.org/mesa/drm
mesa: mesa-11.2.2 3a9f628from git://anongit.freedesktop.org/mesa/mesa
cairo 1.15.2 db8a7f1 from git://anongit.freedesktop.org/cairo
xorg-server-1.18.0-535 25e4f9e from git://git.freedesktop.org/git/xorg/xserver
xf86-video-intel 2.99.917-698 71d3273 from git://git.freedesktop.org/git/xorg/driver/xf86-video-intel
libva-1.7.0-47 2ebf897 from git://git.freedesktop.org/git/vaapi/libva 
vaapi-intel-driver: 1.7.0-95 1817bee from git://git.freedesktop.org/git/vaapi/intel-driver
Intel-Gpu-Tools 1.15 572a770 from http://anongit.freedesktop.org/git/xorg/app/intel-gpu-tools.git


Hardware Configuration:
======================================
Platform: IVB
CPU: Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz (Family 6, Model 58, Stepping 9)
Motherboard version: DH77EB
GPU: Intel® HD Graphics 4000 - Xeon E3-1200 v2/3rd Gen Core processor Graphics Controller

IGToutput:
=======================================
IGT-Version: 1.15-g572a770 (x86_64) (Linux: 4.8.0-rc4-nightly+ x86_64)
(pm_rps:4656) igt-core-DEBUG: Test requirement passed: !igt_run_in_simulation()
(pm_rps:4656) drmtest-DEBUG: Test requirement passed: !(fd<0)
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) DEBUG: Test requirement passed: junk->filp
(pm_rps:4656) igt-core-DEBUG: Starting subtest: waitboost
(pm_rps:4656) drmtest-DEBUG: Test requirement passed: !(fd<0)
(pm_rps:4656) DEBUG: Apply low load...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Waited 0 msec to stabilize cur
(pm_rps:4656) DEBUG: Wait for gpu...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Apply low load again...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Waited 0 msec to stabilize cur
(pm_rps:4656) DEBUG: Removing load...
(pm_rps:4657) DEBUG: load helper sent 4220 dword writes
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Required 0 msec to reach cur=idle
(pm_rps:4656) CRITICAL: Test assertion failure function waitboost, file pm_rps.c:615:
(pm_rps:4656) CRITICAL: Failed assertion: boost_freqs[CUR] == boost_freqs[MAX]
(pm_rps:4656) CRITICAL: error: 350 != 1150
Stack trace:
  #0 [__igt_fail_assert+0xf1]
  #1 [waitboost+0x25b]
  #2 [__real_main635+0x2f2]
  #3 [main+0x29]
  #4 [__libc_start_main+0xf0]
  #5 [_start+0x29]
  #6 [<unknown>+0x29]
Subtest waitboost failed.
**** DEBUG ****
(pm_rps:4656) drmtest-DEBUG: Test requirement passed: !(fd<0)
(pm_rps:4656) DEBUG: Apply low load...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Waited 0 msec to stabilize cur
(pm_rps:4656) DEBUG: Wait for gpu...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Apply low load again...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Waited 0 msec to stabilize cur
(pm_rps:4656) DEBUG: Removing load...
(pm_rps:4656) DEBUG: gt freq (MHz):  cur=350  min=350  max=1150  RP0=1150  RP1=650  RPn=350
(pm_rps:4656) DEBUG: Required 0 msec to reach cur=idle
(pm_rps:4656) CRITICAL: Test assertion failure function waitboost, file pm_rps.c:615:
(pm_rps:4656) CRITICAL: Failed assertion: boost_freqs[CUR] == boost_freqs[MAX]
(pm_rps:4656) CRITICAL: error: 350 != 1150
****  END  ****
Subtest waitboost: FAIL (2.505s)
(pm_rps:4656) igt-core-DEBUG: Exiting with status code 99

Dmesg:
========================================
[   53.233697] pm_rps: executing
[   53.233748] [drm:i915_gem_open]
[   53.247053] [drm:i915_gem_open]
[   53.247477] [drm:i915_gem_open]
[   53.247636] pm_rps: starting subtest waitboost
[   53.247667] [drm:i915_gem_open]
[   55.749970] pm_rps: exiting, ret=0
[   60.053604] pm_rps: executing
[   60.053648] [drm:i915_gem_open]
[   60.063425] [drm:i915_gem_open]
[   60.063829] [drm:i915_gem_open]
[   60.063947] pm_rps: starting subtest waitboost
[   60.063957] [drm:i915_gem_open]
[   62.566798] pm_rps: exiting, ret=99
[   82.721142] pm_rps: executing
[   82.721229] [drm:i915_gem_open]
[   82.729076] [drm:i915_gem_open]
[   82.729564] [drm:i915_gem_open]
[   82.729811] pm_rps: starting subtest waitboost
[   82.729833] [drm:i915_gem_open]
[   85.234062] pm_rps: exiting, ret=99
[  121.340884] pm_rps: executing
[  121.340977] [drm:i915_gem_open]
[  121.344092] [drm:i915_gem_open]
[  121.344598] [drm:i915_gem_open]
[  121.344861] pm_rps: starting subtest waitboost
[  121.344896] [drm:i915_gem_open]
[  123.848670] pm_rps: exiting, ret=99
[  125.996188] pm_rps: executing
[  125.996284] [drm:i915_gem_open]
[  126.010571] [drm:i915_gem_open]
[  126.011082] [drm:i915_gem_open]
[  126.011424] pm_rps: starting subtest waitboost
[  126.011461] [drm:i915_gem_open]
[  128.514021] pm_rps: exiting, ret=0
[  130.204250] pm_rps: executing
[  130.204326] [drm:i915_gem_open]
[  130.210376] [drm:i915_gem_open]
[  130.210833] [drm:i915_gem_open]
[  130.211058] pm_rps: starting subtest waitboost
[  130.211078] [drm:i915_gem_open]
[  132.713648] pm_rps: exiting, ret=0
[  134.867670] pm_rps: executing
[  134.867777] [drm:i915_gem_open]
[  134.876837] [drm:i915_gem_open]
[  134.877332] [drm:i915_gem_open]
[  134.877582] pm_rps: starting subtest waitboost
[  134.877618] [drm:i915_gem_open]
[  137.381350] pm_rps: exiting, ret=99
[  138.724719] pm_rps: executing
[  138.724814] [drm:i915_gem_open]
[  138.726671] [drm:i915_gem_open]
[  138.727186] [drm:i915_gem_open]
[  138.727438] pm_rps: starting subtest waitboost
[  138.727476] [drm:i915_gem_open]
[  141.231213] pm_rps: exiting, ret=99
[  142.699171] pm_rps: executing
[  142.699256] [drm:i915_gem_open]
[  142.709841] [drm:i915_gem_open]
[  142.710311] [drm:i915_gem_open]
[  142.710541] pm_rps: starting subtest waitboost
[  142.710562] [drm:i915_gem_open]
[  145.214202] pm_rps: exiting, ret=99
[  146.595081] pm_rps: executing
[  146.595163] [drm:i915_gem_open]
[  146.609666] [drm:i915_gem_open]
[  146.610174] [drm:i915_gem_open]
[  146.610431] pm_rps: starting subtest waitboost
[  146.610466] [drm:i915_gem_open]
[  149.115107] pm_rps: exiting, ret=99
[  236.340880] random: crng init done
Comment 1 Chris Wilson 2016-09-01 20:30:38 UTC 
commit c1d427b0d764c919a34fe0b2249d941649e31216
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Sep 1 21:26:29 2016 +0100

    igt/pm_rps: Remove reliance on guessing the busy workload
    
    Create an unbounded batch in order to ensure that the workload doesn't
    disappear before the wait and so we should be given the RPS waitboost.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=97564
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Hopefully does the trick.
Comment 2 Luis Botello 2016-09-01 22:12:52 UTC 
Test passes now with the following config:
Component         : drm
	url       : http://cgit.freedesktop.org/mesa/drm
	tag       : libdrm-2.4.70-2-gb214b05
	commit    : b214b05
	author    : Rob Clark <robclark@freedesktop.org>
	age       : 4 weeks ago
	comment   : list: fix an issue with android build using clang

Component         : cairo
	url       : http://cgit.freedesktop.org/cairo
	tag       : 1.15.2
	commit    : db8a7f1
	author    : Bryce Harrington <bryce@osg.samsung.com>
	age       : 9 months ago
	comment   : 1.15.2 release 

Component         : intel-gpu-tools
	url       : https://cgit.freedesktop.org/xorg/app/intel-gpu-tools
	tag       : intel-gpu-tools-1.15-256-gc1d427b
	commit    : c1d427b
	author    : Chris Wilson <chris@chris-wilson.co.uk>
	age       : 85 minutes ago
	comment   : igt/pm_rps: Remove reliance on guessing the busy workload

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.