Closed Bug 1803770 Opened 2 years ago Closed 2 years ago

Intermittent org.mozilla.geckoview.test.NavigationDelegateTest#loadExternalDenied | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$ChildCrashedException: Child process crashed

Categories

(GeckoView :: General, defect, P5)

All
Android
defect

Tracking

(firefox109 wontfix, firefox110 wontfix, firefox111 wontfix, firefox112 wontfix, firefox113 fixed)

RESOLVED FIXED
113 Branch
Tracking Status
firefox109 --- wontfix
firefox110 --- wontfix
firefox111 --- wontfix
firefox112 --- wontfix
firefox113 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: m_kato)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])

Attachments

(1 file)

Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=398456622&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SWgxUZ3DSzutNCpI8ZJN6g/runs/0/artifacts/public/logs/live_backing.log


[task 2022-12-02T13:08:11.416Z] 13:08:11     INFO -  12-02 13:08:10.168 E/GeckoConsole( 3458): [JavaScript Error: "TypeError: can't access property "maybeCancelContentJSExecution", this._browser.frameLoader.remoteTab is null" {file: "resource://gre/modules/RemoteWebNavigation.jsm" line: 28}]
[task 2022-12-02T13:08:11.416Z] 13:08:11     INFO -  12-02 13:08:10.402 E/SystemStateListener( 3458): mInputManager should be valid!
[task 2022-12-02T13:08:11.416Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): Error
[task 2022-12-02T13:08:11.416Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): org.mozilla.geckoview.test.rule.GeckoSessionTestRule$ChildCrashedException: Child process crashed
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$1.invoke(GeckoSessionTestRule.java:1201)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at java.lang.reflect.Proxy.invoke(Proxy.java:813)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at $Proxy22.onKill(Unknown Source)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.GeckoSession$3.handleMessage(GeckoSession.java:521)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.GeckoSession$3.handleMessage(GeckoSession.java:509)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.GeckoSessionHandler.handleMessage(GeckoSessionHandler.java:88)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.gecko.EventDispatcher$3.run(EventDispatcher.java:426)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-12-02T13:08:11.417Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1785)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1541)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1516)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1506)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.NavigationDelegateTest.testLoadErrorWithErrorPage(NavigationDelegateTest.kt:121)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.NavigationDelegateTest.testLoadExpectError(NavigationDelegateTest.kt:155)
[task 2022-12-02T13:08:11.418Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.NavigationDelegateTest.loadExternalDenied(NavigationDelegateTest.kt:267)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-12-02T13:08:11.419Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1470)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(D8$$SyntheticClass)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-12-02T13:08:11.420Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.os.Looper.loop(Looper.java:154)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.403 E/GeckoSessionTestRule( 3458): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-12-02T13:08:11.421Z] 13:08:11     INFO -  12-02 13:08:10.404 D/GeckoViewContent( 3458): handleEvent: DOMWindowClose
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  12-02 13:08:10.406 D/GeckoViewNavigation( 3458): canClose
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  12-02 13:08:10.414 D/GeckoViewClipboardPermissionChild[C]( 3458): handleEvent: pagehide
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  12-02 13:08:10.423 D/GeckoThread( 3458): State changed to EXITING
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  12-02 13:08:10.425 D/GeckoViewConsole( 3458): onEvent GeckoView:WebExtension:List null
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  12-02 13:08:10.429 E/GeckoSessionTestRule( 3458): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 loadExternalDenied(org.mozilla.geckoview.test.NavigationDelegateTest)
[task 2022-12-02T13:08:11.422Z] 13:08:11  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.NavigationDelegateTest#loadExternalDenied | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$ChildCrashedException: Child process crashed
[task 2022-12-02T13:08:11.422Z] 13:08:11     INFO -  TEST-INFO took 1020ms

Regressor is somewhere in this range, bustages and mass test failures are blocking backfills and retriggers.

