Closed Bug 1860490 Opened 1 year ago Closed 1 year ago

Reader mode produces a blank screen, for KRON-4 News amp article on Android

Categories

(Fenix :: General, defect)

Product:
Fenix
Component:
General
Platform:
All
Android
Type:
defect

Tracking

(firefox119 unaffected, firefox120 fixed, firefox121 fixed)

Status:
RESOLVED DUPLICATE of bug 1860130
Tracking Flags:
Tracking Status
firefox119 --- unaffected
firefox120 --- fixed
firefox121 --- fixed

People

(Reporter: dholbert, Assigned: rpl)

References

(Regression)

Details

(Keywords: regression)

Steps to reproduce

  1. Visit this URL in Firefox on Android:
    https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1&amp_js_v=a9&usqp=mq331AQGsAEggAID#amp_tf=From%20%251%24s&aoh=16978684449801&csi=0&referrer=https%3A%2F%2Fwww.google.com&ampshare=https%3A%2F%2Fwww.kron4.com%2Fnews%2Fbay-area%2Fsilicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud%2F
  2. Tap the reader mode icon in the URL bar.

Expected behavior

Reader mode presentation of article.

Actual behavior

Blank white page.

Device information

  • Firefox version: 120.0a1 (latest Nightly)
  • Android device model: Pixel 8
  • Android OS version: 14

Any additional information?

If I check the web console using about:debugging, I can see two errors go by, when I enter reader mode (i.e. when the issue happens).

First error, a failed XHR:

readerview.html
XHR GET
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1
[HTTP/3 404  120ms]

Second error:

Uncaught (in promise) Error: Incorrect argument types for storage.StorageArea.remove. undefined

​

Also notably: reader mode works just fine in Firefox Nightly on desktop, including when viewing this same URL in responsive-design-mode with a mobile-phone UA string.

Here's a profile:
https://share.firefox.dev/46GtfxQ

I tap the "reader mode" icon at around t=3s in the profile, and then you can see in the screenshots track that we switch to a blank black screen very briefly, and then a blank white screen.

(Also: this is a recent Firefox Nightly installation on this device, with no add-ons installed.)

Thanks!

Keywords: regression
Regressed by: 1856731
See Also: → 1860740

Set release status flags based on info from the regressing bug 1856731

status-firefox119: --- → unaffected
status-firefox120: --- → affected
status-firefox121: --- → affected

I couldn't confirm locally if the fix from Bug 1860130 does fix this issue (because the url in comment 0 seems to be regionally restricted and so I can't load its expected content from where I'm located, at least not without a vpn node exiting from the right region), but it is very likely to be the case given that this and Bug 1860740 should be having the exact same underlying reason for the bug to be hit (and, as I mentioned in Bug 1860740 comment 5, I confirmed locally that with Bug 1860130 change applied Bug 1860740 can't be reproduced anymore).

And in the meantime I'm linking Bug 1860130 as a seealso, but if someone (in the region where the content at the url mentioned in comment 0 is going to be available) wants to give it a try, a Fenix debug apk can be downloaded from the artifacts linked to the taskcluster CI task as described in the PR comment 0 section named "To download an APK when reviewing a PR (after all CI tasks finished running"), which links to the following task (the apk artifacts are linked from the panel on the right):

(Feel free to move Bug 1860130 from the seealso to the depends bugzilla field once confirmed Bug 1860130 patch fixes this issue)

See Also: → 1860130

Thanks, Luca -- I installed the debug build following steps from comment 6, but unfortunately the issue still reproduces with that build.

DevTools still show the same two errors from comment 0 in that debug build, too, FWIW.

Presumably the error about storage.StorageArea.remove. undefined corresponds to this line from the regressing commit:

     case 'getSerializedDoc':
       let doc = await browser.storage.session.get(message.id);
       browser.storage.session.remove(message.id);

https://github.com/boek/firefox-android/blob/f901e9b2ac19278578facfd0af298122f1d74753/android-components/components/feature/readerview/src/main/assets/extensions/readerview/readerview-background.js#L15

