Closed Bug 429521 Opened 13 years ago Closed 13 years ago

[Trunk] database schema upgrade 6/7/8/9 -> 10 fails [An error was encountered preparing the calendar located at moz-profile-calendar:// for use.]

Categories

(Toolkit :: Storage, defect)

x86
Windows XP
defect
Not set
critical

Tracking

()

RESOLVED FIXED

People

(Reporter: ssitter, Assigned: mrbkap)

References

Details

(Keywords: regression, testcase, Whiteboard: [needs trunk baking before 1.9 approval])

Attachments

(1 file, 2 obsolete files)

[Trunk] database schema upgrade 6/7 -> 8 fails

Loading a profile that was created with a nightly build before 2008-02-18 in a nightly build after 2008-02-18 will result in a popup error message: "An error was encountered preparing the calendar located at moz-profile-calendar:// for use. It will not be available.". Error Console shows additional messages, see below.

Regression range:
  WORKS in Sunbird 0.6a1 (2008-02-18-18) trunk
  FAILS in Sunbird 0.6a1 (2008-02-19-21) trunk

  WORKS in Lightning 0.6a1 (2008-02-17-21) + Tb 3.0a1pre (2008041703)
  FAILS in Lightning 0.6a1 (2008-02-18-20) + Tb 3.0a1pre (2008041703)

Checkins during regression range: http://tinyurl.com/4vus7s --> Only Bug 410931

The error happens only if there exists at least one event in the database. From the console output it seems that in the error case the schema upgrade 6/7 -> 8 is started twice. The database itself is still schema 7 afterwards but console shows no dumps for failure case.

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

Console output if no event exists (success case):
    **** Upgrading schema from 6/7 -> 8
    [calAlarmService] starting...

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

Console output if event exists (failure case):
    **** Upgrading schema from 6/7 -> 8
    **** Upgrading schema from 6/7 -> 8

Error Console output:

Error: Assert failed: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [calICalendar.uri]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///[...]/sunbird/js/calCalendarManager.js :: anonymous :: line 459"  data: no]
1: [file:///[...]/sunbird/js/calUtils.js:1369] ASSERT
2: [file:///[...]/sunbird/js/calCalendarManager.js:462] anonymous
3: [file:///[...]/sunbird/js/calCalendarManager.js:602] cmgr_assureCache
4: [file:///[...]/sunbird/js/calCalendarManager.js:579] cmgr_getCalendars
5: [null:0] null
Source File: file:///[...]/sunbird/js/calUtils.js Line: 1373

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

Error: Can't create calendar for 1 (storage, moz-profile-calendar://): TypeError: cal is null
Source File: file:///[...]/sunbird/js/calCalendarManager.js Line: 709

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

Error: Assert failed: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [calICalendar.uri]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///[...]/sunbird/js/calCalendarManager.js :: anonymous :: line 459"  data: no]
1: [file:///[...]/sunbird/js/calUtils.js:1369] ASSERT
2: [file:///[...]/sunbird/js/calCalendarManager.js:462] anonymous
3: [null:0] null
4: [chrome://calendar/content/calendar-management.js:104] loadCalendarManager
5: [chrome://calendar/content/calendar.js:89] calendarInit
Source File: file:///[...]/sunbird/js/calUtils.js Line: 1373

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

Error: calendar is null
Source File: file:///[...]/sunbird/js/calCalendarManager.js Line: 563

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

Error: uncaught exception: [Exception... "'[JavaScript Error: "calendar is null" {file: "file:///[...]/sunbird/js/calCalendarManager.js" line: 563}]' when calling method: [calICalendarManager::registerCalendar]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: chrome://calendar/content/calendar-management.js :: loadCalendarManager :: line 106"  data: yes]

--------------------------------------------------------------------
Duplicate of this bug: 418562
Duplicate of this bug: 428271
Possible workaround:
1. Open with the old working Sunbird/Lightning build
2. Export each calendar to iCalendar format and save the .ics file 
   Note the URLs for remote calendars
3. Close Sunbird/Thunderbird
4. Delete the database file "storage.sdb" from profile
5. Start Sunbird/Thunderbird to create a new database file "storage.sdb"
6. Create new calendars and import the .ics files
   Resubscribe to remote calendars
Flags: wanted-calendar0.9?
Additional information:

By adding dump() statements to the source code I can follow the upgrade procedure to the following line:

    tzId = getTzIds.row.zone;

http://bonsai.mozilla.org/cvsblame.cgi?file=/mozilla/calendar/providers/storage/calStorageCalendar.js&rev=1.136&mark=1171#1152

I don't see any dump() output directly added after that statement. Seems the execution hangs/waits or has been aborted silently.

Anyone knows why the statement mentioned above works on MOZILLA_1_8_BRANCH but not on Trunk?
This should definitely be fixed, but trunk bugs cannot become wanted/blocking0.9 by definition as it will be released from the branch.
Severity: major → critical
Flags: wanted-calendar0.9?
Using the same Lightning builds as mentioned in Comment #0 but different Thunderbird builds I get the additional regression range:

    Works in Thunderbird 3.0a1pre (2008-01-10-03)
    Fails in Thunderbird 3.0a1pre (2008-01-11-03)

Checkins during that range: http://tinyurl.com/45w8zt

From a first glance I'd say Bug 406087 (update to sqlite 3.5.4) might be related.
Shawn, do you know if the SQLite update (Bug 406087) might be responsible for the mozStorage statement failure/hang mentioned in Comment #4 above?
There's *a lot* different from trunk to branch in storage.  SQLite shouldn't have had an behavior change there.  Can I see a stack trace of the hang (including JS stack please)?
See also regression range mentioned in Comment #6. The very same calendar code works on Trunk up to the 2008-01-10-03 nightly build but fails in the next nightly Trunk build.

How do I create the requested JS stack? Currently all the code runs during application startup and I was only able to add some dump() statements in the code for debugging.
When you get the hang, attach gdb, then do the following two things:
call DumpJSStack()
bt

The js stack will dump out to the console window you opened the application with, and the backtrace will dump out into gdb's terminal.

I don't know how to do that on windows though...
When trying with a debug build the information I get is:

0[a94eb0]: BEGIN TRANSACTION

0[a94eb0]: WARNING: Unsafe use of LIKE detected!  Please ensure that you are using mozIStorageConnection::escapeStringForLIKE and that you are binding that result to the statement to prevent SQL injection attacks.: file e:/dev/sb-trunk/mozilla/storage/src/mozStorageStatement.cpp, line 176

0[a94eb0]: SELECT DISTINCT(zone) FROM (SELECT recurrence_id_tz AS zone FROM cal_attendees  WHERE recurrence_id_tz LIKE '/mozilla.org%' UNION SELECT recurrence_id_tz AS zone FROM cal_events     WHERE recurrence_id_tz LIKE '/mozilla.org%' UNION SELECT event_start_tz   AS zone FROM cal_events     WHERE event_start_tz   LIKE '/mozilla.org%' UNION SELECT event_end_tz     AS zone FROM cal_events     WHERE event_end_tz     LIKE '/mozilla.org%' UNION SELECT alarm_time_tz    AS zone FROM cal_events     WHERE alarm_time_tz    LIKE '/mozilla.org%' UNION SELECT recurrence_id_tz AS zone FROM cal_properties WHERE recurrence_id_tz LIKE '/mozilla.org%' UNION SELECT recurrence_id_tz AS zone FROM cal_todos      WHERE recurrence_id_tz LIKE '/mozilla.org%' UNION SELECT todo_entry_tz    AS zone FROM cal_todos      WHERE todo_entry_tz    LIKE '/mozilla.org%' UNION SELECT todo_due_tz      AS zone FROM cal_todos      WHERE todo_due_tz      LIKE '/mozilla.org%' UNION SELECT alarm_time_tz    AS zone FROM cal_todos      WHERE alarm_time_tz    LIKE '/mozilla.org%');
Attached file xpcshell testcase (obsolete) —
xpcshell testcase that shows the same behavior as observed above in calStorageCalendar.js by doing the same basic steps.

Basically the code creates and initializes a mozIStorageStatementWrapper object and calls step() on it (line 64). When trying to read the row member of the wrapper object (line 69) the execution stops immediately. There is no sign for a hang.

I hope someone can use it to debug the issue.
Keywords: testcase
It'll be a lot easier if you make this test run in |make check| like the rest of the storage tests (and a lot of your functions are needed either since they are provided by head_storage.js).  It will certainly increase the likelihood of me looking at this sooner rather than later.
Duplicate of this bug: 437075
Attached file xpcshell testcase, v2 (obsolete) —
testcase can be run by copying it to mozilla/storage/test/unit and executing |make check|. The execution stops immediately at the line |var tzId = wrapper.row.zone;|
Attachment #318228 - Attachment is obsolete: true
(In reply to comment #15)
> Created an attachment (id=323585) [details]
> xpcshell testcase, v2
> 
> testcase can be run by copying it to mozilla/storage/test/unit and executing
> |make check|. The execution stops immediately at the line |var tzId =
> wrapper.row.zone;|
Awesome!  I was actually going to do that myself today.  This bug is next on my todo list.
I can reproduce - not sure what's up though...

Stepping through with gdb doesn't find it, but printing out the strings, I see they are equal.  Looking for some JS folks to chime in.
Component: Internal Components → Storage
Product: Calendar → Toolkit
QA Contact: base → storage
Same failure using Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.0.2pre) Gecko/2008070219 Calendar/0.6a1.

Is there an possible workaround for the error, e.g. by changing the SQL query?
Summary: [Trunk] database schema upgrade 6/7 -> 8 fails [An error was encountered preparing the calendar located at moz-profile-calendar:// for use.] → [Trunk] database schema upgrade 6/7/8/9 -> 10 fails [An error was encountered preparing the calendar located at moz-profile-calendar:// for use.]
The error is in the wrapper code (but I'm not sure why).  The workaround would be to use the mozIStorageStatement API's directly.  I need someone more familiar with the JS engine to help me out with this since it's not clear why it's hanging.
Attached patch Possible fixSplinter Review
The reason for the problem here is that the code returns false from a JS hook without reporting an error.

A minimized testcase would be either someMozStorageStatementRow[3] or someMozStorageStatementRow.foopy (where foopy isn't a column name).

Also, if you set *_retval, you don't really want to return NS_ERROR_* because that'll override the exception that the JS engine threw.
Assignee: nobody → mrbkap
Attachment #323585 - Attachment is obsolete: true
Status: NEW → ASSIGNED
Attachment #331647 - Flags: review?(sdwilsh)
Note - the issue with this test case is that the name isn't defined.  You need to use "AS zone" in the SQL.
Comment on attachment 331647 [details] [diff] [review]
Possible fix

r=sdwilsh
Attachment #331647 - Flags: review?(sdwilsh)
Attachment #331647 - Flags: review+
Attachment #331647 - Flags: approval1.9.0.2?
Whiteboard: [needs trunk baking before 1.9 approval]
Comment on attachment 331647 [details] [diff] [review]
Possible fix

Please re-request approval after this lands and bakes on mozilla-central.
Attachment #331647 - Flags: approval1.9.0.2?
Fix pushed as http://hg.mozilla.org/index.cgi/mozilla-central/rev/f01bfd359595
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.