[Zotero 5.0 Beta] Repeated failure to upgrade database with Standalone Beta

edited January 3, 2017
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?


Update: I installed the Firefox beta. The database upgrade process similarly failed there.
  • Hmm, that's no good. Could you generate real-time debug output for the upgrade attempt and send it to support@zotero.org?
  • How can I do that when Zotero locks itself to do the upgrade upon startup?
  • Real-time debug output isn't the same as a Debug ID — see the link.
  • edited January 4, 2017
    Sorry, didn't see the link (the red text is hard to differentiate from the black with my form of colorblindness).

    Here is output for Standalone:

    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.):
  • Do you have other extensions installed in Standalone? If so, could you 1) make a list and 2) try deleting them from the 'extensions' directory within your Zotero profile directory? (That won't delete any data. You'll just need to reinstall them.) Something seems to be trying to access the database during the upgrade, and I didn't think we had any code that did that.
  • edited January 5, 2017
    Here is a gist for standalone with no extensions installed:

    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:
  • Is there any more information I can provide that would be helpful?
  • I'm hoping the next beta will fix this. We're aiming to have that out in the next few days.
  • Unfortunately, upgrade is still failing in the new Standalone Beta.

    Fails with this error message:
    Error: Transaction timeout, most likely caused by unresolved pending work.
    From previous event:
    From previous event:
    From previous event:
    From previous event:

    Full real-time debug:
  • So that's actually not the full debug output. I thought we used to have this in the instructions, but try this:

    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.
  • On Windows 10, I can only set the buffer to a maximum of 999.

    Here is a gist with the beginning of a run and the end of the same run:
  • On Windows 10, I can only set the buffer to a maximum of 999.
    Good to see debugging on Windows becoming even more difficult than before…

    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?
  • edited January 15, 2017
    It's taking a really long time to submit the Debug report. I will post the Debug ID when it's finished.

    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.
  • OK, this obviously isn't a great solution, but in build 114 I've increased the timeout in question from 4 minutes to an hour. Try that and let me know if the upgrade goes through (and if so, how long it takes).

    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?)
  • I'll run it. It's a 2013 MacBook Air. SSD. 8 gb RAM. Zotero runs in a Windows 10 Parallels Virtual machine with 4 GB of RAM allocated to it.
  • Is there a way to see how long the upgrade takes post hoc? I'd like to just let it run and come back later.
  • Oh, I didn't realize this was a VM — timing doesn't matter, then. Windows filesystem access is pretty slow in general, but in a VM it's always been positively glacial for me.
  • Okay, now the upgrade finished without any errors in about 8 minutes. However, after finishing, the Zotero UI stayed on "Loading items..." for more than 10 minutes, and trying to close Zotero and re-open did not resolve the problem (still got stuck at "Loading items...").
  • you can open preferences? Database integrity check passes?
  • Checking integrity never seemed to finish. I manually ran the SQL commands to clean the database; no change in behavior.
  • edited January 23, 2017

    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.
  • Hmm. Could I get a Debug ID from startup through when it finally appears? (It doesn't appear to actually be doing anything at the end of this one, so I'm hoping that the moment when it actually finishes it's clearer what the hold-up was.)
  • Here is a Debug ID through completion of loading: D2059005156
  • User interface ready in 832559 ms
    So that took about 14 minutes.

    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:
    Component returned failure code: 0x8052000e (NS_ERROR_FILE_IS_LOCKED) [mozIStorageService.backupDatabaseFile]
    Which suggests that something about this virtualized filesystem isn't allowing normal database backups to work.
  • Same setup as 4.0. It took maybe 10-20 seconds to start Standalone then. Hmm, never had any problems with Zotero backups before.

    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.
  • Oh, so this delay only happens on the upgraded database, not the synced one? That's good. I've added some temporary functions in the latest beta that might help narrow this down. Try this:

    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.
  • DB Info:

    "auto_vacuum": 1,
    "cache_size": 2000,
    "locking_mode": "exclusive",
    "page_size": 4096

    Debug ID for Vacuum:

    Debug ID for restart after Vacuum (still very slow):
  • Could I see a Debug ID for starting the upgraded database — the 20-30 seconds one? That's in the same VM?
  • Debug ID:

    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).

Sign In or Register to comment.