Closed Bug 1130047 Opened 10 years ago Closed 8 years ago

TEST-UNEXPECTED-FAIL | /builds/slave/test/build/mozmill/testTodayPane.js | testTodayPane.js::testTodayPane

Categories

(Calendar :: General, defect)

Product:
Calendar
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: rkent, Assigned: Taraman)

References

Details

(Keywords: intermittent-failure)

No description provided.
From log file: Warning: Warning: Using guessed timezone America/Los_Angeles (UTC-0800/-0700). ... EXCEPTION: could not validate element Lookup: /id("messengerWindow")/id("tabmail-container")/id("today-pane-panel")/[1]/id("agenda-panel")/{"flex":"1"}/id("agenda-listbox")/[6]/anon({"anonid":"agenda-container-box"})/anon({"anonid":"agenda-description"})/[0]/anon({"anonid":"agenda-event-start"})/ with text Fri 13 Mar 2015 09:00 AM I suspect that the test fails because it tries to compare with a date time in the future but doesn't take into account that daylight saving time starts tomorrow in the used timezone. If correct, the test might succeed tomorrow after the timezone change.
I investigated a bit and there are two different failures here. The ones on 7th and 8th March fail to verify the timing of future event. Later ones cannot find the event for tomorrow. In the first case the date or time isn't wrong in Lightning due to daylight savings as suspected by Stefan. Rather if you switch to LA timezone and set time to 7th or 8th March 2AM you can run the test locally and witness it failing because the time is displayed without date in today pane. As I understand it this shouldn't happen for events falling into "Soon" section. It does not happen when running the test content manually. It also does not happen on later March dates when running the test. So it may be test specific issue or a real issue that's not easy to repro. Don't know yet which. The second failure remained bigger mystery. Removing any fixed sleeps from the test and looping it 100 times does not reproduce the failure locally. Other than something taking longer than expected possible reasons why the event is not there include: * it not being saved successfully * being saved on a different date * soon section not opening on click * soon section being open by default before the click that's supposed to show it I'll try a few more things with it but running on try with additional checks for abovementioned cases is probably the best way forward.
Depends on: 1262373
At first glance the test passed with the patch for bug 1262373. I run the test locally with the system date set to the day of DST change in Europe (27/3/2016) and the test failed: TEST-UNEXPECTED-FAIL | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane.js::testTodayPane INFO Passed: 2 INFO Failed: 1 INFO Skipped: 0 SUMMARY-PASS | testTodayPane.js::setupModule SUMMARY-PASS | testTodayPane.js::teardownTest SUMMARY-UNEXPECTED-FAIL | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane.js::testTodayPane Instead the test passed with the patch applied: Warning: Warning: Using guessed timezone Europe/Berlin (UTC+0100/+0200). This ZoneInfo timezone seems to match the operating system timezone this year. This ZoneInfo timezone was chosen based on the operating system timezone identifier "W. Europe Standard Time". TEST-START | c:\mozmilltest\mozmill\testTodayPane.js | setupModule TEST-PASS | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane.js::setupModule TEST-START | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane TEST-START | c:\mozmilltest\mozmill\testTodayPane.js | teardownTest TEST-PASS | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane.js::teardownTest TEST-PASS | c:\mozmilltest\mozmill\testTodayPane.js | testTodayPane.js::testTodayPane INFO Passed: 3 INFO Failed: 0 INFO Skipped: 0 SUMMARY-PASS | testTodayPane.js::setupModule SUMMARY-PASS | testTodayPane.js::teardownTest SUMMARY-PASS | testTodayPane.js::testTodayPane
Testing my current patches, I stumbled across this one again. At the Moment we have the Test failing at: controller.assertJS(lookup(dayPath).getNode().mDate.icalString == getIsoDate()); At this point, only the current day is tested against Date(). The current day is taken from the day-view header. I noticed the test passing on tryserver when I started the run during the day and failing when I started it in the evening. This made me think of a timezone Problem. So I introduced some debug code, to see what is happening: 18:02:38 INFO - console.log: debugstring: 20161019 should be 20161020 The latter being the date from getIsoDate(); So there is definitely a difference. This are the logs in timely order: [1] >15:38:37 INFO - console.log: debugstring: 20161019 should be 20161019 >15:54:01 INFO - console.log: debugstring: 20161019 should be 20161019 >-------------------------------------------------------------------------- >16:19:44 INFO - console.log: debugstring: 20161019 should be 20161020 >17:12:47 INFO - console.log: debugstring: 20161019 should be 20161020 >18:02:38 INFO - console.log: debugstring: 20161019 should be 20161020 >18:43:55 INFO - console.log: debugstring: 20161019 should be 20161020 >18:45:55 INFO - console.log: debugstring: 20161019 should be 20161020 >19:03:33 INFO - console.log: debugstring: 20161019 should be 20161020 >19:26:39 INFO - console.log: debugstring: 20161019 should be 20161020 >19:30:16 INFO - console.log: debugstring: 20161019 should be 20161020 So, until 15:54 the test passed, after 16:00 it failed. I changed the debug code to: > console.log(`debugstring: ${lookup(dayPath).getNode().mDate.icalString} should be ${getIsoDate()}`); > let field = lookup(dayPath).getNode().mDate; > console.log(`debugstring: TodayPane shows: ${field.toString()} in Timezone: ${field.timezoneOffset}`); > let datum = new Date(); > console.log(`debugstring: Date() returns: > ${datum.getFullYear()}-${datum.getMonth() + 1}-${datum.getDate()}/ > ${datum.getHours()}:${datum.getMinutes()} in Timezone: ${datum.getTimezoneOffset()}`); and the result during the day is: [2] >06:19:05 INFO - console.log: debugstring: 20161020 should be 20161020 >06:19:05 INFO - console.log: debugstring: TodayPane shows: 2016-10-20 in Timezone: -25200 >06:19:05 INFO - console.log: debugstring: Date() returns: 2016-10-20/6:19 in Timezone: 420 All Tests passed this time. Unfortunately, the daybox does not have a time set and the timezoneOffset it returns does not seem to be right... More investigation is needed, to find if it is dependant on timezone and if so, which. [1]: https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=c3fd09f6763b0df0eec1c84c0e9dee576845a172 [2]: https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=f38941fab14e909d8609fed1aedbcc37ef0e7c1c
Logged tonight: [1] >20:57:19 INFO - console.log: debugstring: 20161020 should be 20161021 >20:57:19 INFO - console.log: debugstring: TodayPane shows: 2016-10-20 in Timezone: -25200 >20:57:19 INFO - console.log: debugstring: Date() returns: 2016-10-20/20:57 in Timezone: 420 >19:41:51 INFO - console.log: debugstring: 20161020 should be 20161021 >19:41:51 INFO - console.log: debugstring: TodayPane shows: 2016-10-20 in Timezone: -25200 >19:41:51 INFO - console.log: debugstring: Date() returns: 2016-10-20/19:41 in Timezone: 420 Maybe some glitch in the getIsoDate function... [1]: https://treeherder.mozilla.org/logviewer.html#?job_id=23984&repo=try-comm-central#L6639 https://treeherder.mozilla.org/logviewer.html#?job_id=23984&repo=try-comm-central#L72225
Blocks: 938787
Looking at the JS reference, I found that toISOString always returns the UTC-Date. [1] This made the failure locally reproducible in a certain time-window: console.log: debugstring: 20161228 should be 20161227 console.log: debugstring: TodayPane shows: 2016-12-28 in Timezone: 3600 console.log: debugstring: Date() returns: 2016-12-28/0:1 in Timezone: -60 console.log: debugstring: toISOString() returns: 2016-12-27T23:01:22.950Z So a solution should be at hand soon. [1]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Date/toISOString
I assume you blocked the wrong bug here. Bug 938787 doesn't seem to related at all.
(In reply to Markus Adrario [:Taraman] from comment #86) > Looking at the JS reference, I found that toISOString always returns the > UTC-Date. [1] Nice find! This bug finally has some hope to get resolved.
You're right. Two numbers mixed up.
Blocks: 983787
No longer blocks: 938787
Assignee: nobody → Mozilla
Will be fixed with bug 1303626 Test Run from yesterday [1] shows: 16:59:18 INFO - console.log: debugstring: 20161227 should be 20161227 16:59:18 INFO - console.log: debugstring: TodayPane shows: 2016-12-27 in Timezone: -28800 16:59:18 INFO - console.log: debugstring: Date() returns: 2016-12-27/16:59 in Timezone: 480 16:59:18 INFO - console.log: debugstring: toISOString() returns: 2016-12-28T00:59:18.462Z As one can see, toISOString shows the wrong date. The corrected function now returns the correct string. [1]: https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=3788dcbcff1016effd1d41045da4f892259cc585
Depends on: 1303626
No longer depends on: 1262373
After Bug 1303626 has landed, this one is also fixed.
Status: NEW → RESOLVED
Closed: 8 years ago
OS: Linux → All
Hardware: x86_64 → All
Resolution: --- → FIXED
Target Milestone: --- → 5.5
Unfortunately the problem seems just to have moved to another line in the test and another time of day [1]. Will investigate further. [1]: https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=fb871d138ff7eba7a2ac515b0e939264c4952493
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
As the tests passed yesterday and as usual there are xpcshell test failures for daily builds today, this is likely another incarnation of the first day in a month test failure problem with ical.js
I can reproduce this locally. And it looks more like a "post 2016 problem" On dec 31st 2016 the test passes, from jan 1st 2017 on it fails. So I close this bug and open a new one, when I know more.
Status: REOPENED → RESOLVED
Closed: 8 years ago → 8 years ago
Resolution: --- → FIXED
Blocks: 1388177
You need to log in before you can comment on or make changes to this bug.