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

Issue 827588 link

Starred by 7 users

Issue metadata

Status: WontFix
Owner:
Closed: Jun 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

Speed: Eve, Samus: after 4min of browsing, main browser thread takes ~150% cpu until browser is restarted

Project Member Reported by tbroch@chromium.org, Mar 30 2018

Issue description

Repro:

1. login corp account open some tabs (gmail, gdrive, cal, googlesource, buganizer, crbug.com) & pin them.
2. restart browser (alt+VolUp+X)
3. restore pages
4. wait 3.5min
4. start trace

Trace shows a bunch of 'hwrng' calls afterwards the cpu utilization remains at ~150% regardless of what is attempted.  Only way to fix is to restart the browser.
 
trace_Fri_Mar_30_2018_10.06.35_AM.json.gz
2.9 MB Download

Comment 1 by tbroch@chromium.org, Mar 30 2018

FWIW here's a feedback report as well.

https://listnr.corp.google.com/report/85251512491

Comment 2 by tbroch@chromium.org, Mar 30 2018

Transitioning to suspend and back (lid close / open ) is also a workaround but needs to be performed every 4min as well.
Cc: adurbin@chromium.org
Todd, I can reproduce on my samus. multiprofile (goog, chromium, gmail). 4 minute time bomb.

feedback report from my original filing: https://listnr.corp.google.com/report/85260603160

I don't see 'hwrng' in there, but I don't know how to use trace. Maybe I didn't select the right option.


Components: OS>Kernel>Power
Summary: Speed: Eve, Samus: after 4min of browsing, main browser thread takes ~150% cpu until browser is restarted (was: Speed: Eve: after 4min of browsing, main browser thread takes ~150% cpu until browser is restarted)
Your trace metadata looks the same as mine from a quick scan so hopefully that means they're the same ... but I'm new to chrome tracing as well.

Absence of hwrng may be because samus lacks same implementation as eve (hw backed via cr50 I believe).

Owner: apronin@chromium.org
Cc: puneetster@chromium.org
Labels: M-67 Pri-1
Tried moving to Dev (10539.0.0) to see if it may have been addressed somewhere already but still seeing the repro unfortunately.

Also tried disable arc++ but that is now blocked by administrator.
Tried flushing everything cached in chrome ... didn't fix.
Tried deleting all but my corp account ... didn't fix.
Tried powerwashing in the explicit sense (ctrl+alt+shift+r) but that didn't work nor could I locate from settings anymore.  Reference:https://support.google.com/chromebook/answer/183084?hl=en 

Tried just deleting my corp account and that DID work and presumably is now equivalent to a powerwash.
In the trace I see a chrome thread also running (probably the browser thread) but I don't see any more info about the browser process in that trace -- could we take another trace with more options enabled if it's easy to reproduce this? 
Sonny and I just took a trace. The following pegged at the end of the trace:

src_file	
"../../../../../../../home/chrome-bot/chrome_root/src/components/drive/chromeos/change_list_loader.cc"
src_func	
"LoadChangeListFromServerAfterLoadChangeList"

Attached is the trace.
trace_cpu-pegged-trace.json.gz
5.8 MB Download
Cc: hashimoto@chromium.org sonnyrao@chromium.org satorux@chromium.org kinaba@chromium.org
We also noticed that the files app was hung at this point -- can someone from the drive component comment on what that function is doing?  I added a couple random people who touched that function to CC :-)


Cc: slangley@chromium.org sashab@chromium.org
Components: Platform>Apps>FileManager
One of the possible hypothesis is that the account was having large number of updates from Drive (e.g. when not booting the device for long) and needed to download them to the device.
During the "4 minutes" it would have been fetching data from server, then would have started to apply it after it with high CPU load.
When the browser gets restarted before finishing the both procedure, it redoes them from the beginning.

If this is the case, pinning and reopening tabs will not affect the result.

I could not see supporting data in the trace by #0, but in the case of #10, there are a series of data fetch from Drive server (drive.google.com/drive/v2/changes). The task in question is invoked after that, looks WAI.

It'd be helpful to see how the device works with other google accounts.


We can verify it by the steps below:
======
1. Restart browser.
2. Open chrome://drive-internals
3. Observe "Event Logs".
 << Expected >> "TYPE_GET_REMAINING_CHANGE_LIST" or "TYPE_GET_REMAINING_FILE_LIST" continuously added to there.
> 2018-04-11T12:24:00.043: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [254] => HTTP_SUCCESS (elapsed time: 1899ms) - METADATA_QUEUE pending: 0, running: 0
> 2018-04-11T12:24:00.043: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [255] - METADATA_QUEUE pending: 1, running: 0

4. After the "4 minutes", the log would say like:
> 2018-04-11T12:41:54.353: [info] Apply change lists (is delta: **)
> 2018-04-11T12:42:23.022: [info] Change lists applied (elapsed time: *****ms)
 Read the elapsed time.
 This would be the timing when the CPU load goes up and then down.
 (Note that this can also be seen during normal operation, like applying small change after the big loading. So find the ones right next to the large list by step 3.)

5. Open chrome://histograms and find Drive.FullFeedLoadTime.
 (This may not be found other than after clearing local data. If not found, skip this.)
======

FYI, LoadChangeListFromServerAfterLoadChangeList is a function that invokes a task to apply file updates fetched from Drive server. So I guess the box indicates the invoked task by that, rather than the function itself.

Cc: yamaguchi@chromium.org
If it's the first boot after login, your Chromebook may be extremely busy fetching data of your account (Googlers tend to have much more synced data and push-installed extensions than an average user).

As yamaguchi@ said, Drive code fetching metadata of files you uploaded and files your coworkers have shared with you might be contributing to this problem, but it shouldn't result in blocking the browser thread as the data is processed on a worker thread.

Probably it may be helpful to try uninstalling some extensions from chrome://extensions, or disabling some sync features from chrome://settings
At least in my case ... the failure persisted across many days of successful active use so in terms of pulling gdrive updates I'd expect they would have completed or were some how blocked from completing successfully.

FWIW, had a look at chrome://drive-internal -> event log and it looks very well behaved on my system.

Unfortunately since powerwash I've not seen failure again.  Hopefully Aaron's device can still repro.


Owner: satorux@chromium.org
I'm clearly not the right owner for this bug, which went into discussing Files / Drive performance-related internals.

satorux@, could you please help select the owner? Assigning to you for now.

Comment 18 by derat@chromium.org, Apr 11 2018

Components: -OS>Kernel>Power
Owner: yamaguchi@chromium.org
Status: Assigned (was: Unconfirmed)
It looks like Yamaguchi-san has been investigating, so would seem the right owner for now.
Owner: ----
Status: Available (was: Assigned)
According to comment #16, the issue is not likely to have something to do with the Files app, because the possible cause which I suspected in comment #13 was denied by that.

Re: #10, the long runtime of a task invoked from LoadChangeListFromServerAfterLoadChangeList, was verified to have happened after initial loading of Drive files. However, that task taking more than 10 seconds or 1 minute is usual. The log is truncated while it is running. Therefore we cannot consider it as a abnormal run pattern by that record alone.

By these reasons I think we don't have enough clue to consider Files app to be the cause. We will need more reliable repro steps and breakdown of the issue.

Since it's indicated to be dependent on a specific account, I'd also recommend turning off some extensions or disabling sync feature, as hashimoto@ suggested in #15.
Owner: satorux@chromium.org
Status: Untriaged (was: Available)
Pulling out of the "available" black hole.
Owner: ----
Owner: weifangsun@chromium.org
Status: Assigned (was: Untriaged)
Checked in with abodenha@ on this one. Latest status:

- There are few other related investigations going on. Will monitor to see if we can get consistent repo and if Files is contributing to the issue.
- Latest feedback on Eve is that while performance issues are reported, it's not broadly effecting users.

Assigning to myself as we monitor the progress on this investigation.
Status: WontFix (was: Assigned)
I haven't seen any further updates on this still being an issue so closing for now as M67 is now on Stable. Please re-open if investigations are still needed.

Sign in to add a comment