Open Bug 1564373 Opened 5 months ago Updated 15 days ago

Intermittent org.mozilla.geckoview.test.NavigationDelegateTest.trackingProtection | status -2

Categories

(GeckoView :: Tracking Protection, defect, P2)

Unspecified
All

Tracking

(firefox70 fix-optional)

Tracking Status
firefox70 --- fix-optional

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [stockwell disabled])

Attachments

(1 file)

Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=255443903&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/I52RyIFGQNixaiyZHrFDgA/runs/0/artifacts/public/logs/live_backing.log


[task 2019-07-09T09:54:51.787Z] 09:54:51 INFO - TEST-START | org.mozilla.geckoview.test.NavigationDelegateTest.trackingProtection
[task 2019-07-09T09:55:23.032Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=477
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | Error in trackingProtection(org.mozilla.geckoview.test.NavigationDelegateTest):
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:58)
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:161)
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1528)
[task 2019-07-09T09:55:23.033Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1470)
[task 2019-07-09T09:55:23.034Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1423)
[task 2019-07-09T09:55:23.034Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.NavigationDelegateTest.trackingProtection(NavigationDelegateTest.kt:203)
[task 2019-07-09T09:55:23.034Z] 09:55:23 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2019-07-09T09:55:23.034Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2019-07-09T09:55:23.034Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.support.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.support.test.internal.runner.junit4.statement.RunAfters.evaluate(RunAfters.java:61)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1261)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$Lambda$0.run(Unknown Source)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test |
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=trackingProtection
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.NavigationDelegateTest
[task 2019-07-09T09:55:23.037Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:58)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:161)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1528)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1470)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1423)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.NavigationDelegateTest.trackingProtection(NavigationDelegateTest.kt:203)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2019-07-09T09:55:23.038Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2019-07-09T09:55:23.039Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2019-07-09T09:55:23.039Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.support.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80)
[task 2019-07-09T09:55:23.039Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.support.test.internal.runner.junit4.statement.RunAfters.evaluate(RunAfters.java:61)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1261)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$Lambda$0.run(Unknown Source)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2019-07-09T09:55:23.040Z] 09:55:23 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2019-07-09T09:55:23.041Z] 09:55:23 INFO - org.mozilla.geckoview.test |
[task 2019-07-09T09:55:23.041Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=213
[task 2019-07-09T09:55:23.041Z] 09:55:23 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2019-07-09T09:55:23.041Z] 09:55:23 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.NavigationDelegateTest.trackingProtection | status -2
[task 2019-07-09T09:55:23.041Z] 09:55:23 INFO - TEST-INFO took 31253ms

Type: -- → defect

I suspect Bug 1567268 made this intermittent a lot worse.

Agi, I see this test has been disabled on debug builds:
https://searchfox.org/mozilla-central/source/mobile/android/geckoview/src/androidTest/java/org/mozilla/geckoview/test/NavigationDelegateTest.kt#200

The remaining failures are all on opt builds:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-08-13&endday=2019-08-20&tree=trunk&bug=1564373

It is failing frequently, should we go ahead and disable this test on opt builds as well?

Flags: needinfo?(agi)

Dylan worked on this recently so forwarding the ni.

Flags: needinfo?(agi) → needinfo?(droeh)

(In reply to :Agi | ⏰ PST | he/him from comment #15)

Dylan worked on this recently so forwarding the ni.

Yeah, the new failures are no longer timeouts, they're failing to call onContentLoaded the expected number of times. I'll investigate.

Flags: needinfo?(droeh)
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

Pushed by nbeleuzu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/ae9b04ed1956
Disable NavigationDelegateTest.trackingProtection for frequent failures. r=droeh

Keywords: checkin-needed

Resetting priority so we can discuss it during triage. Note: the test was disabled (that's why no more intermittents).

Priority: P5 → --

Dylan is investigating this intermittent ETP test failure.

Assignee: nobody → droeh
Priority: -- → P2
Rank: 20
Component: General → Tracking Protection
You need to log in before you can comment on or make changes to this bug.