Closed Bug 648255 Opened 13 years ago Closed 13 years ago

Intermittent failure in test_history_sidebar.js | Yesterday == Today crossing midnight

Categories

(Toolkit :: Places, defect)

Product:
Toolkit
Component:
Places
Platform:
x86
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla6

People

(Reporter: philor, Assigned: ehsan.akhgari)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Patch (v1)
1.11 KB, patch
mak
: review+
Details | Diff | Splinter Review 
I very much doubt it's coincidence that this test run started at 23:43 and finished at 00:09.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1302158588.1302160038.1877.gz&fulltext=1
Rev3 Fedora 12 mozilla-central debug test xpcshell on 2011/04/06 23:43:08
s: talos-r3-fed-024

TEST-UNEXPECTED-FAIL | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | test failed (with xpcshell return code: 0), see following log:
>>>>>>>
...
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [add_normalized_visit : 81] true == true
Found containers:
Yesterday
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
Last 7 days
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
March
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
February
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
January
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
December 2010
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
November 2010
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
Older than 6 months
TEST-PASS | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | [check_visit : 197] -1 == -1
Found containers:
Yesterday
TEST-UNEXPECTED-FAIL | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js | Yesterday == Today - See following stack:
JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: do_throw :: line 439
JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: do_check_eq :: line 491
JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js :: fill_history :: line 156
JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/places/tests/unit/test_history_sidebar.js :: run_test :: line 464
JS frame :: /home/cltbld/talos-slave/test/build/xpcshell/head.js :: _execute_test :: line 322
JS frame :: -e :: <TOP_LEVEL> :: line 1
TEST-INFO | (xpcshell/head.js) | exiting test
Ehsan, I believe these kind of situations should be mentioned in https://developer.mozilla.org/en/QA/Avoiding_intermittent_oranges
interesting that it never happened till now!
Sounds like the check runs just after midnight while addition runs just before it.
(In reply to comment #1)
> Ehsan, I believe these kind of situations should be mentioned in
> https://developer.mozilla.org/en/QA/Avoiding_intermittent_oranges

I agree.  Would you mind adding this to the page, please?  :-)
So, after looking into this, I don't think there is any good way to fix this failure, since we don't want to modify the behavior of places (which has its own concept of "now" which is out of the control of this test).

One way to address the orange would be to just abort the test is the we're past 23:50 or something.  Does that sounds totally insane?
Hm so, we could maybe change visibleContainers to a getter, and have visible property on today depend on the fact it's still the same day or not...

Otherwise, your quick approach is fine, don't think that testing around midnight here is really that useful.
Attached patch Patch (v1) — — Splinter Review 
I'm lazy!
Assignee: nobody → ehsan
Status: NEW → ASSIGNED
Attachment #526447 - Flags: review?(mak77)
Comment on attachment 526447 [details] [diff] [review]
Patch (v1)

>diff --git a/toolkit/components/places/tests/unit/test_history_sidebar.js b/toolkit/components/places/tests/unit/test_history_sidebar.js

> // main
> function run_test() {
>   // Cleanup.
>   bh.removeAllPages();
>   remove_all_bookmarks();

While here, could you please remove these cleanup things?
They are useless in a xpcshell test, and removeAllPages is also dangerous (it's async and so this is calling for trouble).

Also the "// main" completely useless comment :)

Profit!
Attachment #526447 - Flags: review?(mak77) → review+
http://hg.mozilla.org/mozilla-central/rev/ef29d1761717
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla6
Flags: in-testsuite+
I don't think this change is a good idea. It means that a change that genuinely breaks this behaviour might pass on the try server, but fail on checkin. Or pass on checkin, but fail on the subsequent checkin, causing unnecessary confusion. This is worse than the previous failure mode, which was rare and self-explanatory (Yesterday == Today).

The test should be made more robust if you want to avoid the rare orange, rather than just being skipped (it's now going to be skipped much more often than it was likely to fail as the definition of "dangerously close" is 10 minutes).
(In reply to comment #10)
> I don't think this change is a good idea. It means that a change that genuinely
> breaks this behaviour might pass on the try server, but fail on checkin. Or
> pass on checkin, but fail on the subsequent checkin, causing unnecessary
> confusion. This is worse than the previous failure mode, which was rare and
> self-explanatory (Yesterday == Today).

I didn't like writing this patch for this exact reason, but the good news is that such a faulty patch would immediately be backed out on the next test run.  Also, the chance of a patch breaking this functionality landing and the test on all of our platforms running at the last 10 minutes of a day is really slim (though it's still possible).

> The test should be made more robust if you want to avoid the rare orange,
> rather than just being skipped (it's now going to be skipped much more often
> than it was likely to fail as the definition of "dangerously close" is 10
> minutes).

Unfortunately I don't have any better ideas on how to address this.  If you do, please let us know, and I will be happy to write a better patch.
If stopping intermittent oranges (however rare) is a priority then I can't think of a way to address the problem without rewriting the entire test.

Could you add an output message that at least states that although the test "passes" it hasn't actually been run? And I think you can safely reduce the time window, as the test is not going to take very long even on a heavily loaded VM.
Ehsan, could we do something like that:
- if midnight minus the current time isn't higher than the current test timeout, do nothing;
- otherwise, double the test timeout time and wait until we reach midnight.

The solution isn't ideal but at least, the tests should always be ran. This assumes we can change the test timeout dynamically during a test run (but I think I saw that once).
I don't think we should care about the above try fact, the probability that a developer runs the test locally with a pass, then try runs it again with a pass, and then it ails on central is practically none. Both of the first runs should be in the 10 minutes before midnight, and if a dev uses try only without running the tests locally before, as previously said, he is doing this wrong.
(In reply to comment #12)
> If stopping intermittent oranges (however rare) is a priority

It's a priority, though not the highest one.

> Could you add an output message that at least states that although the test
> "passes" it hasn't actually been run? And I think you can safely reduce the
> time window, as the test is not going to take very long even on a heavily
> loaded VM.

Unfortunately the xpcshell test framework doesn't print any output messages for tests which are successful, so doing that wouldn't make any difference.  :(
(In reply to comment #13)
> Ehsan, could we do something like that:
> - if midnight minus the current time isn't higher than the current test
> timeout, do nothing;
> - otherwise, double the test timeout time and wait until we reach midnight.
> 
> The solution isn't ideal but at least, the tests should always be ran. This
> assumes we can change the test timeout dynamically during a test run (but I
> think I saw that once).

This wouldn't work, because we would be racing against timer resolution, and we would fail that game some of the time.
(In reply to comment #15)
> Unfortunately the xpcshell test framework doesn't print any output messages for
> tests which are successful, so doing that wouldn't make any difference.  :(

Comment 0 shows output from the print() statements in the passing tests. Can't you do:

  if (nowObj.getHours() == 23 && nowObj.getMinutes() >= 50) {
    print("Skipping test as the definition of \"today\" might change midway through... Test started at: " + nowObj.toTimeString());
    return;
  }

?
(In reply to comment #17)
> (In reply to comment #15)
> > Unfortunately the xpcshell test framework doesn't print any output messages for
> > tests which are successful, so doing that wouldn't make any difference.  :(
> 
> Comment 0 shows output from the print() statements in the passing tests. Can't
> you do:
> 
>   if (nowObj.getHours() == 23 && nowObj.getMinutes() >= 50) {
>     print("Skipping test as the definition of \"today\" might change midway
> through... Test started at: " + nowObj.toTimeString());
>     return;
>   }
> 
> ?

That output would *only* show up if the test fails.  This is what I meant in comment 15.
regarding comment 19, bug 576220 has been reopened.
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: