(4)(+0000013): DELETE FROM betterbibtex.citationkey WHERE itemID = ? [11054]
(4)(+0000031): Committed DB transaction ijEEA477
(4)(+0000012): Beginning DB transaction YOOthWww
(4)(+0000013): DELETE FROM betterbibtex.citationkey WHERE itemID = ? [11026]
(4)(+0000026): Committed DB transaction YOOthWww
(4)(+0000010): Beginning DB transaction Cx4FsnzS
(4)(+0000012): DELETE FROM betterbibtex.citationkey WHERE itemID = ? [26033]
(4)(+0000029): Committed DB transaction Cx4FsnzS
(4)(+0000010): Beginning DB transaction N8qavwWS
(4)(+0000012): DELETE FROM betterbibtex.citationkey WHERE itemID = ? [14874]
(4)(+0000029): Committed DB transaction N8qavwWS
(4)(+0000010): Beginning DB transaction 6xqHSovh
(4)(+0000014): DELETE FROM betterbibtex.citationkey WHERE itemID = ? [5768]
(4)(+0000028): Committed DB transaction 6xqHSovh
Yeah, this is all BBT. @emilianoeheyns, you need to batch these into transactions. You can't execute thousands and thousands of transactions one after another.
(And same with the REPLACE statements that come later.)
A release build is running that batches key persistence so it only runs batched changes in one transaction at most once per 5 seconds. The 24k3 database runs key assignment in 66 seconds now, batch size average is 1842.
That's great — thanks. @warguelles, could you try with the latest version of BBT and see how that does? Might as well generate a Debug ID for that while you're testing it.
You can probably just trigger the upgrade but say to restart later and then use "Restart with Logging Enabled…". You just can't let the update do the restart if you haven't set debug.store manually.
Again, those aren't separate popups. That's just the one popup Zotero shows during the Extra field migration. After the circular progress bar finishes, it changes to the journal article icon while it sends notifications about the item changes, including to plugins. You'd see a delay there if a plugin takes a long time to do whatever it does when it receives those notifications.
We'd want some Debug IDs from as soon as the delay starts and at intervals after — so when it's showing that journal article icon where normally it would just close immediately. The goal is to try to capture whatever is happening there before it fills up the log buffer and loses earlier lines.
Probably not news, but these aren't BBTs, and I wouldn't typically expect the BBT "assigning" popup to appear in this scenario. That only happens when there are lots of keys without a BBT citekey. In this scenario, the items would typically have a BBT key, but BBT would update citation keys for each of them, without any UI. All BBT citekey persistance is now batched, so these updates would also be.
@emilianoeheyns: Right, but it would hang while showing the journal article icon while plugins are processing the Notifier updates, so this is absolutely due to BBT or another plugin (and @warguelles only has a couple other enabled — though should obviously test with just BBT to eliminate variables)
Just to confirm... I will just run the migration again under the same conditions as the last run. But sending some Debug ID after the progress bar finishes (with the journal icon)
You'd see a delay there if a plugin takes a long time to do whatever it does when it receives those notifications.
which I wouldn't expect the BBT key persistence to contribute (too) much to. The notifier responder registered the key in BBTs in-memory database for citation keys, and is then handed off to the batcher for persistence without waiting for that to complete. This was always the case, but the previous behavior is like the batch size was set to 1.
I think that's likely, but part of that is certainly key recalculation, and that won't be affected by the key persistence, whether batched or not. The batching is a good thing, cuts down the time a lot, but calculating 24k3 keys still takes a fair bit of time.
I've just ran the 24k test with persistence disabled and as I expected, that is merely fractions of a second faster than with persistence. I could technically hand that off so it would not show up in the notifier timing, but it would consume this time all the same at some point.
Upgrade Storage
D589831860 just now
(And same with the REPLACE statements that come later.)
The process took around 4 minutes but the app is still running in the background
Can you try again and submit a few Debug IDs as it runs, including 10 seconds and 30 seconds after the circular progress bar completes?
What do you mean by "the app is still running in the background"?
https://s3.amazonaws.com/zotero.org/images/forums/u2580262/9t9a3h902lwgxpxza2ia.png
https://s3.amazonaws.com/zotero.org/images/forums/u2580262/vmn0udt4gfvew5wec86e.png
when the second one dissapears, the app continues work in the background and it is VERY slow Just 10 and 30 seconds afetr the progress bar, but with the other one running?
https://s3.amazonaws.com/zotero.org/images/forums/u2580262/coakhtzrdk4av9i13riz.png
We'd want some Debug IDs from as soon as the delay starts and at intervals after — so when it's showing that journal article icon where normally it would just close immediately. The goal is to try to capture whatever is happening there before it fills up the log buffer and loses earlier lines.
Right?