Re: ✗ Fi.CI.BAT: failure for drm/i915: Some GT freq stuff

["Ville Syrjälä" <ville.syrjala@linux.intel.com>]

On Mon, Mar 07, 2016 at 05:07:51PM +0200, Ville Syrjälä wrote:
> On Mon, Mar 07, 2016 at 10:34:26AM -0000, Patchwork wrote:
> > == Series Details ==
> > 
> > Series: drm/i915: Some GT freq stuff
> > URL   : https://patchwork.freedesktop.org/series/4129/
> > State : failure
> > 
> > == Summary ==
> > 
> > Series 4129v1 drm/i915: Some GT freq stuff
> > http://patchwork.freedesktop.org/api/1.0/series/4129/revisions/1/mbox/
> > 
> > Test kms_flip:
> >         Subgroup basic-flip-vs-dpms:
> >                 pass       -> DMESG-WARN (ilk-hp8440p) UNSTABLE
> 
> ilk underrun
> https://bugs.freedesktop.org/show_bug.cgi?id=93787
> 
> >         Subgroup basic-flip-vs-wf_vblank:
> >                 fail       -> PASS       (bsw-nuc-2)
> >                 pass       -> DMESG-FAIL (hsw-brixbox)
> 
> 
> (kms_flip:6763) DEBUG: name = flip
> last_ts = 333.745977 usec
> last_received_ts = 333.745522 usec
> last_seq = 1706
> current_ts = 333.929216 usec
> current_received_ts = 333.929426 usec
> current_seq = 1716
> count = 51
> seq_step = 1
> (kms_flip:6763) CRITICAL: Test assertion failure function check_state,
> file kms_flip.c:692:
> (kms_flip:6763) CRITICAL: Failed assertion: fabs((((double)
> diff.tv_usec) - usec_interflip) / usec_interflip) <= 0.005
> (kms_flip:6763) CRITICAL: Last errno: 25, Inappropriate ioctl for device
> (kms_flip:6763) CRITICAL: inter-flip ts jitter: 0s, 183239usec
> ****  END  ****
> 
> This sort of looks like the off by one error between the vbl timestamp
> and seq number
> https://bugs.freedesktop.org/show_bug.cgi?id=94294
> except here seq_step==1, so not sure why we ended up getting a
> difference of 11 frames (based on ts, 10 according to seq). I've seen
> this same thing before at least once before.
> 
> >         Subgroup basic-plain-flip:
> >                 dmesg-warn -> PASS       (hsw-gt2)
> > Test kms_frontbuffer_tracking:
> >         Subgroup basic:
> >                 pass       -> DMESG-WARN (hsw-gt2)
> 
> [  333.891630] Device suspended during HW access
> [  333.891668]  [<ffffffffa03027ac>] hsw_write32+0x1dc/0x270 [i915]
> [  333.891676]  [<ffffffffa02ab9c8>] _ilk_disable_lp_wm+0x98/0xd0 [i915]
> https://bugs.freedesktop.org/show_bug.cgi?id=94349
> 
> > Test kms_pipe_crc_basic:
> >         Subgroup nonblocking-crc-pipe-b-frame-sequence:
> >                 pass       -> DMESG-WARN (hsw-brixbox)
> 
> same
> [  346.472879]  [<ffffffffa03397eb>] hsw_write32+0x21b/0x270 [i915]
> [  346.472888]  [<ffffffffa02e29c8>] _ilk_disable_lp_wm+0x98/0xd0 [i915]
> 
> >         Subgroup read-crc-pipe-c:
> >                 dmesg-warn -> PASS       (hsw-gt2)
> >         Subgroup suspend-read-crc-pipe-a:
> >                 dmesg-warn -> PASS       (skl-i5k-2)
> >                 skip       -> PASS       (hsw-brixbox)
> > Test pm_rpm:
> >         Subgroup basic-rte:
> >                 pass       -> DMESG-WARN (snb-dellxps)
> 
> same
> [  306.449231]  [<ffffffffa0329dec>] gen6_write32+0x1dc/0x270 [i915]
> [  306.449244]  [<ffffffffa02d39c8>] _ilk_disable_lp_wm+0x98/0xd0 [i915]
> 
> 
> > Test pm_rps:
> >         Subgroup basic-api:
> >                 pass       -> FAIL       (skl-i5k-2)
> 
> (pm_rps:6439) CRITICAL: Test assertion failure function do_writeval, file pm_rps.c:136:
> (pm_rps:6439) CRITICAL: Failed assertion: readval(filp) == val
> (pm_rps:6439) CRITICAL: Last errno: 22, Invalid argument
> (pm_rps:6439) CRITICAL: error: 350 != 0
> 
> Hmm. This looks like the patches might have a problem. Need to
> investigate more.

OK, so I think with the flush_delayed_work()+locking gone, userspace
managed to read out the sysfs files before the delayed enable rps work
had populated the values. On VLV/CHV that can't happen since we populate
the values already before registering the sysfs files. I think I'll
change the gen6+ code to follow the same pattern.

This also highlighted a bug with the test itself. It failed to notice
that writing a bogus value to the sysfs file returned an error when we
weren't expecting one. I'll need to fix up the assert to check for the
right thing.

> 
> > 
> > bdw-ultra        total:183  pass:165  dwarn:0   dfail:0   fail:0   skip:18 
> > bsw-nuc-2        total:183  pass:149  dwarn:0   dfail:0   fail:0   skip:34 
> > byt-nuc          total:183  pass:152  dwarn:0   dfail:0   fail:0   skip:31 
> > hsw-brixbox      total:183  pass:162  dwarn:1   dfail:1   fail:0   skip:19 
> > hsw-gt2          total:183  pass:168  dwarn:1   dfail:0   fail:0   skip:14 
> > ilk-hp8440p      total:183  pass:124  dwarn:1   dfail:0   fail:0   skip:58 
> > ivb-t430s        total:183  pass:162  dwarn:0   dfail:0   fail:0   skip:21 
> > skl-i5k-2        total:183  pass:162  dwarn:0   dfail:0   fail:1   skip:20 
> > skl-i7k-2        total:183  pass:163  dwarn:0   dfail:0   fail:0   skip:20 
> > snb-dellxps      total:183  pass:152  dwarn:2   dfail:0   fail:0   skip:29 
> > 
> > Results at /archive/results/CI_IGT_test/Patchwork_1530/
> > 
> > d369e0096716c6000139162b3b340f684f0a51da drm-intel-nightly: 2016y-03m-04d-17h-18m-08s UTC integration manifest
> > 7e3aa23d98537d012a1af05c5fef19b28ba71404 drm/i915: Drop locking/rpm resume/flush_delayed_work for cur/min/max freq sysfs read
> > d027c2e4920ffe7c0cf514c06327485376ef16ba drm/i915: Set GPU freq to idle_freq initially
> > 83be894eede637336015c43f661341c05f236681 drm/i915: Use GPLL ref clock to calculate GPU freqs on VLV/CHV
> 
> -- 
> Ville Syrjälä
> Intel OTC
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx