DFC Query Timing, Take 2

A few years back I wrote a post explaining a brute force method to capture and calculate the execution time of queries run against a Documentum repository.  I have found this technique to be useful from time-to-time to prove to users, managers, other engineers that the latency in a system is not caused by Documentum*.  🙂

Krzysztof Jurkowski has taken this technique to a new level with his DQLPerformanceTest tool.  The DQLPerformanceTest tool is a command line Java app with lots of features.  To try it out, I reran the queries that were the subject of my previous post on query timing to see if those conclusions still held true using Krzysztof’s tool.  Recall the two queries were:

  • select r_object_id from dm_document where DATEFLOOR(day,"r_creation_date") > DATE("01/01/2014")
  • select r_object_id from dm_document where r_creation_date > DATE("01/01/2014")**

where I was interested in how “expensive” the DATEFLOOR function was.  Here are the transcripts of my two tests using the DQLPerformanceTest tool:

C:\>java -jar DQLPerformanceTest.jar -d repo1 -l dmadmin -p dmadmin -w 10 -q "select r_object_id from dm_document where DATEFLOOR(day,""r_creation_date"") > DATE('01/01/2014')" -f 
Do you want to execute following query 10 time(s)? 
select r_object_id from dm_document where DATEFLOOR(day,"r_creation_date") > DATE('01/01/2014') 
Do you want to proceed [y/n]? 
y 
Script started 
Creating performance testing workers... 
Worker-0 loged in as dmadmin on repo1@DCTM7DEV 
Worker-1 loged in as dmadmin on repo1@DCTM7DEV 
Worker-2 loged in as dmadmin on repo1@DCTM7DEV 
Worker-3 loged in as dmadmin on repo1@DCTM7DEV 
Worker-4 loged in as dmadmin on repo1@DCTM7DEV 
Worker-5 loged in as dmadmin on repo1@DCTM7DEV 
Worker-6 loged in as dmadmin on repo1@DCTM7DEV 
Worker-7 loged in as dmadmin on repo1@DCTM7DEV 
Worker-8 loged in as dmadmin on repo1@DCTM7DEV 
Worker-9 loged in as dmadmin on repo1@DCTM7DEV 
Created 10 workers 
Executing workers... 
Waiting for workers to finish... 
Worker-6: 20318 ms 
Worker-1: 20318 ms 
Worker-3: 21977 ms 
Worker-0: 22120 ms 
Worker-8: 23721 ms 
Worker-7: 23725 ms 
Worker-9: 41218 ms 
Worker-5: 41220 ms 
Worker-2: 41307 ms 
Worker-4: 41309 ms 
Workers finished 
Average time: 29,29694 s 
Median time: 23,23700 s 
Min time: 20,20298 s 
Max time: 41,41268 s 
Script finished 

C:\>java -jar DQLPerformanceTest.jar -d repo1 -l dmadmin -p dmadmin -w 10 -q "select r_object_id from dm_document where r_creation_date > DATE('01/01/2014')" -f 
Do you want to execute following query 10 time(s)? 
select r_object_id from dm_document where r_creation_date > DATE('01/01/2014') 
Do you want to proceed [y/n]? 
y 
Script started 
Creating performance testing workers... 
Worker-0 loged in as dmadmin on repo1@DCTM7DEV 
Worker-1 loged in as dmadmin on repo1@DCTM7DEV 
Worker-2 loged in as dmadmin on repo1@DCTM7DEV 
Worker-3 loged in as dmadmin on repo1@DCTM7DEV 
Worker-4 loged in as dmadmin on repo1@DCTM7DEV 
Worker-5 loged in as dmadmin on repo1@DCTM7DEV 
Worker-6 loged in as dmadmin on repo1@DCTM7DEV 
Worker-7 loged in as dmadmin on repo1@DCTM7DEV 
Worker-8 loged in as dmadmin on repo1@DCTM7DEV 
Worker-9 loged in as dmadmin on repo1@DCTM7DEV 
Created 10 workers 
Executing workers... 
Waiting for workers to finish... 
Worker-1: 5584 ms 
Worker-7: 14351 ms 
Worker-3: 14539 ms 
Worker-0: 14609 ms 
Worker-8: 14835 ms 
Worker-6: 15081 ms 
Worker-4: 15417 ms 
Worker-2: 15418 ms 
Worker-5: 15792 ms 
Worker-9: 15808 ms 
Workers finished 
Average time: 14,14129 s 
Median time: 14,14944 s 
Min time: 5,5579 s 
Max time: 15,15793 s 
Script finished

My conclusion is the same:  DATEFLOOR is expensive to use; in this case, roughly twice as expensive.  No surprise, really.  The point is the tool, not the conclusion.

The DQLPerformanceTest tool is nicely put together and a real cut above my brute force method for query timing.  You can access Krzysztof’s tool from the ECN, or on the dm_misc Tools page.

* – It is also a useful technique for tuning DQL queries to make them perform better before you engage with others.
** – I changed the dates from the original queries to adjust for the fact that A LOT of content has been added to the repository since the original post was written, and I didn’t want the queries to run too long.

Advertisements

About Scott
I have been implementing Documentum solutions since 1997. In 2005, I published a book about developing Documentum solutions for the Documentum Desktop Client (ISBN 0595339689). In 2010, I began this blog as a record of interesting and (hopefully) helpful bits of information related to Documentum, and as a creative outlet.

3 Responses to DFC Query Timing, Take 2

  1. Your interpretation of results is completely wrong (and testcase too). Documentum translates DATEFLOOR to SQL trunc function:

    API> ?,c,select r_object_id from dm_document where DATEFLOOR(day,r_creation_date) > DATE(’01/01/2014′)
    API> ?,c,execute GET_LAST_SQL
    result
    ——————————————————————————————————
    select all dm_document.r_object_id from dm_document_sp dm_document where
    (( trunc(dm_document.r_creation_date, ‘ddd’)> to_date(’31/12/2013 21:0:0′, ‘DD/MM/YYYY HH24:MI:SS’)))
    and (dm_document.i_has_folder = 1 and dm_document.i_is_deleted = 0)
    (1 row affected)

    If you try to compare following SQL statements:

    SELECT MAX (d)
    FROM (SELECT TRUNC (r_creation_date, ‘ddd’) d FROM dm_sysobject_s)

    SELECT MAX (d)
    FROM (SELECT r_creation_date d FROM dm_sysobject_s)

    you will find that TRUNC function does not introduce significant delays in query execution. So, all what you get is: different queries have different execution plans, it’s expected, but not related to DATEFLOOR function.

    Like

    • Scott says:

      Andrey, thanks for your thorough explanation, but I respectfully disagree. The two queries clearly differ in their execution times — whether that is a function of their query plans or the implementation of DATEFLOOR, the perception is same. The point of the post was about the DQLPerformanceTest tool. The point of the previous post was that the DATEFLOOR function adds noticeable lag (i.e., “expense”) to the execution of the query. I beleive both posts demonstrated that.

      On my Microsoft SQL Server Docbase, if I run the query in DA and expose the generated SQL, I get this query:

      select all dm_document.r_object_id from dm_document_sp dm_document where ((convert(datetime, convert(char(11),dm_document.r_creation_date, 106), 103)> convert(datetime, ’03/02/2014 5:0:0′, 103))) and (dm_document.i_has_folder = 1 and dm_document.i_is_deleted = 0).

      SQL Server clearly implements the DATEFLOOR function using embedded convert() funcitons, not a simple trunc().

      Like

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: