[PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
on some CI machines I have concluded that: a) the PMU readout of RC6 can
race against runtime PM transitions, and b) there are other reasons than
being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
fail.

Therefore when estimating RC6 the code needs to assert we are indeed in
suspended state and if not the best we can do is return the last known RC6
value.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Imre Deak <imre.deak@intel.com>
---
I was able to trigger state != RPM_SUSPENDED on the shards, but not yet
the actual estimation overaccounting. As such this fix is based partially
on speculation that it will fix the sporadic perf_pmu/rc6* failures.
Nevertheless I think it is correct to add this check regardless.
---
 drivers/gpu/drm/i915/i915_pmu.c | 24 ++++++++++++++++++++++++
 1 file changed, 24 insertions(+)

diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
index bd7e695fc663..e92a9571db77 100644
--- a/drivers/gpu/drm/i915/i915_pmu.c
+++ b/drivers/gpu/drm/i915/i915_pmu.c
@@ -473,6 +473,30 @@ static u64 get_rc6(struct drm_i915_private *i915)
 		spin_lock_irqsave(&i915->pmu.lock, flags);
 		spin_lock(&kdev->power.lock);
 
+		/*
+		 * After the above branch intel_runtime_pm_get_if_in_use failed
+		 * to get the runtime PM reference we cannot assume we are in
+		 * runtime suspend since we can either: a) race with coming out
+		 * of it before we took the power.lock, or b) there are other
+		 * states than suspended which can bring us here.
+		 *
+		 * We need to double-check that we are indeed currently runtime
+		 * suspended and if not we cannot do better than report the last
+		 * known RC6 value.
+		 */
+		if (kdev->power.runtime_status != RPM_SUSPENDED) {
+			spin_unlock(&kdev->power.lock);
+
+			if (i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
+				val = i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur;
+			else
+				val = i915->pmu.sample[__I915_SAMPLE_RC6].cur;
+
+			spin_unlock_irqrestore(&i915->pmu.lock, flags);
+
+			return val;
+		}
+
 		if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
 			i915->pmu.suspended_jiffies_last =
 						kdev->power.suspended_jiffies;
-- 
2.14.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Chris Wilson]

Quoting Tvrtko Ursulin (2018-04-10 10:23:28)
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> 
> While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
> on some CI machines I have concluded that: a) the PMU readout of RC6 can
> race against runtime PM transitions, and b) there are other reasons than
> being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
> fail.
> 
> Therefore when estimating RC6 the code needs to assert we are indeed in
> suspended state and if not the best we can do is return the last known RC6
> value.
> 
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Imre Deak <imre.deak@intel.com>
> ---
> I was able to trigger state != RPM_SUSPENDED on the shards, but not yet
> the actual estimation overaccounting. As such this fix is based partially
> on speculation that it will fix the sporadic perf_pmu/rc6* failures.
> Nevertheless I think it is correct to add this check regardless.
> ---
>  drivers/gpu/drm/i915/i915_pmu.c | 24 ++++++++++++++++++++++++
>  1 file changed, 24 insertions(+)
> 
> diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
> index bd7e695fc663..e92a9571db77 100644
> --- a/drivers/gpu/drm/i915/i915_pmu.c
> +++ b/drivers/gpu/drm/i915/i915_pmu.c
> @@ -473,6 +473,30 @@ static u64 get_rc6(struct drm_i915_private *i915)
>                 spin_lock_irqsave(&i915->pmu.lock, flags);
>                 spin_lock(&kdev->power.lock);
>  
> +               /*
> +                * After the above branch intel_runtime_pm_get_if_in_use failed
> +                * to get the runtime PM reference we cannot assume we are in
> +                * runtime suspend since we can either: a) race with coming out
> +                * of it before we took the power.lock, or b) there are other
> +                * states than suspended which can bring us here.
> +                *
> +                * We need to double-check that we are indeed currently runtime
> +                * suspended and if not we cannot do better than report the last
> +                * known RC6 value.
> +                */
> +               if (kdev->power.runtime_status != RPM_SUSPENDED) {
> +                       spin_unlock(&kdev->power.lock);
> +
> +                       if (i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
> +                               val = i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur;
> +                       else
> +                               val = i915->pmu.sample[__I915_SAMPLE_RC6].cur;

If rpm awake, but having lost the race to read the regs, report the last
known value.

This is because we don't know if another thread is in the other branch,
and so we will have one updating the estimate while it being compared
against.

But I'm not understanding the failure -- why is the estimate bad? At the
very least we still ensure that it is monotonic? Is it just the jitter
you are worrying about? (If the estimate is bad here, isn't it always
bad?)

> +
> +                       spin_unlock_irqrestore(&i915->pmu.lock, flags);
> +
> +                       return val;
> +               }

I'd prefer moving the RPM_SUSPENDED code into an else branch to avoid
another unlock/early return here. (It just fits into 80cols, so no
excuses ;)
-Chris
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

✗ Fi.CI.BAT: warning for drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Patchwork]

== Series Details ==

Series: drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6
URL   : https://patchwork.freedesktop.org/series/41453/
State : warning

== Summary ==

Series 41453v1 drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6
https://patchwork.freedesktop.org/api/1.0/series/41453/revisions/1/mbox/

---- Possible new issues:

Test gem_exec_gttfill:
        Subgroup basic:
                pass       -> SKIP       (fi-pnv-d510)

---- Known issues:

Test gem_exec_suspend:
        Subgroup basic-s3:
                dmesg-warn -> PASS       (fi-glk-j4005) fdo#103359
Test kms_flip:
        Subgroup basic-flip-vs-wf_vblank:
                fail       -> PASS       (fi-glk-j4005) fdo#100368 +1

fdo#103359 https://bugs.freedesktop.org/show_bug.cgi?id=103359
fdo#100368 https://bugs.freedesktop.org/show_bug.cgi?id=100368

fi-bdw-5557u     total:285  pass:264  dwarn:0   dfail:0   fail:0   skip:21  time:431s
fi-bdw-gvtdvm    total:285  pass:261  dwarn:0   dfail:0   fail:0   skip:24  time:446s
fi-blb-e6850     total:285  pass:220  dwarn:1   dfail:0   fail:0   skip:64  time:379s
fi-bsw-n3050     total:285  pass:239  dwarn:0   dfail:0   fail:0   skip:46  time:539s
fi-bwr-2160      total:285  pass:180  dwarn:0   dfail:0   fail:0   skip:105 time:297s
fi-bxt-dsi       total:285  pass:255  dwarn:0   dfail:0   fail:0   skip:30  time:513s
fi-bxt-j4205     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:510s
fi-byt-j1900     total:285  pass:250  dwarn:0   dfail:0   fail:0   skip:35  time:520s
fi-byt-n2820     total:285  pass:246  dwarn:0   dfail:0   fail:0   skip:39  time:508s
fi-cfl-8700k     total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:410s
fi-cfl-s3        total:285  pass:258  dwarn:0   dfail:0   fail:1   skip:26  time:550s
fi-cfl-u         total:285  pass:259  dwarn:0   dfail:0   fail:0   skip:26  time:511s
fi-cnl-y3        total:285  pass:259  dwarn:0   dfail:0   fail:0   skip:26  time:585s
fi-elk-e7500     total:285  pass:226  dwarn:0   dfail:0   fail:0   skip:59  time:427s
fi-gdg-551       total:285  pass:176  dwarn:0   dfail:0   fail:1   skip:108 time:316s
fi-glk-1         total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:536s
fi-glk-j4005     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:491s
fi-hsw-4770      total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:405s
fi-ilk-650       total:285  pass:225  dwarn:0   dfail:0   fail:0   skip:60  time:428s
fi-ivb-3520m     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:466s
fi-ivb-3770      total:285  pass:252  dwarn:0   dfail:0   fail:0   skip:33  time:441s
fi-kbl-7500u     total:285  pass:260  dwarn:1   dfail:0   fail:0   skip:24  time:470s
fi-kbl-7567u     total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:465s
fi-kbl-r         total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:511s
fi-pnv-d510      total:285  pass:219  dwarn:1   dfail:0   fail:0   skip:65  time:633s
fi-skl-6260u     total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:439s
fi-skl-6600u     total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:541s
fi-skl-6700k2    total:285  pass:261  dwarn:0   dfail:0   fail:0   skip:24  time:506s
fi-skl-6770hq    total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:502s
fi-skl-guc       total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:425s
fi-skl-gvtdvm    total:285  pass:262  dwarn:0   dfail:0   fail:0   skip:23  time:446s
fi-snb-2520m     total:285  pass:245  dwarn:0   dfail:0   fail:0   skip:40  time:564s
fi-snb-2600      total:285  pass:245  dwarn:0   dfail:0   fail:0   skip:40  time:409s

617cdf0bd4fd2cb0dcc64ddf07fbb56572ba800a drm-tip: 2018y-04m-09d-19h-55m-54s UTC integration manifest
b1c4a2bf8bb8 drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

== Logs ==

For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8653/issues.html
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Tvrtko Ursulin]

On 10/04/2018 10:57, Chris Wilson wrote:
> Quoting Tvrtko Ursulin (2018-04-10 10:23:28)
>> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>
>> While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
>> on some CI machines I have concluded that: a) the PMU readout of RC6 can
>> race against runtime PM transitions, and b) there are other reasons than
>> being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
>> fail.
>>
>> Therefore when estimating RC6 the code needs to assert we are indeed in
>> suspended state and if not the best we can do is return the last known RC6
>> value.
>>
>> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
>> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
>> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> Cc: Chris Wilson <chris@chris-wilson.co.uk>
>> Cc: Imre Deak <imre.deak@intel.com>
>> ---
>> I was able to trigger state != RPM_SUSPENDED on the shards, but not yet
>> the actual estimation overaccounting. As such this fix is based partially
>> on speculation that it will fix the sporadic perf_pmu/rc6* failures.
>> Nevertheless I think it is correct to add this check regardless.
>> ---
>>   drivers/gpu/drm/i915/i915_pmu.c | 24 ++++++++++++++++++++++++
>>   1 file changed, 24 insertions(+)
>>
>> diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
>> index bd7e695fc663..e92a9571db77 100644
>> --- a/drivers/gpu/drm/i915/i915_pmu.c
>> +++ b/drivers/gpu/drm/i915/i915_pmu.c
>> @@ -473,6 +473,30 @@ static u64 get_rc6(struct drm_i915_private *i915)
>>                  spin_lock_irqsave(&i915->pmu.lock, flags);
>>                  spin_lock(&kdev->power.lock);
>>   
>> +               /*
>> +                * After the above branch intel_runtime_pm_get_if_in_use failed
>> +                * to get the runtime PM reference we cannot assume we are in
>> +                * runtime suspend since we can either: a) race with coming out
>> +                * of it before we took the power.lock, or b) there are other
>> +                * states than suspended which can bring us here.
>> +                *
>> +                * We need to double-check that we are indeed currently runtime
>> +                * suspended and if not we cannot do better than report the last
>> +                * known RC6 value.
>> +                */
>> +               if (kdev->power.runtime_status != RPM_SUSPENDED) {
>> +                       spin_unlock(&kdev->power.lock);
>> +
>> +                       if (i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
>> +                               val = i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur;
>> +                       else
>> +                               val = i915->pmu.sample[__I915_SAMPLE_RC6].cur;
> 
> If rpm awake, but having lost the race to read the regs, report the last
> known value.
> 
> This is because we don't know if another thread is in the other branch,
> and so we will have one updating the estimate while it being compared
> against.

No, the race is intel_runtime_pm_get_if_in_use telling us the device is 
not active, but a) that doesn't mean it is suspended, and b) it doesn't 
mean it is still suspended after the check.

Also PMU internal state is serialized by the spinlock so there is no 
inconsistency there.
> But I'm not understanding the failure -- why is the estimate bad? At the
> very least we still ensure that it is monotonic? Is it just the jitter
> you are worrying about? (If the estimate is bad here, isn't it always
> bad?)

As far as I have seen failures from CI are all estimate being too large. 
(no jitter and no going backwards)

What I suspect is going bad in either case, is that we must not add the 
delta from current jiffies to internal runtime pm counters if state is 
not suspended. If we do that we are accounting an unknown period of time 
as suspended time and that would explain the over-estimation.

In other words we are only allowed to estimate if the current state is 
definitely suspended. If it is anything else we need to report either 
the last estimated value, or the last real value, depending what is more 
recent.

I've done a CI run which definitely shows we can end up in this path 
when state is not suspended.

>> +
>> +                       spin_unlock_irqrestore(&i915->pmu.lock, flags);
>> +
>> +                       return val;
>> +               }
> 
> I'd prefer moving the RPM_SUSPENDED code into an else branch to avoid
> another unlock/early return here. (It just fits into 80cols, so no
> excuses ;)

