Query perfromance problem

Hi,

I was playing with paging and sorting recently and after trying few different aproaches got some strange behavior from ODB.

First of all, I will show you results from page rendering times, but trust me - when debugging application, getting data from ODB takes a long time in one case. Anyway, one of my methods in DAO looks like this:

 public List<Product> list(int start, int count, String sortColumn, boolean isAscending) {
  logger.debug("Method start.");
  List<Product> prodList = null;
  TypedQuery<Product> icQuery = null;
  if (sortColumn == null) {
   icQuery = em.createQuery("select prod from Product prod", Product.class);
  } else {
   logger.debug("Sort column: {}, ascending {}", sortColumn, isAscending);
   String q = null;
   if (isAscending) {
    q = "select prod from Product prod order by prod." + sortColumn + " ASC";
   } else {
    q = "select prod from Product prod order by prod." + sortColumn + " DESC";
   }
   icQuery = em.createQuery(q, Product.class);
  }
  try {
   logger.debug("Executing query");
   prodList = icQuery.setFirstResult(start).setMaxResults(count).getResultList();
   logger.debug("Query executed");
  } catch (NullPointerException ex) {
   return null;
  }
  logger.debug("Returning data");
  return prodList;
 }

Nothing special here, it just returns list of objects with paging order in given way. Now, when running this query with sort column set to 'id', it takes about 9-11 seconds to render webpage:

2011-03-11 13:08:05.552 [http-18080-exec-3] INFO  Click - handleRequest:  /catalogs/product-list.htm - 10484 ms

Refreshing this page with any other column for index with @Index set on it, lowers this time do 1-3 secodns.

2011-03-11 13:08:30.897 [http-18080-exec-6] INFO  Click - handleRequest:  /catalogs/product-list.htm - 1407 ms

I was trying to run this query with sorting column set to something else than id, but without @Index - results are more or less in middle at about 5-6 seconds.

There is about 14k objects of this type in this database.

ODB is using quite a lot of CPU during this query:

Mem:    645948k total,   209792k used,   436156k free,     8060k buffers
Swap:   144544k total,        0k used,   144544k free,    67320k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 2467 odb       20   0  672m 116m 7332 S 24.0 18.5   0:43.39 java

There is almost none of I/O activity after first query, so I assume data are in memory already.

Hi,

Could you please upload a runnable test case that demonstrates this issue?

Sure, I will try to prepare such a test program.

Thank you for the bug report and for the test program.

Version 2.1.1_01 should fix this issue.

Fix works perfectly well. The difference in speed is really huge.

Thanks for the fix.