Speed: Eve, Samus: after 4min of browsing, main browser thread takes ~150% cpu until browser is restarted |
|||||||||||||||||
Issue descriptionRepro: 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.
,
Mar 30 2018
Transitioning to suspend and back (lid close / open ) is also a workaround but needs to be performed every 4min as well.
,
Apr 2 2018
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.
,
Apr 2 2018
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).
,
Apr 2 2018
,
Apr 2 2018
,
Apr 4 2018
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.
,
Apr 4 2018
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.
,
Apr 5 2018
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?
,
Apr 5 2018
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.
,
Apr 5 2018
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 :-)
,
Apr 11 2018
,
Apr 11 2018
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.
,
Apr 11 2018
,
Apr 11 2018
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
,
Apr 11 2018
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.
,
Apr 11 2018
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.
,
Apr 11 2018
,
Apr 11 2018
It looks like Yamaguchi-san has been investigating, so would seem the right owner for now.
,
Apr 17 2018
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.
,
Apr 25 2018
Pulling out of the "available" black hole.
,
Apr 25 2018
,
Apr 26 2018
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.
,
Jun 21 2018
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 |
|||||||||||||||||
Comment 1 by tbroch@chromium.org
, Mar 30 2018