782598 - jstests.py runs forever when tests exceed their timeout

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Jon Coppeard (:jonco)]

Since updating recently I've been seeing jstests running forever.  Looking at what was running it seems that there are a few tests that run for a very long time and which are not being timed out.

Comment 1

[Jon Coppeard (:jonco)]

Attachment: Proposed fix

I think what's happening is that the function total_seconds() is returning zero which get_max_wait() interprets as meaning wait for ever.

The fix for bug 781445 replaced the call to timedelta.total_seconds() with the function total_seconds() that the python documentation describes as "equivalent ... with true division enabled".  True division turns out to be a python feature where integer division can return a float rather than rounding floating point results down to the nearest int, and it is not enabled here.

The patch just forces this function to return a float, as presumably timedelta.total_seconds() does.  Apparently true division can be enabled with "from __future__ import division" but to me it's less clear what that is doing.

Comment 2

[Jon Coppeard (:jonco)]

Attachment: Tidyup for get_max_wait()

While looking at this I noticed that the "remaining > wait" condition in get_max_wait() seems to be the wrong way round, unless I've misunderstood what's going on here.  Also, I can't see why this function would ever want to return None / wait forever - there are always tasks running when it is called.

Here's a patch and tidyup for this.

Comment 3

[Terrence Cole [:terrence]]

Comment on attachment 651727 [details] [diff] [review]
Proposed fix

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

Thanks for fixing this!  I should have read the docs more carefully.

::: js/src/tests/lib/tasks_unix.py
@@ +45,5 @@
>  def total_seconds(td):
> +    """
> +    Return the total number of seconds contained in the duration as a float
> +    """
> +    return (1.0 * td.microseconds + (td.seconds + td.days * 24 * 3600) * 10**6) / 10**6

I think float(td.microseconds) would make the intention clearer.

Comment 4

[Terrence Cole [:terrence]]

Comment on attachment 651793 [details] [diff] [review]
Tidyup for get_max_wait()

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

(In reply to Jon Coppeard (:jonco) from comment #2)
> While looking at this I noticed that the "remaining > wait" condition in
> get_max_wait() seems to be the wrong way round, unless I've misunderstood
> what's going on here.

My version starts at 0 and pushes wait up to the maximum required.  Your version starts at the maximum possible wait and then pulls it down to what is needed.  I think they are equivalent.

> Also, I can't see why this function would ever want
> to return None / wait forever - there are always tasks running when it is
> called.

Like the comment says, if you pass |-t 0| to the harness, that means to disable timing out the test.  As you noticed, the code doesn't implement that behavior :-).  I think it should be |if timeout == 0: wait = None|.
 
> Here's a patch and tidyup for this.

It's a nice cleanup, let's get it committed!

Comment 5

[Jon Coppeard (:jonco)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/92f022b4ae92
https://hg.mozilla.org/integration/mozilla-inbound/rev/726c3013ab9f

Comment 6

[Jon Coppeard (:jonco)]

(In reply to Terrence Cole [:terrence] from comment #4)

Cheers for the review, comments addressed and pushed to inbound.

Comment 7

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/726c3013ab9f
https://hg.mozilla.org/mozilla-central/rev/92f022b4ae92