New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 620359 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Jul 2016
Cc:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 2
Type: Bug



Sign in to add a comment

Browser process pegs CPU, main thread blocked causing SPOD

Project Member Reported by pinkerton@chromium.org, Jun 15 2016

Issue description

Version: M51beta
OS: 10.11.x

Leaving my personal laptop sitting for a while (days) when I brought it back from sleep, the browser process pegged the cpu and the main thread was blocked. Sample attached.

I saw similar behavior on my work Mac that had been sitting for a while. We also got a report from a googler (https://bugs.chromium.org/p/chromium/issues/detail?id=620336).


 
sample
1.2 MB View Download
Cc: shrike@chromium.org
Labels: -Pri-3 Hotlist-Jank Performance Pri-2
Now that GCER doesn't use ALP, we should be able to make a lot of optimizations to prevent this.  I'll try to prioritize this work.

To confirm, this caused lag/jank/delay, but didn't crash the system, correct?
Cc: asargent@chromium.org lazyboy@chromium.org
Status: Assigned (was: Untriaged)

Comment 4 by shrike@chromium.org, Jun 15 2016

rdevlin.cronin@ - can you discuss the problem that's occurring? I'd like to understand what happening.
Sure.  There's an extension API called activityLogPrivate, which is used to log all the extension activity that happens (for the purpose of power users auditing extensions, etc).  Unfortunately, we do this logging unconditionally at the moment, which results in many extra copies of potentially large data (e.g., if an extension is passing a long serialized message).  I've been hoping to tweak the API so that the logging is only done if the user has an active app/extension using the API so that this cost isn't paid by all chrome users.  Eventually, I'd like to push it further to only record if the user has the app open or has opted into some setting, but that's a bit harder and requires some UI tweaks.  For a long time, though, we were blocked because GCER relied on activityLogPrivate, but that is no longer the case (happy to discuss that part offline).  Now that that's no longer the case, I can move forward with some of these optimizations.

To be clear, I don't think this is a regression - I seem to recall seeing some of these reports before.  (Though that's the reason for the questions re lag vs crash in #2 - if it's a crash, it *is* likely a regression.)  But now we can do something about it! :)
Project Member

Comment 6 by bugdroid1@chromium.org, Jun 22 2016

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

commit a84983c58d89dbb83fc97eb24ad70f5780375dd9
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Wed Jun 22 02:06:20 2016

[Extensions] Short-circuit activity logging if not enabled

In order to log activity events in extensions, we need to copy all the
arguments that were passed to the method or event. In some cases (such
as messaging), this can be an extreme amount of work. Additionally, this
can require passing objects from the IO to UI thread. In an extreme
case, we would also create copies of arguments sent via the activityLog
API itself - meaning that for any given API call, we created two extra
copies of all arguments (one for the activity log itself, and another
for the record of the activityLog event dispatch). In some cases, this
activity logging resulted in more work than the API call itself.

Instead, store state around which profiles have an actively-recording
ActivityLog and which extensions are whitelisted in a thread-safe manner
so that we can short-circuit the logging in most cases, and avoid
creating excessive copies for the 99% case.

BUG= 620359 

Review-Url: https://codereview.chromium.org/2077723002
Cr-Commit-Position: refs/heads/master@{#401162}

[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/activity_log/activity_log.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/activity_log/activity_log.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/activity_log/activity_log_browsertest.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/activity_log/activity_log_unittest.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/api/chrome_extensions_api_client.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/api/chrome_extensions_api_client.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/api/web_request/chrome_extension_web_request_event_router_delegate.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/api/web_request/chrome_extension_web_request_event_router_delegate.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/chrome_extensions_browser_client.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/extensions/chrome_extensions_browser_client.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/renderer_host/chrome_extension_message_filter.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/chrome/browser/renderer_host/chrome_extension_message_filter.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api/extensions_api_client.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api/extensions_api_client.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api/web_request/web_request_api.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api/web_request/web_request_api.h
[delete] https://crrev.com/0402963c3f9452446b89d3d7807bcf749a519777/extensions/browser/api/web_request/web_request_event_router_delegate.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api/web_request/web_request_event_router_delegate.h
[add] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api_activity_monitor.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/api_activity_monitor.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/event_router.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/extension_function_dispatcher.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/extensions_browser_client.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/test_extensions_browser_client.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/browser/test_extensions_browser_client.h
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/extensions.gypi
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/shell/browser/shell_extensions_browser_client.cc
[modify] https://crrev.com/a84983c58d89dbb83fc97eb24ad70f5780375dd9/extensions/shell/browser/shell_extensions_browser_client.h

Project Member

Comment 7 by bugdroid1@chromium.org, Jun 24 2016

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

commit 6fba7ec7467f6f6b3a48636a6006425b5f748f5a
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Fri Jun 24 16:15:05 2016

[Extensions] Add renderer-side logic to short circuit activity logging

Revision a84983c58d89dbb83fc97eb24ad70f5780375dd9 added logic to short-
circuit activity logging on the browser side so that we don't log
anything if the user doesn't have an activity-logging extension enabled.
This patch adds logic to the renderer side to avoid adding the
DOMActivityLoggers and APIActivityLoggers that would generate additional
IPCs sent to the browser, in addition to requiring each DOM modification
in the given world to be logged. Now, each of these is only logged in
the case of the user having an active activity-logging extension.

BUG= 620359 

Review-Url: https://codereview.chromium.org/2089333002
Cr-Commit-Position: refs/heads/master@{#401868}

[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/chrome/browser/extensions/activity_log/activity_log.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/chrome/browser/extensions/activity_log/activity_log.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/chrome/browser/extensions/chrome_extensions_browser_client.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/chrome/browser/extensions/chrome_extensions_browser_client.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/chrome/browser/renderer_host/chrome_extension_message_filter.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/browser/extensions_browser_client.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/browser/extensions_browser_client.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/browser/renderer_startup_helper.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/common/extension_messages.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/api_activity_logger.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/api_activity_logger.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/dispatcher.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/dispatcher.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/script_injection.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/script_injection.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/script_injection_manager.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/script_injection_manager.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/scripts_run_info.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/scripts_run_info.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/user_script_set.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/user_script_set.h
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/user_script_set_manager.cc
[modify] https://crrev.com/6fba7ec7467f6f6b3a48636a6006425b5f748f5a/extensions/renderer/user_script_set_manager.h

Status: Fixed (was: Assigned)
This should be fixed, unless you have the Chrome Apps and Extensions Developer Tool installed and enabled.

Please let me know if you see something like this again.
Should have added more detail here:
> This should be fixed, unless you have the Chrome Apps and Extensions Developer Tool installed and enabled.

If you have this tool installed and enabled, we treat that as user opt in for extension activity logging, which can cause this slow down (though note it should *still* be faster than it was previously).  It's kind of like having dev tools or the profiler open - you expect a performance hit.  I'd like to make this more clear at some point, but for now the 99(.99)% case for our users should be addressed.

Sign in to add a comment