Search code examples
javaperformancesqlitejdbcresultset

Why does the last "ResultSet.next()"-iteration take way more time than the previous iterations?


The last iteration of my "while(res.next())"-loop takes 1.5 seconds whereas the previous iterations only take around ~0,003 milliseconds. I'm very confused.

I'm getting a ResultSet from my SQLite database with a common JDBC query. The ResultSet is not huge, it's always 4 columns wide and between 0 and 100 rows long. Then I want to save the ResultSet-data in POJOs and store those POJOs in an ArrayList. I use the usual iteration-method where you simply put up a "while(res.next())"-loop and iterate over the entire ResultSet. I recognized a bottleneck in my code and could narrow it down to the while(res.next())-loop. I started debugging and also measuring execution-times in my code and it turns out that the last .next()-call, which should return false so that the loop stops, takes a very long time.

    ArrayList<Trade> trades = new ArrayList<>();
    try
    {
      Statement statement = connector.getConnection().createStatement();
      statement.setFetchSize(1337);

      ResultSet res = statement.executeQuery("SELECT * FROM trades WHERE timestamp >= 0 AND timestamp < 1337;");
      res.setFetchSize(1337);

      int numberOfTrades = 0;
      long startTime = System.nanoTime();
      while(res.next())
      {
        long addObjectTime = System.nanoTime();
        trades.add(new Trade(res.getLong("id"),res.getLong("timestamp"),res.getDouble("price"),res.getDouble("amount")));
        numberOfTrades++;
        System.out.println("Added trade to list within "+(System.nanoTime()-addObjectTime)+"ns.");
      }
      System.out.println("List-creation completed within "+(System.nanoTime()-startTime)+"ns.");
      System.out.println("Number of trades: "+numberOfTrades);
    } catch (SQLException e)
    {
      e.printStackTrace();
    }

That's my code. As you can see I already tried playing around with various fetchSizes as other people mentioned in performance-threads concerning the .next()-method. I tried everything I could but the outcome of it all looks still like this:

Added trade to list within 46000ns.
Added trade to list within 3200ns.
Added trade to list within 2400ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 4500ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 3100ns.
Added trade to list within 2400ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 2400ns.
Added trade to list within 2400ns.
Added trade to list within 2300ns.
Added trade to list within 2200ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 2300ns.
Added trade to list within 11100ns.
List-creation completed within 1548543200ns.
Number of trades: 22

Adding a POJO to my ArrayList with the data from the ResultSet usually takes between 2-5 microseconds. So all in all, the loop shouldn't take much longer than all the execution-times for adding trades combined right? In my example that would be 0,1073 milliseconds. Instead the loop takes a total of more than 1,5 seconds which would be 10,000x the amount that I'd expect. I actually have zero clue what's happening here. And this is a severe problem for my program because the code-fragment is executed about 100,000 times, so 150,000 seconds would be 40 hours of performance-loss :(


Solution

  • I actually solved the problem but I am not 100% sure why it's solved now. The database I was querying had many millions of entries and was always accessed by a single column (timestamp). I indexed timestamp and the performance issues vanished completely. I still don't know why the .next()-method behaved the way it did.