Closed Bug 1545918 Opened 5 years ago Closed 5 years ago

Various |Disconnect Error: Application unexpectedly closed| likely caused by testEventDialog.js

Categories

(Calendar :: General, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: jorgk-bmo, Assigned: darktrojan)

References

Details

(Whiteboard: [Thunderbird-testfailure: Z all][Thunderbird-disabled-test])

Attachments

(2 files, 1 obsolete file)

https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=f8a27eb022631ef4e106dd7cb0af077f1858ea24&selectedJob=241517191
https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=f8a27eb022631ef4e106dd7cb0af077f1858ea24&selectedJob=241524935
https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=f8a27eb022631ef4e106dd7cb0af077f1858ea24&selectedJob=241530922

Not so healthy since no further tests will run.

https://taskcluster-artifacts.net/bLdd2RWDQSC3dXYkSe3Gsg/0/public/logs/live_backing.log

[task 2019-04-19T22:46:23.231Z] 22:46:23 INFO - TEST-START | /builds/worker/workspace/build/tests/mozmill/eventDialog/testEventDialog.js | testEventDialog
[task 2019-04-19T22:46:23.231Z] 22:46:23 INFO - First day in view is: 2019-3-31
[task 2019-04-19T22:48:28.670Z] 22:48:28 INFO - Timeout: bridge.execFunction("f3b933d2-62f4-11e9-8371-0242ac110005", bridge.registry["{edadf569-f48a-4135-b40b-a52dfef1d2c6}"]["runTestDirectory"], ["/builds/worker/workspace/build/tests/mozmill/eventDialog"])
[task 2019-04-19T22:48:28.671Z] 22:48:28 WARNING - TEST-UNEXPECTED-FAIL | Disconnect Error: Application unexpectedly closed
[task 2019-04-19T22:48:28.671Z] 22:48:28 INFO - Timeout: bridge.set("3fb27474-62f5-11e9-8371-0242ac110005", ChromeUtils.import('chrome://mozmill/content/modules/mozmill.jsm'))

I'll try it locally and then I will take the test down.

This has started on the last push:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=0b1de782bd32ee277ad609c2bbe7e35b8a&tochange=30b70a449280e6df10496a51e89c01b8c9

Flags: needinfo?(geoff)

Hmm, mozmake -C comm/calendar/test/mozmill SOLO_TEST=eventDialog/testEventDialog.js mozmill-one passes locally, but no harm done in disabling it for a moment.

Keywords: leave-open
Whiteboard: [Thunderbird-testfailure: Z all][Thunderbird-disabled-test]
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/38b96cc589ce
temporarily disable testEventDialog.js. rs=bustage-fix DONTBUILD
Flags: needinfo?(geoff)
See Also: → 1545004

This started at least as early as bug 1545004, but every time I poke it with a stick, it goes away for no apparent reason and then reappears.

Which one are you referring to? testEventDialog.js or testEventDialogModificationPrompt.js which is what I'm referring to in comment #3 and comment #4.

The first. I actually get a different failure for the second:

SUMMARY-UNEXPECTED-FAIL | testEventDialogModificationPrompt.js | testEventDialogModificationPrompt.js::testEventDialogModificationPrompt
  EXCEPTION: Expression "{"class":"item-attendees-row"}" returned null. Anonymous == false
    at: elementslib.jsm line 468
       reduceLookup elementslib.jsm:468 15
       Lookup.prototype.getNode elementslib.jsm:480 19
       wrapperFunc test-window-helpers.js:1148 20
       deleteAttendees test-item-editing-helpers.js:562 19
       setData test-item-editing-helpers.js:421 13
       testEventDialogModificationPrompt/< testEventDialogModificationPrompt.js:96 9

I think I know why this error appears and disappears.

All of the "application unexpectedly closed" messages occur on pushes at around 20:00 22:00 UTC. That would be the busiest time for the build infrastructure, with merge builds in progress on m-c (2), m-i, and autoland, plus it's afternoon US time where a lot of the developers are.

