Closed Bug 1614048 Opened 5 years ago Closed 5 years ago

Intermittent raptor-main Critical: TEST-UNEXPECTED-FAIL: test 'raptor-tp6-imdb-firefox' timed out loading test page: https://www.imdb.com/title/tt0084967/?ref_=nv_sr_2 pending metrics:

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Version:
Version 3
Platform:
x86_64
Windows 10
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=287884025&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aePN_YVYQzycGs0nxySAWA/runs/0/artifacts/public/logs/live_backing.log

[task 2020-02-07T21:02:31.946Z] 21:02:31 INFO - raptor-control-server Info: received webext_results: {u'expected_browser_cycles': 1, u'subtest_unit': u'ms', u'name': u'raptor-tp6-fandom-firefox', u'lower_is_better': True, u'measurements': {u'dcf': [1473, 459, 367, 395, 274, 264, 247, 872, 259, 289, 269, 260, 265, 270, 270, 270, 299, 262, 257, 272, 279, 263, 259, 861, 255], u'fcp': [1572, 519, 420, 440, 339, 319, 290, 273, 315, 346, 333, 322, 320, 326, 321, 315, 357, 315, 302, 334, 337, 326, 311, 907, 315], u'fnbpaint': [1490, 471, 386, 408, 308, 287, 255, 239, 282, 313, 299, 289, 291, 291, 294, 281, 324, 280, 268, 302, 287, 294, 283, 874, 281], u'loadtime': [1781, 586, 490, 520, 385, 381, 514, 911, 384, 413, 391, 368, 376, 692, 1455, 372, 425, 378, 372, 397, 380, 385, 370, 977, 369]}, u'browser_cycle': u'1', u'subtest_lower_is_better': True, u'cold': False, u'browser': u'Firefox 74.0a1 20200207035551', u'type': u'pageload', u'page': u'https://www.fandom.com/articles/fallout-76-will-live-and-die-on-the-creativity-of-its-playerbase', u'unit': u'ms', u'alert_threshold': 2}
[task 2020-02-07T21:02:31.946Z] 21:02:31 INFO - perftest-results-handler Info: received results in RaptorResultsHandler.add
[task 2020-02-07T21:02:31.948Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] closed tab 1"
[task 2020-02-07T21:02:31.948Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] pageload test finished"
[task 2020-02-07T21:02:31.950Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] posting to control server"
[task 2020-02-07T21:02:31.950Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] "
[task 2020-02-07T21:02:31.955Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] cancelled raptor alarm raptor-page-timeout"
[task 2020-02-07T21:02:31.960Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] post success"
[task 2020-02-07T21:02:31.960Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] post success"
[task 2020-02-07T21:02:31.979Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] Removed tab: 1"
[task 2020-02-07T21:02:31.980Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] posting to control server"
[task 2020-02-07T21:02:31.980Z] 21:02:31 INFO - PID 1976 | console.log: "[raptor-runnerjs] Removed tab: 1"
[task 2020-02-07T21:02:31.999Z] 21:02:31 INFO - raptor-control-server Info: received request to shutdown the browser
[task 2020-02-07T21:02:32.000Z] 21:02:31 INFO - raptor-control-server Info: shutting down browser (pid: 1976)
[task 2020-02-07T21:02:32.000Z] 21:02:32 INFO - raptor-control-server Info: received webext_status: Removed tab: 1
[task 2020-02-07T21:02:32.000Z] 21:02:32 INFO - PID 1976 | console.log: "[raptor-runnerjs] post success"
[task 2020-02-07T21:02:32.005Z] 21:02:32 INFO - PID 1976 | console.log: "[raptor-runnerjs] post success"
[task 2020-02-07T21:02:33.801Z] 21:02:33 INFO - raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 6452
[task 2020-02-07T21:02:33.818Z] 21:02:33 INFO - raptor-mitmproxy Info: Successfully killed the mitmproxy playback process with exit code 572
[task 2020-02-07T21:02:33.818Z] 21:02:33 INFO - raptor-mitmproxy Info: Turning off the browser proxy
[task 2020-02-07T21:02:33.818Z] 21:02:33 INFO - raptor-mitmproxy Info: writing: C:\Users\task_1581104480\build\application\firefox\distribution\policies.json
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - raptor-webext Info: removing webext C:\Users\task_1581104480\build\tests\raptor\raptor\webextension....\webext\raptor
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - perftest-results-handler Info: summarizing raptor test results
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - perftest-output Info: ignoring the first dcf value due to initial pageload noise
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - perftest-output Info: ignoring the first fcp value due to initial pageload noise
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - perftest-output Info: turning on subtest alerting for measurement type: fcp
[task 2020-02-07T21:02:33.819Z] 21:02:33 INFO - perftest-output Info: ignoring the first fnbpaint value due to initial pageload noise
[task 2020-02-07T21:02:33.820Z] 21:02:33 INFO - perftest-output Info: ignoring the first loadtime value due to initial pageload noise
[task 2020-02-07T21:02:33.820Z] 21:02:33 INFO - perftest-output Info: turning on subtest alerting for measurement type: loadtime
[task 2020-02-07T21:02:33.829Z] 21:02:33 INFO - perftest-output Info: ignoring the first dcf value due to initial pageload noise
[task 2020-02-07T21:02:33.829Z] 21:02:33 INFO - perftest-output Info: ignoring the first fcp value due to initial pageload noise
[task 2020-02-07T21:02:33.829Z] 21:02:33 INFO - perftest-output Info: turning on subtest alerting for measurement type: fcp
[task 2020-02-07T21:02:33.830Z] 21:02:33 INFO - perftest-output Info: ignoring the first fnbpaint value due to initial pageload noise
[task 2020-02-07T21:02:33.830Z] 21:02:33 INFO - perftest-output Info: ignoring the first loadtime value due to initial pageload noise
[task 2020-02-07T21:02:33.830Z] 21:02:33 INFO - perftest-output Info: turning on subtest alerting for measurement type: loadtime
[task 2020-02-07T21:02:33.831Z] 21:02:33 INFO - perftest-output Info: screen captures can be found locally at: C:\Users\task_1581104480\build\screenshots.html
[task 2020-02-07T21:02:33.831Z] 21:02:33 INFO - perftest-output Info: PERFHERDER_DATA: {"framework": {"name": "raptor"}, "application": {"version": "74.0a1", "name": "firefox"}, "suites": [{"value": 315.26, "extraOptions": [], "name": "raptor-tp6-fandom-firefox", "tags": ["pageload", "warm"], "lowerIsBetter": true, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 270.0, "replicates": [1473, 459, 367, 395, 274, 264, 247, 872, 259, 289, 269, 260, 265, 270, 270, 270, 299, 262, 257, 272, 279, 263, 259, 861, 255], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 324.0, "shouldAlert": true, "replicates": [1572, 519, 420, 440, 339, 319, 290, 273, 315, 346, 333, 322, 320, 326, 321, 315, 357, 315, 302, 334, 337, 326, 311, 907, 315], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 291.0, "replicates": [1490, 471, 386, 408, 308, 287, 255, 239, 282, 313, 299, 289, 291, 291, 294, 281, 324, 280, 268, 302, 287, 294, 283, 874, 281], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 388.0, "shouldAlert": true, "replicates": [1781, 586, 490, 520, 385, 381, 514, 911, 384, 413, 391, 368, 376, 692, 1455, 372, 425, 378, 372, 397, 380, 385, 370, 977, 369], "unit": "ms"}], "type": "pageload", "alertThreshold": 2.0, "unit": "ms"}, {"value": 619.74, "extraOptions": [], "name": "raptor-tp6-imgur-firefox", "tags": ["pageload", "warm"], "lowerIsBetter": true, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 462.5, "replicates": [2014, 698, 611, 604, 439, 464, 425, 630, 430, 465, 450, 426, 423, 440, 2535, 639, 486, 442, 1474, 457, 545, 461, 411, 456, 476], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 525.5, "shouldAlert": true, "replicates": [1136, 791, 649, 744, 497, 531, 513, 677, 502, 533, 525, 487, 495, 476, 2580, 146, 526, 490, 1524, 519, 597, 526, 461, 524, 539], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 498.5, "replicates": [952, 767, 628, 629, 460, 507, 483, 657, 463, 503, 495, 453, 472, 463, 2548, 128, 506, 461, 1489, 502, 573, 491, 432, 486, 509], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1217.0, "shouldAlert": true, "replicates": [6829, 1194, 1385, 1734, 2006, 1740, 1240, 1463, 757, 891, 750, 853, 862, 873, 3314, 1734, 1254, 2198, 2259, 892, 1036, 1115, 884, 833, 1256], "unit": "ms"}], "type": "pageload", "alertThreshold": 2.0, "unit": "ms"}]}
[task 2020-02-07T21:02:33.831Z] 21:02:33 INFO - perftest-output Info: results can also be found locally at: C:\Users\task_1581104480\build\raptor.json
[task 2020-02-07T21:02:34.177Z] 21:02:34 INFO - perftest-results-handler Info: Validating PERFHERDER_DATA against C:\Users\task_1581104480\mozharness\external_tools\performance-artifact-schema.json
[task 2020-02-07T21:02:34.207Z] 21:02:34 INFO - raptor-control-server Info: shutting down control server
[task 2020-02-07T21:02:34.506Z] 21:02:34 INFO - raptor-webext Info: finished
[task 2020-02-07T21:02:34.506Z] 21:02:34 ERROR - raptor-main Critical: TEST-UNEXPECTED-FAIL: test 'raptor-tp6-imdb-firefox' timed out loading test page: https://www.imdb.com/title/tt0084967/?ref_=nv_sr_2 pending metrics:
[task 2020-02-07T21:02:34.838Z] 21:02:34 ERROR - Return code: 1

Blocks: 1612795
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64

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

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.