combined index not used

#1

we have a query like this:

SELECT a.endDate,a.objectsInCharge.nodePath,a.objectsInCharge.properties.doubleValue
FROM Action a
WHERE a.type = 0 and a.subType = 3 and a.state = 3 and a.endDate >= ?1 and
     (a.objectsInCharge.linkedObjects.classIdentifier = '(TC)' and
      a.objectsInCharge.linkedObjects.objectNameUpper = 'SETUP' and
      a.objectsInCharge.linkedObjects.type = 1) and
     (a.objectsInCharge.properties.name = 'scheduledSlot')
GROUP BY a.endDate, a.objectsInCharge.nodePath, a.objectsInCharge.properties.doubleValue

In the class Action we have a combined index (see attachment) but in the query plan we can see that this index is not used:

Query Plan Description
======================

Step 1: Process Action (a) instances
------------------------------------
[Step 1a]
Scan index com.agile.hummingbird.Action[endDate]
locating all the Action (a) instances.

[Step 1b]
Filter the results of step 1a
retaining only results that satisfy:
  (a.endDate>=:1).

[Step 1c]
Retrieve fields in Action (a) instances.

[Step 1d]
Filter the results of step 1c
retaining only results that satisfy:
  (a.state=3).

[Step 1e]
Filter the results of step 1d
retaining only results that satisfy:
  (a.subType=3).

[Step 1f]
Filter the results of step 1e
retaining only results that satisfy:
  (a.type=0).

Step 2: Process ObjectNode (v$1) instances
  (for every result of step 1)
------------------------------------------
Iterate over all the instances (v$1) in a.objectsInCharge.

Step 3: Extract field values
----------------------------
Retrieve fields in ObjectNode (v$1) instances.

Step 4: Process ObjectNode (v$2) instances
  (for every result tuple of the steps above)
------------------------------------------
[Step 4a]
Scan index com.agile.hummingbird.ObjectNode[classIdentifier, type, state, objectNameUpper]
locating ObjectNode (v$2) instances that satisfy:
  and(and((v$2.objectNameUpper='SETUP'),(v$2.classIdentifier='(TC)')),(v$2.type=1)).

[Step 4b]
Filter the results of step 4a
retaining only results that satisfy:
  (v$1.linkedObjects join v$2).

Step 5: Process ObjectProperty (v$3) instances
  (for every result tuple of the steps above)
----------------------------------------------
[Step 5a]
Scan type com.agile.hummingbird.ObjectProperty
locating ObjectProperty (v$3) instances that satisfy:
  (v$1.properties join v$3).

[Step 5b]
Evaluate fields in ObjectProperty (v$3) instances.

[Step 5c]
Filter the results of step 5b
retaining only results that satisfy:
  (v$3.name='scheduledSlot').

Step 6: Group results
---------------------
Group the results of step 5 by:
  a.endDate,v$1.nodePath,v$3.doubleValue.

Step 7: Apply selection
-----------------------
Apply selection and prepare final results.

 

 

#2

Running the query on the sample database that you sent in the Explorer shows that it is indeed very slow.

Could you please provide a typical value for the ?1 (end date) parameter (on that sample database) for further analysis?

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#3

we do not have that database any more, but you could check in the Action table, typically we take an endDate that is 30 days from the current date (in your case the date of the last Action). The endDate is created as soon as an Action switches to state = 2 or state = 3

#4

The query planner considered the composite index but eventually selected another query plan. We will try to understand that selection and provide a fix.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#5

The reason for not using the composite index was found and can be fixed.  As there are too many possible combinations for covering the filter: "a.type = 0 and a.subType = 3 and a.state = 3 and a.endDate >= ?1" with indexes (each field is covered by many indexes and there were about 5,000 total combinations), ObjectDB did not evaluate all of them and missed the best combination of using the composite index on these 4 fields. Increasing the threshold from 1024 combinations to 10000 solves this issue so a quick fix is possible for this specific issue (although a better approach will be needed for a permanent solution).

However, this query is still extremely slow as using this composite index doesn't solve the problem, so further work is needed. Will keep you informed.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#6

