Roku Developer Program

Developers and content creators—a complete solution for growing an audience directly.
cancel
Showing results for 
Search instead for 
Did you mean: 
oomzay
Level 7

Regression: screen.swapBuffers() held of till after VSYNC

I just re-ran an old test [viewtopic.php?f=34&t=83900]that was designed to illustrate a different problem, and observed that what was once a rock-steady 60 FPS animation now suffers frequent (> 1/sec) judders.

The displayed moving average frame time for fast (< 10mSec) animations used to be rock steady at 16.666 uSecs, now it averages greater than 16.900 uSecs. This is because the call to screen.swapBuffers() is frequently not returning until 20 or 30 mSecs after the previous swapBuffers()/VSYNC instead of 16.666 mSecs later as was the case before.

Is there a bug tracking system?

Test configuration
-----------------------
Model: 2400SK (Roku LT)
Firmware Version: 075.05E00430A - No Jitter
Firmware Version: 077.00E09593A - Jitter
0 Kudos
9 Replies
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

Correction: Those units should read mSecs (milliseconds) not uSecs (microseconds).
0 Kudos
EnTerr
Level 8

Re: Regression: screen.swapBuffers() held of till after VSYNC

Any chance that "adaptive VSYNC" can something to do with it?
See this viewtopic.php?f=34&t=54513#p490795
It's a very obscure topic, there might be only a single person at RokuCo that understands it, rest comes with some external library.
0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

> Any chance that "adaptive VSYNC" can something to do with it?

No. Adaptive VSYNC could explain (*1 & *2) why frames that take longer than 16.66 mSecs to draw then subsequently fail to swap to the screen after an exact multiple of 16.66 mSecs and hence tear. Indeed this was the problem that the test was originally developed to demonstrate. However I am now (firmware version 7.00) observing that even frames that take only 5 mSecs to draw are often (~1 per second) failing to swap on the next VSYNC. This means that even a very simple 60FPS animations gets the judders/jaggies - which is very shoddy.

