Dear Martin and Stefan, As Martin mentioned, the *usec* value of *start* event for MAL instructions depends on whether it is the first-time execution in current session. For the *first-time* execution, the output is as follows: =================================== ... [ 91, "user.s1_5[45]175", 3, "*start*", *0*, 828, 0, 0, 0, 0, 0, 0, "X_35=nil:bat[:int] := algebra.projectionpath(r1_27=<tmp_2705>[7194884]:bat[:oid],C_2=<tmp_2710>[7194884]:bat[:oid],X_34=<tmp_2135>[7197566]:bat[:int]);" ] [ 92, "user.s1_5[45]175", 3, "done ", *189672*, 883, 137, 0, 56216, 1, 0, 50, "X_35=<tmp_2702>[7194884]:bat[:int] := algebra.projectionpath(r1_27=<tmp_2705>[7194884]:bat[:oid],C_2=<tmp_2710>[7194884]:bat[:oid],X_34=<tmp_2135>[7197566]:bat[:int]);" ] [ 93, "user.s1_5[46]175", 3, "*start*", *0*, 883, 0, 0, 0, 0, 0, 0, "X_36=nil:bat[:int] := sql.bind(X_1=0:int,\"sys\":str,\"web_sales\":str,\"ws_order_number\":str,0:int);" ] [ 94, "user.s1_5[46]175", 3, "done ", *62*, 883, 0, 0, 0, 0, 0, 0, "X_36=<tmp_421>[7197566]:bat[:int] := sql.bind(X_1=0:int,\"sys\":str,\"web_sales\":str,\"ws_order_number\":str,0:int);" ] ... =================================== For the *second-time* execution, the output is as follows: =================================== ... [ 91, "user.s1_5[45]180", 3, "*start*", *189672*, 883, 137, 0, 0, 0, 0, 0, "X_35=nil:bat[:int] := algebra.projectionpath(r1_27=<tmp_2710>[7194884]:bat[:oid],C_2=<tmp_2704>[7194884]:bat[:oid],X_34=<tmp_2135>[7197566]:bat[:int]);" ] [ 92, "user.s1_5[45]180", 3, "done ", *185919*, 911, 274, 0, 56216, 1, 0, 46, "X_35=<tmp_2713>[7194884]:bat[:int] := algebra.projectionpath(r1_27=<tmp_2710>[7194884]:bat[:oid],C_2=<tmp_2704>[7194884]:bat[:oid],X_34=<tmp_2135>[7197566]:bat[:int]);" ] [ 93, "user.s1_5[46]180", 3, "*start*", *62*, 911, 0, 0, 0, 0, 0, 0, "X_36=nil:bat[:int] := sql.bind(X_1=0:int,\"sys\":str,\"web_sales\":str,\"ws_order_number\":str,0:int);" ] [ 94, "user.s1_5[46]180", 3, "done ", *37*, 911, 0, 0, 0, 0, 0, 0, "X_36=<tmp_421>[7197566]:bat[:int] := sql.bind(X_1=0:int,\"sys\":str,\"web_sales\":str,\"ws_order_number\":str,0:int);" ] ... ==================================== So, -- for the first-time execution, the *usec* value of *start* event for an MAL instruction is always 0. -- for subsequent execution, that value is the *average* *usec* of *done* event w.r.t. that instruction over all historical executions. Best regards, Wenjian On Fri, Aug 5, 2016 at 5:03 PM, Martin Kersten <martin.kersten@cwi.nl> wrote:
// determine the Estimated Time of Completion if ( pci->calls){ logadd("\"usec\":"LLFMT",%s", pci->totticks/pci->calls, prettify); } else{ logadd("\"usec\":"LLFMT",%s", pci->ticks, prettify); }
Running the same MAL procedure leads to accumulated timings, which provides an indication how long a MAL instruction is likely to take.
On 05/08/16 10:56, Stefan Manegold wrote:
Wenjian,
Afaik, the used value with start events should always be 0. Let us know if not.
Stefan
On August 5, 2016 8:23:31 AM CEST, "Xu,Wenjian" <zeroxwj@gmail.com> wrote:
Hi Moritz,
Thanks a lot for your help.
I have tried *stethscope*. When I looked at the output, I understand that entries with *done* state display the actual time needed for execution. But what about the entries with *start* state? What does *usec* refer to in those entries?
Best regards, Wenjian
On Thu, Aug 4, 2016 at 9:17 PM, Moritz Bruder < moritz.bruder@student.uni-tuebingen.de <mailto:moritz.bruder@student. uni-tuebingen.de>> wrote:
Hi,
Hi all,
MonetDB version: 11.23.7 Ubuntu version: 14.04
How could I obtain the running time information in the MAL interface of mclient? I tried to use the *--interactive* option but it did not work.
I think what you're looking for is *stethoscope*.
I would like to obtain the running time information after getting the result of that query. How can I do it?
Start *stethoscope* and connect it to the same database, run your query. It should now show the needed execution time for every instruction while you run it (entries with *done* state display the actual time needed for execution), and additionally you will see the complete time for your function at the end. Works for both languages I use (*mal* and *sql*).
Further information: https://www.monetdb.org/Docume ntation/Manuals/MonetDB/Profiler/Stethoscope
Regards,
Moritz _______________________________________________ users-list mailing list users-list@monetdb.org <mailto:users-list@monetdb.org> https://www.monetdb.org/mailman/listinfo/users-list
------------------------------------------------------------ ------------------------------------------------------------ ------------------------------------------------------------ ------------------------------------------------------------ ----------------
users-list mailing list users-list@monetdb.org https://www.monetdb.org/mailman/listinfo/users-list
-- | Stefan.Manegold@CWI.nl | DB Architectures (DA) | | www.CWI.nl/~manegold <http://www.CWI.nl/~manegold>/ | Science Park 123 (L321) | | +31 (0)20 592-4212 | 1098 XG Amsterdam (NL) |
_______________________________________________ users-list mailing list users-list@monetdb.org https://www.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org https://www.monetdb.org/mailman/listinfo/users-list