As discussed above, the reason that this query is very slow is not because of not using the composite index (although using the composite index is preferred and can improve performance).

Complex heavy queries with several JOIN operations require examining large number of options for executing the query. The query planner examines thousands of options eliminating options that are clearly inferior to other available options. Eventually a short list of query plans that represent different approaches for executing the query is prepared, each query plan is evaluated and the best evaluated query plan is selected.

The problem is that the evaluation of a query plan without executing it is guessing. Think of the progress bar and the evaluation of time remained when you copy directories with many files in Windows, which is very inaccurate. Evaluating query plans is much more complex and could easily be inaccurate. Future version of ObjectDB will probably have to try different query plans by running them in the background in order to optimise and select best query plans better.

The following query was examined:

SELECT a.endDate,a.objectsInCharge.nodePath,a.objectsInCharge.properties.doubleValue
FROM Action a
WHERE a.type = 0 and a.subType = 3 and a.state = 3 and a.endDate >= {d '2018-07-20'} and
     (a.objectsInCharge.linkedObjects.classIdentifier = '(TC)' and
      a.objectsInCharge.linkedObjects.objectNameUpper = 'SETUP' and
      a.objectsInCharge.linkedObjects.type = 1) and
     (a.objectsInCharge.properties.name = 'scheduledSlot')
GROUP BY a.endDate, a.objectsInCharge.nodePath, a.objectsInCharge.properties.doubleValue

on a database with actions until 2018-07-25.

8 query plans are included in the final short list of candidate query plans. The following list shows the actual execution time of each query plan from the best evaluated to the worst evaluated (after fixing the "composite index not used" issue):

Plan 1 - 339 results 88446 ms
Plan 2 - 339 results 2827 ms
Plan 3 - 339 results 31764 ms
Plan 4 - 339 results 2913 ms
Plan 5 - 339 results 52364 ms
Plan 6 - 339 results 22174 ms
Plan 7 - 339 results 51636 ms
Plan 8 - 339 results 22524 ms

Plans 2 and 4 are clearly much faster than the other query plans. However due to an incorrect evaluation of plan 1 it takes the first place in the evaluation contest and selected.

This issue requires further analysis and work, but in order to offer a quick solution ObjectDB 2.7.6_01 was now released, with:

  • Increased threshold of examining combination, which fixes the "composite index not used" and a new warning to the log if this threshold is exceeded again.
  • Ability to manually select the query plan that is executed using a hint (will be explained in the next post).

As you have several heavy queries with multiple JOIN operations with very slow execution time you may be able to manually select the best query plans for these queries as a quick workaround.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#7

To manually select a query plan 2 new query hints are introduced in build 2.7.6_01:

1. Selecting a query plan from the sorted list of query plans by position:

This tells ObjectDB to skip the first query plan in the list.

2. Selecting a query plan by a specific required text in its XML representation:

This tells ObjectDB to prefer a query plan that uses the "ObjectNode[set]" element (included in the query plan XML representation).  In the case of the query from the post above it will select the 2nd query plan. Selecting a query plan by text (e.g. specific index or component that has to be used) may be more stable and less affected by small changes in the query or in ObjectDB.

The Explorer includes changes that can help in examining different query plans and selecting the best manually:

  1. The log panel shows the position (in the list of query plans) of the executed query plan (always 1 unless a hint is provided), the total number of query plans in the list and the XML representation of the query plan (to help using the text hint).
  2. Query hints can be embedded at the end of the query text in the format [[name=value]]. For example:
SELECT a.endDate,a.objectsInCharge.nodePath,a.objectsInCharge.properties.doubleValue
FROM Action a
WHERE a.type = 0 and a.subType = 3 and a.state = 3 and a.endDate >= {d '2018-07-20'} and
     (a.objectsInCharge.linkedObjects.classIdentifier = '(TC)' and
      a.objectsInCharge.linkedObjects.objectNameUpper = 'SETUP' and
      a.objectsInCharge.linkedObjects.type = 1) and
     (a.objectsInCharge.properties.name = 'scheduledSlot')
GROUP BY a.endDate, a.objectsInCharge.nodePath, a.objectsInCharge.properties.doubleValue
[[objectdb.query-plan-pos=2]]

