New issue
Advanced search Search tips

Issue 895309 link

Starred by 2 users
Status: Fixed
Owner:
sebmarchand@chromium.org
Closed: Oct 30
Cc:
etiennep@chromium.org
etienneb@chromium.org
ssid@chromium.org
gab@chromium.org
fdoray@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 3
Type: Bug



Sign in to add a comment

Stalled StartProfiling on the main thread

Project Member Reported by etiennep@chromium.org, Oct 15 
We are seeing a suspiciously long task posted from StartProfiling() (../../base/trace_event/trace_event_system_stats_monitor.cc), which stalls for several seconds.

Slow-reports are getting traces when jank are detected on the browser main thread. These following reports contains example of the stalled task:

08226726cbea1d2e
944a24587924ae9f
18eda2cc9ac055b6
3c6fa4dc5862ce90
0e3856e1f570d4b6

The janky event can last for ~6  to ~10 seconds.

The stackframes points to a call to "base::GetSystemCommitCharge()":

NtQuerySystemInformation
K32GetPerformanceInfo
base::GetSystemCommitCharge()
base::SystemMetrics::Sample()
base::trace_event::TraceEventSystemStatsMonitor::DumpSystemStats()
base::RepeatingTimer::RunUserTask()
base::internal::BaseTimerTaskInternal::Run()
base::debug::TaskAnnotator::RunTask(char const *,base::PendingTask *)
base::MessageLoop::RunTask(base::PendingTask *)
base::MessageLoop::DoDelayedWork(base::TimeTicks *)
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 &
Screen Shot 2018-10-15 at 12.54.26 PM.png
75.1 KB View Download
Screen Shot 2018-10-15 at 12.54.44 PM.png
60.8 KB View Download

Comment 1 by etiennep@chromium.org, Oct 15

Cc: etiennep@chromium.org

Comment 2 by etiennep@chromium.org, Oct 15 

More reports:
c47b76050cffc2b2
c7467b97d7a2ba98
2823dd7781e1a1cd
dfea76181d6f8806
6ff8c8e3f0268921

Comment 3 by etienneb@chromium.org, Oct 15

Cc: gab@chromium.org fdoray@chromium.org ssid@chromium.org
Labels: Hotlist-Jank Performance-Browser Hotlist-SamplingProfilerInField OS-Windows

Comment 4 by etienneb@chromium.org, Oct 15 

Some reports are pointing to a waitable event, which may be stalled on something else happening in chrome or on the system (e.g. 4d874a89a265b0d5):

NtWaitForAlertByThreadId
RtlpWaitOnAddressWithTimeout
RtlpWaitOnAddress
RtlpWaitOnCriticalSection
RtlpEnterCriticalSectionContended
RtlpAllocateHeap
RtlpAllocateHeapInternal
LocalAlloc
K32GetPerformanceInfo
base::GetSystemCommitCharge()
base::SystemMetrics::Sample()
base::trace_event::TraceEventSystemStatsMonitor::DumpSystemStats()
base::RepeatingTimer::RunUserTask()
base::internal::BaseTimerTaskInternal::Run()
base::debug::TaskAnnotator::RunTask(char const *,base::PendingTask *)
base::MessageLoop::RunTask(base::PendingTask *)
base::MessageLoop::DoDelayedWork(base::TimeTicks *)
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)

Comment 5 by sebmarchand@chromium.org, Oct 16

Status: Assigned (was: Untriaged)
The DumpSystemStats function is only called when tracing is enabled, so I don't think that this is really causing jank that's affecting users but it might be worth moving the call to GetPerformanceInfo to a blocking sequence.
Project Member

Comment 7 by bugdroid1@chromium.org, Oct 30 

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

commit 05183ceb83f3117a973282fb98fb495dbc70116f
Author: Sebastien Marchand <sebmarchand@chromium.org>
Date: Tue Oct 30 02:20:04 2018

Move the calls to DumpSystemStats to a MayBlock thread.

Bug:  895309 
Change-Id: Ib777900ba581c77e4e94d998cd36b3ca2ada9ba6
Reviewed-on: https://chromium-review.googlesource.com/c/1282393
Reviewed-by: oysteine <oysteine@chromium.org>
Reviewed-by: François Doray <fdoray@chromium.org>
Reviewed-by: Etienne Pierre-Doray <etiennep@chromium.org>
Commit-Queue: Sébastien Marchand <sebmarchand@chromium.org>
Cr-Commit-Position: refs/heads/master@{#603743}
[modify] https://crrev.com/05183ceb83f3117a973282fb98fb495dbc70116f/base/process/process_metrics_win.cc
[modify] https://crrev.com/05183ceb83f3117a973282fb98fb495dbc70116f/base/trace_event/trace_event_system_stats_monitor.cc

Comment 8 by sebmarchand@chromium.org, Oct 30

Status: Fixed (was: Assigned)
►

Sign in to add a comment