test_ext_webRequest_style_cache.js fails on Android, due to cache miss of SharedStyleSheetCache
Categories
(Core :: CSS Parsing and Computation, defect)
Tracking
()
People
(Reporter: robwu, Unassigned, NeedInfo)
References
Details
Attachments
(3 files)
test_ext_webRequest_style_cache.js fails on Android. I took a closer look, and it looks like the style cache is not hit despite the logs suggesting it to be populated.
When I compare the output of a run on desktop vs Android (see below for instructions), I see that the CSS file is cached as expected at the first load,
[Child 12345: Main Thread]: D/nsCSSLoader SharedStyleSheetCache::InsertIfNeeded
[Child 12345: Main Thread]: D/nsCSSLoader Putting style sheet in shared cache: http://example.com/data/file_stylesheet_cache.css
... but that the cache hit behavior is different at the second load. The following log fragments demonstrate this clearly (the cache hit/miss log originate from this part of the source code of Loader::CreateSheet
).
Good (Desktop):
INFO "Loading second page to check the caching behavior"
[Child 12345: Main Thread]: D/nsCSSLoader css::Loader::LoadSheet(aURL, aObserver) api call
[Child 12345: Main Thread]: D/nsCSSLoader Non-document sheet uri: 'http://example.com/data/file_stylesheet_cache.css'
[Child 12345: Main Thread]: D/nsCSSLoader css::Loader::CreateSheet(http://example.com/data/file_stylesheet_cache.css)
[Child 12345: Main Thread]: D/nsCSSLoader KeyEquals(http://example.com/data/file_stylesheet_cache.css)
[Child 12345: Main Thread]: D/nsCSSLoader Hit cache with state: Complete
Bad (Android):
INFO "Loading second page to check the caching behavior"
[Child 12345: Main Thread]: D/nsCSSLoader css::Loader::LoadSheet(aURL, aObserver) api call
[Child 12345: Main Thread]: D/nsCSSLoader Non-document sheet uri: 'http://example.com/data/file_stylesheet_cache.css'
[Child 12345: Main Thread]: D/nsCSSLoader css::Loader::CreateSheet(http://example.com/data/file_stylesheet_cache.css)
[Child 12345: Main Thread]: D/nsCSSLoader KeyEquals(http://example.com/data/file_stylesheet_cache.css)
[Child 12345: Main Thread]: D/nsCSSLoader Needs parser
("Need parser" means that the cache was missed)
Desktop (for comparison)
- Command:
MOZ_LOG=nsCSSLoader:5,sync ./mach test toolkit/components/extensions/test/xpcshell/test_ext_webRequest_style_cache.js --verbose --log-mach-verbose --tag=remote-webextensions
- Log: see stdout.
Android
- Setup to prepare the build: Create
.mozconfig-android
with the output of./mach bootstrap
(documentation). - Setup of
MOZ_LOG
(generic documentation: GeckoView automation):- Create
org.mozilla.geckoview.test_runner-geckoview-config.yaml
with the following content:env: MOZ_LOG: nsCSSLoader:5,sync
- Push the file to the device with
adb push org.mozilla.geckoview.test_runner-geckoview-config.yaml /data/local/tmp/
- Create
- Command:
MOZCONFIG=.mozconfig-android ./mach test toolkit/components/extensions/test/xpcshell/test_ext_webRequest_style_cache.js --verbose --log-mach-verbose --tag=remote-webextensions
- Log:
adb logcat
- Note: run
adb logcat
before running the test. Due to bug 1844829 there is tons of logspam; see that bug for agrep
command to filter the output.
- Note: run
Reporter | ||
Comment 1•1 year ago
|
||
Example of good log, from a test run on desktop.
Minimal post-processing of the log file:
- Stripped timestamp prefixes.
- Replaced child process ID with 12345.
Reporter | ||
Comment 2•1 year ago
|
||
Example of bad log, from a test run on Android ( emulator - ./mach android-emulator
).
Post-processing of the log file:
- Stripped timestamp / adb log prefixes.
- Replaced child process ID with 12345.
- Removed lots of logspam from bug 1844829.
- Removed even more unrelated log lines that are not relevant in the comparison with desktop.
- Converted INFO/FAIL/PASS JSON "action" messages to the format as seen on desktop.
This log shows the nsCSSLoader
+ INFO/PASS/FAIL parts of the test.
Due to the post-processing this can compared easily with the desktop variant with diff
.
Reporter | ||
Comment 3•1 year ago
|
||
To help with debugging:
-
Add comments and explicit test assertion messages that explains the
test expectation in the webRequest listener. -
Add
info()
calls to clearly mark the stage of the test. -
Add explicit test support for opening a ContentPage in a specific
process, and open a new ContentPage in that process. This is done
instead of the current logic (=navigate ContentPage to new
destination), to rule out document destruction as a cause of the
stylesheet cache destruction.
Despite these measures, the test is still failing on Android.
Reporter | ||
Comment 4•1 year ago
|
||
The test was introduced in bug 1599160. In comment 3 I added an improved version of the test to rule out some failure causes, but the test still fails on Android.
The cause of the failure is independent of extensions, because the actual trigger for the failure is an unexpected cache miss at https://searchfox.org/mozilla-central/rev/77dd6aa3810610949a5ff925e24de2f8c11377fd/layout/style/Loader.cpp#961,969,984,998
Therefore I'm moving this bug to that component for further triage. See the initial report for reproduction steps and analysis, and comment 1 and comment 2 for formatted log messages.
Comment 5•1 year ago
|
||
The severity field is not set for this bug.
:jfkthame, could you have a look please?
For more information, please visit BugBot documentation.
Comment 6•1 year ago
|
||
Does android, the cp.loadURL
call have different navigation / bfcache behavior than desktop here? Does making the bfcache behavior the same fix the test?
What it seems to me is that the first page dies, then we clear the sheet from the cache, and the second page doesn't find it by the time we get to load it.
Reporter | ||
Comment 7•1 year ago
|
||
(In reply to Emilio Cobos Álvarez (:emilio) from comment #6)
Does android, the
cp.loadURL
call have different navigation / bfcache behavior than desktop here? Does making the bfcache behavior the same fix the test?
I suspected navigation & bfcache, but ruled that out as the cause, by keeping the page open while opening a new page. I have attached these changes in the updated test (attached in comment 3 - https://phabricator.services.mozilla.com/D186043) and the issue is still reproduced.
What it seems to me is that the first page dies, then we clear the sheet from the cache, and the second page doesn't find it by the time we get to load it.
In the updated test, the first page is not closed, yet the issue still happens. Due to the difference in observed logs (comment 1 vs comment 2), a next step could be to look at the conditions at https://searchfox.org/mozilla-central/rev/77dd6aa3810610949a5ff925e24de2f8c11377fd/layout/style/Loader.cpp#961,969,984,998 and see what triggers the difference in behavior.
Description
•