Closed Bug 1687362 Opened 3 years ago Closed 3 years ago

Intermittent toolkit/content/tests/browser/browser_datetime_datepicker.js | Test timed out -

Categories

(Toolkit :: General, defect, P5)

Product:
Toolkit
Component:
General
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
91 Branch
Tracking Flags:
Tracking Status
firefox91 --- fixed

People

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

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(2 files)

mozilla-test-fail-screenshot_kfnse87z.png
118.22 KB, image/png
Details
Bug 1687362 - Make DateTimeTestHelper.waitForPickerReady wait until the datepicker.xhtml document is loaded. r?emilio!
48 bytes, text/x-phabricator-request
Details | Review

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

[task 2021-01-18T18:58:52.675Z] 18:58:52     INFO - TEST-START | toolkit/content/tests/browser/browser_datetime_datepicker.js
[task 2021-01-18T18:59:37.775Z] 18:59:37     INFO - TEST-INFO | started process screencapture
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - TEST-INFO | screencapture: exit 0
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - Buffered messages logged at 18:58:52
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - Entering test bound test_datepicker_today
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html, <input type='date'>" line: 0}]
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - Buffered messages logged at 18:58:53
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | "January 2021" == "January 2021" - 
[task 2021-01-18T18:59:37.855Z] 18:59:37     INFO - Leaving test bound test_datepicker_today
[task 2021-01-18T18:59:37.856Z] 18:59:37     INFO - Entering test bound test_datepicker_open
[task 2021-01-18T18:59:37.856Z] 18:59:37     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html, <input type="date" value="2016-12-15">" line: 0}]
[task 2021-01-18T18:59:37.856Z] 18:59:37     INFO - Buffered messages finished
[task 2021-01-18T18:59:37.856Z] 18:59:37     INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/browser/browser_datetime_datepicker.js | Test timed out - ```

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=331315250&repo=autoland&lineNumber=3130

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There are 23 total failures in the last 7 days on

task 2021-05-17T23:59:35.437Z] 23:59:35 INFO - TEST-INFO | started process screentopng
[task 2021-05-17T23:59:35.687Z] 23:59:35 INFO - TEST-INFO | screentopng: exit 0
[task 2021-05-17T23:59:35.687Z] 23:59:35 INFO - Buffered messages logged at 23:58:05
[task 2021-05-17T23:59:35.688Z] 23:59:35 INFO - Entering test bound test_datepicker_today
[task 2021-05-17T23:59:35.688Z] 23:59:35 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html, <input type='date'>" line: 0}]
[task 2021-05-17T23:59:35.688Z] 23:59:35 INFO - Console message: Invalid chrome URI (need path): chrome://global/
[task 2021-05-17T23:59:35.688Z] 23:59:35 INFO - Buffered messages logged at 23:58:06
[task 2021-05-17T23:59:35.689Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | "May 2021" == "May 2021" -
[task 2021-05-17T23:59:35.690Z] 23:59:35 INFO - Leaving test bound test_datepicker_today
[task 2021-05-17T23:59:35.690Z] 23:59:35 INFO - Entering test bound test_datepicker_open
[task 2021-05-17T23:59:35.691Z] 23:59:35 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html, <input type="date" value="2016-12-15">" line: 0}]
[task 2021-05-17T23:59:35.691Z] 23:59:35 INFO - Console message: Invalid chrome URI (need path): chrome://global/
[task 2021-05-17T23:59:35.694Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | "December 2016" == "December 2016" -
[task 2021-05-17T23:59:35.694Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | 2016-12 - ["27","28","29","30","1","2","3","4","5","6","7","8","9","10","11","12","13","14","15","16","17","18","19","20","21","22","23","24","25","26","27","28","29","30","31","1","2","3","4","5","6","7"] deepEqual ["27","28","29","30","1","2","3","4","5","6","7","8","9","10","11","12","13","14","15","16","17","18","19","20","21","22","23","24","25","26","27","28","29","30","31","1","2","3","4","5","6","7"] -
[task 2021-05-17T23:59:35.695Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | 2016-12 classNames - [["weekend","outside"],["outside"],["outside"],["outside"],[],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend"],[],[],[],["selection"],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend","outside"],["outside"],["outside"],["outside"],["outside"],["outside"],["weekend","outside"]] deepEqual [["weekend","outside"],["outside"],["outside"],["outside"],[],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend"],[],[],[],["selection"],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend"],[],[],[],[],[],["weekend"],["weekend","outside"],["outside"],["outside"],["outside"],["outside"],["outside"],["weekend","outside"]] -
[task 2021-05-17T23:59:35.695Z] 23:59:35 INFO - Leaving test bound test_datepicker_open
[task 2021-05-17T23:59:35.696Z] 23:59:35 INFO - Entering test bound test_datepicker_focus_change
[task 2021-05-17T23:59:35.697Z] 23:59:35 INFO - Buffered messages logged at 23:58:07
[task 2021-05-17T23:59:35.699Z] 23:59:35 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html,<input id=date type=date><input id=other>" line: 0}]
[task 2021-05-17T23:59:35.699Z] 23:59:35 INFO - Console message: Invalid chrome URI (need path): chrome://global/
[task 2021-05-17T23:59:35.700Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | datepicker x position: 167 should be equal(-ish) to 167 -
[task 2021-05-17T23:59:35.701Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | datepicker y position: 211 should be equal(-ish) to 211 -
[task 2021-05-17T23:59:35.702Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | Panel should be visible -
[task 2021-05-17T23:59:35.704Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | Panel should be closed now -
[task 2021-05-17T23:59:35.705Z] 23:59:35 INFO - Leaving test bound test_datepicker_focus_change
[task 2021-05-17T23:59:35.706Z] 23:59:35 INFO - Entering test bound test_datepicker_keyboard_open
[task 2021-05-17T23:59:35.707Z] 23:59:35 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html,<input id=date type=date value=2016-12-15>" line: 0}]
[task 2021-05-17T23:59:35.708Z] 23:59:35 INFO - Console message: Invalid chrome URI (need path): chrome://global/
[task 2021-05-17T23:59:35.709Z] 23:59:35 INFO - Buffered messages logged at 23:58:08
[task 2021-05-17T23:59:35.710Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | datepicker x position: 167 should be equal(-ish) to 167 -
[task 2021-05-17T23:59:35.710Z] 23:59:35 INFO - TEST-PASS | toolkit/content/tests/browser/browser_datetime_datepicker.js | datepicker y position: 211 should be equal(-ish) to 211 -
[task 2021-05-17T23:59:35.712Z] 23:59:35 INFO - Console message: [JavaScript Error: "TypeError: can't access property "ownerGlobal", aElement is null" {file: "resource://gre/actors/DateTimePickerChild.jsm" line: 64}]
[task 2021-05-17T23:59:35.712Z] 23:59:35 INFO - removeListeners@resource://gre/actors/DateTimePickerChild.jsm:64:5
[task 2021-05-17T23:59:35.712Z] 23:59:35 INFO - close@resource://gre/actors/DateTimePickerChild.jsm:33:10
[task 2021-05-17T23:59:35.713Z] 23:59:35 INFO - receiveMessage@resource://gre/actors/DateTimePickerChild.jsm:94:14
[task 2021-05-17T23:59:35.713Z] 23:59:35 INFO -
[task 2021-05-17T23:59:35.714Z] 23:59:35 INFO - Console message: Invalid chrome URI (need path): chrome://global/
[task 2021-05-17T23:59:35.716Z] 23:59:35 INFO - Console message: [JavaScript Error: "TypeError: can't access property "ownerGlobal", aElement is null" {file: "resource://gre/actors/DateTimePickerChild.jsm" line: 64}]
[task 2021-05-17T23:59:35.716Z] 23:59:35 INFO - removeListeners@resource://gre/actors/DateTimePickerChild.jsm:64:5
[task 2021-05-17T23:59:35.719Z] 23:59:35 INFO - close@resource://gre/actors/DateTimePickerChild.jsm:33:10
[task 2021-05-17T23:59:35.720Z] 23:59:35 INFO - receiveMessage@resource://gre/actors/DateTimePickerChild.jsm:94:14
[task 2021-05-17T23:59:35.720Z] 23:59:35 INFO -
[task 2021-05-17T23:59:35.720Z] 23:59:35 INFO - Buffered messages finished
[task 2021-05-17T23:59:35.722Z] 23:59:35 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/browser/browser_datetime_datepicker.js | Test timed out -
[task 2021-05-17T23:59:35.724Z] 23:59:35 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-05-17T23:59:35.725Z] 23:59:35 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/browser/browser_datetime_datepicker.js | Uncaught exception received from previously timed out test - PickerReady listener not removed before the end of test
[task 2021-05-17T23:59:35.727Z] 23:59:35 INFO - GECKO(7558) | MEMORY STAT | vsize 11708MB | residentFast 372MB | heapAllocated 113MB
[task 2021-05-17T23:59:35.727Z] 23:59:35 INFO - TEST-OK | toolkit/content/tests/browser/browser_datetime_datepicker.js | took 90145ms
[task 2021-05-17T23:59:35.728Z] 23:59:35 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-05-17T23:59:35.732Z] 23:59:35 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/browser/browser_datetime_datepicker.js | Found a tab after previous test timed out: data:text/html,<input id=date type=date value=2016-12-15> -
[task 2021-05-17T23:59:35.732Z] 23:59:35 INFO - GECKO(7558) | [Parent 7558: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f01bb5a1400 == 7 [pid = 7558] [id = 13]
[task 2021-05-17T23:59:35.733Z] 23:59:35 INFO - GECKO(7558) | [Parent 7558: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 14 (7f01bb561040) [pid = 7558] [serial = 41] [outer = 0]

Dave, can you take a look?

Flags: needinfo?(dtownsend)
Whiteboard: [stockwell needswork:owner]

Mike, you reviewed the initial test here, can you take a look?

Flags: needinfo?(dtownsend) → needinfo?(mconley)

Looks like we're timing out because the test is waiting for the picker panel to close, and it never is.

This error message in the log might point to the problem:

[task 2021-05-24T06:30:20.826Z] 06:30:20     INFO - Console message: [JavaScript Error: "TypeError: can't access property "ownerGlobal", aElement is null" {file: "resource://gre/actors/DateTimePickerChild.jsm" line: 64}]
[task 2021-05-24T06:30:20.827Z] 06:30:20     INFO - removeListeners@resource://gre/actors/DateTimePickerChild.jsm:64:5
[task 2021-05-24T06:30:20.827Z] 06:30:20     INFO - close@resource://gre/actors/DateTimePickerChild.jsm:33:10
[task 2021-05-24T06:30:20.828Z] 06:30:20     INFO - receiveMessage@resource://gre/actors/DateTimePickerChild.jsm:94:14

This helps to fix an intermittent that occurs when the iframe that loads
the picker sometimes has an opportunity to fire a "load" event before
datepicker.xhtml is actually loaded (perhaps from the initial about:blank
document). This made it so that waitForPickerReady would attach the
PickerReady CustomEvent listener on the wrong document, and the test
would time out despite the PickerReady event properly firing.

The fix is to ensure that the load event that waitForPickerReady waits
for is for the datepicker.xhtml document.

Assignee: nobody → mconley

Here's a try push of the patch with a bunch of retriggers (and inane logging): https://treeherder.mozilla.org/jobs?repo=try&revision=e067c5ced2cec986574399de7ed43f34d8d1c148

Flags: needinfo?(mconley)
Pushed by mconley@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/1559a4611ae1
Make DateTimeTestHelper.waitForPickerReady wait until the datepicker.xhtml document is loaded. r=emilio

https://hg.mozilla.org/mozilla-central/rev/1559a4611ae1

Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
status-firefox91: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 91 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: