Reasonable OGM Query Performance (150 sec to retrieve <900 nodes?)

[usuallycwdillon]

I have a pretty large graph (865k nodes, 3.93M relationships) that I'm querying from Java. I've been using OGM to create and store data. Now I'm starting to use some queries in my application. The performance isn't as good as I'd expected, so I printed out some test cases. Is this reasonable?

It's taking about 2-1/2 min to retrieve <900 nodes from the database. ...which is a lot longer than I expected.

The code below prints out a few timestamps:

• when the program begins
• after the first Neo4j Session gets called (~.65 sec)
• after running a query to retrieve a count of nodes with :Territory label (~.6 sec)
• after calling session.loadAll() and returning a Collection object (~140 sec)
• after calling session.load() for a single node by String id (~.1 sec)
• after creating a Map object via my Service interface (~142 sec)

I'm nervous about the performance I should expect when I try to instantiate 50k-100k nodes into a collection.

My database is running in Neo4j Desktop. Would it be better to run it as a real service?

public class GeoJSONFactory {
    
    public static void main(String args[]) {

        LocalTime startTime = LocalTime.now();
        System.out.println("The program started working at: " + startTime);

        Session session = Neo4jSessionFactory.getInstance().getNeo4jSession();
        LocalTime sessionTime = LocalTime.now();
        System.out.println("The session was initialized at: " + sessionTime);

        String query = "MATCH (n:Territory) RETURN COUNT(n)";
        System.out.println(Neo4jSessionFactory.getInstance().getNeo4jSession().query(query, Collections.emptyMap()));
        LocalTime queryTime = LocalTime.now();
        System.out.println("The query returned at: " + queryTime);

        Collection<Territory> territories = session.loadAll(Territory.class, 1);
        LocalTime collectionTime = LocalTime.now();
        System.out.println("The collection was retrieved at: " + collectionTime);
        LocalTime endTime = LocalTime.now();
        System.out.println("...and the collection size calculation (" + territories.size() + ") returned at at " + endTime);
        // Browser: Started streaming 897 records after 4 ms and completed after 445 ms.

        Territory territory = session.load(Territory.class, "Israel of 1938");
        LocalTime oneNodeTime = LocalTime.now();
        System.out.println("The node <Israel of 1938> was retrieved at: " + oneNodeTime);

        Map<String, Territory> territoryMap = new TerritoryServiceImpl().getMap();
        LocalTime implTime = LocalTime.now();
        System.out.println("The map retrieval from _TerritoryServiceImpl_ returned at at " + implTime);

        System.exit(0);
    }
}

Results:

The program started working at: 14:58:14.539
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

The session was initialized at: 14:58:15.275
Nov 20, 2018 2:58:15 PM org.neo4j.driver.internal.logging.JULogger info
INFO: Direct driver instance 558216562 created for server address localhost:7687

org.neo4j.ogm.response.model.QueryResultModel@3d285d7e
The query returned at: 14:58:15.941

The collection was retrieved at: 15:00:35.825
...and the collection size calculation (897) returned at at 15:00:35.825

The node <Israel of 1938> was retrieved at: 15:00:35.904

The map retrieval from _TerritoryServiceImpl_ returned at at 15:02:57.673

Process finished with exit code 0

[gerrit_meier · Accepted solution]

This is indeed very slow and nothing we are excepting to happen. Could you please also post your Territory class? Because you are fetching with the depth of 1 (default) Neo4j-OGM will also collect all related nodes.

[usuallycwdillon]

Ah! I should be collecting it with depth 0, then. There are about 80k related nodes (Tiles) and each of those 80k related nodes has 6 relations to 1 or more Territories.

The session was initialized at: 21:03:30.375
Nov 20, 2018 9:03:30 PM org.neo4j.driver.internal.logging.JULogger info
INFO: Direct driver instance 367746789 created for server address localhost:7687
org.neo4j.ogm.response.model.QueryResultModel@302552ec

The query returned at: 21:03:31.041

The collection was retrieved at: 21:03:31.447
...and the collection size calculation (897) returned at at 21:03:31.447

The node <Israel of 1938> was retrieved at: 21:03:31.516
The map retrieval from _TerritoryServiceImpl_ returned at at 21:03:31.856

Process finished with exit code 0