[Zotero 5.0 Beta] Repeated failure to upgrade database with Standalone Beta
I installed the current Standalone beta and tried to upgrade my database. It has repeatedly failed after a few minutes of upgrading, given the error message "Database upgrade error. Error: Transaction timeout, most likely caused by unresolved pending work."
I have a solid internet connection that isn't failing during the upgrade process. I also ran a full sync in (4.0) Zotero for Firefox to be sure the database was all synced. I have somewhere around 50,000 items in my library. Is the sheer size of the database causing the problems?
Thanks.
Update: I installed the Firefox beta. The database upgrade process similarly failed there.
I have a solid internet connection that isn't failing during the upgrade process. I also ran a full sync in (4.0) Zotero for Firefox to be sure the database was all synced. I have somewhere around 50,000 items in my library. Is the sheer size of the database causing the problems?
Thanks.
Update: I installed the Firefox beta. The database upgrade process similarly failed there.
Here is output for Standalone:
https://gist.github.com/bwiernik/e98d80f1cf6c5007b3ec7628ab528276
Here is output for Firefox (note that the error message only pops up when I click on the Open Zotero Pane button after the upgrade process starts. If I just let it run, even with Zotero pane or tab open, the Upgrading message displays continuously, even after the debug log has stopped updating.):
https://gist.github.com/bwiernik/33c47f62c5187e2945cacd9096d895bc
https://gist.github.com/bwiernik/a764bff3297078af21775d766c60646d
Same error. Eventually reaches "Zotero is locked -- skipping backup of DB 'zotero' "
Similar results for firefox -- ran for over an hour upgrading things, then hit the DB locked message, which repeated about 15 times over an hour before I stopped it.
Edit: Here is a log for a Firefox failure:
https://gist.github.com/bwiernik/f9b8b4948ca721604ba8cee313e13e10
Fails with this error message:
Error: Transaction timeout, most likely caused by unresolved pending work.
ConnectionData.prototype<.executeTransaction/promise</timeoutPromise</<@resource://gre/modules/Sqlite.jsm:649:33
setTimeout_timer@resource://gre/modules/Timer.jsm:30:5
From previous event:
Zotero.Schema</this.updateSchema<@chrome://zotero/content/xpcom/schema.js:128:24
From previous event:
_initFull<@chrome://zotero/content/xpcom/zotero.js:573:25
From previous event:
this.init<@chrome://zotero/content/xpcom/zotero.js:395:11
self.setTimeout/<.notify@resource://zotero/bluebird.js:54:5
From previous event:
ZoteroService@file:///C:/Program%20Files%20(x86)/Zotero%20Standalone/components/zotero-service.js:343:4
XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:326:19
@chrome://zotero/content/include.js:1:14
Full real-time debug:
https://gist.github.com/bwiernik/58e83b6425c7020a29590661520b5ddb
1) Open a cmd.exe window.
2) Click on the icon in the top left and select Defaults.
3) Under Layout, set Height under Screen Buffer Size to 9999.
4) Click OK.
Then try it again, and see if you get more output.
Here is a gist with the beginning of a run and the end of the same run:
https://gist.github.com/bwiernik/2d0be448f4a706bd4a72d4926e3d9e9f
So I think the problem here is that you're hitting a built-in timeout from the Mozilla database code that aborts transactions after 4 minutes. Does that sound possible? We can override that in Zotero, but that's a very long time for an upgrade, so I'd be interested in seeing the full debug output to see if there's anything we can do to speed this up. In the latest beta I've added a new viewer/submitter for real-time debug output, which you can trigger with just the -ZoteroDebug flag. (You can omit the -console flag.) Could you try generating a Debug ID with that?
In the meantime, I copied the output here as well: https://gist.github.com/bwiernik/e81f63259ca707f420b1bf636605c794
(I also just found that you sink the output of a cmd command to a text file like this:
[command] > C:\debugOutput.txt
)
Edit: 2 hours later, the debug report still never completed.
Also, is this a recent machine? Does it have a HDD or an SSD? (I'm guessing the former based on the times in the debug output?)
Report ID: 1602396143
Debug ID: D2102850522
(That is for a startup with the upgraded database that never finishes loading.)
Edit: After leaving Zotero open for about 30 minutes, the library finally finished loading. Closing Zotero and re-opening, however, lead to the same very slow loading process.
Is this the setup you used previously with 4.0? If so, how long did it take to open?
Along with the extreme slowness, you're getting this error: Which suggests that something about this virtualized filesystem isn't allowing normal database backups to work.
By comparison, starting a new database built from syncing the account to an empty 5.0 database, opening takes about 20-30 seconds (there are a few group libraries I'm not syncing to this database, but the database sizes aren't that different).
Obviously, I've got a working database without upgrading, so we don't have to keep troubleshooting if it's not helpful on your end.
1) Back up your upgraded database.
2) Update to build 117.
3) Click the "DB Info" button in the Advanced pane of the prefs and copy the result here.
4) Start debug output logging and click the "Vacuum DB" button. That should hopefully be more or less immediate, but if not, you can let it go, and when it's done, generate a Debug ID, which will log how long it took. (If it's quick, no need for the output.) Then restart Zotero and see if it's still slow.
{
"auto_vacuum": 1,
"cache_size": 2000,
"locking_mode": "exclusive",
"page_size": 4096
}
Debug ID for Vacuum:
D1841859343
Debug ID for restart after Vacuum (still very slow):
D1115359860
D151934620
This is for syncing the 20-30 second DB (this one was synced from my account to an empty database, not upgraded from a 4.0 database). In the same VM. Loading the collections/tags pane is almost immediate for this one, takes 20-30 seconds to get the item list in My Library to appear.
Besides how the database was constructed, the other major difference is that this one has only 4 group libraries, while the upgraded database has 14 group libraries (some of which are very large).