(In reply to Daniel Holbert [:dholbert] from comment #7)

Thanks, Luca -- I installed the debug build following steps from comment 6, but unfortunately the issue still reproduces with that build.

I just tried on my phone by going through a VPN and on that device (a Pixel 6a) I was able to enter into readerview mode on that page, but I think I got to hit another issue (a race from what I can see at the moment) where the change from Bug 1860130 isn't enough yet:

  • on my phone, when trying to enter readerview mode on the addons.mozilla.org details page for tree style tab:
    • when going over the VPN, the tab was consistently entering in readerview mode
    • when NOT going over the VPN, the tab was apparently entering in readerview mode shortly but then the tab was reloaded, and in the adb logcat logs I was able to see the following logs:
10-25 18:42:43.687 14794 14823 E WebExtensions: [JavaScript Error: "Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://addons.mozilla.org/en-US/firefox/addon/tree-style-tab/. (Reason: CORS header ‘Access-Control-Allow-Origin’ missing). Status code: 200."]
10-25 18:42:43.689 14794 14823 E WebExtensions: [JavaScript Error: "Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://addons.mozilla.org/en-US/firefox/addon/tree-style-tab/. (Reason: CORS header ‘Access-Control-Allow-Origin’ missing). Status code: 200."]
...
10-25 18:42:43.697 14794 14823 I WebExtensions: AggregateError: No Promise in Promise.any was resolved

Based on a little bit on inspection by connecting remotely to the Fenix instance from about:debugging, it seems this still happens if we didn't got a serialized doc stored into the browser.storage.session store, and I believe that may be due to a race between:

I can't see yet how the VPN would be affecting that behavior, and I need to confirm we are really hitting that kind of race, but I think that there is a chance for the tab to be reloaded before the content script have been able to serialize the doc and sending it to the extension background context, given that there is no coordination between those two steps and so it is not unlikely that a race may be hit intermittently (and also that content script lives in a child process, while the event page and GeckoView/Fenix layer lives in the parent process, and so there are two separate processes involved).

Jeff may also have some insight about this part, in the meantime I'm going to look more into this and see if I can gather some more confirmation of this race I just described to be the reason for the patch not yet always fixing the readerview mode issue.

FWIW I'm not seeing that WebExtensions error in logcat, and I also don't see any change in behavior (I don't see any reader mode) when I'm connected using Mozilla VPN. (Though maybe that just means my network characteristics aren't the same as yours, with respect to the race condition that you're seeing).

I do see this error in logcat when I tap the reader mode icon, though (using the debug build from comment 6):

10-25 11:15:01.752 10339 10366 E GeckoConsole: [JavaScript Error: "TypeError: can't access property "eventDispatcher", this.window.moduleManager is undefined" {file: "resource://gre/modules/GeckoViewActorParent.sys.mjs" line: 28}]
10-25 11:15:01.752 10339 10366 E GeckoConsole: get eventDispatcher@resource://gre/modules/GeckoViewActorParent.sys.mjs:28:5
10-25 11:15:01.752 10339 10366 E GeckoConsole: receiveMessage@resource://gre/modules/GeckoViewActorParent.sys.mjs:41:9
10-25 11:15:01.752 10339 10366 E GeckoConsole: receiveMessage@resource:///actors/GeckoViewClipboardPermissionParent.sys.mjs:37:22
10-25 11:15:01.754 10339 10339 D GeckoSession: handleMessage GeckoView:ProgressChanged uri=null
10-25 11:15:01.755 10339 10339 D GeckoSession: handleMessage GeckoView:PageStart uri=moz-extension://cf7d7ac7-e96a-4361-b5b1-674bc15940ae/readerview.html?url=https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1&amp_js_v=a9&usqp=mq331AQGsAEggAID#amp_tf=From%20%251%24s&aoh=16978684449801&csi=0&referrer=https%3A%2F%2Fwww.google.com&ampshare=https%3A%2F%2Fwww.kron4.com%2Fnews%2Fbay-area%2Fsilicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud%2F&id=1f7c83c7-a4c4-4ef9-af32-84d05e1d3248&colorScheme=light
10-25 11:15:01.755 10339 10339 I GeckoSession: handleMessage GeckoView:PageStart uri=

This seems potentially-related to the error in comment 8, given that this logging has to do with handleMessage and receiveMessage for reader view, with comment 8 being apparently about an undefined/unexpected message.id.

Also, somewhat unrelatedly -- regarding the URL that readerview.html is loading via XHR and hitting 404 (1st error in comment 0): that seems to be a "query-parameters-stripped" version of the full URL (only preserving amp_gsa=1), and unfortunately that stripping makes the URL 404 as far as the web server is concerned (which I can confirm when I load the truncated URL directly). But if we change the preserved-query-parameter to instead preserve amp_js_v=a9, then the URL continues to load just fine!

i.e. this truncated URL that we're using is 404:
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1
...but this one loads successfully for me:
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_js_v=a9

...and if I directly load the query-params-mostly-stripped URL that loads successfully in the debug build on Android, and tap the Reader Mode icon, then reader mode loads just fine (!)

(In reply to Daniel Holbert [:dholbert] from comment #12)

...and if I directly load the query-params-mostly-stripped URL that loads successfully in the debug build on Android, and tap the Reader Mode icon, then reader mode loads just fine (!)

yeah, that would make it work because the XHR request being triggered is resolving, and so it "hides" the issue we may still have when we need to retrieve the doc using the "getSerializedDoc" message.

(In reply to Daniel Holbert [:dholbert] from comment #8)

DevTools still show the same two errors from comment 0 in that debug build, too, FWIW.

Presumably the error about storage.StorageArea.remove. undefined corresponds to this line from the regressing commit:

     case 'getSerializedDoc':
       let doc = await browser.storage.session.get(message.id);
       browser.storage.session.remove(message.id);

https://github.com/boek/firefox-android/blob/f901e9b2ac19278578facfd0af298122f1d74753/android-components/components/feature/readerview/src/main/assets/extensions/readerview/readerview-background.js#L15

uhm... interesting, the call to remove is the same in the version of that js file with Bug 1860130 changes, but I was not able to hit that specific error in any of my attempts (instead the one I was hitting was on the other side of the getSerializedDoc message, when we were trying to deserialize the doc as it was sent back from readerview-background.js before Bug 1860130 changes).

The id should be the uuid that is being generated from the ReaderViewFeature.kt file, and so I'm wondering what makes it to not be of the expected type, I'll re-read more closely the code that is propagating the id to see if I can think of any scenario where the message.id may be able to trigger that Incorrect argument types for storage.StorageArea.remove error and see what I may be missing from the STR to be able to hit that one.

Still using the debug build from comment 6...
This URL shows the XHR 404 error in web console, and reproduces this bug (blank rendering in reader-mode):
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1&amp_js_v=a9

But this next URL (just swapping the order of the query params) shows a successful XHR and lets me successfully enter reader mode (no bug!):
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_js_v=a9&amp_gsa=1
(but **it does still show the Uncaught (in promise) Error: Incorrect argument types for storage.StorageArea.remove. undefined error in web console when I enter reader mode.)

The only difference between those two URLs (broken vs working) is whether amp_js_v=a9 is the first query-param or not; and that apparently matters because web console show us doing an XHR for an amended version of the document URL, stripped to only preserve whatever-the-first-query-param-was. If that preserved query-param is amp_js_v=a9, then the URL is OK. If it's something else, then the load fails, and that failure causes reader mode to fail to render, at least in this case.

So: independent of the getSerializedDoc issue, we also have an issue where Reader Mode seems to be arbitrarily choosing to preserve the first query-param for its XHR, which is maybe (?) an anti-tracking heuristic but in this case is breaking things.

(In reply to Daniel Holbert [:dholbert] from comment #10)

FWIW I'm not seeing that WebExtensions error in logcat, and I also don't see any change in behavior (I don't see any reader mode) when I'm connected using Mozilla VPN. (Though maybe that just means my network characteristics aren't the same as yours, with respect to the race condition that you're seeing).

I do see this error in logcat when I tap the reader mode icon, though (using the debug build from comment 6):

10-25 11:15:01.752 10339 10366 E GeckoConsole: [JavaScript Error: "TypeError: can't access property "eventDispatcher", this.window.moduleManager is undefined" {file: "resource://gre/modules/GeckoViewActorParent.sys.mjs" line: 28}]
10-25 11:15:01.752 10339 10366 E GeckoConsole: get eventDispatcher@resource://gre/modules/GeckoViewActorParent.sys.mjs:28:5
10-25 11:15:01.752 10339 10366 E GeckoConsole: receiveMessage@resource://gre/modules/GeckoViewActorParent.sys.mjs:41:9
10-25 11:15:01.752 10339 10366 E GeckoConsole: receiveMessage@resource:///actors/GeckoViewClipboardPermissionParent.sys.mjs:37:22
10-25 11:15:01.754 10339 10339 D GeckoSession: handleMessage GeckoView:ProgressChanged uri=null
10-25 11:15:01.755 10339 10339 D GeckoSession: handleMessage GeckoView:PageStart uri=moz-extension://cf7d7ac7-e96a-4361-b5b1-674bc15940ae/readerview.html?url=https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1&amp_js_v=a9&usqp=mq331AQGsAEggAID#amp_tf=From%20%251%24s&aoh=16978684449801&csi=0&referrer=https%3A%2F%2Fwww.google.com&ampshare=https%3A%2F%2Fwww.kron4.com%2Fnews%2Fbay-area%2Fsilicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud%2F&id=1f7c83c7-a4c4-4ef9-af32-84d05e1d3248&colorScheme=light
10-25 11:15:01.755 10339 10339 I GeckoSession: handleMessage GeckoView:PageStart uri=

This seems potentially-related to the error in comment 8, given that this logging has to do with handleMessage and receiveMessage for reader view, with comment 8 being apparently about an undefined/unexpected message.id.

that receiveMessage is from the GeckoViewClipboardPermissionParent JSWindowActorParent instance, and so I'd expect it to be unrelated, but... "never say never" and so I'll still keep an eye on that while I'm digging more into this.

(In reply to Luca Greco [:rpl] [:luca] [:lgreco] from comment #14)

see what I may be missing from the STR to be able to hit that one.

FWIW my STR are literally just the following, starting with a freshly installed copy of the debug build downloaded from taskcluster:

  1. Tap through the Firefox onboarding prompts.
  2. Visit this bug page ( https://bugzilla.mozilla.org/show_bug.cgi?id=1860490 )
  3. Tap the link in comment 0.
  4. Wait a few seconds for the page to load.
  5. Tap the reader mode icon in the URL bar.

(If I do that with devtools connected from about:debugging and inspecting the tab, after toggling the switch for "Remote debugging via USB" in Firefox settings, then I see that storage.StorageArea.remove error in web console. This happens with or without Mozilla VPN connected [tested San Jose and Ashburn as exit targets.])

If that's not repro'ing the issue for you, in a fresh install, then presumably there may be some dependency on network conditions or some sort of race, I guess.

If that's not repro'ing the issue for you, in a fresh install, then presumably there may be some dependency on network conditions or some sort of race, I guess.

that is basically my same STR (the only difference I can see is that I'm loading the url directly by I'm collapsing steps 1 to 3 into a single step by pasting it from adb using adb shell input text "https://....").

In a moment I'm going to try to go through navigating to the bug and clicking the link instead, in case navigating to the url that is hitting the readerview issue (instead of loading that url as the first and only url) may be related to the reasons why I'm unable to hitting the exact same error.

In the meantime, given that you can reproduce it, would you mind to put a logpoint on the line that throws to log the entire message object?

I'm wondering how the message looks like when inspected, based on another quick look to the code propagating the message id I can't see yet how we get to hit that.

Eh, that was it,
by using the STR from comment 17 (navigating to the url instead of loading that directly) seems to be now making me able to hit the same storage.StorageArea.remove error mentioned in comment 8.

By using a logpoint I can see that message looks like the following when that is being hit:

{ action: "getSerializedDoc", id: null }

and so the action property is the expected one (that's set to a literal value here on the sender side and so not really surprising), but the id is set to null (that comes from the message originated from the ReaderViewFeature.kt side) and the doc property is completely missing.

Now that I can reproduce consistently I'm going to dig more into it, thanks a lot Daniel for helping me to pinpoint what I was missing from my STR!

Great, I'm glad you can repro -- thanks for looking into it!

This morning I came back to this issue to continue this investigation, and it seems that I can bring some good news from today's investigation:

  • Turned out that the underlying reason for this issue was on the ReaderViewFeature.kt side, but the issue was actually different from what my original guess was (a potential race), instead while digging more into what was going on with propagating the message.id when we were getting the getSerializedDoc message with a null message id property I recalled you mentioned in comment 11 and comment 15 that there were other url search params from the original webpage url that were being unexpectectly messed up... and recalling that made me look in the right direction and finally seeing that the "getSerializedDoc" was being sent with a null message id property when we were not able to retrieve one from the generated moz-extension readerview page url.

  • By looking to the generated moz-extension url that was hitting the issue, I realized that the original webpage url was being interpolated into the generated moz-extension url as is without being escaped (see WebExtensionController.createReaderUrl as currently defined in ReaderViewFeature.kt here), that looked definitely as something that would be able to mess up the ability of the readerview extension page of both retrieving the message id and retrieving the original url along with its original search params (which was the unexpected detail that you noticed already and mentioned in comment 11 and comment 15), that looked like a pretty realistic theory for what was going on

  • Realizing where the issue was originating also allowed me to track back in the github repo issue where we have introduced this particular issue, https://github.com/mozilla-mobile/firefox-android/commit/891d124ddb387705dbf77f9f946a73620179a6f0, and looking that diff confirmed that in the previous version we were building the readerview url using the URL webAPI, and by appending the original webpage url into the generated url using searchParams.append we were implicitly encoding the url as a side effect, and the new version of the Kotlin code generating the url was instead just interpolating the url as is

I've rolled into the exiting PR a couple line changes to explicitly encoding the webpage url on the kotlin side, with both those fixes I could not reproduce this issue anymore and my Fenix instance was finally entering readerview mode just fine.

Daniel,
Would you mind to also give a try to the new generate apk to double-check that it does also fix it for you? ("just in case (tm)" :-P)

Thanks again for reporting this issue and then basically pairing with me on investigating it, as mentioned above the details you gathered were invaluable to let me more quickly pinpoint what was going on!!!

Flags: needinfo?(jboek)

:boek, since you are the author of the regressor, bug 1856731, could you take a look? Also, could you set the severity field?

For more information, please visit BugBot documentation.

Flags: needinfo?(jboek)

(In reply to Luca Greco [:rpl] [:luca] [:lgreco] from comment #21)

Daniel,
Would you mind to also give a try to the new generate apk to double-check that it does also fix it for you? ("just in case (tm)" :-P)

Sure -- yes, it does seem to fix it for me.

I downloaded the APK from here: https://firefox-ci-tc.services.mozilla.com/tasks/c07zlp6yQF2y6RzKig5XNQ , and with my comment 17 STR, reader mode works just fine.

Thanks for fixing this!

[assigning Luca so that bugbot hopefully stops jumping in with needinfos. Tentatively setting Severity to S3 to address its request, too, but feel free to adjust if that doesn't feel right.]

Assignee: nobody → lgreco
Severity: -- → S3
Status: NEW → ASSIGNED
Flags: needinfo?(jboek)

Additional notes RE this-now-working-correctly:

  • It seems we're XHR'ing the correct full URL, and that XHR is succeeding -- web console now shows:
GET
https://www-kron4-com.cdn.ampproject.org/v/s/www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/amp/?amp_gsa=1&amp_js_v=a9&usqp=mq331AQGsAEggAID#amp_tf=From %1$s&aoh=16978684449801&csi=0&referrer=https://www.google.com&ampshare=https://www.kron4.com/news/bay-area/silicon-valley-tech-executive-sentenced-to-prison-for-covid-testing-fraud/
[HTTP/3 200  133ms]

(And that bypasses one of the issues, i.e. it works as well as it did in comment 11-12 with the shorter specially-crafted-to-not-404 URL that has the all-important amp_js_v=a9 query-param first to ensure that we didn't trigger a 404.)

  • I still am able to correctly enter reader mode, even if I prevent the XHR from succeeding by disconnecting from wifi/data just before I tap the reader mode icon (which prevents the XHR from resolving, as I can see in web console). In current Nightly, reader-mode fails when I disconnect from wifi before tapping reader mode for comment 11's specially-crafted-to-work-better amp-URL -- the reader-mode icon takes me to a "No Internet connection" error-page in current Nightly, vs. to an actual reader-formatted presentation in the latest debug build that I'm testing here.

Bug 1860130 will be in the next round of nightly builds starting in a few hours - can you please re-test after that update becomes available from the Play Store?

Flags: needinfo?(dholbert)

I can still repro in the latest Nightly build available in the Play Store. Not sure if this is the one referenced in comment 26, or if that one's still in play-store pipeline; I'll retest tomorrow, and we can worry at that point if things are still broken.

Update: verified fixed in latest nightly (in play store after my previous comment). Hooray!

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Duplicate of bug: 1860130
Flags: needinfo?(dholbert)
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.