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

7 Aug 2016

      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