1530722 - Intermittent raptor-main TEST-UNEXPECTED-FAIL: test 'raptor-tp6m-youtube-geckoview' timed out loading test page: https://www.youtube.com

Status: RESOLVED INCOMPLETE

(Testing :: Raptor, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: cbrindusan [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=230543531&repo=autoland

https://queue.taskcluster.net/v1/task/aH00AYL8RUiTT1BARBqnNg/runs/0/artifacts/public/logs/live_backing.log

15:18:40 INFO - Status: ok
15:18:40 INFO - Activity: org.mozilla.geckoview_example/.GeckoViewActivity
15:18:40 INFO - ThisTime: 336
15:18:40 INFO - TotalTime: 336
15:18:40 INFO - WaitTime: 346
15:18:40 INFO - Complete
15:18:43 INFO - 127.0.0.1 - - [26/Feb/2019 15:18:43] "POST / HTTP/1.1" 200 -
15:18:43 INFO - raptor-control-server received webext_status: raptor runner.js is loaded!
15:18:43 INFO - 127.0.0.1 - - [26/Feb/2019 15:18:43] "GET /raptor-tp6m-youtube-geckoview.json HTTP/1.1" 200 -
15:18:43 INFO - raptor-control-server reading test settings from raptor-tp6m-youtube-geckoview.json
15:18:43 INFO - raptor-control-server sent test settings to web ext runner
15:18:43 INFO - 127.0.0.1 - - [26/Feb/2019 15:18:43] "POST / HTTP/1.1" 200 -
15:18:43 INFO - raptor-control-server received webext_status: * pausing 30 seconds to let browser settle... *
15:19:13 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:13] "POST / HTTP/1.1" 200 -
15:19:13 INFO - raptor-control-server received webext_status: running 15 pagecycles of https://www.youtube.com
15:19:14 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:14] "POST / HTTP/1.1" 200 -
15:19:14 INFO - raptor-control-server received webext_status: begin pagecycle 1
15:19:15 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:15] "POST / HTTP/1.1" 200 -
15:19:15 INFO - raptor-control-server received webext_status: update tab 0
15:19:15 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:15] "POST / HTTP/1.1" 200 -
15:19:15 INFO - raptor-control-server received webext_status: test tab updated 0
15:19:17 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:17] "POST / HTTP/1.1" 200 -
15:19:17 INFO - raptor-control-server received webext_status: results received
15:19:18 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:18] "POST / HTTP/1.1" 200 -
15:19:18 INFO - raptor-control-server received webext_status: begin pagecycle 2
15:19:19 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:19] "POST / HTTP/1.1" 200 -
15:19:19 INFO - raptor-control-server received webext_status: update tab 0
15:19:19 INFO - 127.0.0.1 - - [26/Feb/2019 15:19:19] "POST / HTTP/1.1" 200 -
15:19:19 INFO - raptor-control-server received webext_status: test tab updated 0
15:20:18 INFO - 127.0.0.1 - - [26/Feb/2019 15:20:18] "POST / HTTP/1.1" 200 -
15:20:18 INFO - raptor-control-server received webext_raptor-page-timeout: [u'raptor-tp6m-youtube-geckoview', u'https://www.youtube.com']
15:20:18 INFO - 127.0.0.1 - - [26/Feb/2019 15:20:18] "POST / HTTP/1.1" 200 -
15:20:18 INFO - raptor-control-server received webext_status: __raptor_shutdownBrowser
15:20:18 INFO - raptor-control-server shutting down android app org.mozilla.geckoview_example
15:20:19 INFO - adb shell_output: adb -s ZY322M59S3 wait-for-device shell am force-stop org.mozilla.geckoview_example; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
15:20:21 INFO - adb command_output: adb -s ZY322M59S3 wait-for-device pull /sdcard/raptor/profile/minidumps /tmp/tmpJ5UDIY/minidumps, timeout: None, timedout: None, exitcode: 0, output: pull: building file list...
15:20:21 INFO - /sdcard/raptor/profile/minidumps/: 0 files pulled.
15:20:21 INFO - raptor-mitmproxy Stopping mitmproxy playback, klling process 5526
15:20:21 INFO - Replaying from files: ['/builds/worker/workspace/testing/raptor/android-youtube.mp']
15:20:31 INFO - raptor-mitmproxy Successfully killed the mitmproxy playback process
15:20:31 INFO - raptor-main removing webext /builds/worker/workspace/build/tests/raptor/webext/raptor
15:20:31 INFO - results-handler summarizing raptor test results
15:20:31 INFO - raptor-output ignoring the first dcf value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first fcp value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: fcp
15:20:31 INFO - raptor-output ignoring the first fnbpaint value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first ttfi value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first loadtime value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: loadtime
15:20:31 INFO - raptor-output ignoring the first dcf value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first fcp value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: fcp
15:20:31 INFO - raptor-output ignoring the first fnbpaint value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first ttfi value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first loadtime value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: loadtime
15:20:31 INFO - raptor-output ignoring the first dcf value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first fcp value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: fcp
15:20:31 INFO - raptor-output ignoring the first fnbpaint value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first ttfi value due to initial pageload noise
15:20:31 INFO - raptor-output ignoring the first loadtime value due to initial pageload noise
15:20:31 INFO - raptor-output turning on subtest alerting for measurement type: loadtime
15:20:31 INFO - raptor-output PERFHERDER_DATA: {"framework": {"name": "raptor"}, "suites": [{"extraOptions": [], "name": "raptor-tp6m-amazon-geckoview", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 873.46, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 468.0, "replicates": [927, 604, 382, 435, 382, 501, 637, 403, 601, 382, 427, 571, 381, 554, 626], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 654.5, "shouldAlert": true, "replicates": [1278, 829, 620, 630, 559, 679, 858, 584, 773, 567, 617, 813, 581, 760, 800], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 570.5, "replicates": [1065, 730, 513, 541, 477, 600, 754, 498, 689, 490, 532, 703, 492, 676, 716], "unit": "ms"}, {"name": "ttfi", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5837.0, "replicates": [5412, 7362, 4251, 4319, 3394, 3184, 7427, 3206, 8488, 4330, 5836, 8088, 14776, 5838, 8276], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 497.5, "shouldAlert": true, "replicates": [1408, 624, 400, 474, 400, 521, 654, 424, 617, 409, 448, 591, 409, 595, 642], "unit": "ms"}], "type": "pageload", "unit": "ms"}, {"extraOptions": [], "name": "raptor-tp6m-facebook-geckoview", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 2184.64, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1112.0, "replicates": [1997, 1340, 1191, 1192, 1416, 1133, 1058, 1022, 1210, 1009, 1091, 993, 1366, 1069, 1046], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1185.5, "shouldAlert": true, "replicates": [2081, 1425, 1268, 1282, 1503, 1228, 1135, 1097, 1298, 1087, 1134, 1076, 1447, 1143, 1136], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1128.0, "replicates": [2009, 1363, 1212, 1227, 1441, 1168, 1076, 1041, 1231, 1028, 1069, 1025, 1392, 1088, 1075], "unit": "ms"}, {"name": "ttfi", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 16349.5, "replicates": [10001, 16332, 2275, 18063, 2758, 17734, 2378, 19130, 12209, 17673, 2368, 19957, 16367, 2776, 17854], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 2045.0, "shouldAlert": true, "replicates": [3392, 2379, 2208, 2258, 2363, 2086, 1949, 1969, 5245, 1944, 1988, 1949, 2245, 1996, 2004], "unit": "ms"}], "type": "pageload", "unit": "ms"}, {"extraOptions": [], "name": "raptor-tp6m-google-geckoview", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 200.48, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 132.5, "replicates": [463, 144, 139, 136, 129, 106, 102, 115, 128, 137, 133, 132, 137, 137, 122], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 258.0, "shouldAlert": true, "replicates": [775, 257, 259, 254, 260, 222, 217, 227, 248, 262, 260, 261, 265, 274, 245], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 173.5, "replicates": [672, 181, 181, 172, 166, 144, 130, 145, 161, 179, 175, 175, 178, 196, 161], "unit": "ms"}, {"name": "ttfi", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 393.5, "replicates": [1372, 520, 537, 647, 393, 378, 352, 361, 394, 404, 388, 380, 398, 425, 379], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 138.5, "shouldAlert": true, "replicates": [1137, 149, 146, 141, 137, 113, 105, 119, 136, 142, 139, 138, 143, 146, 128], "unit": "ms"}], "type": "pageload", "unit": "ms"}]}
15:20:31 INFO - raptor-output results can also be found locally at: /builds/worker/workspace/build/raptor.json
15:20:31 INFO - raptor-control-server shutting down control server
15:20:32 INFO - raptor-main removing reverse socket connections
15:20:32 INFO - adb command_output: adb -s ZY322M59S3 wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
15:20:32 INFO - raptor-main finished
15:20:32 INFO - raptor-main TEST-UNEXPECTED-FAIL: test 'raptor-tp6m-youtube-geckoview' timed out loading test page: https://www.youtube.com

Comment 1

[Intermittent Failures Robot]

1 failures in 2981 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• android-hw-g5-7-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1530722&startday=2019-02-25&endday=2019-03-03&tree=all

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 3

[Cristian Brindusan [:cbrindusan]]

Recent log failure:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=237598798&repo=mozilla-inbound&lineNumber=1737

Comment 4

[Intermittent Failures Robot]

1 failures in 2843 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-inbound: 1

Platform breakdown:

• android-hw-g5-7-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1530722&startday=2019-04-01&endday=2019-04-07&tree=all

Comment 5

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 6

[Intermittent Failures Robot]

1 failures in 4131 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• android-hw-g5-7-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1530722&startday=2019-04-29&endday=2019-05-05&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 4753 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• android-hw-p2-8-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1530722&startday=2019-06-10&endday=2019-06-16&tree=all