1710101 - Permanent Android org.mozilla.geckoview.test.StorageControllerTest.clearDataForSessionContext | java.lang.AssertionError: Local storage value should match when Gecko 90 switches to Late Beta on 2021-06-18

Status: VERIFIED FIXED

(Core :: Storage: localStorage & sessionStorage, defect)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

• central-as-late-beta simulation
• How to run these simulations
• Failure log

[task 2021-05-07T12:04:47.290Z] 12:04:47     INFO -  TEST-START | org.mozilla.geckoview.test.StorageControllerTest.clearDataForSessionContext
[task 2021-05-07T12:04:48.336Z] 12:04:48     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=802
[task 2021-05-07T12:04:48.336Z] 12:04:48     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-05-07T12:04:48.336Z] 12:04:48     INFO -  org.mozilla.geckoview.test | Error in clearDataForSessionContext(org.mozilla.geckoview.test.StorageControllerTest):
[task 2021-05-07T12:04:48.336Z] 12:04:48     INFO -  org.mozilla.geckoview.test | java.lang.AssertionError: Local storage value should match
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | Expected: "2"
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test |      but: was "null"
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:112)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.StorageControllerTest.clearDataForSessionContext(StorageControllerTest.kt:401)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-05-07T12:04:48.337Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1317)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$cmP_QJg-X16GIlt8KIQd32egmfU.run(lambda)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Looper.loop(Looper.java:154)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-05-07T12:04:48.338Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2021-05-07T12:04:48.339Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-05-07T12:04:48.339Z] 12:04:48     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)

The failure only affecting Late Beta can be explained by the next generation localStorage only being enabled for Nightly and Early Beta. But which change causes the failure? Changes since last, successful central-as-late-beta simulation

Comment 1

[Andrew Sutherland [:asuth] (he/him)]

The failing assertion is here and I understand it to be checking that clearing the OriginAttributes for origin https://example.com with a userContextId of 1 should not clear the data stored for a userContextId of 2.

So we're either looking at overzealous data clearing or a situation where this is an issue of process lifetime and/or data synchronization where the data for userContextId=2 was not cleared, but rather either never was written to disk or sequencing resulted in it not being loaded from disk.

An interesting thing suggesting that it might be overzealous data-clearing are these lines earlier in the test that assume cookie clearing clears all data which was added in bug 1592752.

Still some more investigation to do...

Comment 2

[Andrew Sutherland [:asuth] (he/him)]

I tried to re-run the failing test with MOZ_LOG=mozStorage:5 to see what clearing query is being run by legacy LocalStorage, but the custom action stuff betrayed me. I've asked if people know how to make custom action work in #GeckoView on chat.mozilla.org at https://matrix.to/#/!LfXZSWEroPFPMQcYmw:mozilla.org/$FrjmYbEgQ03sa8_ezdvSUV3iXnxlVxZ1DXWx2l6taR4?via=mozilla.org&via=matrix.org&via=matrix.joshiepoo.gq

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Similar to bug 1710135 which calls a testing helper function for local storage.

Comment 4

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Sebastian Hengst [:aryx] (needinfo on intermittent or backout) from comment #3)

Similar to bug 1710135 which calls a testing helper function for local storage.

Interesting! Restating the implications from there... bug 1699464 means that Legacy LocalStorage is now operating in multi-e10s mode with 2 processes where previously it would only be operating with 1 process.

This increases the scope of what could be going wrong. In particular, if the test is somehow being run with cookies set so that "network.cookie.lifetimePolicy" is ACCEPT_SESSION, no state ever touches disk in the first place, but the test could have worked due to there ever being a single content process.

I don't suppose there's any way to get an rr/pernosco trace from a cross-compiled android build or something?

And/or maybe we can just enable LSNG in general for GeckoView?

Comment 5

[Julien Cristau [:jcristau]]

Any update on this? It'd be good to have a fix by next week before 90 goes to beta.

Comment 6

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Bug 1710101 - Enable LSNG for GeckoView across all channels. r=aklotz!

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d7a58cff3e92
Enable LSNG for GeckoView across all channels. r=aklotz

Comment 8

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/d7a58cff3e92

Comment 9

[Andreea Pavel [:apavel]]

Verified fixed in latest beta sim: https://treeherder.mozilla.org/jobs?repo=try&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=7cc324c9964bbeb87ca413874a2674ecb9cdc8c6