Talked with piman@, we think it is better to improve UpdateVSyncParametersCallback to provide the time for the previous vsync with a SwapBuffers. We can get the time value from eglGetSyncValuesCHROMIUM(), if it exists. Otherwise, we may use a timer query.
UpdateVSyncParametersCallback happens to include the last page flip time as time base on Chrome OS today and we take advantage of that for Arc++ and wl_presentation_timing interface. Would be nice to make that more explicit instead of assuming that time base is time stamp from last page flip.
That the plan is to reuse UpdateVSyncParametersCallback or rename it to a better name for this usage, and make sure it always uses the time for the last page flip.
BTW, as my test, on my Linux desktop (Nvidia), the UpdateVSyncParametersCallback() not always uses the time base for the last page flip. It could be the time for a vsync after the last page flip.
Linux desktop is unlikely to work. UpdateVSyncParametersCallback is only reliably providing page flip time stamps on Ozone DRM today. Not sure it makes sense to implement this protocol on other platforms.
The original CL https://chromium-review.googlesource.com/1040725 ran webgl_conformance_gl_passthrough_tests on linux_optional_gpu_tests_rel here:
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/linux_optional_gpu_tests_rel/2322
and it was green.
The waterfall bots broke with this CHECK failure:
[10148:10148:0503/115106.481508:FATAL:circular_deque.h(534)] Check failed: !empty().
#0 0x55c7fcc1d14c base::debug::StackTrace::StackTrace()
#1 0x55c7fcb7f12b logging::LogMessage::~LogMessage()
#2 0x55c7fe29b78e gpu::GLES2CommandBufferStub::BufferPresented()
#3 0x55c7fdfa15fa gpu::PassThroughImageTransportSurface::BufferPresented()
#4 0x55c7fdfa22a8 _ZN4base8internal7InvokerINS0_9BindStateIMN3gpu32PassThroughImageTransportSurfaceEFvmRKNS_17RepeatingCallbackIFvRKN3gfx20PresentationFeedbackEEEES9_EJNS_7WeakPtrIS4_EEmSB_EEESA_E3RunEPNS0_13BindStateBaseES9_
#5 0x55c7fd7a75ee gl::GLSurfacePresentationHelper::CheckPendingFrames()
#6 0x55c7fd7a7a80 gl::GLSurfacePresentationHelper::CheckPendingFramesCallback()
#7 0x55c7fa5da214 _ZN4base8internal7InvokerINS0_9BindStateIMN7content28ServiceManagerConnectionImplEFvvEJNS_7WeakPtrIS4_EEEEEFvvEE3RunEPNS0_13BindStateBaseE
#8 0x55c7fcb65130 base::debug::TaskAnnotator::RunTask()
#9 0x55c7fcb87d16 base::internal::IncomingTaskQueue::RunTask()
#10 0x55c7fcb86367 base::MessageLoop::RunTask()
#11 0x55c7fcb8677a base::MessageLoop::DeferOrRunPendingTask()
#12 0x55c7fcb86d22 base::MessageLoop::DoDelayedWork()
#13 0x55c7fcb8b7f5 base::(anonymous namespace)::WorkSourceDispatch()
#14 0x7fb9101c1377 g_main_context_dispatch
#15 0x7fb9101c15e0 <unknown>
#16 0x7fb9101c168c g_main_context_iteration
#17 0x55c7fcb8b582 base::MessagePumpGlib::Run()
#18 0x55c7fcb85c91 base::MessageLoop::Run()
#19 0x55c7fcbb27b6 base::RunLoop::Run()
#20 0x55c800eb6d33 content::GpuMain()
#21 0x55c7fc7b6d11 content::RunNamedProcessTypeMain()
#22 0x55c7fc7b8112 content::ContentMainRunnerImpl::Run()
#23 0x55c7fc7c57d9 service_manager::Main()
#24 0x55c7fc7b5924 content::ContentMain()
#25 0x55c7fa12b1b3 ChromeMain
#26 0x7fb90c3173f1 __libc_start_main
#27 0x55c7fa12b02a _start
I'm not sure why the CQ didn't catch this. By design the CQ runs with dcheck_always_on=true but all of Chromium's waterfall bots do not run with this. Please tell me if it looks like something is misconfigured on the GPU bots. More likely it seems to me that there is logic inside of a DCHECK.
An an FYI, seeing a swathes of "VSync for last SwapBuffers..." log on the bots at the moment.
void Display::DidReceiveSwapBuffersAck(uint64_t swap_id) {
if (!active_presented_callbacks_.empty() ||
!previous_presented_callbacks_.empty()) {
DLOG(WARNING) << "VSync for last SwapBuffers is not received!";
Also note, chromeos ASAN bot browser_tests 'stdout' logs have grown very large due to this "VSync for last SwapBuffers is not received!" warning log. So large, that I cannot attach them to a crbug.com any more :(
Comment 1 by fsamuel@google.com
, Oct 20 2017