or

SELECT a.endDate,a.objectsInCharge.nodePath,a.objectsInCharge.properties.doubleValue
FROM Action a
WHERE a.type = 0 and a.subType = 3 and a.state = 3 and a.endDate >= {d '2018-07-20'} and
     (a.objectsInCharge.linkedObjects.classIdentifier = '(TC)' and
      a.objectsInCharge.linkedObjects.objectNameUpper = 'SETUP' and
      a.objectsInCharge.linkedObjects.type = 1) and
     (a.objectsInCharge.properties.name = 'scheduledSlot')
GROUP BY a.endDate, a.objectsInCharge.nodePath, a.objectsInCharge.properties.doubleValue
[[objectdb.query-plan-text=ObjectNode[set]]]

You can also automate the selection and add to your application code that tests the top 5 query plans of each heavy query and select the fastest one. Similar mechanism will probably be added in future to ObjectDB.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#8

we are a bit lost, where do we find that list/sequence of query plans ?

#9

You can see all the query plans in the log if you enable logging for queries in trace level:

    <logger name="query" level="trace" />

It is shown as a <finalPlans> xml element with child for each query plan:

(however, it may be easier just to try running the query several times in the Explorer with the position hint: 1, 2, 3, 4, 5 as explained above).

<finalPlans>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')))" eval="9.2895" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="9.0342">
            <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="6.9918">
                <extractPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge))" eval="4.9675" variable="v$1">
                    <multiVarPlan plan="a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)" eval="2.9675">
                        <extractPlan plan="extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull]))" eval="2.9675" variable="a">
                            <btreePlan plan="index(esst[3_3_0_2018-07-20->3_3_0:notNull])" eval="0.9675" variable="a" />
                        </extractPlan>
                        <boundPlan plan="bound(a.objectsInCharge)" eval="0.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="1.0122">
                    <btreePlan plan="index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)])" eval="0.991" variable="v$2" />
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                    <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                </extractPlan>
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)')))" eval="9.3923" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="9.137">
            <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="7.0099">
                <extractPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge))" eval="4.9675" variable="v$1">
                    <multiVarPlan plan="a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:bound(a.objectsInCharge)" eval="2.9675">
                        <extractPlan plan="extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull]))" eval="2.9675" variable="a">
                            <btreePlan plan="index(esst[3_3_0_2018-07-20->3_3_0:notNull])" eval="0.9675" variable="a" />
                        </extractPlan>
                        <boundPlan plan="bound(a.objectsInCharge)" eval="0.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="1.0636">
                <filterPlan plan="filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP'))" eval="1.0424">
                    <filterPlan plan="filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1))" eval="1.0212">
                        <extractPlan plan="extract(v$2,type(ObjectNode[set]))" eval="1.0" variable="v$2">
                            <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$2" />
                        </extractPlan>
                    </filterPlan>
                </filterPlan>
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2)))" eval="9.5905" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="9.3352">
            <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="7.3109">
                <extractPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set]))" eval="5.2685" variable="v$1">
                    <multiVarPlan plan="a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])" eval="5.2685">
                        <extractPlan plan="extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull]))" eval="2.9675" variable="a">
                            <btreePlan plan="index(esst[3_3_0_2018-07-20->3_3_0:notNull])" eval="0.9675" variable="a" />
                        </extractPlan>
                        <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="1.0122">
                <btreePlan plan="index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)])" eval="0.991" variable="v$2" />
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)')))" eval="9.6933" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="9.438">
            <multiVarPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="7.3109">
                <extractPlan plan="extract(v$1,a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set]))" eval="5.2685" variable="v$1">
                    <multiVarPlan plan="a:extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull])) <x> v$1:type(ObjectNode[set])" eval="5.2685">
                        <extractPlan plan="extract(a,index(esst[3_3_0_2018-07-20->3_3_0:notNull]))" eval="2.9675" variable="a">
                            <btreePlan plan="index(esst[3_3_0_2018-07-20->3_3_0:notNull])" eval="0.9675" variable="a" />
                        </extractPlan>
                        <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="1.0636">
                <filterPlan plan="filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP'))" eval="1.0424">
                    <filterPlan plan="filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1))" eval="1.0212">
                        <extractPlan plan="extract(v$2,type(ObjectNode[set]))" eval="1.0" variable="v$2">
                            <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$2" />
                        </extractPlan>
                    </filterPlan>
                </filterPlan>
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2)))" eval="18.6359" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="18.3806">
            <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="16.3563">
                <extractPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge))" eval="14.3139" variable="v$1">
                    <multiVarPlan plan="a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)" eval="12.3139">
                        <filterPlan plan="filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0))" eval="12.3139">
                            <filterPlan plan="filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3))" eval="12.2927">
                                <filterPlan plan="filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3))" eval="12.2715">
                                    <filterPlan plan="filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date))" eval="12.2503">
                                        <extractPlan plan="extract(a,type(Action[all]))" eval="12.2291" variable="a">
                                            <btreePlan plan="type(Action[all])" eval="11.9281" variable="a" />
                                        </extractPlan>
                                    </filterPlan>
                                </filterPlan>
                            </filterPlan>
                        </filterPlan>
                        <boundPlan plan="bound(a.objectsInCharge)" eval="0.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="1.0122">
                <btreePlan plan="index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)])" eval="0.991" variable="v$2" />
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)')) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')))" eval="18.7387" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)')) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="18.4834">
            <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="16.441">
                <extractPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge))" eval="14.3139" variable="v$1">
                    <multiVarPlan plan="a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:bound(a.objectsInCharge)" eval="12.3139">
                        <filterPlan plan="filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0))" eval="12.3139">
                            <filterPlan plan="filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3))" eval="12.2927">
                                <filterPlan plan="filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3))" eval="12.2715">
                                    <filterPlan plan="filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date))" eval="12.2503">
                                        <extractPlan plan="extract(a,type(Action[all]))" eval="12.2291" variable="a">
                                            <btreePlan plan="type(Action[all])" eval="11.9281" variable="a" />
                                        </extractPlan>
                                    </filterPlan>
                                </filterPlan>
                            </filterPlan>
                        </filterPlan>
                        <boundPlan plan="bound(a.objectsInCharge)" eval="0.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="1.0636">
                    <filterPlan plan="filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP'))" eval="1.0424">
                        <filterPlan plan="filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1))" eval="1.0212">
                            <extractPlan plan="extract(v$2,type(ObjectNode[set]))" eval="1.0" variable="v$2">
                                <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$2" />
                            </extractPlan>
                        </filterPlan>
                    </filterPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                    <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                </extractPlan>
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2)))" eval="18.9369" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="18.6816">
            <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="16.6573">
                <extractPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set]))" eval="14.6149" variable="v$1">
                    <multiVarPlan plan="a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])" eval="14.6149">
                        <filterPlan plan="filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0))" eval="12.3139">
                            <filterPlan plan="filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3))" eval="12.2927">
                                <filterPlan plan="filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3))" eval="12.2715">
                                    <filterPlan plan="filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date))" eval="12.2503">
                                        <extractPlan plan="extract(a,type(Action[all]))" eval="12.2291" variable="a">
                                            <btreePlan plan="type(Action[all])" eval="11.9281" variable="a" />
                                        </extractPlan>
                                    </filterPlan>
                                </filterPlan>
                            </filterPlan>
                        </filterPlan>
                        <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)]),(v$1.linkedObjects join v$2))" eval="1.0122">
                <btreePlan plan="index(ctso['(TC)'_1->'(TC)'_1:and((v$2.objectNameUpper='SETUP'),notNull)])" eval="0.991" variable="v$2" />
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
    <groupPlan plan="group([a.endDate,v$1.nodePath,v$3.doubleValue],extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)')))" eval="19.0397" group="group(a.endDate,v$1.nodePath,v$3.doubleValue)" eval="[]">
        <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot')) <x> v$2:filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="18.7844">
            <multiVarPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])) <x> v$3:filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="16.6573">
                <extractPlan plan="extract(v$1,a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set]))" eval="14.6149" variable="v$1">
                    <multiVarPlan plan="a:filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0)) <x> v$1:type(ObjectNode[set])" eval="14.6149">
                        <filterPlan plan="filter(filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3)),(a.type=0))" eval="12.3139">
                            <filterPlan plan="filter(filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3)),(a.subType=3))" eval="12.2927">
                                <filterPlan plan="filter(filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date)),(a.state=3))" eval="12.2715">
                                    <filterPlan plan="filter(extract(a,type(Action[all])),(a.endDate>=current-java.sql.Date))" eval="12.2503">
                                        <extractPlan plan="extract(a,type(Action[all]))" eval="12.2291" variable="a">
                                            <btreePlan plan="type(Action[all])" eval="11.9281" variable="a" />
                                        </extractPlan>
                                    </filterPlan>
                                </filterPlan>
                            </filterPlan>
                        </filterPlan>
                        <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$1" />
                    </multiVarPlan>
                </extractPlan>
                <filterPlan plan="filter(extract(v$3,type(ObjectProperty[set])),(v$3.name='scheduledSlot'))" eval="1.0212">
                    <extractPlan plan="extract(v$3,type(ObjectProperty[set]))" eval="1.0" variable="v$3">
                        <btreePlan plan="type(ObjectProperty[set])" eval="1.0" variable="v$3" />
                    </extractPlan>
                </filterPlan>
            </multiVarPlan>
            <filterPlan plan="filter(filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP')),(v$2.classIdentifier='(TC)'))" eval="1.0636">
                <filterPlan plan="filter(filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1)),(v$2.objectNameUpper='SETUP'))" eval="1.0424">
                    <filterPlan plan="filter(extract(v$2,type(ObjectNode[set])),(v$2.type=1))" eval="1.0212">
                        <extractPlan plan="extract(v$2,type(ObjectNode[set]))" eval="1.0" variable="v$2">
                            <btreePlan plan="type(ObjectNode[set])" eval="1.0" variable="v$2" />
                        </extractPlan>
                    </filterPlan>
                </filterPlan>
            </filterPlan>
        </multiVarPlan>
    </groupPlan>