Tests run at other times of day don't have the timeout problem. I've just re-run some failed tests from last week with different results.

What do we do about it? I'm not sure yet, re-running some more recent failed tests to see what happens with them.

Filed bug 1546130 for testEventDialogModificationPrompt.js.

Running mozmake -C comm/calendar/test/mozmill SOLO_TEST=eventDialog/testEventDialog.js mozmill-one at 22:21 local time gives:
The end date you entered occurs before the start date

BTW, Aceman was ran it and motivated me to try it. So this is timezone related or something. Geoff just poked it at the wrong time.

Flags: needinfo?(geoff)

We wanted to say it does not relate to load on the server. We can see the test failing locally at 22:00 (10PM). In that case the event is generated with duration like this:
start=3/31/19 11PM
end=4/1/19 12AM

This does pass checks in the New event dialog, but when you click to invite attendees and add one the error dialog fires.
The failing code is at https://searchfox.org/comm-central/source/calendar/base/content/dialogs/calendar-event-dialog-attendees.js#390, which determines this is a negative duration.

At that point gStartDate=2019-04-23T23:00:00 and gEndDate=2019-04-23T00:00:00 and for some reason gStartTimezone and gEndTimezone are NOT the same. Why?

Attached patch 1545918.patch debug (obsolete) β€” β€” Splinter Review

Debugging patch to visualize the problem. Maybe Geoff can continue from here.

Assignee: nobody → acelists

Screenshot of the dialog and the state of the "invite recipients" window. The time interval looks OK, but some checking code thinks it is not.

And once this unexpected dialog is shown, test does not move further and whole mozmill crashes after the timeout.

Assignee: acelists → nobody
OS: Unspecified → All
Hardware: Unspecified → All

Let's just ignore changes until the dialog is set up properly. It looks like I caused this by fixing a timepicker regression in bug 1541031 and missed seeing the failures because most of the tests ran after midnight.

Assignee: nobody → geoff
Status: NEW → ASSIGNED
Flags: needinfo?(geoff)
Attachment #9060297 - Flags: review?(acelists)

(Side note: bug 1546579)

Comment on attachment 9060297 [details] [diff] [review]
1545918-ignore-update-1.diff

Review of attachment 9060297 [details] [diff] [review]:
-----------------------------------------------------------------

::: calendar/test/mozmill/eventDialog/testEventDialog.js
@@ +217,5 @@
>              ));
>          }
>      }
>  }
>  // testEventDialog.EXCLUDED_PLATFORMS = ["darwin"];

You need to restore this line.
Comment on attachment 9060297 [details] [diff] [review]
1545918-ignore-update-1.diff

Review of attachment 9060297 [details] [diff] [review]:
-----------------------------------------------------------------

Ok, I can't comment on the correctness of the calendar change, hopefully you understand the internal calendar logic to do this change.
But this makes the test pass for me at all times, before 22:00 (10PM), between 22:00 and 24:00, and after 24:00 (12AM).
Thanks.
Attachment #9060297 - Flags: review?(acelists) → review+
Attachment #9060235 - Attachment is obsolete: true
Comment on attachment 9060297 [details] [diff] [review]
1545918-ignore-update-1.diff

Good to go? Or do you want Philipp to look at it?
Flags: needinfo?(geoff)
Attachment #9060297 - Flags: review?(philipp)
Pushed by geoff@darktrojan.net:
https://hg.mozilla.org/comm-central/rev/2458408cc87e
Ignore change listeners while setting initial values in attendees dialog; r=aceman DONTBUILD
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Flags: needinfo?(geoff)
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → 7.0
Comment on attachment 9060297 [details] [diff] [review]
1545918-ignore-update-1.diff

Review of attachment 9060297 [details] [diff] [review]:
-----------------------------------------------------------------

I have no idea what this does without looking closer, given this has been in I'm going to rubber stamp it. Would be good to have some tests though!
Attachment #9060297 - Flags: review?(philipp) → review+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: