Closed Bug 1224842 Opened 6 years ago Closed 6 years ago

TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js

Categories

(Thunderbird :: General, defect)

defect
Not set
normal

Tracking

(thunderbird44 fixed, thunderbird45 fixed)

RESOLVED FIXED
Thunderbird 45.0
Tracking Status
thunderbird44 --- fixed
thunderbird45 --- fixed

People

(Reporter: mkmelin, Assigned: aleth)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js

Apparently a real error. Running 

  make SOLO_TEST=newmailaccount/test-newmailaccount.js mozmill-one

... you end up with a tab showing the raw isp config file xml.  After that obviously nothing works.
http://archive.mozilla.org/pub/thunderbird/tinderbox-builds/comm-central-linux-debug/1447499202/comm-central_ubuntu32_vm-debug_test-mozmill-bm01-tests1-linux32-build6.txt.gz

05:27:49     INFO -  --DOMWINDOW == 34 (0xa1e1fc00) [pid = 3556] [serial = 41] [outer = (nil)] [url = http://localhost:43336/registration.html?product=personalized_email&quote=b28acb3c0a464d33af22]
05:27:57  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_restored_ap_tab_works
05:27:57     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_can_dismiss_account_provisioner
05:27:57     INFO -  --DOCSHELL 0x9cfe6800 == 12 [pid = 3556] [id = 15]
05:27:57     INFO -  --DOMWINDOW == 33 (0x9bff9000) [pid = 3556] [serial = 43] [outer = (nil)] [url = http://localhost:43336/registration.html?product=personalized_email&quote=b28acb3c0a464d33af22]
05:28:04  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_can_dismiss_account_provisioner
05:28:04     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_can_switch_to_existing_email_account_wizard
05:28:04     INFO -  --DOMWINDOW == 32 (0x9d346c00) [pid = 3556] [serial = 29] [outer = (nil)] [url = chrome://messenger/content/msgAccountCentral.xul]
05:28:22  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_can_switch_to_existing_email_account_wizard
05:28:22     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_can_display_providers_in_other_languages
05:28:22     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:28:43  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_can_display_providers_in_other_languages
05:28:43     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_flip_flop_from_provisioner_menuitem
05:28:43  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_flip_flop_from_provisioner_menuitem
05:28:43     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_persist_name_in_search_field
05:28:43     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:28:53  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_persist_name_in_search_field
05:28:53     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_html_characters_and_ampersands
05:28:53     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:29:14  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_html_characters_and_ampersands
05:29:14     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_show_tos_privacy_links_for_selected_providers
05:29:14  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_show_tos_privacy_links_for_selected_providers
05:29:14     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_shows_error_on_bad_suggest_from_name
05:29:14     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:29:24  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_shows_error_on_bad_suggest_from_name
05:29:24     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_shows_error_on_empty_suggest_from_name
05:29:24     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:29:45  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_shows_error_on_empty_suggest_from_name
05:29:45     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_throws_console_error_on_corrupt_XML
05:29:45  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_throws_console_error_on_corrupt_XML
05:29:45     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_broken_provider_list_goes_offline
05:29:45     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:29:55  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_broken_provider_list_goes_offline
05:29:55     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_incomplete_provider_not_displayed
05:29:55     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:30:06  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_incomplete_provider_not_displayed
05:30:06     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_search_button_disabled_cases
05:30:06     INFO -  JavaScript error: resource://mozmill/modules/frame.js -> file:///builds/slave/test/build/tests/mozmill/shared-modules/test-window-helpers.js, line 364: Error: Timeout while waiting for modal dialog.
05:30:06  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test-newmailaccount.js::test_search_button_disabled_cases
05:30:06     INFO -  TEST-START | /builds/slave/test/build/tests/mozmill/newmailaccount/test-newmailaccount.js | test_can_pref_off_account_provisioner
05:30:06     INFO -  ++DOCSHELL 0x9483dc00 == 13 [pid = 3556] [id = 18]
if you comment out the test_restored_ap_tab_works() function, everything else works.  the purpose of this test is unclear.  something isn't torn down or reset correctly perhaps.
This is the first time I notice errors in newmailaccount test series on tryserver.

I develop C-C patches on one of my PCs. But on this particular PC of mine, newmailccount never
worked correctly: I figure it must have something to do with the access to the
dummy (?) or real server that offers ISP configuration information.
Somehow, I think this sever (real or dummy) cannot be accessed by my local PC's test environment and timeout
and other strange error ensued.
[Funny, though, on a different PC, I did not see such errors.]

I wonder if something on the try server changed.
However, that more than 30 tests in newmailaccount directory fail clearly may suggest a more fundamental 
cause...

My two cents worth.

TIA
It's just a (local) dummy http server that's being used. 
Even if it's 30 failures, it's likely just ~ one problem. It's just that after the tab with the XML config file is stuck there for whatever reason, none of the other tests are able to proceed correctly.
(In reply to Magnus Melin from comment #4)
> It's just a (local) dummy http server that's being used. 
> Even if it's 30 failures, it's likely just ~ one problem. It's just that
> after the tab with the XML config file is stuck there for whatever reason,
> none of the other tests are able to proceed correctly.

Does this http server use standard port like 80 (or 8080)?
If so, it may be that my apache server serving something on my PC (Debian GNU/Linux) may
interfere with the local dummy server (!).

I will try to keep an eye just in case I can figure out what the real cause is.

TIA
(In reply to Magnus Melin from comment #2)
> The tab with the config.xml opens (and never get closed) from the page
> http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/newmailaccount/
> html/registration.html?force=1 - opens when clicking the send button gets
> clicked @
> http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/newmailaccount/
> test-newmailaccount.js#149

If you rightclick the page and hit Reload, the expected dialog comes up and then the tests continue, even successfully.

When clicking the "send" button, the url of the form is the xml file so loading it seems correct. However it seems normally it is not displayed but something intercepts it and a success dialog about the new account is show. This "something" seems to not be hooked up when the tab is restored in the test_restored_ap_tab_works test. A reload of the tab fixes that.

It seems to be the last run without this failure is
https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=08aaf7fd5f84 (Oct 5).
Then there is a month of unsuccessful builds.
And the first correct build with the test failure is
https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=2435da3ea8b4 (Nov 3)...
(In reply to Magnus Melin from comment #6)
> No, apparently port 4444 in this test -
> http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/newmailaccount/
> test-newmailaccount.js#42

Thank you for the pointer. I will see if a local firewall setting plays something funny on my PC. (Latest Debian GNU/Linux64-bit. It has experienced the problem for the last few years and I have no idea why while another PC at different place experienced no such issue. )

TIA
(In reply to :aceman from comment #7)
> (In reply to Magnus Melin from comment #2)
> > The tab with the config.xml opens (and never get closed) from the page
> > http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/newmailaccount/
> > html/registration.html?force=1 - opens when clicking the send button gets
> > clicked @
> > http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/newmailaccount/
> > test-newmailaccount.js#149
> 
> If you rightclick the page and hit Reload, the expected dialog comes up and
> then the tests continue, even successfully.

I think the important point is not mentioned explicitly enough.

As soon as the first window that showed XML list appeared, I did
the right click and reload routine mentioned above,
then the subsequent tests did not experience this hung window with XML listing
at all and I got a very clean mozmil test results (only 5 errors which I will investigate further). This is local test that is done under Debian GNU/Linux 64-bit.

This suggests that 
- right click + reload action changes something to the state TB keeps inside (or externally in config information ), but 
- that information does not seem to be initialized properly when TB enters newmailaccount test directory (that is when a new instance of TB is invoked afresh. If I understand correctly, TB is terminated after leaving a directory.)

> 
> When clicking the "send" button, the url of the form is the xml file so
> loading it seems correct. However it seems normally it is not displayed but
> something intercepts it and a success dialog about the new account is show.
> This "something" seems to not be hooked up when the tab is restored in the
> test_restored_ap_tab_works test. A reload of the tab fixes that.
> 
> It seems to be the last run without this failure is
> https://treeherder.mozilla.org/#/jobs?repo=comm-
> central&revision=08aaf7fd5f84 (Oct 5).
> Then there is a month of unsuccessful builds.
> And the first correct build with the test failure is
> https://treeherder.mozilla.org/#/jobs?repo=comm-
> central&revision=2435da3ea8b4 (Nov 3)...

So this setting or resetting *something* gets changed in the time interval above.

TIA
This is indeed a bit weird. The httpRequestObserver is set up correctly before the click on the second run too, but unlike in the first run, doesn't receive a http-on-examine-response notification.
(In reply to aleth [:aleth] from comment #10)
> This is indeed a bit weird. The httpRequestObserver is set up correctly
> before the click on the second run too, but unlike in the first run, doesn't
> receive a http-on-examine-response notification.

Mystery solved: observing http-on-examine-cached-response as well fixes the problem. 

We probably don't want to do this in production, so we have to avoid the cacheing somehow.
Assignee: nobody → aleth
Status: NEW → ASSIGNED
(In reply to aleth [:aleth] from comment #11)
> (In reply to aleth [:aleth] from comment #10)
> > This is indeed a bit weird. The httpRequestObserver is set up correctly
> > before the click on the second run too, but unlike in the first run, doesn't
> > receive a http-on-examine-response notification.
> 
> Mystery solved: observing http-on-examine-cached-response as well fixes the
> problem. 
> 
> We probably don't want to do this in production, so we have to avoid the
> cacheing somehow.

Great to know that the root cause is somehow figured out.

Do you have any idea how I can possibly avoid this hung (and subsequent error) automatically on my local test?: that is, I can't be in front the PC to perform "right-click and reload" all the time. If this can be avoided/automated, so much the better.

BTW,

> We probably don't want to do this in production

Does this mean something changed in October 
in the test code to set up the test environment?
(Not in the TB code itself?)

TIA!
Attachment #8690763 - Flags: review?(mkmelin+mozilla)
(In reply to aleth [:aleth] from comment #11)
> We probably don't want to do this in production, so we have to avoid the
> cacheing somehow.

You mean add code in the restore routine of this tab type to reload the page from network (as the data from server may have changed) ? That seems like the correct thing.
(In reply to aleth [:aleth] from comment #11)
> We probably don't want to do this in production, so we have to avoid the
> cacheing somehow.

Looking at the specs, it appears one should expect HTTP GET responses to be potentially cached, so this patch seems to be the correct thing to do.

The HTML spec also says "If the processing of a form is idempotent (i.e. it has no lasting observable effect on the state of the world), then the form method should be GET. Many database searches have no visible side-effects and make ideal applications of query forms. ... If the service associated with the processing of a form has side effects (for example, modification of a database or subscription to a service), the method should be POST." so it's the design choice of GET here (for an account creation) which is questionable.

I'm not sure what the breaking change was here.
(In reply to :aceman from comment #14)
> You mean add code in the restore routine of this tab type to reload the page
> from network (as the data from server may have changed) ? That seems like
> the correct thing.

I don't see a good way to add this. I mean, we could fix it for the test example, but what those html/xml files look like, and what headers they use (including cache or not) is up to the account provider.
Comment on attachment 8690763 [details] [diff] [review]
httpRequestObserver should also listen for cached responses

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

Nice detective work! Seems like the right thing to do indeed. r=mkmelin
Attachment #8690763 - Flags: review?(mkmelin+mozilla) → review+
https://hg.mozilla.org/comm-central/rev/09d33aaa187b782d1a4324b349c782e31762b7b3
Bug 1224842 - httpRequestObserver should also listen for cached responses. r=mkmelin
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 45.0
Comment on attachment 8690763 [details] [diff] [review]
httpRequestObserver should also listen for cached responses

[Approval Request Comment]
Testing completed (on c-c, etc.): fixes multiple mozmill failures and potential account provisioning errors
Attachment #8690763 - Flags: approval-comm-aurora?
Comment on attachment 8690763 [details] [diff] [review]
httpRequestObserver should also listen for cached responses

https://hg.mozilla.org/releases/comm-aurora/rev/1bc813448f64
Attachment #8690763 - Flags: approval-comm-aurora? → approval-comm-aurora+
You need to log in before you can comment on or make changes to this bug.