New issue
Advanced search Search tips

Issue 900022 link

Starred by 2 users
Status: Fixed
Owner:
dominickn@chromium.org
Closed: Nov 9
Cc:
etienneb@chromium.org
mea...@chromium.org
dominickn@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug
Team-Security-UX

Blocked on:
issue 901287


Sign in to add a comment

Potential jank caused by SiteEngagementService::RecordMetrics()

Project Member Reported by ssid@chromium.org, Oct 29 
We collected slow reports from users facing janks and found that the function mentioned above is taking too much time on the main thread, potentially causing janks at startup.

The issue can be found in reports:
42e13bb57df6f2b9 ,2506 ms
6a6a47a9f4ac9f4c ,2386 ms
ba73c59b292d8fc8 ,2375 ms
10e256a4e195c01c ,2220 ms
5af9b8e378157262 ,1439 ms


Go to crash/ReportID to view the traces.

Some probable suspects from stack samples:
Unknown
crashpad::(anonymous namespace)::InsertOrReplaceMapEntry(std::__ndk1::map<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> >, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> >, std::__ndk1::less<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > >, std::__ndk1::allocator<std::__ndk1::pair<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > > > >*, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&)
std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> >::__init(char const*, unsigned int)
base::Value::Value(base::flat_map<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> >, std::__ndk1::unique_ptr<base::Value, std::__ndk1::default_delete<base::Value> >, std::__ndk1::less<void> > const&)
base::Value::Clone() const
base::Value::DeepCopy() const
_ZN16content_settings12_GLOBAL__N_116RuleIteratorImpl4NextEv$79b512e2cca89928a2e5749cf646f126
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::RuleIterator*, GURL const&, GURL const&, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::ProviderInterface const*, GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, bool, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetWebsiteSettingInternal(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, HostContentSettingsMap::ProviderType, content_settings::SettingInfo*) const
HostContentSettingsMap::GetWebsiteSetting(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, content_settings::SettingInfo*) const
SiteEngagementScore::SiteEngagementScore(base::Clock*, GURL const&, HostContentSettingsMap*)
SiteEngagementService::CreateEngagementScore(GURL const&) const
SiteEngagementService::GetDetails(GURL const&) const
SiteEngagementService::GetAllDetails() const
SiteEngagementService::GetTotalEngagementPoints() const
SiteEngagementService::RecordMetrics()
base::OnceCallback<void ()>::Run() &&
base::internal::Invoker<base::internal::BindState<void (*)(std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> >), std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> > >, void ()>::RunOnce(base::internal::BindStateBase*)
base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)
base::MessageLoop::RunTask(base::PendingTask*)
base::MessageLoop::DoDelayedWork(base::TimeTicks*)
base::MessagePumpForUI::OnDelayedLooperCallback()
base::(anonymous namespace)::DelayedLooperCallback(int, int, void*)


	
Unknown
base::Value::Clone() const
base::Value::Value(base::flat_map<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> >, std::__ndk1::unique_ptr<base::Value, std::__ndk1::default_delete<base::Value> >, std::__ndk1::less<void> > const&)
base::Value::Clone() const
base::Value::DeepCopy() const
_ZN16content_settings12_GLOBAL__N_116RuleIteratorImpl4NextEv$79b512e2cca89928a2e5749cf646f126
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::RuleIterator*, GURL const&, GURL const&, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::ProviderInterface const*, GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, bool, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetWebsiteSettingInternal(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, HostContentSettingsMap::ProviderType, content_settings::SettingInfo*) const
HostContentSettingsMap::GetWebsiteSetting(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, content_settings::SettingInfo*) const
SiteEngagementScore::SiteEngagementScore(base::Clock*, GURL const&, HostContentSettingsMap*)
SiteEngagementService::CreateEngagementScore(GURL const&) const
SiteEngagementService::GetDetails(GURL const&) const
SiteEngagementService::GetAllDetails() const
SiteEngagementService::RecordMetrics()
base::OnceCallback<void ()>::Run() &&
base::internal::Invoker<base::internal::BindState<void (*)(std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> >), std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> > >, void ()>::RunOnce(base::internal::BindStateBase*)
base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)
base::MessageLoop::RunTask(base::PendingTask*)
base::MessageLoop::DoDelayedWork(base::TimeTicks*)
base::MessagePumpForUI::OnDelayedLooperCallback()
base::(anonymous namespace)::DelayedLooperCallback(int, int, void*)



Unknown
GURL::ComponentStringPiece(url::Component const&) const
GURL::SchemeIs(base::BasicStringPiece<std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > >) const
ContentSettingsPattern::Matches(GURL const&) const
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::RuleIterator*, GURL const&, GURL const&, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetContentSettingValueAndPatterns(content_settings::ProviderInterface const*, GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, bool, ContentSettingsPattern*, ContentSettingsPattern*)
HostContentSettingsMap::GetWebsiteSettingInternal(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, HostContentSettingsMap::ProviderType, content_settings::SettingInfo*) const
HostContentSettingsMap::GetWebsiteSetting(GURL const&, GURL const&, ContentSettingsType, std::__ndk1::basic_string<char, std::__ndk1::char_traits<char>, std::__ndk1::allocator<char> > const&, content_settings::SettingInfo*) const
SiteEngagementScore::SiteEngagementScore(base::Clock*, GURL const&, HostContentSettingsMap*)
SiteEngagementService::CreateEngagementScore(GURL const&) const
SiteEngagementService::RecordMetrics()
base::OnceCallback<void ()>::Run() &&
base::internal::Invoker<base::internal::BindState<void (*)(std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> >), std::__ndk1::unique_ptr<(anonymous namespace)::AfterStartupTask, std::__ndk1::default_delete<(anonymous namespace)::AfterStartupTask> > >, void ()>::RunOnce(base::internal::BindStateBase*)
base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)
base::MessageLoop::RunTask(base::PendingTask*)
base::MessageLoop::DoWork()
base::MessagePumpForUI::OnNonDelayedLooperCallback()
base::(anonymous namespace)::NonDelayedLooperCallback(int, int, void*)

Comment 1 by ssid@chromium.org, Oct 29

Components: Internals>Permissions>SiteEngagement
About 1% of collected traces show that SiteEngagementService::RecordMetrics() takes more than 100ms.

Comment 2 by dominickn@chromium.org, Oct 29 

This method is called via content::BrowserThread::PostAfterStartupTask, which is explicitly meant "For use with scheduling non-critical tasks for execution after startup." If jank is happening at startup because of the site engagement method, then PostAfterStartupTask isn't doing a particularly good job......

Comment 3 by ssid@chromium.org, Oct 30

Summary: Potential jank caused by SiteEngagementService::RecordMetrics() (was: Potential jank caused by SiteEngagementService::RecordMetrics() at startup)
Actually you're right. This method is always called once the startup tasks are complete. Leaving aside the startup part, it seems that this function still takes quite long to execute. Android kills browser if the UI thread is busy for more than 5 seconds, and running this method on UI thread might cause janks in general.
Do you think there is a way to move some work off main thread?

Comment 4 by dominickn@chromium.org, Oct 30 

I can make the method a little less expensive, but it can't be moved off the UI thread in its current state. We need to call HostContentSettingsMapFactory::GetForProfile(), which DCHECKs that it's on the UI thread.

Comment 5 by dominickn@chromium.org, Oct 30

Owner: dominickn@chromium.org
Status: Started (was: Untriaged)
With some additional investigation I may be able to move the expensive bit of the method to a background thread, which should help here.
Project Member

Comment 6 by bugdroid1@chromium.org, Oct 31 

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

commit 74bc832a3f961bb28eab4cb227cd6ff2dc781fc7
Author: Dominick Ng <dominickn@chromium.org>
Date: Wed Oct 31 04:45:51 2018

Make SiteEngagementService::RecordMetrics less expensive on the UI thread.

RecordMetrics() is called after browser startup and then no more than
once per hour of browser use. It must fetch all site engagement content
settings and calculate statistics over them, and on some Android devices
it blocks the UI thread for 2500ms. This is bad since Android will kill
the browser if the UI thread is busy for more than 5 seconds.

This CL refactors the method to make it less expensive. In particular:

 - a duplicate call to SiteEngagementService::GetAllDetails is
   eliminated
 - SiteEngagementService::GetAllDetails (the fetch method) is refactored
   so that it may be run as a background task to free the UI thread.
   This involved eliminating all calls to
   HostContentSettingsMapFactory::GetForProfile as this method DCHECKs
   that it is on the UI thread.

After this CL, SiteEngagementService::GetAllDetails() is called once in
SiteEngagementService::RecordMetrics(), and that one call happens on a
background thread. Other callers to the method continue to call it on
the UI thread; future work may convert the method to be callback-driven
so that it is never called on the UI thread.

BUG= 900022 

Change-Id: Ie661b915891ddf981ac4a3049e8e96b73b23684d
Reviewed-on: https://chromium-review.googlesource.com/c/1307018
Commit-Queue: Dominick Ng <dominickn@chromium.org>
Reviewed-by: calamity <calamity@chromium.org>
Cr-Commit-Position: refs/heads/master@{#604156}
[modify] https://crrev.com/74bc832a3f961bb28eab4cb227cd6ff2dc781fc7/chrome/browser/engagement/site_engagement_service.cc
[modify] https://crrev.com/74bc832a3f961bb28eab4cb227cd6ff2dc781fc7/chrome/browser/engagement/site_engagement_service.h
[modify] https://crrev.com/74bc832a3f961bb28eab4cb227cd6ff2dc781fc7/chrome/browser/engagement/site_engagement_service_unittest.cc

Comment 7 by dominickn@chromium.org, Nov 4

Cc: mea...@chromium.org
+meacer FYI - turns out calling SiteEngagementService::GetAllDetails on every navigation may be a little expensive on the UI thread, particularly on Android. I'm thinking about making that method asynchronous to reduce the pressure on the UI thread.

Comment 8 by mea...@chromium.org, Nov 8 

We should only be calling GetAllDetails if the navigated URL has an IDN. In any case, making it async sounds good, LookalikeUrlNavigationObserver doesn't need to be blocking.
Project Member

Comment 9 by bugdroid1@chromium.org, Nov 9 

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

commit f70115b4df17a675652ef65521ba6ddf81f59037
Author: Balazs Engedy <engedy@chromium.org>
Date: Fri Nov 09 10:12:19 2018

Prevent use-after-free in SiteEngagementService.

The profile and its KeyedServices are normally destroyed before the
TaskScheduler shuts down background threads, so the background task to
record site engagement metrics needs to avoid using any members of
SiteEngagementService

Bug:  900022 
Change-Id: Ibdebbd5a64d59fad29b7715be3557eeed411d741
Reviewed-on: https://chromium-review.googlesource.com/c/1326441
Reviewed-by: Dominick Ng <dominickn@chromium.org>
Commit-Queue: Balazs Engedy <engedy@chromium.org>
Cr-Commit-Position: refs/heads/master@{#606781}
[modify] https://crrev.com/f70115b4df17a675652ef65521ba6ddf81f59037/chrome/browser/engagement/site_engagement_service.cc

Comment 10 by engedy@chromium.org, Nov 9

Blockedon: 901287

Comment 11 Deleted

►

Sign in to add a comment