Intermittent test_nodb_pluschanges.js | command timed out: 1200 seconds without output

RESOLVED FIXED in Firefox 15

Status

()

Firefox
Search
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: philor, Assigned: Yoric)

Tracking

({intermittent-failure})

Trunk
Firefox 15
intermittent-failure
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite -

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 4 obsolete attachments)

https://tbpl.mozilla.org/php/getParsedLog.php?id=10830007&tree=Mozilla-Inbound
Rev3 Fedora 12x64 mozilla-inbound debug test xpcshell on 2012-04-11 18:21:30 PDT for push bfa27d58769d

TEST-INFO | /home/cltbld/talos-slave/test/build/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_nodb_pluschanges.js | running test ...

command timed out: 1200 seconds without output, attempting to kill
https://tbpl.mozilla.org/php/getParsedLog.php?id=10934056&tree=Mozilla-Inbound
Investigating. Is this only on Linux 64bit?
Assignee: nobody → dteller
How comes I can't see any log?
I can't see any logs on tbpl (this test should produce pages of logs). Also, I cannot reproduce the issue and I cannot find any occurrence of on inbound it since Marco's message. Right now, I have no idea what can have gone wrong or how I can fix it.

If anybody manages to reproduce the issue, I would be very interested in the logs.
Depends on: 500388
(In reply to David Rajchenbach Teller [:Yoric] from comment #2)
> Investigating. Is this only on Linux 64bit?

Comment 1 is on Mac OS X 32-bit.

The missing logging is because of bug 500388.  Since this failure seems fairly rare, the best bet might be fix or work around that bug so we can get logs if it happens in the future.
OS: Mac OS X → All
Hardware: x86 → All
(In reply to Matt Brubeck (:mbrubeck) from comment #5)
> The missing logging is because of bug 500388.  Since this failure seems
> fairly rare, the best bet might be fix or work around that bug so we can get
> logs if it happens in the future.

Ok. If I set a timeout internally and call |do_throw| from that timeout, this should work around bug 500388, shouldn't it?
Created attachment 617299 [details] [diff] [review]
Forcing timeout, to improve logging

Is this what you have in mind?
Attachment #617299 - Flags: review?(mbrubeck)
Comment on attachment 617299 [details] [diff] [review]
Forcing timeout, to improve logging

Looks like a good idea, but I've never written an xpcshell test and am not the best person to review this.  (For example, it's not clear to me whether unfired do_timeout timers are automatically cleared when the test finishes.)
Attachment #617299 - Flags: review?(mbrubeck)
Comment on attachment 617299 [details] [diff] [review]
Forcing timeout, to improve logging

Ok, placing the burden back on Gavin.
Attachment #617299 - Flags: review?(gavin.sharp)
Comment on attachment 617299 [details] [diff] [review]
Forcing timeout, to improve logging

>diff --git a/toolkit/components/search/tests/xpcshell/test_nodb_pluschanges.js b/toolkit/components/search/tests/xpcshell/test_nodb_pluschanges.js

>+  do_timeout(2000, function() {

2 seconds isn't that long, which might cause this test to fail where it would otherwise pass. Given that the harness timeout seems to occur after 20 minutes, you could stand to make this timeout be ~10 minutes to be sure to only catch the cases where we're truly failing.
Attachment #617299 - Flags: review?(gavin.sharp) → review+
Created attachment 617403 [details] [diff] [review]
Forcing timeout, to improve logging

Done.
Attachment #617299 - Attachment is obsolete: true
Keywords: checkin-needed
Whiteboard: [orange] → [orange][do-not-close-after-landing]
Comment on attachment 617403 [details] [diff] [review]
Forcing timeout, to improve logging

[Approval Request Comment]
Please see https://wiki.mozilla.org/Tree_Rules for information on mozilla-central landings that do not require approval.

Possible risk to Fennec Native 14 (if any): None, it should only impact logging of one test.
Attachment #617403 - Flags: approval-mozilla-central?
Comment on attachment 617403 [details] [diff] [review]
Forcing timeout, to improve logging

You don't need explicit approval; you can just land this with a=test-only:
https://wiki.mozilla.org/Tree_Rules
Attachment #617403 - Flags: approval-mozilla-central?
Created attachment 617550 [details] [diff] [review]
Forcing timeout, to improve logging

Here we go. Thanks, Matt.
Attachment #617403 - Attachment is obsolete: true
https://hg.mozilla.org/integration/mozilla-inbound/rev/efba113561c6
Flags: in-testsuite-
Keywords: checkin-needed
> Created attachment 617550 [details] [diff] [review]
> Forcing timeout, to improve logging

https://hg.mozilla.org/mozilla-central/rev/efba113561c6
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED

Updated

5 years ago
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Updated

5 years ago
Status: REOPENED → ASSIGNED
Whiteboard: [orange][do-not-close-after-landing] → [orange][leave open]
Comment hidden (Treeherder Robot)
Created attachment 618672 [details] [diff] [review]
Closing stream once commit is complete

Ok, logs make it a little better. Adding more logs and what might possibly be a fix.
Attachment #617550 - Attachment is obsolete: true
Attachment #618672 - Flags: review?(gavin.sharp)
This patch doesn't seem to apply on top of the other one, did you attach the wrong one?

I wonder whether asyncCopy should handle explicitly closing the output stream before invoking its callback. It seems like this problem could affect many other consumers of it (who don't currently rely on immediately reading back in the written data, I guess).
Attachment #618672 - Flags: review?(gavin.sharp)
Created attachment 618944 [details] [diff] [review]
Closing stream once commit is complete

Sorry about that, I had posted a merged patch. This one should do the trick.
Attachment #618672 - Attachment is obsolete: true
Attachment #618944 - Flags: review?(gavin.sharp)
(In reply to :Gavin Sharp (use gavin@gavinsharp.com for email) from comment #19)
> This patch doesn't seem to apply on top of the other one, did you attach the
> wrong one?
> 
> I wonder whether asyncCopy should handle explicitly closing the output
> stream before invoking its callback. It seems like this problem could affect
> many other consumers of it (who don't currently rely on immediately reading
> back in the written data, I guess).

If this patch proves to fix the issue, this definitely deserves investigation.
Keywords: checkin-needed
Gavin? Still waiting for your word.
Keywords: checkin-needed
Attachment #618944 - Flags: review?(gavin.sharp) → review+
Thanks
Keywords: checkin-needed
applying c:\users\ed\appdata\local\temp\thg-import-5fuczc.patch
patching file toolkit/components/search/nsSearchService.js
Hunk #1 FAILED at 3781
1 out of 1 hunks FAILED -- saving rejects to file toolkit/components/search/nsSearchService.js.rej
patching file toolkit/components/search/tests/xpcshell/test_nodb_pluschanges.js
abort: patch failed to apply
https://hg.mozilla.org/integration/mozilla-inbound/rev/eb164529f0d5

David, should the [leave open] still be on the whiteboard?
Keywords: checkin-needed
Target Milestone: --- → Firefox 15
You are right, we should probably close this bug and reopen it if necessary.
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago5 years ago
Resolution: --- → FIXED
Whiteboard: [orange][leave open] → [orange]
https://hg.mozilla.org/mozilla-central/rev/eb164529f0d5
Keywords: intermittent-failure
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.