How could I obtain the running time information in the MAL interface of mclient?

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. Specifically, I do the following: =============================================== $ *mclient -dnba2009 -lmsql --interactive=ms* Welcome to mclient, the MonetDB interactive terminal (Jun2016-SP1) Type \q to quit, \? for a list of available commands msql>\<query.txt // I save the MAL instructions of a query (obtained from EXPLAIN statement) in this file msql>user.s1_3("1998"); // call the function of that query % sys.player, sys.player, sys.player # table_name % p_lastname, p_lastseason, p_weight # name % char, int, int # type % 100, 4, 3 # length [ "Wheeler", 1998, 165 ] [ "Baker", 1998, 175 ] [ "Garnett", 1998, 186 ] ...... ======================================================== I would like to obtain the running time information after getting the result of that query. How can I do it? Any help would be appreciated. Best, Wenjian

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/Documentation/Manuals/MonetDB/Profiler/Stethoscope Regards, Moritz

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> 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/Documentation/Manuals/MonetDB/Profiler/Stethoscope
Regards,
Moritz _______________________________________________ users-list mailing list users-list@monetdb.org https://www.monetdb.org/mailman/listinfo/users-list

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> 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/Documentation/Manuals/MonetDB/Profiler/Stethoscope
Regards,
Moritz _______________________________________________ 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
-- | Stefan.Manegold@CWI.nl | DB Architectures (DA) | | www.CWI.nl/~manegold/ | Science Park 123 (L321) | | +31 (0)20 592-4212 | 1098 XG Amsterdam (NL) |

In other words: stethoscope produces two events (incl. Timestamp) for each mal statement, one when its execution "start" and one when it's "done"; for each event, the usec value is the difference between the very event's time stamp and the timestamp of its matching start event (for start events that's the event itself, hence, used == 0). Stefan On August 5, 2016 10:56:35 AM CEST, Stefan Manegold <stefan.manegold@cwi.nl> 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> 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/Documentation/Manuals/MonetDB/Profiler/Stethoscope
Regards,
Moritz _______________________________________________ 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
-- | Stefan.Manegold@CWI.nl | DB Architectures (DA) | | 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
-- | Stefan.Manegold@CWI.nl | DB Architectures (DA) | | www.CWI.nl/~manegold/ | Science Park 123 (L321) | | +31 (0)20 592-4212 | 1098 XG Amsterdam (NL) |

// 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/Documentation/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

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
participants (4)
-
Martin Kersten
-
Moritz Bruder
-
Stefan Manegold
-
Xu,Wenjian