Closed Bug 1912660 Opened 2 years ago Closed 1 year ago

misskey.io - parent process hangs for seconds when newly opening or accessing the tab

Categories

(Core :: Graphics: Text, defect)

defect

Tracking

()

RESOLVED WORKSFORME
Performance Impact medium
Webcompat Priority P3
Webcompat Score 1

People

(Reporter: saschanaz, Unassigned)

References

()

Details

(Keywords: webcompat:platform-bug, webcompat:site-report)

User Story

webcompat:blocked-resources

​​### Basic information

Steps to Reproduce: On an affected profile, open https://misskey.io. Note that a new profile is not affected.

Expected Results: Instant load.

Actual Results: Parent process stalls for a few seconds.


Performance recording (profile)

Profile URL: From reporters - https://share.firefox.dev/3SyPCAg https://share.firefox.dev/4fwCPrV

System configuration:

OS version: Windows 11
GPU model: Intel Iris Plus (Intel Core i7-1065G7)
Number of cores: 4 (8 threads)
Amount of memory (RAM): 16

More information

(I'll find some time to have a new-ish profile with copied data so that I won't leak everything on about:support)

Content process: 2s worth of jank doing something with fontbuilder in dwrite.dll . ni? from :jfk
Parent process: some busyness doing network-y stuff. cc mstange, kershaw,

Flags: needinfo?(jfkthame)

Yeah I think the actual parent process busyness wasn't captured in the profile and is probably on the WrWorker threads - those would be captured with the Graphics profiling preset. The markers on the Compositor thread show that one of the paints took 5.4 seconds. There's also the 1.1 second synchronous IPC on the parent process main thread, which is strangely not marked as jank.

It would be very useful to find out what's different about the affected profile that causes DWrite to do this extra work. Can you try some of the prefs that are mentioned under "Important modified preferences" on about:support?

Flags: needinfo?(krosylight)

Okay, just backed up the profile and it seems it also reproduces on my threadripper machine too with the profile. The Important Modified Preferences section doesn't show anything interesting for dwrite...

The diffs with affected and unaffected profiles:

--- pref-unaffected.txt 2024-08-19 15:06:46.369887800 +0200
+++ pref-affected.txt   2024-08-19 15:27:21.377751200 +0200
@@ -1,17 +1,24 @@
 Important Modified Preferences
 ------------------------------

+accessibility.typeaheadfind.enablesound: false
 accessibility.typeaheadfind.flashBar: 0
+apz.touch_start_tolerance: 0.2
 browser.contentblocking.category: standard
+browser.download.always_ask_before_handling_new_types: true
+browser.download.start_downloads_in_tmp_dir: true
 browser.search.region: DE
-browser.sessionstore.upgradeBackup.latestBuildID: 20240818094039
-browser.startup.homepage_override.buildID: 20240819094101
-browser.startup.homepage_override.mstone: 131.0a1
+browser.sessionstore.resume_from_crash: false
+browser.sessionstore.upgradeBackup.latestBuildID: 20240819094101
+browser.startup.homepage_override.buildID: 20220325214737
+browser.startup.homepage_override.mstone: ignore
 browser.startup.page: 3
+browser.tabs.firefox-view.ui-state.opentabs.open: true
+browser.tabs.firefox-view.ui-state.recently-closed-tabs.open: true
+browser.tabs.firefox-view.ui-state.recentlyclosed.open: true
+browser.tabs.firefox-view.ui-state.syncedtabs.open: true
+browser.tabs.firefox-view.ui-state.tab-pickup.open: true
+browser.tabs.warnOnClose: false
 browser.urlbar.fakespot.featureGate: true
+browser.urlbar.keepPanelOpenDuringImeComposition: true
 browser.urlbar.maxRichResults: 12
-browser.urlbar.placeholderName: Google
-browser.urlbar.placeholderName.private: Google
 browser.urlbar.quicksuggest.dataCollection.enabled: true
 browser.urlbar.quicksuggest.enabled: true
 browser.urlbar.quicksuggest.migrationVersion: 2