Okay makes sense.

Regards,

Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Chris Wilson]

Quoting Tvrtko Ursulin (2018-04-10 11:22:55)
> 
> On 10/04/2018 10:57, Chris Wilson wrote:
> > But I'm not understanding the failure -- why is the estimate bad? At the
> > very least we still ensure that it is monotonic? Is it just the jitter
> > you are worrying about? (If the estimate is bad here, isn't it always
> > bad?)
> 
> As far as I have seen failures from CI are all estimate being too large. 
> (no jitter and no going backwards)
> 
> What I suspect is going bad in either case, is that we must not add the 
> delta from current jiffies to internal runtime pm counters if state is 
> not suspended. If we do that we are accounting an unknown period of time 
> as suspended time and that would explain the over-estimation.
> 
> In other words we are only allowed to estimate if the current state is 
> definitely suspended. If it is anything else we need to report either 
> the last estimated value, or the last real value, depending what is more 
> recent.

i.e. we must not use kdev->power.suspended_jiffies before we know it is
set.

Ok, that is stating to make sense. Thanks, can you update the commitmsg
with this (pretty much verbatim as it is a good explanation).
-Chris
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH v2] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
on some CI machines I have concluded that: a) the PMU readout of RC6 can
race against runtime PM transitions, and b) there are other reasons than
being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
fail.

Therefore when estimating RC6 the code needs to assert we are indeed in
suspended state and if not the best we can do is return the last known RC6
value.

v2:
 * Re-arrange the code a bit to avoid second unlock and return branch.
   (Chris Wilson)

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Imre Deak <imre.deak@intel.com>
---
 drivers/gpu/drm/i915/i915_pmu.c | 39 +++++++++++++++++++++++++++------------
 1 file changed, 27 insertions(+), 12 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
index bd7e695fc663..247a050f816e 100644
--- a/drivers/gpu/drm/i915/i915_pmu.c
+++ b/drivers/gpu/drm/i915/i915_pmu.c
@@ -473,20 +473,35 @@ static u64 get_rc6(struct drm_i915_private *i915)
 		spin_lock_irqsave(&i915->pmu.lock, flags);
 		spin_lock(&kdev->power.lock);
 
-		if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
-			i915->pmu.suspended_jiffies_last =
-						kdev->power.suspended_jiffies;
-
-		val = kdev->power.suspended_jiffies -
-		      i915->pmu.suspended_jiffies_last;
-		val += jiffies - kdev->power.accounting_timestamp;
+		/*
+		 * After the above branch intel_runtime_pm_get_if_in_use failed
+		 * to get the runtime PM reference we cannot assume we are in
+		 * runtime suspend since we can either: a) race with coming out
+		 * of it before we took the power.lock, or b) there are other
+		 * states than suspended which can bring us here.
+		 *
+		 * We need to double-check that we are indeed currently runtime
+		 * suspended and if not we cannot do better than report the last
+		 * known RC6 value.
+		 */
+		if (kdev->power.runtime_status == RPM_SUSPENDED) {
+			if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
+				i915->pmu.suspended_jiffies_last =
+						  kdev->power.suspended_jiffies;
+
+			val = kdev->power.suspended_jiffies -
+			      i915->pmu.suspended_jiffies_last;
+			val += jiffies - kdev->power.accounting_timestamp;
+			val = jiffies_to_nsecs(val);
+			val += i915->pmu.sample[__I915_SAMPLE_RC6].cur;
+			i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur = val;
+		} else if (i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur) {
+			val = i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur;
+		} else {
+			val = i915->pmu.sample[__I915_SAMPLE_RC6].cur;
+		}
 
 		spin_unlock(&kdev->power.lock);
-
-		val = jiffies_to_nsecs(val);
-		val += i915->pmu.sample[__I915_SAMPLE_RC6].cur;
-		i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur = val;
-
 		spin_unlock_irqrestore(&i915->pmu.lock, flags);
 	}
 
-- 
2.14.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH v2] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Chris Wilson]

Quoting Tvrtko Ursulin (2018-04-10 11:34:40)
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> 
> While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
> on some CI machines I have concluded that: a) the PMU readout of RC6 can
> race against runtime PM transitions, and b) there are other reasons than
> being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
> fail.
> 
> Therefore when estimating RC6 the code needs to assert we are indeed in
> suspended state and if not the best we can do is return the last known RC6
> value.
> 
> v2:
>  * Re-arrange the code a bit to avoid second unlock and return branch.
>    (Chris Wilson)
> 
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Imre Deak <imre.deak@intel.com>
> ---
>  drivers/gpu/drm/i915/i915_pmu.c | 39 +++++++++++++++++++++++++++------------
>  1 file changed, 27 insertions(+), 12 deletions(-)
> 
> diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
> index bd7e695fc663..247a050f816e 100644
> --- a/drivers/gpu/drm/i915/i915_pmu.c
> +++ b/drivers/gpu/drm/i915/i915_pmu.c
> @@ -473,20 +473,35 @@ static u64 get_rc6(struct drm_i915_private *i915)
>                 spin_lock_irqsave(&i915->pmu.lock, flags);
>                 spin_lock(&kdev->power.lock);
>  
> -               if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
> -                       i915->pmu.suspended_jiffies_last =
> -                                               kdev->power.suspended_jiffies;
> -
> -               val = kdev->power.suspended_jiffies -
> -                     i915->pmu.suspended_jiffies_last;
> -               val += jiffies - kdev->power.accounting_timestamp;
> +               /*
> +                * After the above branch intel_runtime_pm_get_if_in_use failed
> +                * to get the runtime PM reference we cannot assume we are in
> +                * runtime suspend since we can either: a) race with coming out
> +                * of it before we took the power.lock, or b) there are other
> +                * states than suspended which can bring us here.
> +                *
> +                * We need to double-check that we are indeed currently runtime
> +                * suspended and if not we cannot do better than report the last
> +                * known RC6 value.
> +                */
> +               if (kdev->power.runtime_status == RPM_SUSPENDED) {
> +                       if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
> +                               i915->pmu.suspended_jiffies_last =
> +                                                 kdev->power.suspended_jiffies;
> +
> +                       val = kdev->power.suspended_jiffies -
> +                             i915->pmu.suspended_jiffies_last;
> +                       val += jiffies - kdev->power.accounting_timestamp;

Keep the line of white space here? Breaks up the computation of val from
the power timestamps with the accumulation of sample.

> +                       val = jiffies_to_nsecs(val);
> +                       val += i915->pmu.sample[__I915_SAMPLE_RC6].cur;

Then probably one more line of whitespace here to break up the
computation of val with it's assignment. We definitely want the
assignment on this branch to stand out from the no assignments later.

Reviewed-by: Chris Wilson <chris@chris-wilson.co.uk>
-Chris
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Tvrtko Ursulin]

On 10/04/2018 11:34, Chris Wilson wrote:
> Quoting Tvrtko Ursulin (2018-04-10 11:22:55)
>>
>> On 10/04/2018 10:57, Chris Wilson wrote:
>>> But I'm not understanding the failure -- why is the estimate bad? At the
>>> very least we still ensure that it is monotonic? Is it just the jitter
>>> you are worrying about? (If the estimate is bad here, isn't it always
>>> bad?)
>>
>> As far as I have seen failures from CI are all estimate being too large.
>> (no jitter and no going backwards)
>>
>> What I suspect is going bad in either case, is that we must not add the
>> delta from current jiffies to internal runtime pm counters if state is
>> not suspended. If we do that we are accounting an unknown period of time
>> as suspended time and that would explain the over-estimation.
>>
>> In other words we are only allowed to estimate if the current state is
>> definitely suspended. If it is anything else we need to report either
>> the last estimated value, or the last real value, depending what is more
>> recent.
> 
> i.e. we must not use kdev->power.suspended_jiffies before we know it is
> set.
> 
> Ok, that is stating to make sense. Thanks, can you update the commitmsg
> with this (pretty much verbatim as it is a good explanation).