</finalPlans>
ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#10

Build 2.7.6_08 improves query plan evaluation and provides better selection of query plans by using additional statistic information. To benefit from these changes ObjectDB must collect that statistics. Currently this is done by running a special query:

    public static void main(String[] args) throws Exception
    {
        EntityManagerFactory emf =
            Persistence.createEntityManagerFactory("my.odb");
        EntityManager em = emf.createEntityManager();
        
        Thread thread = em.createQuery(
            "objectdb statistics", Thread.class).getSingleResult();
        thread.join();
        
        em.close();
        emf.close();
    }

It may take some time for this process to complete (about 20-30 minutes on your sample database). It may be effective to run this again occasionally when the database structure or content is changed significantly.

With build 2.7.6_08 and after collecting statistics as explained above the query execution is fast with no need for query hints. This also helps in similar issues (e.g. issue #2417).

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#11

Thanks, question:

do we have to run this query every time we start our application or are the statistics stored in the database file ?

#12

Yes. The statistic info is stored in the database file and only replaced with new info when that query is run again (recommended when the database structure or content is changed significantly).

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#13
  • we implemented version 2.8.0_02, added:
     

                    entityManager = entityManagerFactory.createEntityManager();

                    Thread thread = entityManager.createQuery("objectdb statistics", Thread.class).getSingleResult();

                    thread.join();

  • on startup there is a significant waiting time in the above functionality
  • queries are significantly slow, example query: (version 2.7.6 it takes 47 ms, version 2.8.0_02 it takes 700 ms):
    SELECT DISTINCT o.parentNode FROM ObjectNode o WHERE o.classIdentifier = "(OP)" AND (o.linkedObjects.classIdentifier = "(US)" and o.linkedObjects.objectNameUpper = "ORG" and o.linkedObjects.type = 1 and o.linkedObjects.state = 0) AND (o.parentNode.properties.name = "confirmed" AND o.parentNode.properties.doubleValue = 0) and o.parentNode.classIdentifier = "(ME)" order by o.parentNode.modified desc
  • database can be downloaded from 

https://www.dropbox.com/s/px01hyoelov7gdx/coreSystemDb.odb.zip?dl=0

 

#14

just to make clear: all queries are slow, not only the above example

#15

Just tried that query on that database in the Explorer (of the most recent release) and it seems that a composite index was selected and used and that the execution time is less than 3 seconds. Could you please check running that query in the Explorer?

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#16

Execution time of this query fells to 1457 on repeating runs (when cache is disabled), will be checked now against version 2.7.6.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#17

OK. With 2.7.6 it is indeed much faster. We will investigate the cause.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#18

Some of the statistics in the database that you sent is broken, but it is unclear yet if this is the only issue.

Is it your first attempt to use a build starting 2.7.6_08 that just failed, or did you previously see some success with query execution with the new changes, before having this problem?

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#19

this was our first attempt. We also tried it with the bug database (that you have, too), same result

#20

Build 2.8.0_03 was released now and hopefully it will work better.

There was a critical bug in running the "objectdb statistics" query. Please discard or repair using the Doctor any databases on which this query was run to avoid further issues. Then run the "objectdb statistics" query again using build 2.8.0_03. If you can post the database (from post #13 above) after this action we can verify that it contains statistics as expected.

Please report whether or not the new build runs queries faster now.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#21
  1. done Doctor repair
  2. now we have an 'Unexpected internal exception' cause 'java.lang.ArrayIndexOutOfBoundsException: 2' exception on executing this query what we never had before:
    SELECT DISTINCT o from ObjectNode o join o.properties p1 join o.properties p2 where o.classIdentifier = '(OP)' and ((o.properties.name = 'scheduledSlot' and o.properties.doubleValue <= 2553) and (p2.name = 'scheduledEndSlot' and p2.doubleValue >= 2553 and p2.state = 0) and (p1.name = 'noCapacityLoad' and p1.doubleValue = 0))

 

#22

using the small DB, here the current state of the db:

https://www.dropbox.com/s/1zm96q5trnfogy1/coreSystemDb.odb%202.zip?dl=0 

#23
  • The ArrayIndexOutOfBoundsException was caused by a recent change in 2.8.0_03. Please try 2.8.0_04 that should fix it.
  • The database in #22 has partial statistics. You have to run the statistics query again on the repaired database. If it is not a production database and you can go back to the last backup before running the statistics query previously (without loosing data) - it would be better.
ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#24

we did run the Doctor + the statistics query afterwards before running the problematic query #21

#25

Strangely repeating this procedure of running the Doctor and then the Stat query on the database in #22 above resulted with a new database with full statistics (where the database of #22 itself has partial statistics).

Would you like to try repeating Doctor + Stat on it and send the result?

Or better, start with a new database with no previous stat running and run Stat query once?

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
#26

we did now Doctore + stats query using the _04 and it looks better, we'll continue checking it, the current database is available here:
 

https://www.dropbox.com/s/i4wovoa0oq3wlgx/coreSystemDb.odb%203.zip?dl=0

 

#27

Query plan selection in the new version may be better even without statistics, as there are several other improvements.  However, unfortunately your new database doesn't have the statistics yet, although there are indications that it was run several times. Without the statistics query plan selection and execution will not be optimal.

Here a small program that adds statistics to your database successfully:

import javax.persistence.*;

public class F2379
{
    public static void main(String[] args) throws Exception {
        
        System.setProperty("objectdb.temp.no-schema-upgrade", "true");
        
        EntityManagerFactory emf =
            Persistence.createEntityManagerFactory("D:\\odb-files\\coreSystemDb3.odb");
        EntityManager em = emf.createEntityManager();

        Thread thread = em.createQuery("objectdb statistics", Thread.class).getSingleResult();
        thread.join();
        
        em.close();
        emf.close();
    }        
}

It is unclear why it didn't work well when you ran it. Maybe there is another issue that has to be addressed. If you uploaded the odb file but there was also a recovery odb$ flle then this may explain why we cannot see the statistics, but maybe you have them, but it is unclear yet.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)

Post Reply

To post a reply and/or subscribe to update notifications - please login