First query takes 4+ minutes to complete

Hi,

we are evaluating ObjectDB 2.5.1_04 in embedded mode hoping to replace SQLite in our application.

We observed that in our case it takes on average more than 4 minutes to complete the first SELECT query that we run on the DB which contains about 320,000 records of a single type of object. SQLite in comparison responds within few seconds on average with the same number of records.

We hope to receive your recommendation on how to improve this result with this post.

 

Test System

We are running our tests on a 64bit Linux (CentOS 6.3) machine with JDK 1.7. The system has 4Gb of RAM (DDT III - 1333) and i5-3470 3.20GHz CPU (4 cores). The motherboard that we are using is Intel DQ77MK.

While we test:

1. CPU utilisation never goes beyond 20% on one of the CPUs. The rest are hardly used.
2. SWAP memory is available but never used (no swapping occurs).

 

POJO

We store object of a single class in the DB. The class has data members that are basic Java types. Here is extract of the code (related to the query that we run).

@Entity(name="RecordingMetaData")

@SequenceGenerator(
    name="RecordingMetaData_sequence",
    sequenceName="RecordingMetaData_sequence",
    allocationSize=1
)

@Indices({

    :

    // Indices building trees in client applications
    @Index(members={"startDate", "toExtension"}),
    @Index(members={"startDate", "fromExtension"})
})
public class RecordingMetaData {

    private Long id;                // Primary key - annotated with @Id
    private Long version;           // Annotated with @Version
:   
    private Short channelNumber;
:
    private Date startDate;         // Date: date part of startDateTime
    private Date startTime;         // Time: time part of startDateTime
   
:   
    private String toExtension;
    private String fromExtension;

 

Operation

We use two EntityManagers in our code, each running in a different thread:

1. The first EntityManager only adds records to the DB at a rate of 5 records per second. Each add is a single new object and is wrapped in a transaction.

2. The 2nd EntityManager runs the queries (JPQL SELECT statements) shown next. 

Query

We test with the following query:

SELECT r from RecordingMetaData AS r ORDER BY r.startDate DESC, r.startTime DESC, r.channelNumber DESC

We limit the result to 50 records.

Basically we wish to get the last 50 records stored in the database, or youngest 50 records.

DB configuration

We use following configuration in objectdb.conf:

<objectdb>

<general>
  <temp path="$temp" threshold="64mb" />
  <network inactivity-timeout="0" />
  <url-history size="50" user="true" password="true" />
  <log path="$objectdb/log/" max="8mb" stdout="false" stderr="false" />
  <log-archive path="$objectdb/log/archive/" retain="90" />
  <logger name="*" level="info" />
</general>

<database>
  <size initial="1024mb" resize="256mb" page="2kb" />
  <recovery enabled="true" sync="false" path="$objectdb/" max="512mb" />
  <recording enabled="false" sync="false" path="$objectdb/" mode="write" />
  <locking version-check="true" />
  <processing cache="256mb" max-threads="10" />
  <query-cache results="64mb" programs="50" />
  <extensions drop="temp,tmp" />
</database>

<entities>
  <enhancement agent="false" reflection="warning" />
  <cache ref="weak" level2="512mb" />
  <persist serialization="false" />
  <cascade-persist always="auto" on-persist="false" on-commit="true" />
  <dirty-tracking arrays="false" />
</entities>

<schema>
</schema>

<server>
        <connection port="6136" max="100" />
        <data path="$objectdb/db" />
        <!--
        <replication url="objectdb://localhost/test.odb;user=admin;password=admin" />
        -->
</server>

<users>
</users>

<ssl enabled="false">
</ssl>

</objectdb>

How we test

Teh issue happens with the first query that we run after we start the application that uses the DB in embedded mode. So we basically start the application and let is stabilise for about 60 seconds. By this time a number of new records are already being added by one of the threads. Then we run one of the above query and time it until we get the result set of 50 records.

To run the test again, we stop the appliaction and then repeat the above.

 

Explanation on why this is happening and how we can avoid it will be very much appreciated. Our next test point is 500,000 record, then 700,000 and then 900,000. At this stage we expect the appliaction to be basically unusable when we hit the 500,000 mark unless we find a solution to the issue.

 

Thank you

Emil

Please try adding an index:

    @Index(members={"startDate", "startTime", "channelNumber"})

Start with a new empty database, in order to make sure that the new index is used.

With this index your query execution time should be very good, but if it doesn't, please post your test and we will try to check this issue further.

Hi support,

we spent all of today testing with the index that you recommend as well as a number of others. The problem still exists.

As far as I know indices are only good for fields that appear in the WHERE part of the SQL/JPQL. In our case the fields are in the ORDER part. So, I do not think an index will help.

Also, we tried a different query today:

SELECT DISTINCT NEW com.arunta.base.db.DateExtensionDTO(r.startDate, r.toExtension) FROM RecordingMetaData AS r

The expected result is 7 records (date, extension combinations). This query takes more than 2 minutes to complete on average when run for the first time. We get results back in less than as second on subsequent executions. Note that we have the following index:

@Index(members={"startDate", "toExtension"}),

 

We tried clearing the EntityManager cache before running the query to see if we can reproduce the problem every time we run the query without restarting the application, but no luck. For example, we get the same behavior with the the following code (note, em.clear() at the start of the method, where em is an instance of an EntityManager):

public List getExtensionByDate() {

        em.clear(); // TODO Remove me for production. Testing slow query
      
        List dtoList = new ArrayList();

        String qs =
            "SELECT DISTINCT NEW com.arunta.base.db.DateExtensionDTO(r.startDate, r.toExtension) FROM RecordingMetaData AS r";
       
        Query q = em.createQuery(qs);
        try {
                dtoList = q.getResultList();
        }
        catch (PersistenceException e) {
            logger.error("Unexpected problem", e);
        }

        return dtoList;
    }

 

1. What can we do to enable debugging/profiling information in the logs?

2. Do you have documentation on the best way to initialize ObjectDB in embedded mode?

3. Can you give us details on how you implement the L1 and L2 caches?

 

Thank you

Emil

 

> As far as I know indices are only good for fields that appear in the WHERE part of the SQL/JPQL. In our case the fields are in the ORDER part. So, I do not think an index will help.

ObjectDB uses indexes also to sort results as explained in the manual.

With no proper index, execution of your first query requires processing all the 320,000 objects,  and sorting them in memory in order to pick the first 50 that will be returned. With the suggested index ObjectDB should be able to collect the 50 results with no need to sort anything just using the index.

If you can provide the test database that demonstrates the issues we will check this further and we will also be able to check the second query.

Your other questions are covered, at least to some extent in the manual. If you need more details, we will be happy to answer, but please follow the posting instructions and use a topic per thread.