Can do.

The patch makes sense - but I still cannot explain the failures since 
the test is supposed to be running in an controlled environment:

1. enter runtime suspend
2. sample rc6 (this sets the estimation state)
3. sleep for 2s
4. sample rc6

And the diff between two rc6 states can show from 10% - 50% more RC6 
elapsed time than sleep time, even to 300% more in some reports. If i915 
is runtime suspended the whole time, and dmesg says it is, I don't know 
how this is possible.

There must be another flaw somewhere which I am not seeing currently.

Regards,

Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH v3] drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

While thinking about sporadic failures of perf_pmu/rc6-runtime-pm* tests
on some CI machines I have concluded that: a) the PMU readout of RC6 can
race against runtime PM transitions, and b) there are other reasons than
being runtime suspended which can cause intel_runtime_pm_get_if_in_use to
fail.

Therefore when estimating RC6 the code needs to assert we are indeed in
suspended state, and if not, the best we can do is return the last known
RC6 value.

Without this check we can calculate the estimated value based on un-
initialized or inappropriate internal state, which can result in over-
estimation, or in any case incorrect value being returned.

v2:
 * Re-arrange the code a bit to avoid second unlock and return branch.
   (Chris Wilson)

v3:
 * Insert some strategic blank lines and improve commit msg.
   (Chris Wilson)

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Fixes: 1fe699e30113 ("drm/i915/pmu: Fix sleep under atomic in RC6 readout")
Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=105010
Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Imre Deak <imre.deak@intel.com>
Reviewed-by: Chris Wilson <chris@chris-wilson.co.uk>
---
 drivers/gpu/drm/i915/i915_pmu.c | 37 +++++++++++++++++++++++++++----------
 1 file changed, 27 insertions(+), 10 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_pmu.c b/drivers/gpu/drm/i915/i915_pmu.c
index bd7e695fc663..9135d0ada128 100644
--- a/drivers/gpu/drm/i915/i915_pmu.c
+++ b/drivers/gpu/drm/i915/i915_pmu.c
@@ -473,20 +473,37 @@ static u64 get_rc6(struct drm_i915_private *i915)
 		spin_lock_irqsave(&i915->pmu.lock, flags);
 		spin_lock(&kdev->power.lock);
 
-		if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
-			i915->pmu.suspended_jiffies_last =
-						kdev->power.suspended_jiffies;
+		/*
+		 * After the above branch intel_runtime_pm_get_if_in_use failed
+		 * to get the runtime PM reference we cannot assume we are in
+		 * runtime suspend since we can either: a) race with coming out
+		 * of it before we took the power.lock, or b) there are other
+		 * states than suspended which can bring us here.
+		 *
+		 * We need to double-check that we are indeed currently runtime
+		 * suspended and if not we cannot do better than report the last
+		 * known RC6 value.
+		 */
+		if (kdev->power.runtime_status == RPM_SUSPENDED) {
+			if (!i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur)
+				i915->pmu.suspended_jiffies_last =
+						  kdev->power.suspended_jiffies;
 
-		val = kdev->power.suspended_jiffies -
-		      i915->pmu.suspended_jiffies_last;
-		val += jiffies - kdev->power.accounting_timestamp;
+			val = kdev->power.suspended_jiffies -
+			      i915->pmu.suspended_jiffies_last;
+			val += jiffies - kdev->power.accounting_timestamp;
 
-		spin_unlock(&kdev->power.lock);
+			val = jiffies_to_nsecs(val);
+			val += i915->pmu.sample[__I915_SAMPLE_RC6].cur;
 
-		val = jiffies_to_nsecs(val);
-		val += i915->pmu.sample[__I915_SAMPLE_RC6].cur;
-		i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur = val;
+			i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur = val;
+		} else if (i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur) {
+			val = i915->pmu.sample[__I915_SAMPLE_RC6_ESTIMATED].cur;
+		} else {
+			val = i915->pmu.sample[__I915_SAMPLE_RC6].cur;
+		}
 
