New issue
Advanced search Search tips

Issue 600707 link

Starred by 7 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug



Sign in to add a comment

Explore optimizations for notification click handling in cold startup

Project Member Reported by mvanouwe...@chromium.org, Apr 5 2016

Issue description

This is a follow up on  issue 599201 .

The sequence for handling a notification click when Chrome has been killed (so a cold start) looks roughly like this:
04-04 11:38:36.529  3063  3063 D StatusBar: Clicked on content of 0|com.chrome.canary|-1|NotificationUIManager;https://tests.peter.sh/;1|10169
04-04 11:38:36.549 24367 24367 I NotificationService: Received a notification intent in the NotificationService's receiver.
04-04 11:38:36.817 24367 24367 I cr_LibraryLoader: Time to load native libraries: 226 ms (timestamps 5163-5389)
04-04 11:38:37.278 24367 24367 I NotificationUIManager: Dispatching notification event to native: 1
04-04 11:38:37.293 24367 24417 I chromium: [INFO:notification_event_dispatcher_impl.cc(165)] Lookup for ServiceWoker Registration: success: 1
04-04 11:38:37.310 24367 24417 I chromium: [INFO:notification_event_dispatcher_impl.cc(104)] Trying to dispatch notification for SW with status: 0
04-04 11:38:37.317   897  3506 I ActivityManager: Start proc 24429:com.chrome.canary:privileged_process0/u0a169 for service com.chrome.canary/org.chromium.content.app.PrivilegedProcessService0
04-04 11:38:37.409   897  3094 I ActivityManager: Start proc 24444:com.chrome.canary:sandboxed_process0/u0i77 for service com.chrome.canary/org.chromium.content.app.SandboxedProcessService0
04-04 11:38:37.613 24429 24457 I cr_LibraryLoader: Time to load native libraries: 166 ms (timestamps 6019-6185)
04-04 11:38:37.711 24444 24458 I cr_LibraryLoader: Time to load native libraries: 199 ms (timestamps 6084-6283)
04-04 11:38:37.951 24367 24417 I chromium: [INFO:notification_event_dispatcher_impl.cc(53)] The notification event has finished: 0
04-04 11:38:37.962   897  3094 I ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://tests.peter.sh/... flg=0x10000000 pkg=com.chrome.canary cmp=com.chrome.canary/org.chromium.chrome.browser.document.ChromeLauncherActivity (has extras)} from uid 10169 on display 0
04-04 11:38:38.028   897  3464 I ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://tests.peter.sh/... flg=0x14002000 pkg=com.chrome.canary cmp=com.chrome.canary/org.chromium.chrome.browser.ChromeTabbedActivity (has extras)} from uid 10169 on display 0
04-04 11:38:38.154   897  3094 I ActivityManager: Start proc 24471:com.chrome.canary:sandboxed_process1/u0i78 for service com.chrome.canary/org.chromium.content.app.SandboxedProcessService1
04-04 11:38:38.308   897   928 I ActivityManager: Displayed com.chrome.canary/org.chromium.chrome.browser.ChromeTabbedActivity: +263ms (total +325ms)
04-04 11:38:38.460 24471 24485 I cr_LibraryLoader: Time to load native libraries: 42 ms (timestamps 6990-7032)

In this case, it took 1.779 seconds to start showing a blank activity, the first time Chrome has shown a visible response to the user. The notification itself would have responded visually to a touch, but there's a long period of non-responsiveness in between.

This measurement was taken on a Nexus 5X, many devices are slower.

There are a few things that stand out in these logs:
* It looks like 2 renderers are started. First one for the service worker, then one for the site to be displayed. Could these things happen in the same process, especially as they are for the same origin?
* It looks like the gpu process is loaded quite early. Is this beneficial or does it slow down the time to first paint of an activity? I would not expect a service worker to need the gpu process.
* What is the distribution of timing data in production? I don't think we have instrumentation for the full sequence yet.
* It took over 600ms to dispatch the notification event. According to the ServiceWorker.NotificationClickEvent.Time histogram, in production 50% of users see this taking longer than 2.5 seconds.
 
Cc: toyoshim@chromium.org
Thanks for filing this. Service worker team is also working on improving SW startup in general.

toyoshim@ (no longer working on workers) once investigated this specific scenario. See  issue 519957  (I'll dupe that here as it's stale) and the doc there:
https://docs.google.com/a/chromium.org/document/d/1T_HZvYpE1GF0mAt5mjKwtOK-FJh9wMgGI42Qfo8jaE8/edit?usp=sharing

He also made an investigation in launch from homescreen perf:
https://docs.google.com/document/d/1AR1dtickeq7yKLOVMVg9QWJhHBqImUx23FAKq0oM6VY/edit#

There was also a bug about GPU in workers:  issue 501698 .
Cc: creis@chromium.org
 Issue 519957  has been merged into this issue.

Comment 3 by kinuko@chromium.org, Apr 11 2016

Cc: clamy@chromium.org
We haven't tested it but for the process creation issue I guess we could possibly have the same problem/situation with PlzNavigate.
Status: Available (was: Untriaged)
Project Member

Comment 5 by sheriffbot@chromium.org, Apr 17 2017

Labels: Hotlist-Recharge-Cold
Status: Untriaged (was: Available)
This issue has been available for more than 365 days, and should be re-evaluated. Please re-triage this issue.
The Hotlist-Recharge-Cold label is applied for tracking purposes, and should not be removed after re-triaging the issue.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Comment 6 by falken@chromium.org, Apr 18 2017

Status: Available (was: Untriaged)
Yeah this is likely similar to  issue 705318 .
Project Member

Comment 7 by bugdroid1@chromium.org, Jun 28 2017

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

commit eb576e6c660bc1ce8e7aaf93bfab70042479a237
Author: Tsuyoshi Horo <horo@chromium.org>
Date: Wed Jun 28 08:04:36 2017

Reuse unmatched service worker processes for navigation

This CL introduces UnmatchedServiceWorkerProcessTracker which tracks the
unmatched service processes. The unmatched service processes will be reused for
the later navigation to the same site.

See the doc:
https://docs.google.com/a/chromium.org/document/d/1iT8xvo18-zmlsU2iHqH2RCIXrWoGJOIaZ6aDASubi1Q/edit?usp=sharing

Bug:  732682 ,600707
Change-Id: I15b970afbdb6801d1124616be316c3e4c6e0e9d1
Reviewed-on: https://chromium-review.googlesource.com/535220
Commit-Queue: Tsuyoshi Horo <horo@chromium.org>
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Reviewed-by: Charlie Reis <creis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#482916}
[modify] https://crrev.com/eb576e6c660bc1ce8e7aaf93bfab70042479a237/content/browser/renderer_host/render_process_host_impl.cc
[modify] https://crrev.com/eb576e6c660bc1ce8e7aaf93bfab70042479a237/content/browser/renderer_host/render_process_host_unittest.cc
[modify] https://crrev.com/eb576e6c660bc1ce8e7aaf93bfab70042479a237/content/browser/service_worker/service_worker_process_manager.cc
[modify] https://crrev.com/eb576e6c660bc1ce8e7aaf93bfab70042479a237/content/browser/site_instance_impl.cc
[modify] https://crrev.com/eb576e6c660bc1ce8e7aaf93bfab70042479a237/content/browser/site_instance_impl.h

Status: Untriaged (was: Available)
Would be good for someone to confirm that the fix addressed this.

Comment 9 by awdf@chromium.org, Jul 5 2017

Tsuyoshi, did you do any benchmarking of startup times before/after this change?

Maybe we can see if it makes a difference in the wild by looking at the ServiceWorker.NotificationClickEvent.Time UMA for versions before/after this change, once it hits Beta so we get some more samples (this change went into 61.0.3143.0 so only in Canary so far). That won't be available till next month though..

Comment 10 by awdf@chromium.org, Jul 5 2017

Cc: awdf@chromium.org

Comment 11 by horo@chromium.org, Jul 5 2017

Chrome still creates two processes to start a Service Worker for notificationclick event, and to open a page for clients.openWindow().

When ChromeContentBrowserClient::OpenURL() is called from service_worker_client_utils's OpenWindowOnUI(), a new SiteInstance with an empty site URL is created in WebContentsImpl::Init().
So, the Service Worker's process is not reused for opening the page.

service_worker_client_utils::(anonymous namespace)::OpenWindowOnUI()
 => ChromeContentBrowserClient::OpenURL()
  => chrome::Navigate()
   => chrome::CreateTargetContents()
    => WebContents::Create()
     => WebContentsImpl::CreateWithOpener()
      => WebContentsImpl::Init()
      

I think we should creates a SiteInstance with the site URL in CreateTargetContents() and set to WebContents::CreateParams like this https://chromium-review.googlesource.com/c/560029/.

clamy@
What do you think?

awdf@
I think even if Chrome can reuse the Service Worker's process for opening the page, ServiceWorker.NotificationClickEvent.Time UMA doesn't change.

Comment 12 by horo@chromium.org, Jul 6 2017

Ah, many tests are failing: https://chromium-review.googlesource.com/c/560029/
 PopupBlockerBrowserTest.*
 PopupBlockerBrowserTest.*
 OutOfProcessPPAPITest.InputEvent_AcceptTouchEvent
 LoginPromptBrowserTest.TestCancelAuth_OnBack

We need to find a way to reuse the service worker process for clients.openWindow().
Status: Available (was: Untriaged)
Ahh still more work to do then. At least we are getting closer.
Project Member

Comment 14 by sheriffbot@chromium.org, Jul 6

Status: Untriaged (was: Available)
This issue has been Available for over a year. If it's no longer important or seems unlikely to be fixed, please consider closing it out. If it is important, please re-triage the issue.

Sorry for the inconvenience if the bug really should have been left as Available.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Cc: -awdf@chromium.org
Status: Available (was: Untriaged)

Sign in to add a comment