@@ -19,42 +26,56 @@
 browser.urlbar.quicksuggest.onboardingDialogVersion: {"version":1}
 browser.urlbar.quicksuggest.scenario: history
 browser.urlbar.quicksuggest.showedOnboardingDialog: true
+browser.urlbar.recentsearches.lastDefaultChanged: 1713209314230
+browser.urlbar.resultGroups: {"children":[{"maxResultCount":1,"children":[{"group":"heuristicTest"},{"group":"heuristicExtension"},{"group":"heuristi
+browser.urlbar.suggest.calculator: true
 browser.urlbar.suggest.quicksuggest.sponsored: true
+browser.urlbar.tabToSearch.onboard.interactionsLeft: 0
 browser.urlbar.tipShownCount.searchTip_onboard: 4
+browser.urlbar.tipShownCount.searchTip_persist: 4
+browser.urlbar.tipShownCount.searchTip_redirect: 4
+doh-rollout.balrog-migration-done: true
 doh-rollout.disable-heuristics: true
 doh-rollout.doneFirstRun: true
 doh-rollout.home-region: DE
 dom.forms.autocomplete.formautofill: true
 dom.security.https_only_mode: true
 dom.security.https_only_mode_ever_enabled: true
+extensions.formautofill.creditCards.used: 3
 extensions.lastAppVersion: 131.0a1
+gfx.crash-guard.status.wmfvpxvideo: 2
+gfx.crash-guard.wmfvpxvideo.appVersion: 97.0a1
+gfx.crash-guard.wmfvpxvideo.deviceID: 0x8a52
+gfx.crash-guard.wmfvpxvideo.driverVersion: 27.20.100.9621
 gfx.downloadable_fonts.otl_validation: false
-idle.lastDailyNotification: 1723965369
+idle.lastDailyNotification: 1724009917
 image.jxl.enabled: true
+javascript.options.wasm_simd_wormhole: true
 media.autoplay.default: 5
-media.gmp-gmpopenh264.abi: aarch64-msvc-aarch64
-media.gmp-gmpopenh264.hashValue: (...)
-media.gmp-gmpopenh264.lastDownload: 1723207372
-media.gmp-gmpopenh264.lastInstallStart: 1723207372
-media.gmp-gmpopenh264.lastUpdate: 1723207372
+media.gmp-gmpopenh264.abi: x86_64-msvc-x64
+media.gmp-gmpopenh264.hashValue: (...)
+media.gmp-gmpopenh264.lastDownload: 1711098925
+media.gmp-gmpopenh264.lastDownloadFailed: 1698159808
+media.gmp-gmpopenh264.lastDownloadFailReason: Error: Failed downloading via ServiceRequest, status: 0, channelStatus: 2152398878, errorCode: 2, reason: error
+media.gmp-gmpopenh264.lastInstallStart: 1711098924
+media.gmp-gmpopenh264.lastUpdate: 1711098925
 media.gmp-gmpopenh264.version: 2.3.2
-media.gmp-manager.buildID: 20240818094039
-media.gmp-manager.lastCheck: 1723985262
-media.gmp-manager.lastEmptyCheck: 1723985262
-media.gmp-widevinecdm.abi: aarch64-msvc-aarch64,x86-msvc-x86
-media.gmp-widevinecdm.hashValue: (...)
-media.gmp-widevinecdm.lastDownload: 1723207375
-media.gmp-widevinecdm.lastInstallStart: 1723207372
-media.gmp-widevinecdm.lastUpdate: 1723207375
+media.gmp-manager.buildID: 20240818204048
+media.gmp-manager.lastCheck: 1724071774
+media.gmp-manager.lastEmptyCheck: 1724071774
+media.gmp-widevinecdm.abi: x86_64-msvc-x64
+media.gmp-widevinecdm.hashValue: (...)
+media.gmp-widevinecdm.lastDownload: 1696886201
+media.gmp-widevinecdm.lastInstallStart: 1696886199
+media.gmp-widevinecdm.lastUpdate: 1696886201
 media.gmp-widevinecdm.version: 4.10.2710.0
 media.gmp.storage.version.observed: 1
 media.hardware-video-decoding.failed: false
-media.videocontrols.picture-in-picture.enable-when-switching-tabs.enabled: true
-media.videocontrols.picture-in-picture.video-toggle.first-seen-secs: 1723229570
 media.videocontrols.picture-in-picture.video-toggle.has-used: true
+network.trr.blocklist_cleanup_done: true
 network.trr.mode: 2
 network.trr.uri: https://mozilla.cloudflare-dns.com/dns-query
-places.database.lastMaintenance: 1723878970
+places.database.lastMaintenance: 1724009926
 privacy.bounceTrackingProtection.hasMigratedUserActivationData: true
 privacy.clearOnShutdown_v2.cache: false
 privacy.clearOnShutdown_v2.cookiesAndStorage: false
@@ -67,25 +88,36 @@
 privacy.clearOnShutdown.sessions: false
 privacy.globalprivacycontrol.enabled: true
 privacy.globalprivacycontrol.was_ever_enabled: true
+privacy.history.custom: true
 privacy.purge_trackers.date_in_cookie_database: 0
-privacy.purge_trackers.last_purge: 1723965370325
+privacy.purge_trackers.last_purge: 1724009919405
 privacy.sanitize.clearOnShutdown.hasMigratedToNewPrefs2: true
 privacy.sanitize.pending: [{"id":"newtab-container","itemsToClear":[],"options":{}}]
-privacy.userContext.enabled: false
-security.osreauthenticator.password_last_changed_hi: 802439
-security.osreauthenticator.password_last_changed_lo: 1178064896
+privacy.sanitize.sanitizeOnShutdown.hasMigratedToNewPrefs: true
+privacy.userContext.extension: @contain-facebook
+security.oskeystore.test.encrypted: (...)
+security.oskeystore.test.label: (...)
+security.osreauthenticator.password_last_changed_hi: (...)
+security.osreauthenticator.password_last_changed_lo: (...)
+security.remote_settings.crlite_filters.checked: (...)
+security.remote_settings.intermediates.checked: (...)
+security.sandbox.content.tempDirSuffix: (...)
+security.sandbox.content.win32k-experiment.enrollmentStatus: 3
+security.sandbox.content.win32k-experiment.startupEnrollmentStatus: 3
 security.webauthn.show_ms_settings_link: true
 services.sync.declinedEngines:
 services.sync.engine.addresses: true
 services.sync.engine.addresses.available: true
-services.sync.engine.bookmarks.validation.lastTime: 1724055430
+services.sync.engine.bookmarks.validation.lastTime: 1724007885
 services.sync.engine.creditcards: true
-services.sync.engine.passwords.validation.lastTime: 1724055430
+services.sync.engine.passwords.validation.lastTime: 1724007885
 services.sync.engine.prefs.modified: false
-services.sync.lastPing: 1724055423
-services.sync.lastSync: Mon Aug 19 2024 14:58:08 GMT+0200 (Central European Summer Time)
-signon.suggestImportCount: 2
-storage.vacuum.last.content-prefs.sqlite: 1723298829
+services.sync.lastPing: 1724007826
+services.sync.lastSync: Mon Aug 19 2024 15:26:51 GMT+0200 (Central European Summer Time)
+signon.firefoxRelay.feature: enabled
+signon.management.page.sort: last-used
+signon.suggestImportCount: 0
+storage.vacuum.last.content-prefs.sqlite: 1721684542
 storage.vacuum.last.index: 2
-storage.vacuum.last.places.sqlite: 1723209256
-ui.osk.debug.keyboardDisplayReason: IKPOS: Keyboard presence confirmed.
+storage.vacuum.last.places.sqlite: 1722982489
+ui.osk.debug.keyboardDisplayReason: IKPOS: Touch screen not found.
Flags: needinfo?(krosylight)

I purged prefs.js and doing so certainly fixes it, and restoring it restore the issue too. One interesting thing is that the profile had 6 prefs.js (prefs.js, prefs-1.js, ...). I'll try bisecting.

I found the not-real-culprit: gfx.downloadable_fonts.otl_validation=false, which is true on nightly and false on stable Firefox. And with the validation on, Firefox just rejects the "tabler-icons" font that Misskey uses. This has been known for a while. 1 2

And with the validation pref off, it seems the real culprit is that the tabler-icons font is somehow expensive to render on Firefox? Keeping the NI to jfkthame for that bit.

A new profile: https://share.firefox.dev/4cy7pPe

I can see multiple parent process janks caused by hovering over the tab multiple times with browser.tabs.hoverPreview.enabled=true.

(In reply to Kagami Rosylight [:saschanaz] (they/them) from comment #6)

I found the not-real-culprit: gfx.downloadable_fonts.otl_validation=false, which is true on nightly and false on stable Firefox. And with the validation on, Firefox just rejects the "tabler-icons" font that Misskey uses. This has been known for a while. 1 2

And with the validation pref off, it seems the real culprit is that the tabler-icons font is somehow expensive to render on Firefox? Keeping the NI to jfkthame for that bit.

With graphics preset logging : https://share.firefox.dev/46RpPcA

Duplicate of this bug: 1912650
Performance Impact: --- → ?
Component: Performance → Graphics: Text
Severity: -- → S3

The Performance Impact Calculator has determined this bug's performance impact to be medium. If you'd like to request re-triage, you can reset the Performance Impact flag to "?" or needinfo the triage sheriff.

Platforms: Windows
Impact on browser: Causes noticeable jank
[x] Able to reproduce locally

Performance Impact: ? → medium

Revisiting this... the profile from comment #8 is a bit more interesting than mine, as it shows PresShell::Reflow is called 583 times within 1150 ms, all just to call gfxDWriteFontEntry::CreateFontFace 583 times too in that range, if I understand the profiler right. Perhaps this is actually a layout problem causing excessive reflow? Maybe Emilio can have some more thoughts.

Flags: needinfo?(emilio)

Isn't that likely a single CreateFontFace call that's taking a long time to return (because DirectWrite is internally being really slow to initialize a font), rather than 500-plus separate calls? It's a longstanding issue that sometimes an "innocent-looking" call into dwrite.dll may block for a long time, apparently while it rebuilds internal caches or something.

Given comment 6, my suspicion is that DirectWrite takes a long time to initialize the "tabler-icons" font when we initially instantiate it.

Flags: needinfo?(jfkthame)

Yes I was going to mention the same... 583 is the number of samples, not number of calls. It seems dwrite.dll is just being really slow.

Flags: needinfo?(emilio)

It's a longstanding issue that sometimes an "innocent-looking" call into dwrite.dll may block for a long time

Do we have a tracking issue for that?

(Does Chrome have a different backend than dwrite btw? I wonder why Chrome doesn't have the same issue.)

First load: https://share.firefox.dev/3UtvVuW
Refresh the page: https://share.firefox.dev/3YE84Lg
Force refresh: https://share.firefox.dev/3YGwwvu

In the refresh profiles, atleast the sync ipc in parent is gone. Also curious, this IPC on the DOM worker is labelled as "sync = false", but in the parent-process it is labelled as "sync IPC".

(In reply to Kagami Rosylight [:saschanaz] (they/them) from comment #15)

(Does Chrome have a different backend than dwrite btw? I wonder why Chrome doesn't have the same issue.)

They might be using their bundled FreeType to load/render the font in question; I'm not sure what their criteria are for choosing between font backends.

Jonathan, is this bug actionable at all?

Flags: needinfo?(jfkthame)
User Story: (updated)
Webcompat Priority: --- → P3
Webcompat Score: --- → 2
Webcompat Score: 2 → 1
User Story: (updated)

This is solved by tabler-icons https://github.com/tabler/tabler-icons/pull/1312 and then by Misskey https://github.com/misskey-dev/misskey/pull/15608. Somebody might still want to investigate given this was Firefox-only problem but not a real-world webcompat issue anymore.

Status: NEW → RESOLVED
Closed: 1 year ago
Flags: needinfo?(jfkthame)
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.