I was interested in the measuring the time taken by the GPU to finish rendering each frame so I added an option to do an explicit screen.finish() to my frame loop (after drawing) and found to my surprise that the double buffered screen started tearing. What's more, adjusting the moment when the screen.finish() is called during each frame moves the "tear line" up and down so it looks very much like finish() is actually triggering an unsynchronised swap!
Configuration: Model: 2400SK (Roku LT) (Firmware Version: 077.00E09593A)
In the demo code below (written to demo a different issue) the OK/SELECT button now enables/disables the call to screen.finish() and LEFT & RIGHT buttons adjust the simulated drawing time, and hence the moment when finish() is called, and hence the tear position.
' ----------------------------------------------------------------------------
' 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
' Issue Finish() after rendering
'
explicit_finish = FALSE
' 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_SELECT_PRESSED then
explicit_finish = not explicit_finish
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
' Finish to sync with GPU
' *** This seems to cause horrible tearing ***
'
if explicit_finish then
screen.finish()
end if
' 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