+		spin_unlock(&kdev->power.lock);
 		spin_unlock_irqrestore(&i915->pmu.lock, flags);
 	}
 
-- 
2.14.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

✓ Fi.CI.BAT: success for drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6 (rev3)

[Patchwork]

== Series Details ==

Series: drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6 (rev3)
URL   : https://patchwork.freedesktop.org/series/41453/
State : success

== Summary ==

Series 41453v3 drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6
https://patchwork.freedesktop.org/api/1.0/series/41453/revisions/3/mbox/

---- Possible new issues:

Test gem_exec_gttfill:
        Subgroup basic:
                skip       -> PASS       (fi-pnv-d510)

---- Known issues:

Test debugfs_test:
        Subgroup read_all_entries:
                incomplete -> PASS       (fi-snb-2520m) fdo#103713
Test kms_pipe_crc_basic:
        Subgroup suspend-read-crc-pipe-c:
                pass       -> INCOMPLETE (fi-bxt-dsi) fdo#103927

fdo#103713 https://bugs.freedesktop.org/show_bug.cgi?id=103713
fdo#103927 https://bugs.freedesktop.org/show_bug.cgi?id=103927

fi-bdw-5557u     total:285  pass:264  dwarn:0   dfail:0   fail:0   skip:21  time:428s
fi-bdw-gvtdvm    total:285  pass:261  dwarn:0   dfail:0   fail:0   skip:24  time:446s
fi-blb-e6850     total:285  pass:220  dwarn:1   dfail:0   fail:0   skip:64  time:382s
fi-bsw-n3050     total:285  pass:239  dwarn:0   dfail:0   fail:0   skip:46  time:537s
fi-bwr-2160      total:285  pass:180  dwarn:0   dfail:0   fail:0   skip:105 time:298s
fi-bxt-dsi       total:243  pass:216  dwarn:0   dfail:0   fail:0   skip:26 
fi-bxt-j4205     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:512s
fi-byt-j1900     total:285  pass:250  dwarn:0   dfail:0   fail:0   skip:35  time:518s
fi-byt-n2820     total:285  pass:246  dwarn:0   dfail:0   fail:0   skip:39  time:507s
fi-cfl-8700k     total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:416s
fi-cfl-s3        total:285  pass:259  dwarn:0   dfail:0   fail:0   skip:26  time:559s
fi-cfl-u         total:285  pass:259  dwarn:0   dfail:0   fail:0   skip:26  time:512s
fi-cnl-y3        total:285  pass:259  dwarn:0   dfail:0   fail:0   skip:26  time:584s
fi-elk-e7500     total:285  pass:226  dwarn:0   dfail:0   fail:0   skip:59  time:430s
fi-gdg-551       total:285  pass:177  dwarn:0   dfail:0   fail:0   skip:108 time:311s
fi-glk-1         total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:538s
fi-glk-j4005     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:485s
fi-hsw-4770      total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:404s
fi-ilk-650       total:285  pass:225  dwarn:0   dfail:0   fail:0   skip:60  time:422s
fi-ivb-3520m     total:285  pass:256  dwarn:0   dfail:0   fail:0   skip:29  time:470s
fi-ivb-3770      total:285  pass:252  dwarn:0   dfail:0   fail:0   skip:33  time:439s
fi-kbl-7500u     total:285  pass:260  dwarn:1   dfail:0   fail:0   skip:24  time:473s
fi-kbl-7567u     total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:461s
fi-kbl-r         total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:508s
fi-pnv-d510      total:285  pass:220  dwarn:1   dfail:0   fail:0   skip:64  time:671s
fi-skl-6260u     total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:444s
fi-skl-6600u     total:285  pass:258  dwarn:0   dfail:0   fail:0   skip:27  time:530s
fi-skl-6700k2    total:285  pass:261  dwarn:0   dfail:0   fail:0   skip:24  time:503s
fi-skl-6770hq    total:285  pass:265  dwarn:0   dfail:0   fail:0   skip:20  time:492s
fi-skl-guc       total:285  pass:257  dwarn:0   dfail:0   fail:0   skip:28  time:429s
fi-skl-gvtdvm    total:285  pass:262  dwarn:0   dfail:0   fail:0   skip:23  time:447s
fi-snb-2520m     total:285  pass:245  dwarn:0   dfail:0   fail:0   skip:40  time:565s
fi-snb-2600      total:285  pass:245  dwarn:0   dfail:0   fail:0   skip:40  time:401s

8e7a3b1c5ebd06c5740b0fea76f46ff23d373bd5 drm-tip: 2018y-04m-10d-10h-47m-52s UTC integration manifest
96beacaac4c3 drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6

== Logs ==

For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8655/issues.html
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

✗ Fi.CI.IGT: warning for drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6 (rev3)

[Patchwork]

== Series Details ==

Series: drm/i915/pmu: Inspect runtime PM state more carefully while estimating RC6 (rev3)
URL   : https://patchwork.freedesktop.org/series/41453/
State : warning

== Summary ==

= CI Bug Log - changes from CI_DRM_4040_full -> Patchwork_8655_full =

== Summary - WARNING ==

  Minor unknown changes coming with Patchwork_8655_full need to be verified
  manually.
  
  If you think the reported changes have nothing to do with the changes
  introduced in Patchwork_8655_full, please notify your bug team to allow them
  to document this new failure mode, which will reduce the CI noise.

  External URL: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8655/

== Possible new issues ==

  Here are the unknown changes that may have been introduced in Patchwork_8655_full:

  === IGT changes ===

    ==== Warnings ====

    igt@pm_rc6_residency@rc6-accuracy:
      shard-kbl:          PASS -> SKIP

    
== Known issues ==

  Here are the changes found in Patchwork_8655_full that come from known issues:

  === IGT changes ===

    ==== Issues hit ====

    igt@gem_mmap_wc@write:
      shard-kbl:          PASS -> DMESG-WARN (fdo#103558) +1

    igt@kms_flip@2x-flip-vs-wf_vblank-interruptible:
      shard-hsw:          PASS -> FAIL (fdo#103928)

    igt@kms_flip@2x-plain-flip-ts-check:
      shard-hsw:          PASS -> FAIL (fdo#100368)

    igt@kms_pipe_crc_basic@nonblocking-crc-pipe-c-frame-sequence:
      shard-hsw:          PASS -> FAIL (fdo#103481)

    
    ==== Possible fixes ====

    igt@kms_cursor_legacy@2x-long-flip-vs-cursor-legacy:
      shard-hsw:          FAIL (fdo#104873) -> PASS

    igt@kms_flip@flip-vs-expired-vblank-interruptible:
      shard-hsw:          FAIL (fdo#105189) -> PASS

    igt@kms_setmode@basic:
      shard-apl:          FAIL (fdo#99912) -> PASS
      shard-kbl:          FAIL (fdo#99912) -> PASS

    
  fdo#100368 https://bugs.freedesktop.org/show_bug.cgi?id=100368
  fdo#103481 https://bugs.freedesktop.org/show_bug.cgi?id=103481
  fdo#103558 https://bugs.freedesktop.org/show_bug.cgi?id=103558
  fdo#103928 https://bugs.freedesktop.org/show_bug.cgi?id=103928
  fdo#104873 https://bugs.freedesktop.org/show_bug.cgi?id=104873
  fdo#105189 https://bugs.freedesktop.org/show_bug.cgi?id=105189
  fdo#99912 https://bugs.freedesktop.org/show_bug.cgi?id=99912


== Participating hosts (6 -> 4) ==

  Missing    (2): shard-glk shard-glkb 


== Build changes ==

    * Linux: CI_DRM_4040 -> Patchwork_8655

  CI_DRM_4040: 8e7a3b1c5ebd06c5740b0fea76f46ff23d373bd5 @ git://anongit.freedesktop.org/gfx-ci/linux
  IGT_4418: 7c474e011548d35df6b80ceed81d3e6ca560c71d @ git://anongit.freedesktop.org/xorg/app/intel-gpu-tools
  Patchwork_8655: 96beacaac4c34004b6f38db046f75416785a9016 @ git://anongit.freedesktop.org/gfx-ci/linux
  piglit_4418: 45e115f293fd6acc0c9647cf2d3b76be78819ba5 @ git://anongit.freedesktop.org/piglit

== Logs ==

For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_8655/shards.html
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx