507199 - Fix race condition in finalizing asynchronous storage statements

Status: RESOLVED FIXED

(Core :: SQLite and Embedded Database Bindings, defect)

Description

[Shawn Wilsher :sdwilsh]

This has been happening on the places branch for a little while.  mak has not been able to reproduce it locally, and it appears to be windows only.

Most recent failure:
WINNT 5.2 places unit test on 2009/07/29 09:23:07  
http://tinderbox.mozilla.org/showlog.cgi?log=Places/1248884587.1248892210.567.gz&fulltext=1

Comment 1

[Shawn Wilsher :sdwilsh]

WINNT 5.2 places unit test on 2009/07/29 09:55:51  
http://tinderbox.mozilla.org/showlog.cgi?log=Places/1248886551.1248894720.30438.gz&fulltext=1

Comment 2

[Shawn Wilsher :sdwilsh]

WINNT 5.2 mozilla-central test everythingelse on 2009/07/29 14:09:00  
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1248901740.1248903720.8789.gz&fulltext=1

Comment 3

[Shawn Wilsher :sdwilsh]

According to robarnold, the return code means we are doing a null pointer dereference.

Comment 4

[Shawn Wilsher :sdwilsh]

Correction - it's an access violation.  May or may not be null.

Comment 5

[Shawn Wilsher :sdwilsh]

Running these tests under valgrind doesn't come up with anything.

Comment 6

[Marco Bonardo [:mak]]

i'm now running those tests in an infinite loop... in more than 200 runs i've not seen any crash.

Comment 7

[Shawn Wilsher :sdwilsh]

Maybe we should disable these tests until bug 506042 gets resolved?  This is happening a lot more than I'd like suddenly, and it's lack of reproducibility makes it next to impossible to debug.

Comment 8

[Robert O'Callahan (:roc) (email my personal email if necessary)]

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

Comment 9

[Robert O'Callahan (:roc) (email my personal email if necessary)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1248924517.1248932490.32720.gz#err6

This is happening pretty much every run now

Comment 10

[Shawn Wilsher :sdwilsh]

I'm just going to disable these tests.  Once bug 506042 gets resolved, we can re-enable them and debug.

Comment 11

[Shawn Wilsher :sdwilsh]

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

Comment 12

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1249143659.1249148848.16320.gz
WINNT 5.2 mozilla-central unit test on 2009/08/01 09:20:59  

looks like the same thing except in test_browser_places\unit\test_browserGlue_shutdown.js ?

Comment 13

[Marco Bonardo [:mak]]

at this point this appear to be JS or cycle collector crash, disabling all tests is not an option and will simply move on the crash to another test.

Comment 14

[Marco Bonardo [:mak]]

on Windows xpcshell tests i still crash on bug 507424, could be worth reenabling tests after that has been fixed, to check if it's somehow related.

Comment 15

[Marco Bonardo [:mak]]

in comment 14 i meant i crash in other xpcshell tests, not during the above ones.

Comment 16

[Robert O'Callahan (:roc) (email my personal email if necessary)]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1249428308.1249438734.6705.gz#err0

Comment 17

[Marco Bonardo [:mak]]

i'd like to try reenabling these tests, to see if the crashes were depending on some of the JS crashes recently fixed. I'll try to do that at a quiet time when i'l have enough time to follow the tree.

Comment 18

[(not currently active) Ted Mielczarek]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1250863787.1250865533.11322.gz
OS X 10.5.2 mozilla-central test everythingelse on 2009/08/21 07:09:47

Comment 19

[Marco Bonardo [:mak]]

i'd say there is nothing we can do at this time, till we get a valid stack trace, somehow.

Comment 20

[Nick Thomas [:nthomas] (UTC+12)]

Attachment: Stack

Tracemonkey took the patch from bug 506042 ahead of mozilla-central, this is the stack from the xpcshell run where it crashed running test_browser_places\unit\test_browserGlue_shutdown.js.

Comment 21

[(not currently active) Ted Mielczarek]

sayrer was puzzling over this, but I guess this is the same crash as m-c, just something landed on tracemonkey to make it more frequent.

Comment 22

[Robert Sayre]

yeah, this is happening every run on TM windows. I think there's a race on shutdown in the storage code.

Comment 23

[Marco Bonardo [:mak]]

the same thing on Places branch, see bug 511965.

Comment 24

[Shawn Wilsher :sdwilsh]

This is, indeed, a race condition on shutdown.  Here's what is happening:
1) We call Close on the Connection object.  This causes us to spin the background thread's event loop and process any pending events.
2) The events are processed, and then in AsyncExecuteStatements::notifyComplete we call finalize on the StatementData object.  This resets the statement, and then releases the reference to it.
3) Our reference count on our Statement goes to zero, so the destructor is called, which calls Statement::Finalize.
4) In Statement::Finalize, we try to dispatch an event to the background thread to finalize the async statement (this is needed to serialize access to the async statement).  However, at this time, we can no longer get the background thread.

The fix here is simple - we just synchronously finalize if we cannot get the background thread (because it's shutting down or has been shutdown).

Comment 25

[Shawn Wilsher :sdwilsh]

Attachment: v1.0

Comment 26

[Shawn Wilsher :sdwilsh]

This was happening in the wild too: http://➡.ws/蚯

Comment 27

[(not currently active) Ted Mielczarek]

So, I think the tracemonkey merge turned this into constant Windows orange.

Comment 29

[Marco Bonardo [:mak]]

please when landing this also re-enable disabled tests (see comment 11)

Comment 30

[Marco Bonardo [:mak]]

pushed by Jesse
http://hg.mozilla.org/mozilla-central/rev/2ee676e74eac

I'm going to re-enable the tests and mark this fixed.

Comment 31

[Marco Bonardo [:mak]]

re-enaled by Jesse :)
http://hg.mozilla.org/mozilla-central/rev/cf74f6f746c3

Comment 32

[Shawn Wilsher :sdwilsh]

This impacts 1.9.2 as well.

Comment 33

[Mike Beltzner [:beltzner, not reading bugmail]]

Comment on attachment 396480 [details] [diff] [review]
v1.0

a192=beltzner

Comment 34

[Shawn Wilsher :sdwilsh]

http://hg.mozilla.org/releases/mozilla-1.9.2/rev/f20757ed6f11

Comment 35

[Tracy Walker [:tracy]]

assuming this is fixed with tests re-enabled and passing.