Last Comment Bug 760243 - Lightning enabled in TB trunk - Assertion failure: !connections[i]->ConnectionReady(), mozStorageService.cpp:852
: Lightning enabled in TB trunk - Assertion failure: !connections[i]->Connectio...
Status: RESOLVED FIXED
:
Product: Calendar
Classification: Client Software
Component: Internal Components (show other bugs)
: Lightning 1.7
: All All
: -- critical (vote)
: 1.9
Assigned To: Stefan Sitter
:
Mentors:
Depends on: 758688
Blocks: 711076
  Show dependency treegraph
 
Reported: 2012-05-31 12:51 PDT by :aceman
Modified: 2012-10-10 12:47 PDT (History)
6 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---


Attachments
log with DB tracing (191.80 KB, text/plain)
2012-06-02 05:55 PDT, :aceman
no flags Details
Close one of the connections. (1.95 KB, patch)
2012-06-04 11:38 PDT, Rafael Ávila de Espíndola (:espindola) (not reading bugmail)
philipp: review-
Details | Diff | Review
[checked in] close another one. (804 bytes, patch)
2012-06-04 11:51 PDT, Rafael Ávila de Espíndola (:espindola) (not reading bugmail)
philipp: review+
Details | Diff | Review
[checked in] "last" missing db (1.28 KB, patch)
2012-06-04 12:15 PDT, Rafael Ávila de Espíndola (:espindola) (not reading bugmail)
philipp: review+
Details | Diff | Review
[checked in] refactoring (1.45 KB, patch)
2012-06-06 10:46 PDT, Rafael Ávila de Espíndola (:espindola) (not reading bugmail)
philipp: review+
Details | Diff | Review
debug patch (5.56 KB, patch)
2012-06-11 09:10 PDT, Rafael Ávila de Espíndola (:espindola) (not reading bugmail)
no flags Details | Diff | Review
[checked in] finalize statements and close databases (11.24 KB, patch)
2012-09-25 23:11 PDT, Stefan Sitter
philipp: review+
philipp: approval‑calendar‑beta+
Details | Diff | Review
[checked in] use asyncClose() and add try/catch block (11.91 KB, patch)
2012-09-27 12:05 PDT, Stefan Sitter
philipp: review+
philipp: approval‑calendar‑beta+
Details | Diff | Review

Description :aceman 2012-05-31 12:51:42 PDT
+++ This bug was initially created as a clone of Bug #758688 +++

After bug 758688 got fixed I still see a similar crash when the Lightning addon is enabled in TB trunk.
This is the end of the console output:

###!!! ASSERTION: Oops!  You're asking for a weak reference to an object that doesn't support that.: 'factoryPtr', file /var/SSD/TB-hg/tbird-bin/mozilla/xpcom/build/nsWeakReference.cpp, line 77
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js :: ccm_shutdown :: line 165"  data: no]
************************************************************
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js :: ccm_shutdown :: line 165"  data: no]
************************************************************
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/components/steelApplication.js :: app_observe :: line 622"  data: no]
************************************************************
WARNING: nsExceptionService ignoring thread destruction after shutdown: file /var/SSD/TB-hg/mozilla/xpcom/base/nsExceptionService.cpp, line 166
Assertion failure: !connections[i]->ConnectionReady(), at /var/SSD/TB-hg/mozilla/storage/src/mozStorageService.cpp:852

Program ./thunderbird (pid = 20005) received signal 6.
Stack:
__kernel_rt_sigreturn+0x00000000 [linux-gate.so.1 +0x0000040C]
UNKNOWN [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x0131D604]
UNKNOWN [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x0131DEEB]
UNKNOWN [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x0130E0D2]
UNKNOWN [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x00226CAF]
UNKNOWN [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x0022E2CB]
XRE_main+0x000000A7 [/var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/libxul.so +0x0022E4B1]
UNKNOWN [./thunderbird +0x00001E32]
Sleeping for 300 seconds.
Comment 1 :aceman 2012-05-31 13:36:19 PDT
I applied patch https://bugzilla.mozilla.org/attachment.cgi?id=627338 and I get output like this:

0 XPIDB_shutdown() ["resource://gre/modules/XPIProvider.jsm":4635]
    this = [object Object]
1 XPI_shutdown() ["resource://gre/modules/XPIProvider.jsm":1719]
    this = [object Object]
2 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
3 callProvider() ["resource://gre/modules/AddonManager.jsm":108]
    this = undefined
4 anonymous() ["resource://gre/modules/AddonManager.jsm":644]
    this = undefined
5 AMI_shutdown() ["resource://gre/modules/AddonManager.jsm":643]
    this = [object Object]
6 AMP_shutdown() ["resource://gre/modules/AddonManager.jsm":1892]
    this = [object Object]
7 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
8 AMC_observe() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/components/addonManager.js":62]
    this = [object Object]
9 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>

Rafael, what exactly should I look for?
Comment 2 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-01 06:08:02 PDT
With the patch thunderbird will print a backtrace every time a connection is open and closed. An open will be marked with

ESPINDOLA: Connection::Connection

and a close will be marked with

ESPINDOLA: Close

or

ESPINDOLA: AsyncClose

There should be a connection that is being opened but not closed and a backtrace showing where it was open.
Comment 3 :aceman 2012-06-02 05:55:56 PDT
Created attachment 629466 [details]
log with DB tracing

OK, here is the log. I think the connections 2,3 and 6 are not closed. However I do not know which DBs that are, because I don't know which debug block belongs to which connection. It looks like the block is just before the line with "Connection::connection X', but there is nothing before Connection 1 so I am not sure.
Comment 4 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-04 06:10:17 PDT
The backtraces of the connections that are not being closed are

0 _initDB() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":166]
    this = [object Object]
1 tryTzUri() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":221]
    this = [object BackstagePass @ 0xaf144040 (native @ 0xb2cff124)]
2 calTimezoneService_initialize([xpconnect wrapped calIGenericOperationListener @ 0xaf19de00 (native @ 0xaf3a0ab0)]) ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":228]
    this = [object Object]
3 anonymous() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":157]
    this = [object Object]
4 startup() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":118]
    this = [object Object]
5 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
6 callOrderedServices("startup", [xpconnect wrapped (nsISupports, calICalendarManager, calIStartupService, nsIObserver, nsIClassInfo) @ 0xaf19d8c0 (native @ 0xaf3a0a00)],[object Object]) ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":20]
    this = [object BackstagePass @ 0xafabb040 (native @ 0xb2cff124)]
7 observe() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":103]
    this = [object Object]
8 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>


-----------------------------------

0 calmgr_checkAndMigrateDB() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js":435]
    this = [object Object]
1 ccm_startup() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js":135]
    this = [object Object]
2 callOrderedServices("startup", [object Object]) ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":20]
    this = [object BackstagePass @ 0xafabb040 (native @ 0xb2cff124)]
3 anonymous() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":21]
    this = [object Object]
4 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
5 calTimezoneService_initialize([xpconnect wrapped calIGenericOperationListener @ 0xaf19de00 (native @ 0xaf3a0ab0)]) ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":252]
    this = [object Object]
6 anonymous() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":157]
    this = [object Object]
7 startup() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calTimezoneService.js":118]
    this = [object Object]
8 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
9 callOrderedServices("startup", [object Object]) ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":20]
    this = [object BackstagePass @ 0xafabb040 (native @ 0xb2cff124)]
10 observe() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calStartupService.js":103]
    this = [object Object]
11 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>

-----------------------------------------

0 cSC_prepareInitDB() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calStorageCalendar.js":363]
    this = [object Object]
1 anonymous() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calStorageCalendar.js":174]
    this = [object Object]
2 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
3 cmgr_assureCache() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js":797]
    this = [object Object]
4 cmgr_getCalendars() ["resource://calendar/modules/calUtils.jsm -> file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCalendarManager.js":762]
    this = [object Object]
5 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
6 anonymous() ["file:///var/SSD/TB-hg/tbird-bin/mozilla/dist/bin/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/components/calCompositeCalendar.js":160]
    this = [object Object]
7 <TOP LEVEL> ["<unknown>":0]
    <failed to get 'this' value>
8 getCompositeCalendar() ["chrome://calendar/content/calUtils.js":2033]
    this = [object ChromeWindow @ 0xaeaab140 (native @ 0xb2c08c0c)]
9 () ["chrome://calendar/content/calendar-task-tree.xml":130]
    this = [object XULElement @ 0xaad40800 (native @ 0xab94a1a0)]

I will try to take a look once I find out how to build Lightning
Comment 5 Philipp Kewisch [:Fallen] 2012-06-04 06:24:40 PDT
Thanks for taking a look. Its true we don't close the connections explicitly, I believe we don't even finalize our statements! We have a helper function in calUtils.js (or calUtils.jsm) that sets up a shutdown observer, maybe its time to use that helper.

Building Lightning basically means building Thunderbird with ac_add_options --enable-calendar. See https://developer.mozilla.org/en/Simple_Thunderbird_build#Building_Thunderbird_and_Lightning for details.
Comment 6 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-04 11:38:41 PDT
Created attachment 629863 [details] [diff] [review]
Close one of the connections.
Comment 7 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-04 11:51:22 PDT
Created attachment 629866 [details] [diff] [review]
[checked in] close another one.
Comment 8 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-04 12:15:05 PDT
Created attachment 629873 [details] [diff] [review]
[checked in] "last" missing db

thunderbird closes correctly with this one.
Comment 9 Philipp Kewisch [:Fallen] 2012-06-06 03:49:39 PDT
Comment on attachment 629863 [details] [diff] [review]
Close one of the connections.

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

I'm going to set r- on this patch for lack of alternatives. It really depends on my comment below:

::: calendar/base/src/calTimezoneService.js
@@ +357,5 @@
>              // default timezone getter set up the correct timezone again.
>              this.mDefaultTimezone = null;
>          }
> +        if (aTopic == "profile-before-change")
> +            this.shutdown();

Is the timezone service not shut down? It should be shut down by the startup service, here:

http://mxr.mozilla.org/comm-central/source/calendar/base/src/calStartupService.js#106

If it is shut down, please remove the observer here (in that case r=philipp with observer removed).

If not, please fix the startup service to properly shutdown its services (in that case, r- for a new patch)
Comment 10 Philipp Kewisch [:Fallen] 2012-06-06 03:51:11 PDT
Comment on attachment 629866 [details] [diff] [review]
[checked in] close another one.

r=philipp
Comment 11 Philipp Kewisch [:Fallen] 2012-06-06 03:56:56 PDT
Comment on attachment 629873 [details] [diff] [review]
[checked in] "last" missing db

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

::: calendar/providers/storage/calStorageCalendar.js
@@ +360,5 @@
>              // New style uri, no need for migration here
>              let localDB = cal.getCalendarDirectory();
>              localDB.append("local.sqlite");
>              localDB = Services.storage.openDatabase(localDB);
> +            Services.obs.removeObserver(this, "profile-before-change");

I'd prefer keeping the close code as close as possible, you could do it as follows:

cal.addObserver((function() this.mDB.close()).bind(this), "profile-before-change", true);

See this function: http://mxr.mozilla.org/comm-central/source/calendar/base/modules/calUtils.jsm#525

r=philipp with that changed and tested.
Comment 12 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-06 10:37:31 PDT
Comment on attachment 629866 [details] [diff] [review]
[checked in] close another one.

https://tbpl.mozilla.org/?tree=Thunderbird-Trunk&rev=f6ebae91f995
Comment 13 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-06 10:40:12 PDT
Comment on attachment 629873 [details] [diff] [review]
[checked in] "last" missing db

https://tbpl.mozilla.org/?tree=Thunderbird-Trunk&rev=0a0d5257d2ec
Comment 14 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-06 10:46:23 PDT
Created attachment 630627 [details] [diff] [review]
[checked in] refactoring

Sorry, I only noticed your comment after pushing the original patch. The attached one is just the refactoring.
Comment 15 Philipp Kewisch [:Fallen] 2012-06-06 11:12:37 PDT
Comment on attachment 630627 [details] [diff] [review]
[checked in] refactoring


>             localDB.append("local.sqlite");
>             localDB = Services.storage.openDatabase(localDB);
>-            Services.obs.removeObserver(this, "profile-before-change");
>+            cal.addObserver((function() this.mDB.close()).bind(this),
>+                            "profile-before-change", true);
> 
>             this.mDB = localDB;

Hmm could you put the addObserver calll after this.mDB = localDB? It will probably work due to late evaluation of this.mDB, but it looks wrong.

alternatively:

cal.addObserver(function() localDB.close(), "profile-before-change", true);


r=philipp with that change.
Comment 16 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-06 12:54:48 PDT
Comment on attachment 630627 [details] [diff] [review]
[checked in] refactoring

https://tbpl.mozilla.org/?tree=Thunderbird-Trunk&rev=686474e9b65d
Comment 17 :aceman 2012-06-07 03:30:34 PDT
Is there anything to do here?
It seems the patches have landed, I'll test the trunk soon.
Comment 18 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-07 06:18:42 PDT
There is still one missing. See comment 9.
Comment 19 Stefan Sitter 2012-06-07 06:26:26 PDT
Comment on attachment 629866 [details] [diff] [review]
[checked in] close another one.

check in to https://hg.mozilla.org/comm-central/rev/f6ebae91f995
Comment 20 Stefan Sitter 2012-06-07 06:27:05 PDT
Comment on attachment 629873 [details] [diff] [review]
[checked in] "last" missing db

checked in to https://hg.mozilla.org/comm-central/rev/0a0d5257d2ec
Comment 21 Stefan Sitter 2012-06-07 06:30:33 PDT
Comment on attachment 630627 [details] [diff] [review]
[checked in] refactoring

checked in to https://hg.mozilla.org/comm-central/rev/686474e9b65d

this.mDB.close() was changed to localDB.close(). But is the locally scoped variable |localDB| still available during the later shutdown procedure?
Comment 22 :aceman 2012-06-08 12:31:49 PDT
Current trunk still hangs, so there really is something missing.
Comment 23 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-08 13:07:06 PDT
(In reply to :aceman from comment #22)
> Current trunk still hangs, so there really is something missing.

The patch with a review-.

I was not able to figure out why the timezone service is not shutdown. Philipp, were you able to reproduce the problem with a debug build?
Comment 24 Philipp Kewisch [:Fallen] 2012-06-09 05:32:54 PDT
(In reply to Stefan Sitter from comment #21)
> Comment on attachment 630627 [details] [diff] [review]
> [checked in] refactoring
> 
> checked in to https://hg.mozilla.org/comm-central/rev/686474e9b65d
> 
> this.mDB.close() was changed to localDB.close(). But is the locally scoped
> variable |localDB| still available during the later shutdown procedure?

The closure will keep the localDB variable alive so we are fine as long as it is not set to null explicitly.

(In reply to Rafael Ávila de Espíndola (:espindola) from comment #23)
> (In reply to :aceman from comment #22)
> > Current trunk still hangs, so there really is something missing.
> 
> The patch with a review-.
> 
> I was not able to figure out why the timezone service is not shutdown.
> Philipp, were you able to reproduce the problem with a debug build?

I haven't had a chance to build one, just got a new harddrive and still migrating. Since without a debug build it works fine (with the slight changes we did in IRC), that could be a start, otherwise I'll have to look into it in the coming week.
Comment 25 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-06-11 09:10:24 PDT
Created attachment 631910 [details] [diff] [review]
debug patch

I have to go work on another bug, so I am attaching what I have found so far in case someone else can take a look.

The attached patch adds a bunch of dump calls to try to find out what the regular shutdown process is not working. The failure is coming from XPC_WN_CallMethod. Setting a breakpoint in

    XPCCallContext ccx(JS_CALLER, cx, obj, funobj, JSID_VOID, argc, JS_ARGV(cx, vp), vp);
    XPCWrappedNative* wrapper = ccx.GetWrapper(); // HERE

will show that ccx.mWrapper is null in the case that fails. I still have to debug why.
Comment 26 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-08-09 08:20:32 PDT
Sorry, given that the problem is in the shutdown process and not in the changes I made to sql connections, I have to unassign myself as I will not have time to work on this any time soon.
Comment 27 Stefan Sitter 2012-09-25 23:11:16 PDT
Created attachment 664807 [details] [diff] [review]
[checked in] finalize statements and close databases

CalendarManager: Fix shutdown() being called twice, once incorrectly from observe() and once via calIStartupService. This caused crash during application shutdown resulting in shutdown() of TimezoneService not being called.

TimezoneService: Finalize statement before closing the database to fix error "ASSERTION: sqlite3_close failed. There are probably outstanding statements that are listed above!".

StorageProvider: There are 4 possibilities to open the database, ensure that database will be closed in any case. Finalize statements before closing the database to fix assertion error mentioned above.

With this patch applied the Debug build shutdowns correctly and doesn't crash during shutdown anymore.
Comment 28 :aceman 2012-09-25 23:24:12 PDT
Cool, maybe I'll be able to build calendar again :)
Comment 29 Philipp Kewisch [:Fallen] 2012-09-25 23:42:39 PDT
Comment on attachment 664807 [details] [diff] [review]
[checked in] finalize statements and close databases

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

Looks good to me, very good catch! I hope this fixes our shutdown crash issues.

::: calendar/base/src/calTimezoneService.js
@@ +121,5 @@
>      shutdown: function shutdown(aCompleteListener) {
>          Services.prefs.removeObserver("calendar.timezone.local", this);
>  
> +        if (this.mSelectByTzid) { this.mSelectByTzid.finalize(); }
> +        if (this.mDb) { this.mDb.close(); this.mDb = null; }

Maybe we should keep this in a try/catch block, since not calling the onResult listener will mean the following services won't be shut down.
Comment 30 Stefan Sitter 2012-09-26 09:49:26 PDT
Pushed to https://hg.mozilla.org/comm-central/rev/55fbdfdedfc1 after adding back the try/catch block.
Comment 31 Stefan Sitter 2012-09-27 11:19:04 PDT
I tested a lot with the patch and every time Thunderbird shutdown correct. Today I rebuild and now I get the following shutdown errors after adding/removing events:

> WARNING: NS_ENSURE_TRUE(asyncCloseWasCalled) failed: file .../src/mozilla/storage/src/mozStorageConnection.cpp, line 890
> ************************************************************
> * Call to xpconnect wrapped JSObject produced this error:  *
> [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [mozIStorageConnection.close]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: .../components/calStorageCalendar.js :: cSC_shutdownDB :: line 1489"  data: no]
> ************************************************************
> WARNING: NS_ENSURE_TRUE(asyncCloseWasCalled) failed: file .../src/mozilla/storage/src/mozStorageConnection.cpp, line 890
> ************************************************************
> * Call to xpconnect wrapped JSObject produced this error:  *
> [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [mozIStorageConnection.close]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: .../calendar-js/calDeletedItems.js :: shutdown :: line 150"  data: no]
> ************************************************************
> Assertion failure: !connections[i]->ConnectionReady(), at .../src/mozilla/storage/src/mozStorageService.cpp:837
Comment 32 Stefan Sitter 2012-09-27 12:05:26 PDT
Created attachment 665578 [details] [diff] [review]
[checked in] use asyncClose() and add try/catch block

OK, I hope I got it this time. Instead of close() use asyncClose(), add try/catch/logging block around the close, and fix some other small issue in shutdown.
Comment 33 Stefan Sitter 2012-09-27 12:17:32 PDT
Another question: in calDeletedItems.js we work on database file in the users profile. Should the shutdown happen on "profile-before-change" instead of "xpcom-shutdown" as it is done now?
Comment 34 Philipp Kewisch [:Fallen] 2012-09-29 10:09:55 PDT
Comment on attachment 665578 [details] [diff] [review]
[checked in] use asyncClose() and add try/catch block

r=philipp, good catch on the getCalendarManager() function!
Comment 35 Stefan Sitter 2012-09-30 04:26:37 PDT
Comment on attachment 665578 [details] [diff] [review]
[checked in] use asyncClose() and add try/catch block

Pushed to https://hg.mozilla.org/comm-central/rev/b79fb7f5ae12
Comment 36 Stefan Sitter 2012-10-01 03:01:45 PDT
aceman, I think problem should be fixed now. Could you retest and validate if all problems are gone if time permits?
Comment 37 :aceman 2012-10-01 04:59:44 PDT
Yes I can.
Comment 38 Rafael Ávila de Espíndola (:espindola) (not reading bugmail) 2012-10-01 07:08:03 PDT
thanks!
Comment 39 :aceman 2012-10-01 13:55:29 PDT
It seems to work fine now, I can run with TB enabled in debug build and it does not hang/crash at shutdown.

Is there anything still open here?
Comment 40 :aceman 2012-10-01 13:55:52 PDT
I mean calendar enabled :)
Comment 41 Stefan Sitter 2012-10-01 14:48:22 PDT
Comment on attachment 664807 [details] [diff] [review]
[checked in] finalize statements and close databases

Parts of the patches landed for 1.8. I'd like to take the remaining patches for 1.9 because it seems to be a long running release.
Comment 42 Philipp Kewisch [:Fallen] 2012-10-09 10:54:18 PDT
Comment on attachment 664807 [details] [diff] [review]
[checked in] finalize statements and close databases

Ok, I assume this is on aurora due to the merge.
Comment 43 Stefan Sitter 2012-10-10 12:47:01 PDT
Backported to https://hg.mozilla.org/releases/comm-beta/rev/ffe3ddad9bb8

Note You need to log in before you can comment on or make changes to this bug.