Jackcess, loop with multiple matching rows very slow,

Question

I execute this my code and i don't understant why elapsed time is very high for loop.

There are two loops. First loop on Invoices table and the seconde loop on InvoicesLignes table.

InvoicesLignes table has a index "Code", it's the "foreign-key" of Invoice. In database Access, there is a relation between Invoices and InvoicesLines, but the foreign-key is not defined and i can't use the Joiner class. I can't modify Database.

import java.io.File;
import java.util.Date;
import java.io.IOException;

import com.healthmarketscience.jackcess.*;

class MultipleLoop {

  public static void main(String[] args) {

    File jfile = new File("/project/database.mdb");

    Date start_date= new Date("2013/01/01");
    Date end_date= new Date("2013/12/31");

    try {

        Database db = DatabaseBuilder.open(jfile);

        Table invoices = db.getTable("Invoices");
        Table invoices_lignes = db.getTable("InvoiceLignes");

        Cursor cursor = CursorBuilder.createCursor(invoices_lignes.getIndex("Code"));

        for(Row invoice : invoices) {

          if ((start_date.before((Date)invoice.get("Date")) 
                    || start_date.equals((Date)invoice.get("Date"))) 
              &&  
              (end_date.after((Date)invoice.get("Date")) 
                    || end_date.equals((Date)invoice.get("Date")) )) {

          System.out.println(String.format("Invoice id : '%s' time : '%s'", 
                             invoice.get("Code"),
                             System.currentTimeMillis( ) ));

          long start = System.currentTimeMillis( );

          for (Row invoice_ligne : cursor.newIterable().addMatchPattern("Code",
                                                           invoice.get("Code"))) 
          {
              System.out.println(String.format("Loop time : '%s'", 
                                 System.currentTimeMillis( )));
          }

          long end = System.currentTimeMillis( );

          System.out.println(String.format("\n\nEnd loop time : '%s'", 
                             System.currentTimeMillis( )));
          long diff = end - start;

          System.out.println(String.format("Loop elapsed time : '%s' ms\n\n", 
                             diff ));

          }

        }

       } catch (IOException e) {
      //} catch (Exception e) {

        System.out.println(e);
      }

    }
}

and my log is

Invoice id : '19901/79018' time : '1411043140236' 
Loop time : '1411043140237'
Loop time : '1411043140237'
Loop time : '1411043140237'
Loop time : '1411043140237'


End loop time : '1411043141335'
Loop elapsed time : '1098' ms


 Invoice id : '138901/909719' time : '1411043141335'
 Loop time : '1411043141336'
 Loop time : '1411043141336'


 End loop time : '1411043142418'
 Loop elapsed time : '1083' ms


 Invoice id : '1309091/729090' time : '1411043142419'
 Loop time : '1411043142419'
 Loop time : '1411043142419'


 End loop time : '1411043143515'
 Loop elapsed time : '1096' ms

I don't understand why elapsed time is very high for loop

Thank for your help

