How to find out KDB Query Execution Time

Question

I would like to find out how much time a query took for getting executed. I plan to log this for audit and support purposes.

I have found this in the documentation:

q)\t log til 100000 / milliseconds for log of first 100000 numbers
3

But the above method actually evaluates the query again and tells us the time. It doesn't return the results of the query. So if I use this it will actually be like running every query twice, once for getting the results and once for knowing the execution time.

Is there any other method someone is aware of?

Answer 1

You could also capture the time before/after the query runs to figure out the execution time.

Execute on one line:

q)start:.z.p;result:log til 100000;exectime:.z.p-start 

q)exectime
0D00:00:00.297268000   

q)result 
-0w 0 0.6931472 1.098612 1.386294 ...

This method will give you nano-second precision but can easily be adapted to return the same as \t.

q)res:system"t a:{st:.z.p;log til 10000000;.z.p-st}[]"  
q)`long$`time$a   /convert to Ms
297  
q)res
297

Answer 2

You can use a "system t" call (the equivalent of \t) to store the result and the time in one go.

b:system"t a:log til 100000" 

It's not very general or functional though so it mightn't suit your needs to have the commands inside a string.

Answer 3

Expanding on Connor's idea, you can wrap this in a function that will return the value and print the time taken to stdout:

time:{ t0:.z.t; r:eval x; 0N!.z.t-t0; :r }

And then send the parse tree of your function as the argument:

q)a:time (log;til 100000)
00:00:00.003
q)a
-0w 0 0.6931472 1.098612 1.386294 1.609438 1.791759 1.94591 2.079442 2.197225..