550425 - "TEST-UNEXPECTED-FAIL | deadlock", "(expected 0 == return code, got -1)"

Status: RESOLVED FIXED

Description

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267777084.1267780310.32219.gz
Linux x86-64 mozilla-central leak test build on 2010/03/05 00:18:04  
s: moz2-linux64-slave07
TEST-UNEXPECTED-FAIL | deadlock
make[2]: *** [check] Error 1
make[1]: *** [check] Error 2
make: *** [check] Error 2

This is different problem but apparently related to bug 549435, because the logs there also showed "(expected 0 == return code, got -1)" although the test failed for a different reason.  A return code of -1 seems to imply that the subprocess in that test is being terminated by an uncaught SIGHUP (which doesn't make sense to me).

Comment 1

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

I tried running this in a loop 200 times to hit the -1 return code, but didn't.  I don't really know what's happening, but SIGHUP probably means the subprocess's pipe is probably being closed out from under it, so I've got a speculative fix.

Comment 2

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: Don't close the subprocess's stdout/stderr pipes until after it exits.

Comment 3

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

http://hg.mozilla.org/mozilla-central/rev/b55d2ae8b6c9

Hopefully this fixes things.  Please reopen or file anew if it recurs.

Comment 4

[Benjamin Smedberg]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268388820.1268389924.26446.gz
Linux x86-64 mozilla-central leak test build on 2010/03/12 02:13:40

Comment 5

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Oho!  What's actually failed these two times is this test's storage/ doppelganger, not the xpcom/ one.  Will try applying the speculative fix there tomorrow.

Comment 6

[Daniel Holbert [:dholbert]]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268436821.1268438166.14266.gz
Linux x86-64 mozilla-central leak test build on 2010/03/12 15:33:41
s: moz2-linux64-slave04

Comment 7

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

sdwilsh, might any SQLite code be generating SIGHUP, by chance?

Comment 8

[Shawn Wilsher :sdwilsh]

(In reply to comment #7)
> sdwilsh, might any SQLite code be generating SIGHUP, by chance?
Not that I'm aware of, but drh should be able to answer definitively.

Comment 9

[D. Richard Hipp]

SQLite doesn't generate signals of any kind (other than an occasional SIGSEGV :-)).  Signals are posix-specific and SQLite is cross-platform, so it has no use for signals.

Is there anyway to generate a SIGHUP using file I/O?  I can't think of anything.  The only way I know for an application to generate SIGHUP is to call "kill()" which SQLite never does.  Have I overlooked something?

Comment 10

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

I don't think so.  It's likely an issue with the test harness.  I'll try applying the speculative fix there.

Comment 11

[Phil Ringnalda (:philor)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268513610.1268516406.5657.gz
Linux x86-64 mozilla-central leak test build on 2010/03/13 12:53:30
s: moz2-linux64-slave04

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268513034.1268515573.3312.gz
Linux x86-64 mozilla-central leak test build on 2010/03/13 12:43:54
s: moz2-linux64-slave08

Comment 12

[Phil Ringnalda (:philor)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268679238.1268684995.19754.gz
Linux x86-64 mozilla-central leak test build on 2010/03/15 11:53:58
s: moz2-linux64-slave06

Comment 13

[Phil Ringnalda (:philor)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268691109.1268692504.10629.gz
Linux x86-64 mozilla-central leak test build on 2010/03/15 15:11:49
s: moz2-linux64-slave04

Comment 14

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

I was able to repro this 2/20 on the storage/ version ... but just confirmed that the speculative fix isn't working :(.

Comment 15

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: Bump up the timeout for an expensive deadlock test and print more info on failures

So, what's going on is that the "contention" test is timing out.  Fix I made is to bump timeout from 10 to 60 seconds.  Also took the liberty of syncing the TestDeadlockDetector changes over to test_deadlock_detector.

Comment 16

[Shawn Wilsher :sdwilsh]

Comment on attachment 432724 [details] [diff] [review]
Bump up the timeout for an expensive deadlock test and print more info on failures

r=sdwilsh

Comment 17

[Daniel Holbert [:dholbert]]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268924527.1268929078.1446.gz
Linux x86-64 mozilla-central leak test build on 2010/03/18 08:02:07
s: moz2-linux64-slave08

Comment 18

[(not currently active) Ted Mielczarek]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269097744.1269098420.17908.gz
Linux x86-64 mozilla-central leak test build on 2010/03/20 08:09:04  
s: moz2-linux64-slave06

Comment 19

[Phil Ringnalda (:philor)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269320335.1269323108.25431.gz
Linux x86-64 mozilla-central leak test build on 2010/03/22 21:58:55
s: moz2-linux64-slave03

Comment 20

[:Ehsan Akhgari]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269381918.1269387304.28994.gz
Linux x86-64 mozilla-central leak test build on 2010/03/23 15:05:18

Comment 21

[Phil Ringnalda (:philor)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269462591.1269468718.10605.gz
Linux x86-64 mozilla-central leak test build on 2010/03/24 13:29:51
s: moz2-linux64-slave08

Comment 22

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

http://hg.mozilla.org/mozilla-central/rev/724a5ba759fa

Comment 23

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Aww, this happened on the last run before the fix.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269473484.1269476595.11375.gz