Open Bug 2003910 Opened 14 hours ago

Intermittent org.mozilla.geckoview.test.AutocompleteTest#loginUsed | single tracking bug

Categories

(GeckoView :: General, defect, P5)

All
Android
defect

Tracking

(Not tracked)

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [collect_confirm_failure])

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


[task 2025-12-03T20:03:11.827+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): res_nmkquery: (QUERY, IN, AAAA)
[task 2025-12-03T20:03:11.827+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): resolv_cache_lookup: FOUND IN CACHE entry=0x768e655322b0
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): doQuery: rcode=0, ancount=1, return value=75
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): res_nmkquery: (QUERY, IN, A)
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): resolv_cache_lookup: FOUND IN CACHE entry=0x768e655337b0
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.975 I/resolv  (  374): doQuery: rcode=0, ancount=1, return value=63
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.975 D/TrafficStats(  900): tagSocket(6) with statsTag=0xffffff81, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.976 D/TrafficStats(  900): tagSocket(107) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.976 D/TrafficStats(  900): tagSocket(68) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.977 D/TrafficStats(  900): tagSocket(68) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.978 D/TrafficStats(  900): tagSocket(68) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.979 D/TrafficStats(  900): tagSocket(68) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.828+00:00] 20:03:11     INFO -  12-03 20:02:58.979 D/NetworkMonitor/101(  900): PROBE_HTTP http://connectivitycheck.gstatic.com/generate_204 time=5ms ret=204 request={Connection=[close], User-Agent=[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.32 Safari/537.36]} headers={null=[HTTP/1.1 204 No Content], Connection=[close], Content-Length=[0], Cross-Origin-Resource-Policy=[cross-origin], Date=[Wed, 03 Dec 2025 20:02:59 GMT], X-Android-Received-Millis=[1764792178979], X-Android-Response-Source=[NETWORK 204], X-Android-Selected-Protocol=[http/1.1], X-Android-Sent-Millis=[1764792178977]}
[task 2025-12-03T20:03:11.829+00:00] 20:03:11     INFO -  12-03 20:02:58.980 D/TrafficStats(  900): tagSocket(6) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.829+00:00] 20:03:11     INFO -  12-03 20:02:58.981 D/TrafficStats(  900): tagSocket(6) with statsTag=0xffffffff, statsUid=-1
[task 2025-12-03T20:03:11.829+00:00] 20:03:11     INFO -  12-03 20:02:58.982 D/NetworkMonitor/101(  900): PROBE_DNS www.google.com 15ms OK 74.125.126.99,74.125.126.147,74.125.126.106,74.125.126.104,74.125.126.105,74.125.126.103,2607:f8b0:4001:c08::69,2607:f8b0:4001:c08::68,2607:f8b0:4001:c08::6a,2607:f8b0:4001:c08::67
[task 2025-12-03T20:03:11.829+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): GetAddrInfoHandler::run: {101 983141 101 983141 1073 1}
[task 2025-12-03T20:03:11.829+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): res_nmkquery: (QUERY, IN, AAAA)
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): resolv_cache_lookup: FOUND IN CACHE entry=0x768ed552db50
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): doQuery: rcode=0, ancount=4, return value=144
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): res_nmkquery: (QUERY, IN, A)
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): resolv_cache_lookup: FOUND IN CACHE entry=0x768ed552d490
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.983 I/resolv  (  374): doQuery: rcode=0, ancount=6, return value=128
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.984 D/TrafficStats(  900): tagSocket(6) with statsTag=0xffffff81, statsUid=-1
[task 2025-12-03T20:03:11.830+00:00] 20:03:11     INFO -  12-03 20:02:58.993 D/NetworkMonitor/101(  900): PROBE_HTTPS https://www.google.com/generate_204 time=11ms ret=204 request={Connection=[close], User-Agent=[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.32 Safari/537.36]} headers={null=[HTTP/1.1 204 No Content], Connection=[close], Content-Length=[0], Cross-Origin-Resource-Policy=[cross-origin], Date=[Wed, 03 Dec 2025 20:02:59 GMT], X-Android-Received-Millis=[1764792178993], X-Android-Response-Source=[NETWORK 204], X-Android-Selected-Protocol=[http/1.1], X-Android-Sent-Millis=[1764792178992]}
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:02:58.994 D/NetworkMonitor/101(  900): isCaptivePortal: isSuccessful()=true isPortal()=false RedirectUrl=null isPartialConnectivity()=false Time=27ms
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.020 I/AiAiEcho( 1529): Predicting[0]:
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.020 I/AiAiEcho( 1529): EchoTargets:
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.020 I/AiAiEcho( 1529): Filtered by AiAi flag check:
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.021 I/AiAiEcho( 1529): Ranked targets strategy: SORT, count: 0, ranking metadata:
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.021 I/AiAiEcho( 1529): #postPredictionTargets: Sending updates to UISurface lockscreen with targets# 0 (types=[])
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.036 W/PageIndicator(  789): Total number of pages invalid: 0. Assuming 1 page.
[task 2025-12-03T20:03:11.831+00:00] 20:03:11     INFO -  12-03 20:03:00.041 D/EGL_emulation(  789): app_time_stats: avg=2400.71ms min=25.14ms max=21266.71ms count=9
[task 2025-12-03T20:03:11.832+00:00] 20:03:11     INFO -  12-03 20:03:00.462 W/A       ( 1829): [Download] response code: 400
[task 2025-12-03T20:03:11.832+00:00] 20:03:11     INFO -  12-03 20:03:02.083 D/OomAdjuster(  572): Not killing cached processes
[task 2025-12-03T20:03:11.832+00:00] 20:03:11     INFO -  12-03 20:03:02.807 D/StatusBarIconController(  789): ignoring old pipeline callbacks, because the new mobile icons are enabled
[task 2025-12-03T20:03:11.832+00:00] 20:03:11     INFO -  12-03 20:03:06.293 D/StatusBarIconController(  789): ignoring old pipeline callback because the new wifi icon is enabled
[task 2025-12-03T20:03:11.832+00:00] 20:03:11     INFO -  12-03 20:03:06.625 W/ProcessStats(  572): Tracking association SourceState{7afdc8f com.google.android.googlequicksearchbox:interactor/10132 BTop #8060} whose proc state 2 is better than process ProcessState{e732e20 com.google.android.gms.persistent/10130 pkg=com.google.android.gms} proc state 4 (77 skipped)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:09.298 D/StatusBarIconController(  789): ignoring old pipeline callback because the new wifi icon is enabled
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): Error
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Handler.handleCallback(Handler.java:958)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Handler.dispatchMessage(Handler.java:99)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:3041)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:3026)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.AutocompleteTest.testLoginUsed(AutocompleteTest.kt:1683)
[task 2025-12-03T20:03:11.833+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.AutocompleteTest.loginUsed(AutocompleteTest.kt:1691)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2025-12-03T20:03:11.834+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0(GeckoSessionTestRule.java:1511)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.$r8$lambda$iCBopfpsbLU-HFWW53O-4m1PB6c(Unknown Source:0)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda1.run(D8$$SyntheticClass:0)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:2420)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Handler.handleCallback(Handler.java:958)
[task 2025-12-03T20:03:11.835+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Handler.dispatchMessage(Handler.java:99)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Looper.loopOnce(Looper.java:205)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.os.Looper.loop(Looper.java:294)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at android.app.ActivityThread.main(ActivityThread.java:8177)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:552)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.113 E/GeckoSessionTestRule( 4952): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:971)
[task 2025-12-03T20:03:11.836+00:00] 20:03:11     INFO -  12-03 20:03:11.129 E/GeckoSessionTestRule( 4952): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 loginUsed(org.mozilla.geckoview.test.AutocompleteTest)
[task 2025-12-03T20:03:11.837+00:00] 20:03:11  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.AutocompleteTest#loginUsed | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  TEST-INFO took 30444ms
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.AutocompleteTest
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=49
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=1331
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=loginSelectModifyAccept
[task 2025-12-03T20:03:11.837+00:00] 20:03:11     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
You need to log in before you can comment on or make changes to this bug.