Funky new vblank counter regressions in Linux 4.4-rc1

Mario Kleiner mario.kleiner.de at gmail.com
Wed Nov 25 09:24:13 PST 2015


On 11/23/2015 09:24 PM, Ville Syrjälä wrote:
> On Mon, Nov 23, 2015 at 06:58:34PM +0100, Mario Kleiner wrote:
>>
>>
>> On 11/23/2015 04:51 PM, Ville Syrjälä wrote:
>>> On Mon, Nov 23, 2015 at 04:23:21PM +0100, Mario Kleiner wrote:
>>>> On 11/20/2015 04:34 PM, Ville Syrjälä wrote:
>>>>> On Fri, Nov 20, 2015 at 04:24:50PM +0100, Mario Kleiner wrote:
>>>>
>>>> ...
>>>> Ok, but why would that be a bad thing? I think we want it to think it is
>>>> in the previous frame if it is called outside the vblank irq context.
>>>> The only reason we fudge it to the next frames vblank if i vblank irq is
>>>> because we know the vblank irq handler we are executing atm. was meant
>>>> to execute within the upcoming vblank for the next frame, so we fudge
>>>> the scanout positions and thereby timestamp to correspond to that new
>>>> frame. But if something called outside irq context it should get a
>>>> scanout position/timestamp that corresponds to "reality".
>>>
>>> It would be a bad thing since it would cause the timestamp to jump
>>> backwards, and that would also cause the frame count guesstimate to go
>>> backwards.
>>>
>>
>> But only if we don't use the dev->driver->get_vblank_counter() method,
>> which we try to use on AMD.
>
> Well, if you do it that way then you have the problem of the hw counter
> seeming to jump forward by one after crossing the start of vblank (when
> compared to the value you sampled when you processed the early vblank
> interrupt).
>

Ok, finally i see the bad scenario that wouldn't get prevented by our 
current locking with the new vblank counting in the core. The vblank 
enable path is safe due to locking and discounting of redundant 
timestamps etc. But the disable path could go wrong:

1. Vblank irq fires, drm_handle_vblank() -> drm_update_vblank_count(),
updates timestamps and counts "as if" in vblank -> incremented vblank 
count and timestamp now set in the future.

2. After vblank irq finishes, but just before leading edge of vblank, 
vblank_disable_and_save() executes, doesn't get bumped timestamp or 
count because before vblank and not in vblank irq. Now 
drm_update_vblank_count() would process a
"new" timestamp and count from the past and we'd have time and counts 
going backwards, and bad things would happen.

I haven't observed such a thing happening during testing so far, 
probably because the time window in which it could happen is tiny, but 
given how awfully bad it would be, it needs to be prevented.

I had a look at the description of the Vblank irq in the "M76 Register 
Reference Guide" for older asics and the description suggests that the 
vblank irq fires when the crtc's line buffer is finished reading pixel 
data from the scanout buffer in memory for a frame, ie., when the line 
buffer read "enters" vblank. That would explain why the irq happens a 
few scanlines before actual vblank, because line buffer refills must 
obviously happen before the crtc can send pixel data from the line 
buffer to the encoders, so it would lead a bit in time. That also means 
we can't delay the vblank irq to actually happen at start of vblank and 
have to deal with the early vblank irq.

> I guess one silly idea would be to defer the vblank interrupt processing
> to a timer, and just schedule it a bit into the future from the actual
> interrupt handler.
>

Timer would be bad because then we get problems with the pageflip 
completion irq sometimes being processed before the vblank irq, and 
because we want to be fast in vblank irq handling, delivering vblank 
events etc. I wouldn't trust a timer to be reliable enough for such 
short waits. Busy waiting wouldn't be great either in irq.

So what about this relatively simple one?

1. In radeon_get_crtc_scanoutpos() we artifically define the 
vblank_start line to be, e.g, 5 scanlines before the true start of 
vblank, so for the purpose of vblank counter queries and timestamping 
our "vblank" would start a bit earlier and the vblank irq would always 
execute in "vblank". Non-Irq invocations like vblank_disable_and_save() 
would also be treated to this early vblank start and so what the DRM 
core observes would always be consistent.

2. At least in radeon-kms we also use radeon_get_crtc_scanoutpos() 
internally for "dynpm" dynamic power management/reclocking, and to 
implement pageflip completion detection on asics older than DCE3 which 
don't have pageflip interrupts. For those cases we need to use the true 
start of vblank, so for this internal use we pass in some special flag 
into radeon_get_crtc_scanoutpos() to tell it to not shift the vblank 
start around.

3. I've added another check to my patch for drm_update_vblank_count() to 
catch timestamps going backwards and discounting such cases, for a bit 
of extra robustness against driver trouble.

Any ideas why this would be a stupid idea? I'll try this now and just 
hope meanwhile nobody finds a reason why this would be bad.

thanks,
-mario

>> Also dev->vblank_time_lock should protect us
>> from concurrent execution of the vblank counting/timestamping in irq
>> context and non-irq context? At least that was one of the purposes of
>> that lock in the past?
>
> The scenarion I outlined doesn't require anything to happen
> concurrently.
>
>>
>> -mario
>>
>>>>
>>>> It would maybe be a problem to get different answers for a query at the
>>>> same scanout position if we used .get_scanout_position() for something
>>>> else than for calculating vblank timestamps, but we don't do that atm.
>>>>
>>>> Maybe i'm overlooking something here related to the somewhat rewritten
>>>> code from the last year or so? But in the original design this would be
>>>> exactly what i intended?
>>>>
>>>> ...
>>>>
>>>>>> So it's good enough for typical desktop
>>>>>> applications/compositors/games/media players, and a nice improvement
>>>>>> over the previous state, but not quite sufficient for applications that
>>>>>> need long time consistent vblank counts for long waits of multiple
>>>>>> seconds or even minutes. So it's still good to have hw counters if we
>>>>>> can get some that are reliable enough.
>>>>>
>>>>> Ah, I didn't realize you care about small errors in the counter for
>>>>> such long periods of vblank off.
>>>>>
>>>>
>>>> Actually, you are right, i was stupid - not enough sleep last friday. I
>>>> do care about such small errors, but the long vblank off periods don't
>>>> matter at all the way my software works. I query the current count and
>>>> timestamp (glXGetSyncValuesOML), calculate a target count based on those
>>>> and then schedule a swap for that target count via glXSwapBuffersMscOML.
>>>> That swapbuffers call will keep vblank irqs on until the kms pageflip is
>>>> queued. So i only care about vblank counts/timestamps being consistent
>>>> for short amounts of time, typically 1 video refresh from vblank query
>>>> to queueing a vblank event, and then from reception of that
>>>> event/queuing the pageflip to pageflip completion event. So even if the
>>>> system would be heavily loaded and my code would have big preemption
>>>> delays i think counts that are consistent over a few seconds would be
>>>> enough to keep things working. Otherwise it wouldn't work now either
>>>> with a vblank off after 5 seconds and nouveau not having vblank hw counters.
>>>>
>>>> -mario
>>>>
>>>>
>>>>>>
>>>>>> -mario
>>>>>>
>>>>>>
>>>>>>>>
>>>>>>>> -mario
>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> It almost sort of works on the rs600 code path, but i need a bit of info
>>>>>>>>>> from you:
>>>>>>>>>>
>>>>>>>>>> 1. There's this register from the old specs for m76.pdf, which is not
>>>>>>>>>> part of the current register defines for radeon-kms:
>>>>>>>>>>
>>>>>>>>>> "D1CRTC_STATUS_VF_COUNT - RW - 32 bits - [GpuF0MMReg:0x60A8]"
>>>>>>>>>>
>>>>>>>>>> It contains the lower 16 bits of framecounter and the 13 bits of
>>>>>>>>>> vertical scanout position. It seems to give the same readings as the 24
>>>>>>>>>> bit R_0060A4_D1CRTC_STATUS_FRAME_COUNT we use for the hw counter. This
>>>>>>>>>> would come handy.
>>>>>>>>>>
>>>>>>>>>> Does Evergreen and later have a same/similar register and where is it?
>>>>>>>>>>
>>>>>>>>>> 2. The hw framecounter seems to increment when the vertical scanout
>>>>>>>>>> position wraps back from (VTOTAL - 1) to 0, at least on the one DCE-3
>>>>>>>>>> gpu i tested so far. Is this so on all asics? And is the hw counter
>>>>>>>>>> increment happening exactly at the moment that vertical scanout position
>>>>>>>>>> jumps back to zero, ie. both events are driven by the same signal? Or is
>>>>>>>>>> the framecounter increment just happening somewhere inside either
>>>>>>>>>> scanline VTOTAL-1 or scanline 0?
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> If we can fix this and get it into rc2 or rc3 then we could avoid a bad
>>>>>>>>>> regression and with a bit of luck at the same time improve by being able
>>>>>>>>>> to set dev->vblank_disable_immediate = true then and allow vblank irqs
>>>>>>>>>> to get turned off more aggressively for a bit of extra power saving.
>>>>>>>>>>
>>>>>>>>>> thanks,
>>>>>>>>>> -mario
>>>>>>>>>
>>>>>>>>>> -- a/drivers/gpu/drm/drm_irq.c
>>>>>>>>>> +++ b/drivers/gpu/drm/drm_irq.c
>>>>>>>>>> @@ -172,9 +172,11 @@ static void drm_update_vblank_count(struct drm_device *dev, unsigned int pipe,
>>>>>>>>>>                                          unsigned long flags)
>>>>>>>>>>       {
>>>>>>>>>>              struct drm_vblank_crtc *vblank = &dev->vblank[pipe];
>>>>>>>>>> -       u32 cur_vblank, diff;
>>>>>>>>>> +       u32 cur_vblank, diff = 0;
>>>>>>>>>>              bool rc;
>>>>>>>>>>              struct timeval t_vblank;
>>>>>>>>>> +       const struct timeval *t_old;
>>>>>>>>>> +       u64 diff_ns;
>>>>>>>>>>              int count = DRM_TIMESTAMP_MAXRETRIES;
>>>>>>>>>>              int framedur_ns = vblank->framedur_ns;
>>>>>>>>>>
>>>>>>>>>> @@ -195,13 +197,15 @@ static void drm_update_vblank_count(struct drm_device *dev, unsigned int pipe,
>>>>>>>>>>                      rc = drm_get_last_vbltimestamp(dev, pipe, &t_vblank, flags);
>>>>>>>>>>              } while (cur_vblank != dev->driver->get_vblank_counter(dev, pipe) && --count > 0);
>>>>>>>>>>
>>>>>>>>>> -       if (dev->max_vblank_count != 0) {
>>>>>>>>>> -               /* trust the hw counter when it's around */
>>>>>>>>>> -               diff = (cur_vblank - vblank->last) & dev->max_vblank_count;
>>>>>>>>>> -       } else if (rc && framedur_ns) {
>>>>>>>>>> -               const struct timeval *t_old;
>>>>>>>>>> -               u64 diff_ns;
>>>>>>>>>> -
>>>>>>>>>> +       /*
>>>>>>>>>> +        * Always use vblank timestamping based method if supported to reject
>>>>>>>>>> +        * redundant vblank irqs. E.g., AMD hardware needs this to not screw up
>>>>>>>>>> +        * due to some irq handling quirk.
>>>>>>>>>
>>>>>>>>> Hmm. I'm thinking it would be better to simply not claim that there's a hw
>>>>>>>>> counter if it isn't reliable.
>>>>>>>>>
>>>>>>>>>> +        *
>>>>>>>>>> +        * This also sets the diff value for use as fallback below in case the
>>>>>>>>>> +        * hw does not support a suitable hw vblank counter.
>>>>>>>>>> +        */
>>>>>>>>>> +       if (rc && framedur_ns) {
>>>>>>>>>>                      t_old = &vblanktimestamp(dev, pipe, vblank->count);
>>>>>>>>>>                      diff_ns = timeval_to_ns(&t_vblank) - timeval_to_ns(t_old);
>>>>>>>>>>
>>>>>>>>>> @@ -212,11 +216,28 @@ static void drm_update_vblank_count(struct drm_device *dev, unsigned int pipe,
>>>>>>>>>>                       */
>>>>>>>>>>                      diff = DIV_ROUND_CLOSEST_ULL(diff_ns, framedur_ns);
>>>>>>>>>>
>>>>>>>>>> -               if (diff == 0 && flags & DRM_CALLED_FROM_VBLIRQ)
>>>>>>>>>> -                       DRM_DEBUG_VBL("crtc %u: Redundant vblirq ignored."
>>>>>>>>>> -                                     " diff_ns = %lld, framedur_ns = %d)\n",
>>>>>>>>>> -                                     pipe, (long long) diff_ns, framedur_ns);
>>>>>>>>>> -       } else {
>>>>>>>>>> +               if (diff == 0 && flags & DRM_CALLED_FROM_VBLIRQ) {
>>>>>>>>>> +                   DRM_DEBUG_VBL("crtc %u: Redundant vblirq ignored."
>>>>>>>>>> +                   " diff_ns = %lld, framedur_ns = %d)\n",
>>>>>>>>>> +                   pipe, (long long) diff_ns, framedur_ns);
>>>>>>>>>> +
>>>>>>>>>> +                   /* Treat this redundant invocation as no-op. */
>>>>>>>>>> +                   WARN_ON_ONCE(cur_vblank != vblank->last);
>>>>>>>>>> +                   return;
>>>>>>>>>> +               }
>>>>>>>>>> +       }
>>>>>>>>>> +
>>>>>>>>>> +       /*
>>>>>>>>>> +        * hw counters, if marked as supported via max_vblank_count != 0,
>>>>>>>>>> +        * *must* increment at leading edge of vblank and in sync with
>>>>>>>>>> +        * the firing of the hw vblank irq, otherwise we have a race here
>>>>>>>>>> +        * between gpu and us, where small variations in our execution
>>>>>>>>>> +        * timing can cause off-by-one miscounting of vblanks.
>>>>>>>>>> +        */
>>>>>>>>>> +       if (dev->max_vblank_count != 0) {
>>>>>>>>>> +               /* trust the hw counter when it's around */
>>>>>>>>>> +               diff = (cur_vblank - vblank->last) & dev->max_vblank_count;
>>>>>>>>>> +       } else if (!(rc && framedur_ns)) {
>>>>>>>>>>                      /* some kind of default for drivers w/o accurate vbl timestamping */
>>>>>>>>>>                      diff = (flags & DRM_CALLED_FROM_VBLIRQ) != 0;
>>>>>>>>>>              }
>>>>>>>>>
>>>>>>>>>
>>>>>>>
>>>>>
>>>
>


More information about the dri-devel mailing list