Working with PostgreSQL database is unusably slow

[schniepp]

JabRef version 4.31 on Ubuntu 16.04

• [X ] I have tested the latest development version from http://builds.jabref.org/master/ and the problem persists

Steps to reproduce the behavior:

1. Connect to PostgreSQL db with ≈3,400 entries.
2. See that it takes over 8 minutes the database has still not loaded completely.

This is on a very fast server. The Internet connection from here is only about 1 MB/s download. However, loading the same BibTeX file off a shared drive from the same server takes only a few seconds.
Saving my 3,400 entries to the remote database also took hours and hours, and JabRef consumed something like 8 GB of memory while doing this.

Would it be worth trying a MySQL db instead?

Log File

Paste an excerpt of your log file here

[bruot]

I also have long processing times with a smaller database of about 600 entries. About half an hour to paste 600 entries to the remote PostgreSQL DB when creating the tables. Then, it takes about 2 min to open it.

This occurs on both versions 4.3.1 and 3.8.2.

[abepolk]

I am interested in working on this issue. To recreate the problem, I could set up a test PostgreSQL database on Heroku (a PaaS I've used before), and fill it with BibTeX entries with a script. Then I could try to load the entries as described. Is there anything I should know before getting started?

[tobiasdiez]

We have some database related tests, they might be a good starting point https://github.com/JabRef/jabref/tree/master/src/test/java/org/jabref/logic/shared

However, I would wait until #4520 is merged. This PR already improves the DB performance and maybe this fixes this issue as well.

[abepolk]

Any other issues I can work on? I wanted to take a break from JavaFX, but if there's not a strong need, I can work on the importer dialog. Feel free to move this conversation to Gitter.

[bruot]

I think there may be two issues related to the DB requests:

• Single requests can be quite slow and make the user wait. Solution: speed can be improved, or it could be an idea to let the user continue using Jabref before requests end.
• Some operations seem to generate many DB requests: They could be grouped to be sent as a single request.

Regarding the second point, these operations seem to be concerned (from what I have tested):

• Opening the remote DB.
• Pasting or deleting multiple entries at once.
• Pasting a BibTex source that contains several fields.

[stefan-kolb]

Unfortunately this issue is known. The synch is done way too many times I think. There should be one or more duplicate issues for this already.

[schniepp]

I played around with python (using the psycopg2 library) to access my JabRef (PostGreSQL) database remotely. I have ≈4,000 entries, but I was surprised how blazingly fast this went via python. Getting all keys, or all filenames of attached PDFs, or all group information for all entries — it all happened within very few seconds or even fractions of a second. This compares to minutes that many JabRef operations take. This definitely gives me an idea that there is a lot of room for improvement.

My requests pulled many entries from the DB at once, rather than doing many individual reads.

Not sure if it's of any help here, and I really don't have much experience with databases at all. But I thought I'd mention it.

[Ali96kz]

@schniepp Is it problem still exist?

[stefan-kolb]

Issue should still persist.

[Ali96kz]

@NorwayMaple Do you want to work on it?

[abepolk]

@Ali96kz I'm looking into this. How do I find the keystore I need? Do you recommend I use something along the lines of keytool -genkey?

[tobiasdiez]

@schniepp @stefan-kolb are you sure the issue still exists in the latest development version? If I'm not mistaken @Ali96kz recently implemented some huge improvements to the performance.

It would be nice if you could try out the latest development version before @NorwayMaple invests time in trying to fix it. Thanks!

[bruot]

For me, tests on the latest Windows built with a remote PostgreSQL server show the problem described in the issue is solved, but there are still many actions that remain slow:

• Opening a DB: now fast (a few seconds for a few hundreds of entries)
• Editing a field: still slow as I type the first character (~5 s), a bit faster for the second character, then it gets faster and good as I continue typing.
• Pasting, in the BibTeX tab, an entry containing several fields: still very slow (1-2 min).
• Switching tabs: takes a few seconds.

[schniepp]

Connecting to a remote PostGreSQL DB with ≈3,900 entries took 30 seconds for JabRef to show the entries in the window.

Exporting the same database as a *.bib file and opening this file from the same server (via mounted network share) using the same network connection took exactly the same time: 30 seconds.

So in response to my original problem, this is definitely a huge improvement! Thank you so much! It is well usable now! I apologize for my late response, as I have been totally overloaded at work.

[abepolk]

Is this issue still needing work? I left off trying to connect JabRef to an external Postgres and debugging a error relating to a root certificate.

[Siedlerchr]

@NorwayMaple Regarding the cert stuff have a look here: https://jdbc.postgresql.org/documentation/head/ssl-client.html

and here for the server side:
https://www.postgresql.org/docs/current/ssl-tcp.html#SSL-OPENSSL-CONFIG

[Siedlerchr]

Btw, can someone of you working with the shared databse reproduce this issue? #4804

[abepolk]

@Siedlerchr Thanks for the links. Basically, when I try to connect, JabRef says it cannot find /Users/Abe/.postgresql/root.crt. But I don't have a directory /Users/Abe/.postgresql, and I have set environmental variable $PGHOME is set to somewhere else.

[bruot]

@NorwayMaple There are still the slowdowns mentioned in my previous comment. @schniepp Have you tried in your tests doing other tasks than just opening the database? In particular anything that writes on the DB would be interesting... If these write-related problems should be considered as a separate issue, I can open one.

[abepolk]

@Siedlerchr I looked at the page on setting up the Postgres SSL client, and it looks like it is not using "Java's default mechanism" for connecting to SSL that uses keystores, but rather LibPQFactory, which is part of Postgres's JDBC driver. What is this "default mechanism" and how do I use it?

[Siedlerchr]

Hm, I could get it to work under Windows by following the steps at the bottom of the page, e..g generate a key for the keystore and in JaRef select the keystore

Regarding the location of the certs:
Have you tried connecting with pgAdmin to your db and then editing the configuration? Screenshots are from pgAdmin3

[abepolk]

It seems to be able to connect without certificates on pgAdmin.

When you connect to the Postgres database from JabRef, do you know what driver is being used? Mine implements LibPQ, which apparently does not use keystores.

[abepolk]

@Siedlerchr Would it be possible for you to run my version at https://github.com/NorwayMaple/jabref/tree/test_JDBC? I added the line DriverManager.setLogWriter(new PrintWriter(System.out)); to write debug logs from DriverManager to standard out.

When you connect to the database using this version, what is printed to standard out that does not go through Jabref's logger? For me it is the following:

DriverManager.getConnection("jdbc:postgresql://ec2-23-21-129-125.compute-1.amazonaws.com:5432/d8dtd037lnqrtq")
    trying com.mysql.cj.jdbc.Driver
    trying org.postgresql.Driver
org.postgresql.util.PSQLException: Could not open SSL root certificate file /Users/Abe/.postgresql/root.crt.
        at org.postgresql.ssl.LibPQFactory.<init>(LibPQFactory.java:120)
        at org.postgresql.core.SocketFactoryFactory.getSslSocketFactory(SocketFactoryFactory.java:61)
        at org.postgresql.ssl.MakeSSL.convert(MakeSSL.java:33)
        at org.postgresql.core.v3.ConnectionFactoryImpl.enableSSL(ConnectionFactoryImpl.java:435)
        at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:94)
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:192)
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
        at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:195)
        at org.postgresql.Driver.makeConnection(Driver.java:454)
        at org.postgresql.Driver.connect(Driver.java:256)
        at java.sql.DriverManager.getConnection(DriverManager.java:664)
        at java.sql.DriverManager.getConnection(DriverManager.java:208)
        at org.jabref.logic.shared.DBMSConnection.<init>(DBMSConnection.java:38)
        at org.jabref.gui.shared.SharedDatabaseUIManager.openNewSharedDatabaseTab(SharedDatabaseUIManager.java:121)
        at org.jabref.gui.shared.SharedDatabaseLoginDialogViewModel.openSharedDatabase(SharedDatabaseLoginDialogViewModel.java:162)
        at org.jabref.gui.shared.SharedDatabaseLoginDialogViewModel.openDatabase(SharedDatabaseLoginDialogViewModel.java:125)
        at org.jabref.gui.shared.SharedDatabaseLoginDialogView.openDatabase(SharedDatabaseLoginDialogView.java:70)
        at org.jabref.gui.shared.SharedDatabaseLoginDialogView.lambda$new$925(SharedDatabaseLoginDialogView.java:61)
        at org.jabref.gui.util.ControlHelper.lambda$setAction$959(ControlHelper.java:19)
        at com.sun.javafx.event.CompositeEventHandler$NormalEventFilterRecord.handleCapturingEvent(CompositeEventHandler.java:282)
        at com.sun.javafx.event.CompositeEventHandler.dispatchCapturingEvent(CompositeEventHandler.java:98)
        at com.sun.javafx.event.EventHandlerManager.dispatchCapturingEvent(EventHandlerManager.java:223)
        at com.sun.javafx.event.EventHandlerManager.dispatchCapturingEvent(EventHandlerManager.java:180)
        at com.sun.javafx.event.CompositeEventDispatcher.dispatchCapturingEvent(CompositeEventDispatcher.java:43)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:52)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.EventUtil.fireEventImpl(EventUtil.java:74)
        at com.sun.javafx.event.EventUtil.fireEvent(EventUtil.java:49)
        at javafx.event.Event.fireEvent(Event.java:198)
        at javafx.scene.Node.fireEvent(Node.java:8411)
        at javafx.scene.control.Button.fire(Button.java:185)
        at com.sun.javafx.scene.control.behavior.ButtonBehavior.mouseReleased(ButtonBehavior.java:182)
        at com.sun.javafx.scene.control.skin.BehaviorSkinBase$1.handle(BehaviorSkinBase.java:96)
        at com.sun.javafx.scene.control.skin.BehaviorSkinBase$1.handle(BehaviorSkinBase.java:89)
        at com.sun.javafx.event.CompositeEventHandler$NormalEventHandlerRecord.handleBubblingEvent(CompositeEventHandler.java:218)
        at com.sun.javafx.event.CompositeEventHandler.dispatchBubblingEvent(CompositeEventHandler.java:80)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:238)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:191)
        at com.sun.javafx.event.CompositeEventDispatcher.dispatchBubblingEvent(CompositeEventDispatcher.java:59)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:58)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:56)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.EventUtil.fireEventImpl(EventUtil.java:74)
        at com.sun.javafx.event.EventUtil.fireEvent(EventUtil.java:49)
        at javafx.event.Event.fireEvent(Event.java:198)
        at javafx.scene.Scene$MouseHandler.process(Scene.java:3757)
        at javafx.scene.Scene$MouseHandler.access$1500(Scene.java:3485)
        at javafx.scene.Scene.impl_processMouseEvent(Scene.java:1762)
        at javafx.scene.Scene$ScenePeerListener.mouseEvent(Scene.java:2494)
        at com.sun.javafx.tk.quantum.GlassViewEventHandler$MouseEventNotification.run(GlassViewEventHandler.java:394)
        at com.sun.javafx.tk.quantum.GlassViewEventHandler$MouseEventNotification.run(GlassViewEventHandler.java:295)
        at java.security.AccessController.doPrivileged(Native Method)
        at com.sun.javafx.tk.quantum.GlassViewEventHandler.lambda$handleMouseEvent$353(GlassViewEventHandler.java:432)
        at com.sun.javafx.tk.quantum.QuantumToolkit.runWithoutRenderLock(QuantumToolkit.java:389)
        at com.sun.javafx.tk.quantum.GlassViewEventHandler.handleMouseEvent(GlassViewEventHandler.java:431)
        at com.sun.glass.ui.View.handleMouseEvent(View.java:555)
        at com.sun.glass.ui.View.notifyMouse(View.java:937)
        at com.sun.glass.ui.mac.MacApplication._enterNestedEventLoopImpl(Native Method)
        at com.sun.glass.ui.mac.MacApplication._enterNestedEventLoop(MacApplication.java:109)
        at com.sun.glass.ui.Application.enterNestedEventLoop(Application.java:511)
        at com.sun.glass.ui.EventLoop.enter(EventLoop.java:107)
        at com.sun.javafx.tk.quantum.QuantumToolkit.enterNestedEventLoop(QuantumToolkit.java:590)
        at javafx.stage.Stage.showAndWait(Stage.java:474)
        at javafx.scene.control.HeavyweightDialog.showAndWait(HeavyweightDialog.java:162)
        at javafx.scene.control.Dialog.showAndWait(Dialog.java:341)
        at org.jabref.gui.shared.ConnectToSharedDatabaseCommand.execute(ConnectToSharedDatabaseCommand.java:19)
        at org.jabref.gui.actions.JabRefAction.lambda$new$85(JabRefAction.java:29)
        at org.controlsfx.control.action.Action.handle(Action.java:419)
        at org.controlsfx.control.action.Action.handle(Action.java:64)
        at com.sun.javafx.event.CompositeEventHandler.dispatchBubblingEvent(CompositeEventHandler.java:86)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:238)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:191)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:58)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.EventUtil.fireEventImpl(EventUtil.java:74)
        at com.sun.javafx.event.EventUtil.fireEvent(EventUtil.java:49)
        at javafx.event.Event.fireEvent(Event.java:198)
        at javafx.scene.control.MenuItem.fire(MenuItem.java:462)
        at com.sun.javafx.scene.control.GlobalMenuAdapter.lambda$bindMenuItemProperties$20(GlobalMenuAdapter.java:153)
        at com.sun.javafx.event.CompositeEventHandler.dispatchBubblingEvent(CompositeEventHandler.java:86)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:238)
        at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent(EventHandlerManager.java:191)
        at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent(BasicEventDispatcher.java:58)
        at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent(EventDispatchChainImpl.java:114)
        at com.sun.javafx.event.EventUtil.fireEventImpl(EventUtil.java:74)
        at com.sun.javafx.event.EventUtil.fireEvent(EventUtil.java:54)
        at javafx.event.Event.fireEvent(Event.java:198)
        at javafx.scene.control.MenuItem.fire(MenuItem.java:462)
        at com.sun.javafx.tk.quantum.GlassSystemMenu$1.action(GlassSystemMenu.java:238)
Caused by: java.io.FileNotFoundException: /Users/Abe/.postgresql/root.crt (No such file or directory)
        at java.io.FileInputStream.open0(Native Method)
        at java.io.FileInputStream.open(FileInputStream.java:195)
        at java.io.FileInputStream.<init>(FileInputStream.java:138)
        at java.io.FileInputStream.<init>(FileInputStream.java:93)
        at org.postgresql.ssl.LibPQFactory.<init>(LibPQFactory.java:117)
        ... 99 more
SQLState(08006)
getConnection failed: org.postgresql.util.PSQLException: Could not open SSL root certificate file /Users/Abe/.postgresql/root.crt.

Let me know so I can see why it is working in your environment and not mine.

[Siedlerchr]

Okay tested again, works fine: Postgres 10.x
Seems like your path to the file is not setup correctly. If you overwrite the path settings like I did, then it should work. Otherwise it will load the default files from ~.postgres

DriverManager.getConnection("jdbc:postgresql://localhost:5432/jabref")
    trying com.mysql.cj.jdbc.Driver
    trying org.postgresql.Driver
getConnection returning org.postgresql.Driver
08:18:33.474 [JavaFX Application Thread] INFO  org.jabref.gui.JabRefDialogService - Connection to PostgreSQL server established. -

In pgAdmin Server Properties (you can change them when disconnected)

I also uploaded you my certs file.
No password for the files.
Default connection postgres:postgres

certspostgres.zip

[abepolk]

Are you referring to the postgres URL by "path to the file"? How did you overwrite the path settings?

[abepolk]

I'm still looking into this. It looks like events are being fired from org.jabref.model.entry.BibEntry to org.jabref.model.database.BibDatabase, which is relays them to other classes, but not to org.jabref.model.database.BibDatabaseContext, which is where org.jabref.model.event.CoarseChangeFilter is listening. org.jabref.logic.shared.DBMSSynchronizer listens to CoarseChangeFilter.

[abepolk]

I discovered that when you type, for example, 7 characters into a field in a shared database, org.jabref.model.event.CoarseChangeFilter considers the delta between the old field contents and the new field contents to be 7 for each letter typed. Because each typed character fires a FieldChangedEvent, and each one has a delta of 7 characters, each one passes through the filter and causes a sync with the shared database. Perhaps this is because I type them faster than the GUI can update the field? Either way, it should only fire one event with a delta of 7 characters, or 7 events with a delta of one character (which would be stopped by the filter and prevented from causing a database sync).

[abepolk]

The issue I mentioned above seems to be fixed. However, entries are still updated one at a time. This appears to be because when you update multiple entries, they are updated in a for loop. Each iteration fires an event, which is listened to by DBMSSynchronizer. DBMSSychronizer makes one database query per event. Therefore, if you delete 1000 entries, 1000 events are fired. This is one of the reasons bulk operations take so long.

At least some of the for loops are in org.jabref.gui.BasePanel, which means they are also responsible for local database updates. The only two ways I can think of to solve this problem are to change the for loops to account for firing fewer events to update remote databases, or to aggregate events, so that DBMSSychronizer combines all the fired events into one query. Changing the for loops would mean changing code that is used by the rest of the app, and I don't know if there's a clean way of aggregating events. I can be more specific if that helps.

Does anyone have ideas on this?

[tobiasdiez]

@NorwayMaple feel free to change the for loops to batch operations (such as addAll or removeAll). The code in BasePanel is everything than sacred (in the contrary, you are happily invited to refactor it as much as you want - it's still one of the most dark and dangerous alleys in the JabRef code world). I have no idea how updates to many entries (i.e. changing the value of a field) should be combined/aggregated. These operations currently trigger an update of the UI and thus also lead to performance problems in a usual non-shared environment...

[abepolk]

@tobiasdiez I started writing the code to batch remove entries. I ended up changing EntryRemovedEvent to EntriesRemovedEvent and changing the code wherever it was subscribed to that event. It doesn't compile because I haven't finished. This is actually more of a refactoring of the entry events overall than specifically something that relates to database syncs. Also, I still have to look into if the tests need to be changed. I pushed it to a branch on my fork, linked below. Would you be interested in me making a PR for this?

abepolk@80e8377

[Siedlerchr]

@NorwayMaple Sounds good, please create a PR , so we can look at the changes

[igorsteinmacher]

Sorry about any inconvenience caused here.
I am replicating the discussion that moved ahead in my repo (and will remove the repo to avoid further confusion)

[igorsteinmacher]

@schniepp said:
Anyway, my largest issue in connecting with the DB is not longer the read/write performance, but an issue where doing certain bulk operations would just create to a completely hanging JabRef instance. The only solution in these cases is to kill JabRef and restart it. I happens more often with a slow Internet connection than with a fast one. I usually see this when I am trying to move certain entries into a particular group (say, 20 or so). In some cases it will do it for the first 4 or so and then get completely stuck.
But unfortunately, this is not reproducible. Sometimes, it will not complete a single one, and in other times, all 20 will go through in a reasonably short time.

[igorsteinmacher]

@NorwayMaple said:
Thanks for the feedback. Do you mean that the issue used to be read/write performance, but now that is no longer a problem? Or that the issue was never read/write performance?

[igorsteinmacher]

@schniepp said:

@NorwayMaple: in the beginning it was indeed a performance issue. The biggest performance issue got resolved. Indeed I believe I was the one who originally reported above that loading from a DB with 3,900 entries became as fast as loading the same entries from a *.bib file. This became possible after some of the fixes that were implemented in response to this report.
Once this was fixed, using the DB remotely actually became a viable option for me. I believe this is what enabled the discovery of the hanging/crashing issue. Perhaps, this should be a separate report? But to some extent I was under the impression we are discussion various DB related issues in this thread anyway.

[abepolk]

Either way - we can use this thread or another one. Right now I'm making a fix to batch entry synchronization, but I can look into the hanging operation later.

[github-actions]

This issue has been inactive for half a year. Since JabRef is constantly evolving this issue may not be relevant any longer and it will be closed in two weeks if no further activity occurs.

As part of an effort to ensure that the JabRef team is focusing on important and valid issues, we would like to ask if you could update the issue if it still persists. This could be in the following form:

• If there has been a longer discussion, add a short summary of the most important points as a new comment (if not yet existing).
• Provide further steps or information on how to reproduce this issue.
• Upvote the initial post if you like to see it implemented soon. Votes are not the only metric that we use to determine the requests that are implemented, however, they do factor into our decision-making process.
• If all information is provided and still up-to-date, then just add a short comment that the issue is still relevant.

Thank you for your contribution!