Notes
1: I originally received a quite different explanation from Roku. [viewtopic.php?f=34&t=83540#p479247]
2. The GL EXT_swap_control_tear feature is anyway a "horrible hack" for people who fail to manage their rendering detail/animation complexity properly. If Roku are enabling this feature by default then they must provide an API to disable it because it totally sucks for accurately scheduled applications. This would also allow it to be eliminated from this enquiry. (I am not even sure this is the case on this platform)
0 Kudos
EnTerr
Level 8

Re: Regression: screen.swapBuffers() held of till after VSYNC

On (1), to me the explanation sounds like adaptive_VSYNC explained in "human terms"
On (2), i doubt giving the per-app option to disable it is feasible. I bet will be major mess, like enabling 24 Hz video output.
Also, i don't think adaptive_VSYNC is a bad thing because it shouldn't affect "accurately scheduled applications". As long as you stay under 16ms, it won't be kicking in. OTOH it will save sloppier apps from sudden, discrete drops from 60 to 30 to 15fps - at the price of judder possibility.

This said, indeed adaptive vsync would not explain what you describe, 1/sec tearing with fast draw. Can you post a short&sweet sample code that demonstrates this one problem? Would improve likelihood of response.

Let's see what Roku* says - give it a week or two and if no response here, email developer at roku.com and keep bugging them
0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

> i doubt giving the per-app option to disable [adpative VSYYNC] is feasible. I bet will be major mess, like enabling 24 Hz video output.

Not sure why you think this is infeasable and messy. The mode is changed by the interval parameter passed to glXSwapIntervalEXT(dpy, drawable, interval); Make the default interval be -1 by all means, and restore the default when apps exits.

> i don't think adaptive_VSYNC is a bad thing because it shouldn't affect "accurately scheduled applications". As long as you stay under 16ms [my emphasis]

There are situations where a deliberate and rock steady 30 FPS is more acceptable than trying and failing to deliver 60FPS, plus we really don't want to see tearing when pushing a completely new frame after a few seconds of idle! With adaptive_VSYNC  enabled we have to shadow the screen's buffers and keep re-pushing the last frame every ~16mSecs to avoid tearing on the next frame whenever that is ready - which is a big waste of scarce CPU time and memory.

> Can you post a short&sweet sample code that demonstrates this one problem?

Yes. I will do that.
0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

Below is a script that demonstrates the ~1 per second glitch I am observing on 2400SK (Firmware: 077.00E09593A) with a simple 60FPS animation:-


' ----------------------------------------------------------------------------
' Vertical Synchronisation Glitch Demo
'
' On some platforms there is now (7.00 firmware) an intermittent
' (~1 per second) failure to SwapBuffers at 60FPS, even for animation times
' less than 4mSecs.
'
' This can be observed as tearing and/or juddering of the vertical bars
' and is reflected in the displayed frame times. The average should
' settle to 16,666 uSecs, the instantaneous value should dither between
' 16 and 17 mSecs.
'
' - left/right buttons adjust simulated animation time +/-1 ms
' ----------------------------------------------------------------------------

Library "v30/bslCore.brs"

' ----------------------------------------------------------------------------
' ----------------------------------------------------------------------------

sub main ()

    ' Log system info so we know when we are comparing chalk and cheese
    '
    log_system_info()
    
    ' Handy Facts
    '
    VIDEO_FIELD_MS = 1000.0 / 60.0

    ' Initialise various resources
    '
    ecodes = bslUniversalControlEventCodes()
    clk = CreateObject("roTimespan")
    port = CreateObject("roMessagePort")
    screen = CreateObject("roScreen", TRUE)
    screen.SetMessagePort(port)    
        
    ' Prepare font to display statistics on screen
    '
    font = CreateObject("roFontRegistry").GetDefaultFont()
    txt_height = font.getOneLineHeight()
    txt_color = &h60ff60ff
    txt_margin = 100
    
    ' Create some animated stripes to illustrate tearing and judders.
    '
    num_stripes = 10
    stripes = []
    for x = 0 to screen.getWidth()-1 step screen.getWidth()/num_stripes
        stripes.push(VerticalStripe(screen.getWidth(), screen.getHeight(), x))
    end for
        
    ' Simulated frame animation time (target & moving average)
    '
    animation_target_ms = 4
    animation_avg_filter = jcEWMAFilter(0.995, animation_target_ms * 1000)
    last_animation_overrun_ms = animation_target_ms

    ' Frame timing stats.
    '
    last_frame_start = INVALID
    frame_avg_filter = jcEWMAFilter(0.995, VIDEO_FIELD_MS * 1000)
    last_frame_overrun_ms = 17

    ' Do initial buffer swap before we start timing loop
    '
    screen.clear(0)
    screen.SwapBuffers()        
    screen.clear(0)

    ' Spin around SwappingBuffers and monitoring how long field/frame takes.
    '
    while TRUE       

        screen.SwapBuffers()
        this_frame_start = clk.TotalMilliseconds()

        ' Handle any events
        ' - left/right buttons adjust simulated animation time +/-1 ms
        '
        msg = port.GetMessage()
        if type(msg)="roUniversalControlEvent" then
            ecode = msg.GetInt()
            if ecode = ecodes.BUTTON_RIGHT_PRESSED then
                animation_target_ms = animation_target_ms + 1
            else if ecode = ecodes.BUTTON_LEFT_PRESSED then
                animation_target_ms = animation_target_ms - 1
            else if ecode = ecodes.BUTTON_UP_PRESSED then
                stop ' debug
            end if
        end if

        screen.clear(0)

        ' Animate & render the vertical stripes
        '
        for each stripe in stripes
            stripe.animate(screen)
        end for
                    
        ' Calculate & render statistics.
        '
        if last_frame_start <> INVALID then

            ' Calc
            last_frame_ms = this_frame_start - last_frame_start
            frame_avg_us = int(frame_avg_filter.update(last_frame_ms * 1000))
            animation_avg_us = int(animation_avg_filter.update(last_animation_ms * 1000))
            if last_frame_ms > 17 then
                last_frame_overrun_ms = last_frame_ms
            end if
            if last_animation_ms > animation_target_ms then
                last_animation_overrun_ms = last_animation_ms
            end if

            ' Render
            x = txt_margin
            y = txt_margin
            screen.drawText("Vertical Synchronisation Glitch Demo", x, y, txt_color, font)            
            y = y + 2 * txt_height
            screen.drawText("Animation target: " + animation_target_ms.toStr() + " ms (L = -1, R = +1)", x, y, txt_color, font)            
            y = y + txt_height
            screen.drawText("Animation actual: " + last_animation_ms.toStr() + " ms (Avg: " + animation_avg_us.toStr() + " us, Last overrun: " + last_animation_overrun_ms.toStr() + " ms)", x, y, txt_color, font)                  
            y = y + txt_height
            screen.drawText("Frame actual: " + last_frame_ms.toStr() + "ms (Avg: " + frame_avg_us.toStr() + " us, Last overrun: " + last_frame_overrun_ms.toStr() + " ms)", x, y, txt_color, font)                  

        endif

        ' Spin until the simulated animation time has elapsed.
        '
        this_animation_ms = clk.TotalMilliseconds() - this_frame_start
        while this_animation_ms < animation_target_ms
            this_animation_ms = clk.TotalMilliseconds() - this_frame_start
        end while

        ' Go round again
        '
        last_frame_start = this_frame_start
        last_animation_ms = this_animation_ms
    end while
end sub

' ----------------------------------------------------------------------------
' Animated Vertical White Stripe
' ----------------------------------------------------------------------------

function VerticalStripe (cw as Integer, ch as Integer, x0 as Integer) as Object

    this = {}
    
    this.cw = cw
    this.x = x0
    this.w = 50
    this.h = ch
    this.dx = 4
    this.clr = &h808080ff
    
    ' Animate and render this stripe to canvas.
    '
    this.animate = function (canvas as Object) as Void

        this = m

        this.x = this.x + this.dx
        if this.x > this.cw then
            this.x = this.x - (this.cw + this.w)
        end if        

        canvas.drawRect(this.x, 0, this.w, this.h, this.clr)   
     
    end function
       
    return this

end function

' ----------------------------------------------------------------------------
' Exponentially Weighted Moving Average (EWMA) filter
'
' Yt =  Xt  + α ( Yt-1 - Xt)
' ----------------------------------------------------------------------------

function jcEWMAFilter(alpha as Float, avg0 as Float) as Object

    this = {}    
    
    this.alpha = alpha
    this.avg = avg0
            
    ' Insert new sample, returns updated average.
    '
    this.update = function (x as Float) as Float
        this = m
        this.avg = x + (this.alpha * (this.avg - x))
        return this.avg
    end function
        
    return this

end function

' ----------------------------------------------------------------------------
' Log basic system info
' ----------------------------------------------------------------------------

sub log_system_info()

    di = CreateObject("roDeviceInfo")    
    print "          Device: "; di.GetDeviceUniqueId()
    print "           Model: "; di.GetModel(); " ("; di.GetModelDisplayName(); ")"
    print "Firmware Version: "; di.GetVersion()

    md = di.GetModelDetails()
    print "     Vendor Name: "; md.VendorName
    print "    Model Number: "; md.ModelNumber

    ai = CreateObject("roAppInfo")    
    print "             App: "; ai.GetTitle(); " ("; ai.GetVersion(); ")"
    print "           DevID: "; ai.GetDevID()

end sub
0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

Could someone at roku comment on this please? This loss of sync once per second or so is really messing up what used to be a rock steady 60 fps animation. Thanks.
0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

Below is an almost minimal swap-period logging app that can be used to test for this regression:-
' ----------------------------------------------------------------------------
' Frame Swap Duration Logger
'
' This app creates a double-buffered roScreen and spins in a loop clearing the
' screen to black, swapping the buffers, and logging the inter-swap period to
' the debug console.
'
' This is for the purpose of checking that bufferswap() remains locked to vsync.
'
' If all is well the millisecond resolution times should dither between 16 & 17
' with a long term average of _exactly_ 16.666 mSecs. Any times outside this range
' indicate a loss of vsync and will cause judder and/or tearing in real applications.
'
' You should see absolutely nothing on the screen!
'
' In the log (via telnet) you should see frame timings like this:-
'
' If all is well (e.g. f/w 5.05):-
'
' 17
' 16
' 17
' 17
' 16
' 17
'
' If vsync is being missed badly (e.g. f/w 7.00):-
'
' 16
' 17
' 25
' 25
' 18
' 15
' 17
'
' This output can be processed by an automated regression testing framework
' to detect loss of sync.
' ----------------------------------------------------------------------------

sub main ()

    clk = CreateObject("roTimespan")
    screen = CreateObject("roScreen", TRUE)

    last_frame_start = INVALID
    screen.clear(0)

    while TRUE
        screen.SwapBuffers()
        this_frame_start = clk.TotalMilliseconds()
        screen.clear(0)
        if last_frame_start <> INVALID then
            print (this_frame_start - last_frame_start).toStr()
        end if
        last_frame_start = this_frame_start
    end while

end sub


0 Kudos
oomzay
Level 7

Re: Regression: screen.swapBuffers() held of till after VSYNC

I have now summarised this in the issue tracking system over at https://github.com/rokudev/docs/issues/8
0 Kudos