The crashes here have this line in common https://treeherder.mozilla.org/logviewer?job_id=404172513&repo=autoland&lineNumber=9055
Hit MOZ_CRASH(Resolver error: Unknown variable: $websiteUrl) at intl/l10n/rust/localization-ffi/src/lib.rs:620 I'm thinking from Bug 1685180.
Greg, is this something you could look into?

Flags: needinfo?(gtatum)

The issue here is that $websiteUrl in the ftl file is sometimes undefined.

https://searchfox.org/mozilla-central/search?q=websiteUrl&path=&case=false&regexp=false

This issue was introduced in Bug 1625156, the assertion I introduced in Bug 1685180 is just catching it.

Flags: needinfo?(gtatum)

Julian, could you have a look over these kind of failures? Thank you.

Flags: needinfo?(julianwels)

Hmm,
okay, looking at the log file, it says:

[JavaScript Warning: "Loading failed for the <script> with source “chrome://global/content/httpsonlyerror/errorpage.js”." {file: "about:httpsonlyerror?e=nssBadCert&u=https%3A//expired.example.com/&c=UTF-8&d=%20" line: 46}]

So errorpage.js cannot be loaded for some reason on about:httpsonlyerror, which causes $websiteUrl to never be set, which in turn causes the Fluent assertion to fail.

I don't know enough about GeckoView to understand why errorpage.js does not load though. Just before loadExternalDenied runs, there are some HTTPS-Only tests. Maybe after they're done HTTPS-Only Mode does not get disabled, which causes some unexpected behavior in the following test? But that would not explain why the JS file cannot be loaded on the error page intermittently... which seems like the bigger issue.

Maybe someone from the Android team knows :)

Flags: needinfo?(julianwels)

For what it's worth, the issue can be ignored by changing the lines like { websiteUrl: aURL } to { websiteUrl: aURL ?? "" }. This will bypass the assertion, but not fix the underlying issue.

I don't think it can because it seems the script never even runs :/

Oh I see. Another workaround would be to define it in the markup.

https://searchfox.org/mozilla-central/search?q=data-l10n-args&path=.html&case=false&regexp=false

I don't know that I'd particularly recommend it, since there appears to be an underlying issue, but it's available if you need it.

<... data-l10n-args='{"websiteUrl": ""}'>

https://searchfox.org/mozilla-central/rev/188d0f76a73e0671d12e744a71e9f5701668cc37/toolkit/components/httpsonlyerror/content/errorpage.html#26 defines this in markup, without a websiteUrl, which is how we end up with an error. As Greg said, you could work around by adding this in markup - or, for that matter, removing the data-l10n-id from the markup.

From the log, we run https://searchfox.org/mozilla-central/rev/188d0f76a73e0671d12e744a71e9f5701668cc37/mobile/android/geckoview/src/androidTest/java/org/mozilla/geckoview/test/NavigationDelegateTest.kt#521 which opens the https only error in a subframe. That subtest succeeds, and then we try to load the next test, and at that point we get errors from the https only error. If I had to guess, the subframe with the error page gets destroyed which stops loading the JS, which is how we end up in a state where nothing ever sets websiteUrl.

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

If errorpage.html is unloaded before this HTML and related resources aren't
loaded completed, this issue seems to occur.

When GeckoView-junit test runs loadExternalDenied test after finishing
loadHTTPSOnlyInSubframe test, since GeckoView doesn't handle subframe error
(ex. Bug 1692578), this situation seems to occurs. So, as workaround, we
should set L10N arguments to avoid test failure.

This failure occurs on my workstation frequency, but after applying this fix,
no failure even if I run over 1 hour with --run-until-failure.

Assignee: nobody → m_kato
Status: NEW → ASSIGNED
Pushed by m_kato@ga2.so-net.ne.jp: https://hg.mozilla.org/integration/autoland/rev/992c765f4239 Set websiteUrl arguemnt in HTML as default. r=Gijs
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 113 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: