Failing test (timeout) is https://cs.chromium.org/chromium/src/chrome/test/data/pdf/toolbar_manager_test.js?dr&q=toolbar_manager_test+testToolbarTouchInteraction&sq=package:chromium&g=0&l=165

On further inspection of the logs, the test is timing out, even when all the individual test cases pass.

Seems something is getting pushed over a limit.

[1:8:0107/043951.248588:FATAL:async_layer_tree_frame_sink.cc(309)] Check failed: pipeline_reporting_frame_times_.size() <= 25u (26 vs. 25)

@sadrul what is this check about?

void DirectLayerTreeFrameSink::OnBeginFrame(const BeginFrameArgs& args) {
  DCHECK_LE(pipeline_reporting_frame_times_.size(), 25u);

From: 

https://chromium-review.googlesource.com/c/chromium/src/+/1227141/

I think I saw the same DCHECK error locally yesterday in a Chrome for Chrome OS on Linux build. Just loading a PDF will sometimes trigger it.

I just saw this on the asan bot too:

https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket.appspot.com/8924682659631282448/+/steps/browser_tests/0/logs/PDFExtensionTest.ToolbarManager__status_TIMEOUT_/0

[1:8:0110/134445.221805:FATAL:async_layer_tree_frame_sink.cc(317)] Check failed: pipeline_reporting_frame_times_.size() <= 25u (26 vs. 25)
   #0 0x563cd8b67b01 in __interceptor_backtrace /b/swarming/w/ir/kitchen-workdir/src/third_party/llvm/compiler-rt/lib/asan/../sanitizer_common/sanitizer_common_interceptors.inc:4050:13
    #1 0x563cea9008df in base::debug::StackTrace::StackTrace(unsigned long) ./../../base/debug/stack_trace_posix.cc:820:41
    #2 0x563cea692b10 in logging::LogMessage::~LogMessage() ./../../base/logging.cc:591:29
    #3 0x563cf1d495ea in cc::mojo_embedder::AsyncLayerTreeFrameSink::OnBeginFrame(viz::BeginFrameArgs const&, base::flat_map<unsigned int, gfx::PresentationFeedback, std::__1::less<void> > const&) ./../../cc/mojo_embedder/async_layer_tree_frame_sink.cc:317:3
    #4 0x563ce1c45ace in viz::mojom::CompositorFrameSinkClientStubDispatch::Accept(viz::mojom::CompositorFrameSinkClient*, mojo::Message*) ./gen/services/viz/public/interfaces/compositing/compositor_frame_sink.mojom.cc:1392:13
    #5 0x563cee500553 in mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) ./../../mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:423:32
    #6 0x563cee544848 in mojo::FilterChain::Accept(mojo::Message*) ./../../mojo/public/cpp/bindings/lib/filter_chain.cc:40:17
    #7 0x563cee50468d in mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message*) ./../../mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:306:19
    #8 0x563cee518b1f in mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) ./../../mojo/public/cpp/bindings/lib/multiplex_router.cc:869:42
    #9 0x563cee5167e7 in mojo::internal::MultiplexRouter::Accept(mojo::Message*) ./../../mojo/public/cpp/bindings/lib/multiplex_router.cc:590:38
    #10 0x563cee544848 in mojo::FilterChain::Accept(mojo::Message*) ./../../mojo/public/cpp/bindings/lib/filter_chain.cc:40:17
    #11 0x563cee4f6ba2 in mojo::Connector::ReadSingleMessage(unsigned int*) ./../../mojo/public/cpp/bindings/lib/connector.cc:477:51
    #12 0x563cee4f8bb3 in mojo::Connector::ReadAllAvailableMessages() ./../../mojo/public/cpp/bindings/lib/connector.cc:506:10
    #13 0x563cee4f8564 in mojo::Connector::OnHandleReadyInternal(unsigned int) ./../../mojo/public/cpp/bindings/lib/connector.cc:388:3
    #14 0x563ce156d9c4 in Run ./../../base/callback.h:129:12
    #15 0x563ce156d9c4 in mojo::SimpleWatcher::DiscardReadyState(base::RepeatingCallback<void (unsigned int)> const&, unsigned int, mojo::HandleSignalsState const&) ./../../mojo/public/cpp/system/simple_watcher.h:194:0
    #16 0x563cec448bea in Run ./../../base/callback.h:129:12
    #17 0x563cec448bea in mojo::SimpleWatcher::OnHandleReady(int, unsigned int, mojo::HandleSignalsState const&) ./../../mojo/public/cpp/system/simple_watcher.cc:288:0
    #18 0x563cec449e02 in Invoke<void (mojo::SimpleWatcher::*)(int, unsigned int, const mojo::HandleSignalsState &), const base::WeakPtr<mojo::SimpleWatcher> &, const int &, const unsigned int &, const mojo::HandleSignalsState &> ./../../base/bind_internal.h:516:12
    #19 0x563cec449e02 in MakeItSo<void (mojo::SimpleWatcher::*const &)(int, unsigned int, const mojo::HandleSignalsState &), const base::WeakPtr<mojo::SimpleWatcher> &, const int &, const unsigned int &, const mojo::HandleSignalsState &> ./../../base/bind_internal.h:636:0
    #20 0x563cec449e02 in void base::internal::Invoker<base::internal::BindState<void (mojo::SimpleWatcher::*)(int, unsigned int, mojo::HandleSignalsState const&), base::WeakPtr<mojo::SimpleWatcher>, int, unsigned int, mojo::HandleSignalsState>, void ()>::RunImpl<void (mojo::SimpleWatcher::* const&)(int, unsigned int, mojo::HandleSignalsState const&), std::__1::tuple<base::WeakPtr<mojo::SimpleWatcher>, int, unsigned int, mojo::HandleSignalsState> const&, 0ul, 1ul, 2ul, 3ul>(void (mojo::SimpleWatcher::* const&)(int, unsigned int, mojo::HandleSignalsState const&), std::__1::tuple<base::WeakPtr<mojo::SimpleWatcher>, int, unsigned int, mojo::HandleSignalsState> const&, std::__1::integer_sequence<unsigned long, 0ul, 1ul, 2ul, 3ul>) ./../../base/bind_internal.h:689:0
    #21 0x563cea96a777 in Run ./../../base/callback.h:99:12
    #22 0x563cea96a777 in base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) ./../../base/debug/task_annotator.cc:99:0
    #23 0x563cea7fda27 in base::sequence_manager::internal::ThreadControllerImpl::DoWork(base::sequence_manager::internal::ThreadControllerImpl::WorkType) ./../../base/task/sequence_manager/thread_controller_impl.cc:209:23
    #24 0x563cea80345f in Invoke<void (base::sequence_manager::internal::ThreadControllerImpl::*)(base::sequence_manager::internal::ThreadControllerImpl::WorkType), const base::WeakPtr<base::sequence_manager::internal::ThreadControllerImpl> &, const base::sequence_manager::internal::ThreadControllerImpl::WorkType &> ./../../base/bind_internal.h:516:12
    #25 0x563cea80345f in MakeItSo<void (base::sequence_manager::internal::ThreadControllerImpl::*const &)(base::sequence_manager::internal::ThreadControllerImpl::WorkType), const base::WeakPtr<base::sequence_manager::internal::ThreadControllerImpl> &, const base::sequence_manager::internal::ThreadControllerImpl::WorkType &> ./../../base/bind_internal.h:636:0
    #26 0x563cea80345f in RunImpl<void (base::sequence_manager::internal::ThreadControllerImpl::*const &)(base::sequence_manager::internal::ThreadControllerImpl::WorkType), const std::__1::tuple<base::WeakPtr<base::sequence_manager::internal::ThreadControllerImpl>, base::sequence_manager::internal::ThreadControllerImpl::WorkType> &, 0, 1> ./../../base/bind_internal.h:689:0
    #27 0x563cea80345f in base::internal::Invoker<base::internal::BindState<void (base::sequence_manager::internal::ThreadControllerImpl::*)(base::sequence_manager::internal::ThreadControllerImpl::WorkType), base::WeakPtr<base::sequence_manager::internal::ThreadControllerImpl>, base::sequence_manager::internal::ThreadControllerImpl::WorkType>, void ()>::Run(base::internal::BindStateBase*) ./../../base/bind_internal.h:671:0
    #28 0x563cea96a777 in Run ./../../base/callback.h:99:12
    #29 0x563cea96a777 in base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) ./../../base/debug/task_annotator.cc:99:0
    #30 0x563cea8074ed in base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::DoWorkImpl(base::TimeTicks*) ./../../base/task/sequence_manager/thread_controller_with_message_pump_impl.cc:255:21
    #31 0x563cea6c8250 in base::MessagePumpDefault::Run(base::MessagePump::Delegate*) ./../../base/message_loop/message_pump_default.cc:39:31
    #32 0x563cea8090ae in base::sequence_manager::internal::ThreadControllerWithMessagePumpImpl::Run(bool) ./../../base/task/sequence_manager/thread_controller_with_message_pump_impl.cc:353:12
    #33 0x563cea759c47 in base::RunLoop::Run() ./../../base/run_loop.cc:150:14
    #34 0x563cea85abe8 in base::Thread::Run(base::RunLoop*) ./../../base/threading/thread.cc:251:13
    #35 0x563cea85b5cd in base::Thread::ThreadMain() ./../../base/threading/thread.cc:333:3
    #36 0x563cea9403fc in base::(anonymous namespace)::ThreadFunc(void*) ./../../base/threading/platform_thread_posix.cc:81:13
    #37 0x7f0fd5ba6184 in start_thread ??:0:0
    #38 0x7f0fd146f03d in clone ??:0:0

Another test (PDFExtensionTest.Elements) in  issue 915555  had a similar check start failing ~December 17.

It is possible that <webview>/pdf-related code isn't hooked up with begin-frames correctly. Is it possible to know which process is crashing? (I believe there are multiple renderer/plugin processes at play when a pdf is loaded?)

+thestig

I think the process arrangement is:

https://.../file.pdf
  <embed> -- chrome-extension://...
    <plugin> -- PPAPI plugin

I'm not sure how to tell which one of those the crash is from. 

It's the extension shown in comment 10. It's really easy to repro here. Just build for ChromeOS on Linux, load a PDF, and try scrolling. My build config is roughly:

dcheck_always_on = true
target_os = "chromeos"
use_goma = true
use_ozone = true
use_cups = true

I am indeed able to repro fairly easily on a cros build. Thank you!

I think I see what the problem is. I should be able to put up a CL for a fix soon.

Should we add a PDFExtensionTest to just scroll a multi-page PDF up and down repeatedly? To tickle the cc/ code, with the expectation that the test ends without crashing.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7919db2ce52b20821d7a75f6e1eda18b38049312

commit 7919db2ce52b20821d7a75f6e1eda18b38049312
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Mon Jan 14 17:02:29 2019

<webview>: Do not request begin-frames from platform view.

For <webview> (without OOP-D), begin-frames are pumped to the renderer
from two sources: RenderWidgetHostViewChildFrame, and DelegatedFrameHost
(since a RenderWidgetHostViewGuest is-a RenderWidgetHostViewChildFrame,
but is also backed by a RenderWidgetHostViewAura etc. More details in
crbug.com/330264). This is because the 'platform view' (i.e. the
platform impl like RenderWidgetHostViewAura) also requests begin-frames,
which shouldn't be necessary. So this change removes that.

BUG= 919562 , 330264

Change-Id: Ib7ad078079ce65a2dd23b7f03ce570f11e877d69
Reviewed-on: https://chromium-review.googlesource.com/c/1406143
Commit-Queue: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Saman Sami <samans@chromium.org>
Cr-Commit-Position: refs/heads/master@{#622484}
[modify] https://crrev.com/7919db2ce52b20821d7a75f6e1eda18b38049312/content/browser/frame_host/render_widget_host_view_guest.cc
[modify] https://crrev.com/7919db2ce52b20821d7a75f6e1eda18b38049312/content/browser/frame_host/render_widget_host_view_guest.h

 Issue 915555  has been merged into this issue.