Closed Bug 1603014 Opened 4 years ago Closed 4 years ago

Intermittent browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Test timed out -

Categories

(Firefox :: PDF Viewer, defect, P5)

defect

Tracking

()

RESOLVED FIXED
Firefox 74
Tracking Status
firefox73 --- fixed
firefox74 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])

Attachments

(3 files)

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


[task 2019-12-11T02:14:32.073Z] 02:14:32 INFO - TEST-START | browser/extensions/pdfjs/test/browser_pdfjs_views.js
[task 2019-12-11T02:14:32.872Z] 02:14:32 INFO - GECKO(7500) | MEMORY STAT | vsize 2104192MB | vsizeMaxContiguous 65346870MB | residentFast 316MB | heapAllocated 141MB
[task 2019-12-11T02:14:32.872Z] 02:14:32 INFO - TEST-OK | browser/extensions/pdfjs/test/browser_pdfjs_views.js | took 805ms
[task 2019-12-11T02:14:32.890Z] 02:14:32 INFO - checking window state
[task 2019-12-11T02:14:32.909Z] 02:14:32 INFO - TEST-START | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js
[task 2019-12-11T02:16:02.941Z] 02:16:02 INFO - TEST-INFO | started process screenshot
[task 2019-12-11T02:16:03.026Z] 02:16:03 INFO - TEST-INFO | screenshot: exit 0
[task 2019-12-11T02:16:03.027Z] 02:16:03 INFO - Buffered messages logged at 02:14:32
[task 2019-12-11T02:16:03.027Z] 02:16:03 INFO - Entering test bound test
[task 2019-12-11T02:16:03.027Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | pdf handler defaults to always-ask is false -
[task 2019-12-11T02:16:03.028Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | pdf handler defaults to internal -
[task 2019-12-11T02:16:03.028Z] 02:16:03 INFO - Pref action: 3
[task 2019-12-11T02:16:03.028Z] 02:16:03 INFO - Buffered messages logged at 02:14:33
[task 2019-12-11T02:16:03.028Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2019-12-11T02:16:03.029Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'button#zoomIn' has been found - {} == true -
[task 2019-12-11T02:16:03.029Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "130%" == "130%" -
[task 2019-12-11T02:16:03.029Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed in using the '+' (zoom in) button - true == true -
[task 2019-12-11T02:16:03.030Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'button#zoomOut' has been found - {} == true -
[task 2019-12-11T02:16:03.030Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "100%" == "100%" -
[task 2019-12-11T02:16:03.031Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed out using the '-' (zoom out) button - true == true -
[task 2019-12-11T02:16:03.031Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "110%" == "110%" -
[task 2019-12-11T02:16:03.031Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed in using the CTRL++ keys - true == true -
[task 2019-12-11T02:16:03.032Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "100%" == "100%" -
[task 2019-12-11T02:16:03.032Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed out using the CTRL+- keys - true == true -
[task 2019-12-11T02:16:03.032Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'select#scaleSelect' has been found - {"0":{},"1":{},"2":{},"3":{},"4":{},"5":{},"6":{},"7":{},"8":{},"9":{},"10":{},"11":{},"12":{}} == true -
[task 2019-12-11T02:16:03.032Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "50%" == "50%" -
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed using the zoom picker - true == true -
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - Leaving test bound test
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - Entering test bound test_browser_zoom
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - Buffered messages logged at 02:14:34
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoom in makes the page bigger. -
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - Buffered messages logged at 02:14:35
[task 2019-12-11T02:16:03.033Z] 02:16:03 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2019-12-11T02:16:03.034Z] 02:16:03 INFO - Buffered messages logged at 02:15:17
[task 2019-12-11T02:16:03.034Z] 02:16:03 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
[task 2019-12-11T02:16:03.034Z] 02:16:03 INFO - Buffered messages finished
[task 2019-12-11T02:16:03.034Z] 02:16:03 INFO - TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Test timed out -

Keywords: regression

SpecialPowers.spawn bounces tasks off SpecialPowersParent before sending them
to SpecialPowersChild, which means that any operations which are sent
immediately afterwards and take a more direct route (like zoom changes) will
get to the content process before the task starts running. In the case of
tasks which depending on registering a listener before said operations take
place, this is obviously a problem.

So this patch fixes those cases in this test to wait for the listeners to be
setup before continuing.

Assignee: nobody → kmaglione+bmo
Status: NEW → ASSIGNED
Whiteboard: [retriggered][stockwell disable-recommended] → [stockwell needswork][retriggered]

There are 51 total failures in the last 7 days on macosx1014-64-shippable opt mostly and some on macosx1014-64 debug

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=283399239&repo=autoland&lineNumber=7182

[task 2020-01-03T22:35:04.495Z] 22:35:04 INFO - TEST-START | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js
[task 2020-01-03T22:35:26.285Z] 22:35:26 INFO - GECKO(2167) | 2020-01-03 22:35:26.273 firefox[2167:22448] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
[task 2020-01-03T22:36:34.527Z] 22:36:34 INFO - TEST-INFO | started process screencapture
[task 2020-01-03T22:36:34.744Z] 22:36:34 INFO - TEST-INFO | screencapture: exit 0
[task 2020-01-03T22:36:34.744Z] 22:36:34 INFO - Buffered messages logged at 22:35:04
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - Entering test bound test
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | pdf handler defaults to always-ask is false -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | pdf handler defaults to internal -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - Pref action: 3
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - Buffered messages logged at 22:35:05
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'button#zoomIn' has been found - {} == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "130%" == "130%" -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed in using the '+' (zoom in) button - true == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'button#zoomOut' has been found - {} == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "100%" == "100%" -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed out using the '-' (zoom out) button - true == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "110%" == "110%" -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed in using the CTRL++ keys - true == true -
[task 2020-01-03T22:36:34.745Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "100%" == "100%" -
[task 2020-01-03T22:36:34.746Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed out using the CTRL+- keys - true == true -
[task 2020-01-03T22:36:34.746Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Element 'select#scaleSelect' has been found - {"0":{},"1":{},"2":{},"3":{},"4":{},"5":{},"6":{},"7":{},"8":{},"9":{},"10":{},"11":{},"12":{}} == true -
[task 2020-01-03T22:36:34.746Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Content has correct zoom - "50%" == "50%" -
[task 2020-01-03T22:36:34.746Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoomed using the zoom picker - true == true -
[task 2020-01-03T22:36:34.747Z] 22:36:34 INFO - Leaving test bound test
[task 2020-01-03T22:36:34.747Z] 22:36:34 INFO - Entering test bound test_browser_zoom
[task 2020-01-03T22:36:34.747Z] 22:36:34 INFO - Buffered messages logged at 22:35:06
[task 2020-01-03T22:36:34.747Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2020-01-03T22:36:34.747Z] 22:36:34 INFO - Buffered messages logged at 22:35:07
[task 2020-01-03T22:36:34.748Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2020-01-03T22:36:34.748Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Zoom in makes the page bigger. -
[task 2020-01-03T22:36:34.748Z] 22:36:34 INFO - TEST-PASS | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | document content has viewer UI - {} == true -
[task 2020-01-03T22:36:34.748Z] 22:36:34 INFO - Buffered messages logged at 22:35:49
[task 2020-01-03T22:36:34.748Z] 22:36:34 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - Buffered messages finished
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Test timed out -
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - GECKO(2167) | MEMORY STAT | vsize 7625MB | residentFast 324MB | heapAllocated 97MB
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - TEST-OK | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | took 90044ms
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Found a tab after previous test timed out: http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf -
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - checking window state
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-03T22:36:34.749Z] 22:36:34 INFO - TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | Uncaught exception received from previously timed out test - [Exception... "(null)" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "<unknown>" data: no]
[task 2020-01-03T22:36:35.880Z] 22:36:35 INFO - GECKO(2167) | Completed ShutdownLeaks collections in process 2196

Whiteboard: [stockwell needswork][retriggered] → [stockwell needswork:owner][retriggered]

I've created a patch to disable this on mac opt if needed.

Pushed by ccoroiu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/171467ebb7b2
Disable on OSX for frequent failures. r=jmaher
Keywords: leave-open
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]
Pushed by maglione.k@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/12b3c389fd6d
Wait for content tasks to add listener before triggering things they're listening for. r=mccr8
Attachment #9119639 - Attachment description: Bug 1603014 - unskip browser_pdfjs_zoom.js r=jmaher → Bug 1603014 - unskip browser_pdfjs_zoom.js on mac r=jmaher
Pushed by ccoroiu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/51cc7dcecf6d
unskip browser_pdfjs_zoom.js on mac r=jmaher
Whiteboard: [retriggered][stockwell disabled] → [retriggered]
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → Firefox 74
Flags: needinfo?(kmaglione+bmo)
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: