About compilation time

Stefan Manegold Stefan.Manegold at cwi.nl
Wed Dec 9 08:34:01 CET 2015



----- On Dec 9, 2015, at 7:11 AM, Mustafa Korkmaz t-mukork at microsoft.com wrote:

> Hello again Stephan and all,
> 
> Following the trace idea, I got even stranger timings:
> 
> +-------------+--------------+-----------------------+-----------------------+
>| l_returnfla | l_linestatus | sum_qty               | sum_base_price        |>
> : g           :              :                       :                       :>
> +=============+==============+=======================+=======================+
>| A           | F            |          377518399.00 |       566065727797.25 |
>| N           | F            |            9851614.00 |        14767438399.17 |
>| N           | O            |          743124873.00 |      1114302286901.88 |
>| R           | F            |          377732830.00 |       566431054976.00 |
> +-------------+--------------+-----------------------+-----------------------+
> 4 tuples (49443.396ms) !6 columns dropped!
> note: to disable dropping columns and/or truncating fields use \w-1
> 
> +----------+------------------------------------------------------------------+
>| ticks    | statement                                                        |
> +==========+==================================================================+
>|        1 | X_170=0 at 0:void := querylog.define("trace\n\nselect\n\tl_returnfl |
> :          : ag,\n\tl_linestatus,\n\tsum(l_quantity) as sum_qty,\n\tsum(l_ext :
> :          : endedprice) as sum_base_price,\n\tsum(l_extendedprice * (1 - l_d :
> :
> ://other functions
> :
>| 49413975 | X_4=0 at 0:void := user.s1_1(1:bte,1:bte,1:bte,"1998-12-01":date,77 |
> :          : 76000000:lng);                                                   :
> +----------+------------------------------------------------------------------+
> 714 tuples (49443.589ms)
> 
> Apparently, trace timing  is smaller than -i option timing, which doesn't make
> sense.

I don't see / understand what you mean.
49443.589ms is IMHO larger than 49443.396ms, and
49443.396ms is IMHO larger than 49413975us, isn't it?

> Also tick number of the last MAL function is always the largest and the
> closest the overall TRACE timing.

Indeed. That's because ...

> Is there any relation between these two numbers? If yes, why they are different?

... the last MAL statement is the created function that contains the query plan;
hence, executing that function is executing the query, hence, that's the pure
execution cost (incl. potential runtime (re-)optimization);
thus, 49443.396ms - 49413975us = 29421us = 29.421ms is (an indication of) the
query translation time.

Best,
Stefan

> -----Original Message-----
> From: developers-list
> [mailto:developers-list-bounces+t-mukork=microsoft.com at monetdb.org] On Behalf
> Of Stefan Manegold
> Sent: Tuesday, December 8, 2015 9:30 AM
> To: Communication channel for developers of the MonetDB
> <developers-list at monetdb.org>
> Subject: Re: About compilation time
> 
> Dear Mustafa, et al.,
> 
> here some related info than you might find helpful:
> 
> The MAL code given with EXPLAIN is the output of the second tier, i.e., the
> fully (statically) optimized MAL plan, ready for execution.
> 
> 
> Without diving deep into the MonetDB source code, possible ways to indirectly
> get an indication of the pure query translation cost (excluding execution) are:
> 
> - simple, but not very "accurate":
>  run the query on empty tables; if the plan is small, MAL interpretation should
>  be small and negligible.
>  Caveat: the plan on empty tables might (will) be different than the plan on full
>  tables,
>  and thus also the translation time *might* differ.
> 
> - better (and more accurate?):
>  run the query via mclient with -i option for timing, and prefixed with TRACE for
>  profiling;
>  the difference between the total execution time reported by mclient's -i option
>  and
>  the total execution time reported in the TRACE profile is a reasonable
>  indication for the
>  query translation time (basically, the TRACE reports the pure execution time of
>  the MAL plan,
>  while mclient's -i reports end-to-end wall-clock.
> 
> A caveat for both options is that MonetDB tries to cache (parameterized) MAL
> plans to eliminate query translation time with repeatedly executed queries.
> To exclude the potential effects of potential query plan caching, you might want
> to restart the server before each query execution.
> 
> In any case, any of such indirect measurements are to be taken with a grain of
> salt ...
> 
> Hope this helps you further.
> 
> Best,
> Stefan
> 
> ----- On Dec 3, 2015, at 11:50 PM, Mustafa Korkmaz t-mukork at microsoft.com wrote:
> 
>> Thank you Jannie,
>> By using explore I can see the mat version of the query.
>> In software stack page,
>> https://na01.safelinks.protection.outlook.com/?url=https%3a%2f%2fwww.m
>> onetdb.org%2fDocumentation%2fManuals%2fMonetDB%2fArchitecture%2fSoftwa
>> reStack&data=01%7c01%7ct-mukork%40microsoft.com%7cf0402800bcf54a1afffb
>> 08d2fff55c05%7c72f988bf86f141af91ab2d7cd011db47%7c1&sdata=v%2bP8RwhIal
>> ssVWtz6%2b5tb5AsimZCzLEdNdGkLiwHh1E%3d
>> it is written that
>> Outputs of both the first and the second layer are MAL expressions. So
>> do you have any idea about which layer does the EXPLORE command MAL output
>> belongs to?
>> I am especially interested in the process between query submission and
>> actual execution. So can you suggest me a starting point in the source
>> code to explore more?
>> Thank you,
>> Mustafa Korkmaz
>> 
>> -----Original Message-----
>> From: developers-list
>> [mailto:developers-list-bounces+t-mukork=microsoft.com at monetdb.org] On
>> Behalf Of Ying Zhang
>> Sent: Wednesday, December 2, 2015 7:47 AM
>> To: Communication channel for developers of the MonetDB suite.
>> <developers-list at monetdb.org>
>> Subject: Re: About compilation time
>> 
>> Hai Mustafa,
>> 
>> I’m not aware that monetdb directly gives you this information.  what
>> you could try is to prefix your query with PLAN or EXPLAIN, which will
>> limit a monetdb server to only generate the logical or physical execution plan
>> for the query.
>> Do this with client and server on the same machine, send the output to
>> /dev/null, then you can measure the wall clock time.  This should give
>> you something usable.
>> 
>> For only the parsing time, I’m afraid you need to dig into the source
>> code to add timing…
>> 
>> Not sure what parsing/compilation details you’re looking for, but you
>> can have a look at the output of PLAN and EXPLAIN anyway.
>> 
>> Best,
>> 
>> Jennie
>> 
>>> On Dec 01, 2015, at 20:29 , Mustafa Korkmaz <t-mukork at microsoft.com> wrote:
>>> 
>>> Hello all,
>>> I’m conducting an experiment to show pros/cons of certain DBs and I
>>> need to investigate query compilation performance in details. For
>>> this, Is there any way to measure the elapsed time in query
>>> parsing/compilation time in MonetDB?
>>> Also is there any document out there to show the query
>>> parsing/compilation details?
>>> What I find for timing is only “-i” flag which gives an overall timing stat.
>>> I’d be glad for any help.
>>> Thank you
>>> Mustafa Korkmaz
>>>  
>>> _______________________________________________
>>> developers-list mailing list
>>> developers-list at monetdb.org
>>> https://na01.safelinks.protection.outlook.com/?url=https%3a%2f%2fwww.
>>> m
>>> onetdb.org%2fmailman%2flistinfo%2fdevelopers-list&data=01%7c01%7ct-mu
>>> k
>>> ork%40microsoft.com%7c959abb246ef04a3355c508d2fb2fd7b6%7c72f988bf86f1
>>> 4
>>> 1af91ab2d7cd011db47%7c1&sdata=5sBbGDG7c74uNR18oJ1BrInBQQpTXQ7CDIJMTdw
>>> F
>>> ah0%3d
>> 
>> _______________________________________________
>> developers-list mailing list
>> developers-list at monetdb.org
>> https://na01.safelinks.protection.outlook.com/?url=https%3a%2f%2fwww.m
>> onetdb.org%2fmailman%2flistinfo%2fdevelopers-list%0a&data=01%7c01%7ct-
>> mukork%40microsoft.com%7c959abb246ef04a3355c508d2fb2fd7b6%7c72f988bf86
>> f141af91ab2d7cd011db47%7c1&sdata=ofgvw1tY7Xm9t3I8gcMpzz38zr7mqsg6kCJ2y
>> m2mOxk%3d _______________________________________________
>> developers-list mailing list
>> developers-list at monetdb.org
>> https://na01.safelinks.protection.outlook.com/?url=https%3a%2f%2fwww.m
>> onetdb.org%2fmailman%2flistinfo%2fdevelopers-list&data=01%7c01%7ct-muk
>> ork%40microsoft.com%7cf0402800bcf54a1afffb08d2fff55c05%7c72f988bf86f14
>> 1af91ab2d7cd011db47%7c1&sdata=%2bbGEtXb7Dnrpnd7%2be9dCHk4Vpd74JWrk2bND
>> AWX2C%2f0%3d
> 
> --
>| Stefan.Manegold at CWI.nl | DB Architectures   (DA) |
>| https://na01.safelinks.protection.outlook.com/?url=www.CWI.nl%2f~maneg
>| old%2f&data=01%7C01%7Ct-mukork%40microsoft.com%7Cf0402800bcf54a1afffb0
>| 8d2fff55c05%7C72f988bf86f141af91ab2d7cd011db47%7C1&sdata=f2lWg7g9986vj
>| TtY9O7o0n6P6zivxTjz86fe%2f3uiQBA%3d  | Science Park 123 (L321) |
>| +31 (0)20 592-4212     | 1098 XG Amsterdam  (NL) |
> _______________________________________________
> developers-list mailing list
> developers-list at monetdb.org
> https://na01.safelinks.protection.outlook.com/?url=https%3a%2f%2fwww.monetdb.org%2fmailman%2flistinfo%2fdevelopers-list%0a&data=01%7c01%7ct-mukork%40microsoft.com%7cf0402800bcf54a1afffb08d2fff55c05%7c72f988bf86f141af91ab2d7cd011db47%7c1&sdata=E2k2L4A5m9LWb2zrnS%2bl5wSwPSPOHTjRWkt%2fL57NU2s%3d
> _______________________________________________
> developers-list mailing list
> developers-list at monetdb.org
> https://www.monetdb.org/mailman/listinfo/developers-list

-- 
| Stefan.Manegold at CWI.nl | DB Architectures   (DA) |
| www.CWI.nl/~manegold/  | Science Park 123 (L321) |
| +31 (0)20 592-4212     | 1098 XG Amsterdam  (NL) |


More information about the developers-list mailing list