Issue 892747 link

Starred by 1 user

Issue metadata

Status:	Untriaged
Owner:	etienneb@chromium.org
Cc:	etiennep@chromium.org fdoray@google.com etienneb@chromium.org ssid@chromium.org gab@chromium.org
EstimatedDays:	----
NextAction:	----
OS:	----
Pri:	3
Type:	Bug
Hotlist-Jank Performance-Browser Hotlist-SamplingProfilerInField

Jank detected in ViewHostMsg::ClosePage

Project Member Reported by etienneb@chromium.org, Oct 5

Issue description

Slow-reports are showing cases where processing the IPC message ViewHostMsg_ClosePage_ACK on the main thread can be really slow.

Example:
  56edb55fdb1dc208
  88d77babaed890fa
  2fb07335a67b678e

Unfortunately, there is not enough context yet to figure out where the time is spent.

At a glance, lot of code seems to run under:
  content::WebContentsImpl::~WebContentsImpl()
  content::WebContentsImpl::~WebContentsImpl

Let wait for more reports.

	windows_close.png 16.3 KB View Download

Comment 1 by etienneb@chromium.org, Oct 15

Labels: Performance-Browser

From this slow-report: c793793902a7526d

The main thread is stalled on this following stackframe:

"NtWaitForMultipleObjects
 off:0x13ed - KERNELBASE.dll [0B80AB9F62D1485EB26AF0C07523E8F12]
 off:0x106f - KERNEL32.DLL [A49C2B8068D747D5B88373C92E68D42C2]
 base::WaitableEvent::WaitMany(base::WaitableEvent * *,unsigned __int64)
 mojo::WaitSet::State::Wait(base::WaitableEvent * *,unsigned __int64 *,mojo::Handle *,unsigned int *,MojoHandleSignalsState *)
 mojo::SyncHandleRegistry::Wait(bool const * * const,unsigned __int64)
 mojo::SyncEventWatcher::SyncWatch(bool const * *,unsigned __int64)
 mojo::SequenceLocalSyncEventWatcher::SyncWatch(bool const *)
 mojo::InterfaceEndpointClient::AcceptWithResponder(mojo::Message *,std::unique_ptr<mojo::MessageReceiver,std::default_delete<mojo::MessageReceiver> >)
 viz::mojom::FrameSinkManagerProxy::DestroyCompositorFrameSink(viz::FrameSinkId const &)
 viz::HostFrameSinkManager::InvalidateFrameSinkId(viz::FrameSinkId const &)
 ui::Compositor::~Compositor()
 ui::Compositor::~Compositor
 views::HWNDMessageHandler::OnDestroy()
 views::HWNDMessageHandler::_ProcessWindowMessage(HWND__ *,unsigned int,unsigned __int64,__int64,__int64 &,unsigned long)
 views::HWNDMessageHandler::OnWndProc(unsigned int,unsigned __int64,__int64)
 base::win::WrappedWindowProc<&gfx::WindowImpl::WndProc(HWND__ *,unsigned int,unsigned __int64,__int64)>(HWND__ *,unsigned int,unsigned __int64,__int64)
 off:0x23fd - USER32.dll [CFAEEEAD336E4562AB6EB187BD9184E42]
 off:0x3bea - USER32.dll [CFAEEEAD336E4562AB6EB187BD9184E42]
 off:0x3cbe - USER32.dll [CFAEEEAD336E4562AB6EB187BD9184E42]
 KiUserCallbackDispatcherContinue
 off:0x12ca - USER32.dll [CFAEEEAD336E4562AB6EB187BD9184E42]
 base::debug::TaskAnnotator::RunTask(char const *,base::PendingTask *)
 base::MessageLoop::RunTask(base::PendingTask *)
 base::MessageLoop::DoWork()
 base::MessagePumpForUI::DoRunLoop()
 base::MessagePumpWin::Run(base::MessagePump::Delegate *)
 base::RunLoop::Run()
 ChromeBrowserMainParts::MainMessageLoopRun(int *)
 content::BrowserMainLoop::RunMainMessageLoopParts()
 content::BrowserMainRunnerImpl::Run()
 content::BrowserMain(content::MainFunctionParams const &)
 content::RunBrowserProcessMain(content::MainFunctionParams const &,content::ContentMainDelegate *)
 content::ContentMainRunnerImpl::Run(bool)
 service_manager::Main(service_manager::MainParams const &)
 content::ContentMain(content::ContentMainParams const &)
 ChromeMain
 MainDllLoader::Launch(HINSTANCE__ *,base::TimeTicks)
 wWinMain
 __scrt_common_main_seh
 off:0x13d2 - KERNEL32.DLL [A49C2B8068D747D5B88373C92E68D42C2]
 RtlUserThreadStart

trace-c793793902a7526d.json.gz
407 KB Download

	close1.png 32.5 KB View Download

Comment 2 by etienneb@chromium.org, Oct 15

From this slow-report: ab527d6e2112bc54

The main thread is stalled for 11 seconds on

NtWaitForMultipleObjects
 off:0x13ed - KERNELBASE.dll [6B725CF1E7AA49458B4007B0387504652]
 off:0x106f - KERNEL32.dll [A49C2B8068D747D5B88373C92E68D42C2]
 base::WaitableEvent::WaitMany(base::WaitableEvent * *,unsigned __int64)
 mojo::WaitSet::State::Wait(base::WaitableEvent * *,unsigned __int64 *,mojo::Handle *,unsigned int *,MojoHandleSignalsState *)
 mojo::SyncHandleRegistry::Wait(bool const * * const,unsigned __int64)
 mojo::SyncEventWatcher::SyncWatch(bool const * *,unsigned __int64)
 mojo::SequenceLocalSyncEventWatcher::SyncWatch(bool const *)
 mojo::InterfaceEndpointClient::AcceptWithResponder(mojo::Message *,std::unique_ptr<mojo::MessageReceiver,std::default_delete<mojo::MessageReceiver> >)
 viz::mojom::FrameSinkManagerProxy::DestroyCompositorFrameSink(viz::FrameSinkId const &)
 viz::HostFrameSinkManager::InvalidateFrameSinkId(viz::FrameSinkId const &)
 ui::Compositor::~Compositor()
 ui::Compositor::~Compositor
 views::HWNDMessageHandler::OnDestroy()
 views::HWNDMessageHandler::_ProcessWindowMessage(HWND__ *,unsigned int,unsigned __int64,__int64,__int64 &,unsigned long)
 views::HWNDMessageHandler::OnWndProc(unsigned int,unsigned __int64,__int64)
 base::win::WrappedWindowProc<&gfx::WindowImpl::WndProc(HWND__ *,unsigned int,unsigned __int64,__int64)>(HWND__ *,unsigned int,unsigned __int64,__int64)
 off:0x24fd - USER32.dll [61561D337B0E4DE3ADB457CF090DD3BA2]
 off:0x3af2 - USER32.dll [61561D337B0E4DE3ADB457CF090DD3BA2]
 off:0x3bbe - USER32.dll [61561D337B0E4DE3ADB457CF090DD3BA2]
 KiUserCallbackDispatcherContinue
 off:0x12ca - USER32.dll [61561D337B0E4DE3ADB457CF090DD3BA2]
 base::debug::TaskAnnotator::RunTask(char const *,base::PendingTask *)
 base::MessageLoop::RunTask(base::PendingTask *)
 base::MessageLoop::DoWork()
 base::MessagePumpForUI::DoRunLoop()
 base::MessagePumpWin::Run(base::MessagePump::Delegate *)
 base::RunLoop::Run()
 ChromeBrowserMainParts::MainMessageLoopRun(int *)
 content::BrowserMainLoop::RunMainMessageLoopParts()
 content::BrowserMainRunnerImpl::Run()
 content::BrowserMain(content::MainFunctionParams const &)
 content::RunBrowserProcessMain(content::MainFunctionParams const &,content::ContentMainDelegate *)
 content::ContentMainRunnerImpl::Run(bool)
 service_manager::Main(service_manager::MainParams const &)
 content::ContentMain(content::ContentMainParams const &)
 ChromeMain
 MainDllLoader::Launch(HINSTANCE__ *,base::TimeTicks)
 wWinMain
 __scrt_common_main_seh
 off:0x13d2 - KERNEL32.dll [A49C2B8068D747D5B88373C92E68D42C2]
 RtlUserThreadStart

trace-ab527d6e2112bc54.json.gz
1.3 MB Download

	close2.png 19.3 KB View Download

Comment 3 by etienneb@chromium.org, Oct 15

Cc: etiennep@chromium.org

Comment 4 by etienneb@chromium.org, Oct 15

From this slow-report: 7f003c801957abf7
The main thread is stalled for 15 seconds.


	
"off:0x69e5a - ntdll.dll [E9EB7F399DB7487BA5F91125568619991]
 off:0x1430 - KERNELBASE.dll [CBABF941FF9C4D0F9E807CA8B21645D22]
 off:0x106c0 - kernel32.dll [217F00226BC642DD86DD676FF93BD6932]
 base::WaitableEvent::WaitMany(base::WaitableEvent * *,unsigned __int64)
 mojo::WaitSet::State::Wait(base::WaitableEvent * *,unsigned __int64 *,mojo::Handle *,unsigned int *,MojoHandleSignalsState *)
 mojo::SyncHandleRegistry::Wait(bool const * * const,unsigned __int64)
 mojo::SyncEventWatcher::SyncWatch(bool const * *,unsigned __int64)
 mojo::SequenceLocalSyncEventWatcher::SyncWatch(bool const *)
 mojo::InterfaceEndpointClient::AcceptWithResponder(mojo::Message *,std::unique_ptr<mojo::MessageReceiver,std::default_delete<mojo::MessageReceiver> >)
 viz::mojom::FrameSinkManagerProxy::DestroyCompositorFrameSink(viz::FrameSinkId const &)
 viz::HostFrameSinkManager::InvalidateFrameSinkId(viz::FrameSinkId const &)
 ui::Compositor::~Compositor()
 ui::Compositor::~Compositor
 views::HWNDMessageHandler::OnDestroy()

trace-7f003c801957abf7.json.gz
383 KB Download

	close3.png 52.6 KB View Download

Comment 5 by etienneb@chromium.org, Oct 15

From this slow-report: ebb5a721ef176d88

The GPU process is not involved.

trace-ebb5a721ef176d88.json.gz
3.9 MB Download

Comment 6 by etienneb@chromium.org, Oct 15

Looking to the code, this is pointing to:

https://cs.chromium.org/chromium/src/components/viz/host/host_frame_sink_manager.cc?l=92

  if (data.has_created_compositor_frame_sink && data.is_root) {
    // This synchronous call ensures that the GL context/surface that draw to
    // the platform window (eg. XWindow or HWND) get destroyed before the
    // platform window is destroyed.
    mojo::SyncCallRestrictions::ScopedAllowSyncCall allow_sync_call;
    frame_sink_manager_->DestroyCompositorFrameSink(frame_sink_id);
  }

Comment 7 by etienneb@chromium.org, Oct 15

From UMA sampling profiler, it seems that most of the time is spent in the destructor is for waiting for something.

	close_flame.png 343 KB View Download

►

Issue 892747 link

Issue metadata

Jank detected in ViewHostMsg::ClosePage

Issue description

Comment 1 by etienneb@chromium.org, Oct 15

Comment 1 Deleted

Comment 2 by etienneb@chromium.org, Oct 15

Comment 2 Deleted

Comment 3 by etienneb@chromium.org, Oct 15

Comment 3 Deleted

Comment 4 by etienneb@chromium.org, Oct 15

Comment 4 Deleted

Comment 5 by etienneb@chromium.org, Oct 15

Comment 5 Deleted

Comment 6 by etienneb@chromium.org, Oct 15

Comment 6 Deleted

Comment 7 by etienneb@chromium.org, Oct 15

Comment 7 Deleted

Sign in to add a comment