1344920 - Second-long pauses between tab switches for /u/djbluntmagic on Reddit

Status: RESOLVED INCOMPLETE

(Core :: DOM: Content Processes, defect)

Description

[Mike Conley (:mconley) (:⚙️)]

I've been communicating with a user over Reddit for the past few weeks about a tab switch performance problem they've been experiencing for quite a while now.

They've been very patient as I've done various diagnostics and requested various information.

The information I've accumulated has become unwieldy enough in the Reddit messaging system that I feel it'd be best if I just dump it into a bug. So here's that bug.

Comment 1

[Mike Conley (:mconley) (:⚙️)]

This is the about:support they'd given me from the start. They've since updated to 51, with no significant improvement.

Application Basics

Name: Firefox Version: 50.1.0
Build ID: 20161208153507
Update Channel: release
User Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:50.0) Gecko/20100101 Firefox/50.0 OS: Windows_NT 10.0
Multiprocess Windows: 1/1 (Enabled by default)
Safe Mode: false

Crash Reports for the Last 3 Days

All Crash Reports (including 5 pending crashes in the given time range)

Extensions
Name: Adblock Plus Version: 2.8.2 Enabled: true ID: {d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d}
Name: Application Update Service Helper Version: 1.0 Enabled: true ID: [e-mail]
Name: ChatZilla Version: 0.9.93 Enabled: true ID: {59c81df5-4b7a-477b-912d-4e0fdf64e5f2}
Name: Multi-process staged rollout Version: 1.5 Enabled: true ID: [e-mail]
Name: Pocket Version: 1.0.5 Enabled: true ID: [e-mail]
Name: Web Compat Version: 1.0 Enabled: true ID: [e-mail]

Graphics
Features
Compositing: Direct3D 11
Asynchronous Pan/Zoom: wheel input enabled
WebGL Renderer: Google Inc. -- ANGLE (Intel(R) HD Graphics 530 Direct3D11 vs_5_0 ps_5_0)
WebGL2 Renderer: (no info)
Hardware H264 Decoding: Yes; Using D3D11 API Audio
Backend: wasapi
Direct2D: true
DirectWrite: true (10.0.14393.351)
GPU #1 Active: Yes
Description: Intel(R) HD Graphics 530
Vendor ID: 0x8086
Device ID: 0x191b
Driver Version: 21.20.16.4471
Driver Date: 6-6-2016
Drivers: igdumdim64 igd10iumd64 igd10iumd64 igd12umd64 igdumdim32 igd10iumd32 igd10iumd32 igd12umd32
Subsys ID: 00000000
RAM: Unknown

Diagnostics
AzureCanvasAccelerated: 0
AzureCanvasBackend: direct2d 1.1
AzureContentBackend: direct2d 1.1
AzureFallbackCanvasBackend: cairo
Decision Log
D3D9_COMPOSITING: disabled by default: Disabled by default

Important Modified Preferences

accessibility.typeaheadfind.flashBar: 0
browser.cache.disk.capacity: 358400
browser.cache.disk.filesystem_reported: 1
browser.cache.disk.hashstats_reported: 1
browser.cache.disk.smart_size_cached_value: 358400
browser.cache.disk.smart_size.first_run: false
browser.cache.disk.smart_size.use_old_max: false
browser.cache.frecency_experiment: 3
browser.download.importedFromSqlite: true
browser.download.manager.alertOnEXEOpen: true
browser.fixup.domainwhitelist.face: true
browser.places.smartBookmarksVersion: 8
browser.search.useDBForOrder: true
browser.sessionstore.upgradeBackup.latestBuildID: 20161208153507
browser.startup.homepage: https://en.wikipedia.org/wiki/Main_Page
browser.startup.homepage_override.buildID: 20161208153507
browser.startup.homepage_override.mstone: 50.1.0
browser.tabs.remote.autostart.2: true
browser.urlbar.userMadeSearchSuggestionsChoice: true
dom.apps.lastUpdate.buildID: 20161019084923
dom.apps.lastUpdate.mstone: 49.0.2
dom.apps.reset-permissions: true
dom.mozApps.used: true
extensions.lastAppVersion: 50.1.0
font.internaluseonly.changed: true
gfx.crash-guard.d3d11layers.appVersion: 50.1.0
gfx.crash-guard.d3d11layers.deviceID: 0x191b
gfx.crash-guard.d3d11layers.driverVersion: 21.20.16.4471
gfx.crash-guard.d3d11layers.feature-d2d: true
gfx.crash-guard.d3d11layers.feature-d3d11: true
gfx.crash-guard.glcontext.gfx.driver-init.direct3d11-angle: true
gfx.crash-guard.glcontext.gfx.driver-init.webgl-angle: true
gfx.crash-guard.glcontext.gfx.driver-init.webgl-angle-force-d3d11: false
gfx.crash-guard.glcontext.gfx.driver-init.webgl-angle-force-warp: false
gfx.crash-guard.glcontext.gfx.driver-init.webgl-angle-try-d3d11: true
gfx.crash-guard.status.: 2
gfx.crash-guard.status.d3d11layers: 2
gfx.crash-guard.status.d3d11video: 2
gfx.crash-guard.status.d3d9video: 2
gfx.crash-guard.status.glcontext: 2
gfx.direct3d.last_used_feature_level_idx: 0
gfx.driver-init.appVersion: 42.0
gfx.driver-init.deviceID: 0x0116
gfx.driver-init.driverVersion: 8.15.10.2476
gfx.driver-init.feature-d2d: true
gfx.driver-init.feature-d3d11: true
gfx.driver-init.status: 2
keyword.URL: true
media.benchmark.vp9.fps: 95
media.benchmark.vp9.versioncheck: 1
media.gmp-eme-adobe.abi: x86-msvc-x64
media.gmp-eme-adobe.lastUpdate: 1472237030
media.gmp-eme-adobe.version: 17
media.gmp-gmpopenh264.abi: x86-msvc-x64
media.gmp-gmpopenh264.lastUpdate: 1472237031
media.gmp-gmpopenh264.version: 1.6
media.gmp-manager.buildID: 20161208153507
media.gmp-manager.lastCheck: 1481996178
media.gmp-widevinecdm.abi: x86-msvc-x64
media.gmp-widevinecdm.lastUpdate: 1474574541
media.gmp-widevinecdm.version: 1.4.8.903
media.gmp.storage.version.observed: 1
media.hardware-video-decoding.failed: false
media.webrtc.debug.aec_log_dir: C:\Users\user\AppData\Local\Temp
media.webrtc.debug.log_file: C:\Users\user\AppData\Local\Temp\WebRTC.log
network.cookie.prefsMigrated: true
network.predictor.cleaned-up: true
places.database.lastMaintenance: 1481531891
places.history.expiration.transient_current_max_pages: 121928
plugin.disable_full_page_plugin_for_types: application/pdf
plugin.importedState: true
print.printer_Microsoft_XPS_Document_Writer.print_bgcolor: false
print.printer_Microsoft_XPS_Document_Writer.print_bgimages: false
print.printer_Microsoft_XPS_Document_Writer.print_colorspace:
print.printer_Microsoft_XPS_Document_Writer.print_command:
print.printer_Microsoft_XPS_Document_Writer.print_downloadfonts: false
print.printer_Microsoft_XPS_Document_Writer.print_duplex: 638043948
print.printer_Microsoft_XPS_Document_Writer.print_edge_bottom: 0
print.printer_Microsoft_XPS_Document_Writer.print_edge_left: 0
print.printer_Microsoft_XPS_Document_Writer.print_edge_right: 0
print.printer_Microsoft_XPS_Document_Writer.print_edge_top: 0
print.printer_Microsoft_XPS_Document_Writer.print_evenpages: true
print.printer_Microsoft_XPS_Document_Writer.print_footercenter:
print.printer_Microsoft_XPS_Document_Writer.print_footerleft: &PT
print.printer_Microsoft_XPS_Document_Writer.print_footerright: &D
print.printer_Microsoft_XPS_Document_Writer.print_headercenter:
print.printer_Microsoft_XPS_Document_Writer.print_headerleft: &T
print.printer_Microsoft_XPS_Document_Writer.print_headerright: &U
print.printer_Microsoft_XPS_Document_Writer.print_in_color: true
print.printer_Microsoft_XPS_Document_Writer.print_margin_bottom: 0.5
print.printer_Microsoft_XPS_Document_Writer.print_margin_left: 0.5
print.printer_Microsoft_XPS_Document_Writer.print_margin_right: 0.5
print.printer_Microsoft_XPS_Document_Writer.print_margin_top: 0.5
print.printer_Microsoft_XPS_Document_Writer.print_oddpages: true
print.printer_Microsoft_XPS_Document_Writer.print_orientation: 0
print.printer_Microsoft_XPS_Document_Writer.print_page_delay: 50
print.printer_Microsoft_XPS_Document_Writer.print_paper_data: -1
print.printer_Microsoft_XPS_Document_Writer.print_paper_height: 11.00
print.printer_Microsoft_XPS_Document_Writer.print_paper_name:
print.printer_Microsoft_XPS_Document_Writer.print_paper_size_type: 0
print.printer_Microsoft_XPS_Document_Writer.print_paper_size_unit: 0
print.printer_Microsoft_XPS_Document_Writer.print_paper_width: 8.50
print.printer_Microsoft_XPS_Document_Writer.print_plex_name:
print.printer_Microsoft_XPS_Document_Writer.print_resolution: 600
print.printer_Microsoft_XPS_Document_Writer.print_resolution_name:
print.printer_Microsoft_XPS_Document_Writer.print_reversed: false
print.printer_Microsoft_XPS_Document_Writer.print_scaling: 1.00
print.printer_Microsoft_XPS_Document_Writer.print_shrink_to_fit: true
print.printer_Microsoft_XPS_Document_Writer.print_to_file: false
print.printer_Microsoft_XPS_Document_Writer.print_unwriteable_margin_bottom: 0 print.printer_Microsoft_XPS_Document_Writer.print_unwriteable_margin_left: 0 print.printer_Microsoft_XPS_Document_Writer.print_unwriteable_margin_right: 0 print.printer_Microsoft_XPS_Document_Writer.print_unwriteable_margin_top: 0
privacy.cpd.offlineApps: true
privacy.cpd.siteSettings: true
privacy.donottrackheader.enabled: true
privacy.sanitize.migrateClearSavedPwdsOnExit: true
privacy.sanitize.migrateFx3Prefs: true
privacy.sanitize.timeSpan: 0
security.sandbox.content.tempDirSuffix: {a14fb9dc-7c96-40fa-9556-d4b5178455de}
security.ssl.errorReporting.automatic: true
services.sync.declinedEngines:
storage.vacuum.last.index: 1
storage.vacuum.last.places.sqlite: 1480178679
ui.osk.debug.keyboardDisplayReason: IKPOS: Touch screen not found.

user.js Preferences

Your profile folder contains a user.js file, which includes preferences that were not created by Firefox.

Important Locked Preferences

Places Database

JavaScript

Incremental GC: true

Accessibility
Activated: false
Prevent Accessibility: 0


Library Versions
NSPR Expected minimum version: 4.12 Version in use: 4.12
NSS Expected minimum version: 3.26.2 Version in use: 3.26.2
NSSSMIME Expected minimum version: 3.26.2 Version in use: 3.26.2
NSSSSL Expected minimum version: 3.26.2 Version in use: 3.26.2
NSSUTIL Expected minimum version: 3.26.2 Version in use: 3.26.2

Experimental Features

Sandbox

Content Process Sandbox Level: 1

Comment 2

[Mike Conley (:mconley) (:⚙️)]

A screen recording of what the user is experiencing: https://www.youtube.com/watch?v=8oUzPPrMSIk

Comment 3

[Mike Conley (:mconley) (:⚙️)]

Note that the Spotify tab is not required in order to reproduce this behaviour: https://www.youtube.com/watch?v=mOYSuGwoGGU&feature=youtu.be

Comment 4

[Mike Conley (:mconley) (:⚙️)]

This user has a pretty decent network connection. A run at speedtest.net gave:

21ms ping, 52.35 Mbps down, 1.22 Mbps up

Disabling hardware acceleration did not help the user.

Comment 5

[Mike Conley (:mconley) (:⚙️)]

I don't see in our conversation thread a time where I asked the user to reproduce in safe mode, so I've asked them to do that.

Comment 6

[Mike Conley (:mconley) (:⚙️)]

Safe mode did not address this user's problem.

The user is running MBAM[1].

Hey RaresM: do you have any Windows 7+ machines in your testing lab with BitLocker encryption enabled? I'm curious to know what (if any) impact BitLocker disk encryption has on e10s tab switching performance. Would someone from SV be willing to investigate that scenario?

See comment 2 and comment 3 for the behaviour we're attempting to reproduce.

[1]: Microsoft BitLocker Administration and Monitoring. See https://technet.microsoft.com/en-us/windows/hh826072.aspx

Comment 7

[Ciprian Muresan [:cmuresan], Ecosystem QA]

about:support screen shot: https://pageshot.net/KmYCiNfPl8zdUFXK/about

From what I've seen in the two videos, this is what I believe the user is doing (I say I believe, because the videos don't show any information about the number of tabs or what's happening to them):
1. Have a session with a lot of tabs (30-50)
2. Open the browser and hold CTRL+TAB to go through all the tabs
3. While the tabs are loading:
	- switch through them and observe the behavior
	- open new tabs, search for keywords and observe the behavior
	
I've used the above steps to try and reproduce the issue and I've encountered different behaviors on Firefox 50 and 53:
- On Firefox 53 (the latest release), after going through all the tabs I only see white pages and no spinners. CPU usage is at about 90%. After about half of them are loaded, switching through tabs shows a white page for about 1-2 seconds and then the content is painted. After all tabs are loaded, content is shown immediately when tab switching. Screen recording https://goo.gl/J140Fh.
- On Firefox 50 (the reported version), after going through all the tabs I see spinners on all pages, for a long time. CPU usage is just as above, at about 90%. After half of them are loaded, switching through tabs shows the spinner for 3-4 seconds and if I'm lucky content starts to be painted. After all tabs are loaded, visiting other tabs show spinners for about 1-2 seconds. Screen recording https://goo.gl/hP5q2N. 

While doing the steps above I've also had Spotify playing in background and I haven't observed any stuttering or hiccups in playback.

I'm not entirely sure this is what the user is doing but based on the video in comment 2 (t=20s) you can see that a lot of URLs are displayed in a very quick succession. 
Mike, could you ask the reporter to verify/confirm this scenario before we investigate further?

P.S. Mike, the laptop we have with BitLocker is a loaner laptop and we have to return it in about a week. Obtaining more details about this as fast as possible would be appreciated.

Comment 8

[Mike Conley (:mconley) (:⚙️)]

(In reply to Ciprian Muresan [:cmuresan] from comment #7)

Hey cmuresan,

Thanks for your work on this. I've been having off and on communication with the user, and the scenario you're describing sounds extremely similar. At any rate, we should understand what you're seeing, even if it's not the same bug. Would you be willing to capture a profile using the Gecko Profiler add-on[1]? Let me know if you need guidance doing that[2].

In the meantime, I'll point the user at your bug comment for direct confirmation.

[1]: http://perf-html.io/ and https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Reporting_a_Performance_Problem , if you've not done this before.
[2]: The user originally had some difficulty dumping profiles - I suspect the OS (or BitLocker) may have been blocking them in some way. You might experience similar difficulty, but let's find out.

Comment 9

[Ciprian Muresan [:cmuresan], Ecosystem QA]

Apparently the Gecko Profiler doesn't work on Firefox 50, 51, and 52 x32 or x64 (it works on FF53 because bug 1185106 was fixed). But since the behavior is partially better on 53, do we still want to debug Firefox 50 for this?

If it helps, this is the profile I've taken from Firefox 53 https://perfht.ml/2oZepkm just after I've loaded all the tabs and switched through a few of them.
I've tried to get a profile after all the tabs were loaded and after I left the browser open a while (20 mins), but while switching tabs, one of them crashed. Might be related bp-9b12cb41-1d1c-4ddd-8ecd-572041170420.

I've also took two profiles using the latest Nightly in the same circumstances as above: https://perfht.ml/2p2cYS5 and https://perfht.ml/2pK3vwB.

Let me know If there's anything more I can do.

Comment 10

[Mike Conley (:mconley) (:⚙️)]

Quote from the user on Reddit:

"You can quote me - for some reason I can't access my bugzilla account:

    It's generally closer to 20 tabs
    Ctrl+Pg up and dn - amounts to the same?
    This is what I was doing in the video, just to show the thorough and general nature of the problem. Any browsing activity is likely to produce the response, although quickly opening and comparing tabs is part of my normal browsing activity.

Significant improvements have been made between the build documented in the video (which I do not believe was 50 but rather the most recent nightly build as of the upload date) and the current nightly. The problem is nowhere near so frequent and so total but the current nightly is still far inferior to pre-e10s performance.

Again, Bitlocker was never enabled."


On that last bit, he had said earlier,

"PowerShell says BitLocker is not enabled on this drive" (where this drive is the drive that Firefox is running on).

Comment 11

[Mike Conley (:mconley) (:⚙️)]

cmuresan, can you please provide the about:support from the machine you're testing on?

Comment 12

[Ciprian Muresan [:cmuresan], Ecosystem QA]

Attachment: aboutsupport.txt

Attached a .txt doc with the about:support info.

Comment 13

[Mike Conley (:mconley) (:⚙️)]

(In reply to Ciprian Muresan [:cmuresan], Desktop Engineering QA (on PTO until 2nd of May, please ni? :pauloiegasSV) from comment #12)
> Created attachment 8860415 [details]
> aboutsupport.txt
> 
> Attached a .txt doc with the about:support info.

Thanks! Does the behaviour change if AdBlock Plus is disabled?

Comment 14

[Ciprian Muresan [:cmuresan], Ecosystem QA]

I haven't tested specifically with AdBlock Plus disabled. But after a quick check, the behavior remains unchanged with AdBlock Plus disabled. https://perfht.ml/2p3qfd6

P.S. I'm about to leave the office for today and next week I'll be on PTO. Please redirect all further questions to either :pauloiegasSV or :emilpasca.

Comment 15

[Mike Conley (:mconley) (:⚙️)]

/u/djbluntmagic reports that the 55.0a1 (2017-05-03) (64-bit) build is considerably worse for his problem than the previous build (presumably 2017-05-02).

Comment 16

[Mike Conley (:mconley) (:⚙️)]

/u/djbluntmagic has confirmed that 2017-05-02 was the better build.

Here's the commit range:

https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=48c0fd9c9ec5d68061ea7b59358874ae8da72572&tochange=82c2d17e74ef9cdf38a5d5ac4eb3ae846ec30ba4

Comment 17

[Mike Conley (:mconley) (:⚙️)]

Update: waiting on a new profile from /u/djbluntmagic.

Comment 18

[Mike Conley (:mconley) (:⚙️)]

One thing we've noticed having examined a UIforETW trace is that the user has something called "BOINC" (see https://www.worldcommunitygrid.org) installed and running. I should ask the user to temporarily disable that and see if performance improves.

Comment 19

[Mike Conley (:mconley) (:⚙️)]

I was able to get a profile from this user now:

https://perf-html.io/public/0d4b3022ecadae4dbeab55feb875d8b97708ff95/calltree/?hiddenThreads=&thread=0&threadOrder=0-2-3-4-5-6-1-7

Comment 20

[Mike Conley (:mconley) (:⚙️)]

In the profile in comment 19, /u/djbluntmagic's content processes 1, 2 and 3 seem to be garbage collecting a _lot_. I wonder if this is maybe related to bug 1374797 - especially since those 3 content processes have Facebook loaded.

I've asked the user for:

1) Which version of Firefox they got this profile from
2) Whether or not they can supply an about:memory report when they're in this state