Basically, as @GordThompson wrote, if you don't have an index on the search column, then you have to do a full table scan for every find. if you have enough memory in your jvm, you could build your own lookup table. — jtahlborn, Sep 18 '14 at 12:46
I use index ["Code"]... i updated my code and my log. exemple : invoice '19901/79018', no dealy to find InvoiceLignes, but there is delay at the end of the loop. — Phane, Sep 18 '14 at 13:07
hmm, i wonder if there is a bug in the index lookups where it's not fast failing at the end of the matching range. — jtahlborn, Sep 18 '14 at 13:23
Related: [Bug report](http://sourceforge.net/p/jackcess/bugs/109/). — Gord Thompson, Sep 21 '14 at 13:31

score 1 · Accepted Answer · edited May 23 '17 at 11:49

I suspect that you are still effectively scanning the whole [InvoicesLignes] table for each iteration of the outer [Invoices] loop. Your approach ...

Table invoices = db_opened.getTable("Invoices");
Table invoices_lignes = db_opened.getTable("InvoicesLignes");
Cursor cursor = CursorBuilder.createCursor(invoices_lignes.getIndex("Code"));

for (Row row : invoices) {
    long start = System.currentTimeMillis( );
    System.out.println(String.format("Invoice : '%s'", start));

    for (Row crow : cursor.newIterable().addMatchPattern("Code", row.get("Code"))) {
        System.out.println(String.format("Loop : '%s'", System.currentTimeMillis( )));
    }

    long end = System.currentTimeMillis( );
    System.out.println(String.format("End loop : '%s'", System.currentTimeMillis( )));
    long diff = end - start;
    System.out.println(String.format("Loop elapsed time : '%s' ms", diff ));
}

... produces:

Invoice : '1411041092492'
Loop : '1411041092527'
Loop : '1411041092528'
Loop : '1411041092529'
End loop : '1411041094440'
Loop elapsed time : '1948' ms
Invoice : '1411041094442'
Loop : '1411041094443'
Loop : '1411041094444'
End loop : '1411041095882'
Loop elapsed time : '1440' ms

However, this variation ...

Table invoices = db_opened.getTable("Invoices");
Table invoices_lignes = db_opened.getTable("InvoicesLignes");

for (Row row : invoices) {
    long start = System.currentTimeMillis( );
    System.out.println(String.format("Invoice : '%s'", start));

    IndexCursor cursor = new CursorBuilder(invoices_lignes)
            .setIndexByName("Code")
            .setSpecificEntry(row.get("Code"))
            .toIndexCursor();
    for (Row crow : cursor) {
        System.out.println(String.format("Loop : '%s'", System.currentTimeMillis( )));
    }

    long end = System.currentTimeMillis( );
    System.out.println(String.format("End loop : '%s'", System.currentTimeMillis( )));
    long diff = end - start;
    System.out.println(String.format("Loop elapsed time : '%s' ms", diff ));
}

... produces:

Invoice : '1411041030007'
Loop : '1411041030060'
Loop : '1411041030062'
Loop : '1411041030063'
End loop : '1411041030063'
Loop elapsed time : '56' ms
Invoice : '1411041030067'
Loop : '1411041030069'
Loop : '1411041030070'
End loop : '1411041030071'
Loop elapsed time : '4' ms

Also, have you considered using UCanAccess? The corresponding UCanAccess code ...

String dbFileSpec = "C:/Users/Gord/Desktop/InvoiceTest.mdb";
try (Connection conn=DriverManager.getConnection("jdbc:ucanaccess://" + dbFileSpec)) {
    PreparedStatement psLignes = conn.prepareStatement("SELECT * FROM InvoicesLignes WHERE Code=?");
    Statement sInv = conn.createStatement();
    ResultSet rsInv = sInv.executeQuery("SELECT Code FROM Invoices");
    while (rsInv.next()) {
        long start = System.currentTimeMillis( );
        System.out.println(String.format("Invoice : '%s'", start));

        psLignes.setString(1, rsInv.getString("Code"));
        ResultSet rsLignes = psLignes.executeQuery();
        while (rsLignes.next()) {
            System.out.println(String.format("Loop : '%s'", System.currentTimeMillis()));
        }
        long end = System.currentTimeMillis( );
        System.out.println(String.format("End loop : '%s'", System.currentTimeMillis( )));
        long diff = end - start;
        System.out.println(String.format("Loop elapsed time : '%s' ms", diff ));
    }
    conn.close();
} catch (Exception e) {
    e.printStackTrace(System.out);
}

... produces:

Invoice : '1411041417462'
Loop : '1411041417478'
Loop : '1411041417478'
Loop : '1411041417479'
End loop : '1411041417479'
Loop elapsed time : '17' ms
Invoice : '1411041417482'
Loop : '1411041417483'
Loop : '1411041417483'
End loop : '1411041417483'
Loop elapsed time : '1' ms

UCanAccess can increase the startup time of the Java application because it copies the Access data into an hsqldb "mirror" database (in-memory by default), but once loaded it is very fast and we can use regular SQL instead of working directly with the Jackcess API.

For more information on UCanAccess see

Manipulating an Access database from Java without ODBC

Thank Gord, i updated my code. I don't understand : scanning the whole [InvoicesLignes] table, i use index ["Code"]. In the new log we can see the Invoice '19901/79018' with measure point '1411043140236' and after, the measure points of InvoicesLignes, there is no delay. But at end of the loop there is delay '1097 ms' why, i don't... — Phane, Sep 18 '14 at 12:50
I can't use UCanAccess, because the database is updating by another application in the same time, it's not compatible the "mirror" of hsqldb. And the database is tall, > 1Go. — Phane, Sep 18 '14 at 12:58
Your version is all right, thank Gord. And the winner is... Jackcess ! 15.2 secondes for ODBC and 6.1 secondes for Jackcess. In French : Il n'y a pas photo ! — Phane, Sep 19 '14 at 13:38

Jackcess, loop with multiple matching rows very slow,

1 Answers1