Query Histroy & query parsing / translation / compilation / optimization time
Hi,
looking for ways to measure the query parsing / translation / compilation / optimization time in MonetDB, I found these two documentations on the MonetDB website: https://www.monetdb.org/Documentation/Cookbooks/SQLrecipes/QueryHistory and https://www.monetdb.org/Documentation/Cookbooks/SQLrecipes/QueryHistoryNew
While the documentation is not entirely clear on whether the latter did, will, or is supposed to replace the former (and if so, when), using the latest Jul2015-SP4 release, I get with the former:
sql>set history=true; operation successful (137.545ms)
sql>select 1; +--------------+ | single_value | +==============+ | 1 | +--------------+ 1 tuple (155.577ms)
sql>select 2; +--------------+ | single_value | +==============+ | 2 | +--------------+ 1 tuple (193.633ms)
sql>select * from sys.queryHistory; SELECT: no such table 'queryhistory'
sql>select * from sys.callHistory; SELECT: no such table 'callhistory'
sql>select * from sys.queryLog; SELECT: no such table 'querylog'
sql>call sys.resetHistory(); SELECT: no such operator 'resethistory'
I.e, this does not seem to work (anymore?).
The latter seems to work fine:
sql>call sys.querylog_enable(); sql>select 1; +--------------+ | single_value | +==============+ | 1 | +--------------+ 1 tuple (127.056ms) sql>select 1; +--------------+ | single_value | +==============+ | 1 | +--------------+ 1 tuple (124.303ms) sql>select 2; +--------------+ | single_value | +==============+ | 2 | +--------------+ 1 tuple (148.923ms) sql>select * from sys.querylog_catalog; +------+---------+----------------------------+-------------------------------------+--------------+-----------+------+----------+ | id | owner | defined | query | pipe | plan | mal | optimize | +======+=========+============================+=====================================+==============+===========+======+==========+ | 42@0 | monetdb | 2016-05-03 00:06:44.000000 | call sys.querylog_enable(); | default_pipe | user.s6_1 | 19 | 267 | | 43@0 | monetdb | 2016-05-03 00:06:47.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | | 44@0 | monetdb | 2016-05-03 00:06:48.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | | 45@0 | monetdb | 2016-05-03 00:06:50.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | | 46@0 | monetdb | 2016-05-03 00:06:56.000000 | select * from sys.querylog_catalog; | default_pipe | user.s8_1 | 68 | 665 | +------+---------+----------------------------+-------------------------------------+--------------+-----------+------+----------+ 5 tuples (132.446ms) sql>select * from sys.querylog_calls; +------+----------------------------+----------------------------+------------------------------------------+--------+-------+------+------+------+ | id | start | stop | arguments | tuples | run | ship | cpu | io | +======+============================+============================+==========================================+========+=======+======+======+======+ | 41@0 | 2016-05-03 00:06:38.000000 | 2016-05-03 00:06:39.000000 | user.s5_1{autoCommit=true}():void; | 1 | 85485 | 1 | 3 | 24 | | 42@0 | 2016-05-03 00:06:44.000000 | 2016-05-03 00:06:44.000000 | user.s6_1{autoCommit=true}():void; | 1 | 71 | 0 | 0 | 0 | | 43@0 | 2016-05-03 00:06:47.000000 | 2016-05-03 00:06:47.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 120 | 0 | 0 | 0 | | 44@0 | 2016-05-03 00:06:48.000000 | 2016-05-03 00:06:48.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 104 | 0 | 0 | 0 | | 45@0 | 2016-05-03 00:06:50.000000 | 2016-05-03 00:06:50.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 66 | 1 | 0 | 0 | | 46@0 | 2016-05-03 00:06:56.000000 | 2016-05-03 00:06:56.000000 | user.s8_1{autoCommit=true}():void; | 8 | 886 | 0 | 50 | 0 | +------+----------------------------+----------------------------+------------------------------------------+--------+-------+------+------+------+ 6 tuples (100.344ms) sql>select * from sys.querylog_history; +------+---------+----------------------------+-------------------------------------+--------------+-----------+------+----------+----------------------------+----------------------------+------------------------------------------+--------+------+------+------+------+ | id | owner | defined | query | pipe | plan | mal | optimize | start | stop | arguments | tuples | run | ship | cpu | io | +======+=========+============================+=====================================+==============+===========+======+==========+============================+============================+==========================================+========+======+======+======+======+ | 42@0 | monetdb | 2016-05-03 00:06:44.000000 | call sys.querylog_enable(); | default_pipe | user.s6_1 | 19 | 267 | 2016-05-03 00:06:44.000000 | 2016-05-03 00:06:44.000000 | user.s6_1{autoCommit=true}():void; | 1 | 71 | 0 | 0 | 0 | | 43@0 | monetdb | 2016-05-03 00:06:47.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | 2016-05-03 00:06:47.000000 | 2016-05-03 00:06:47.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 120 | 0 | 0 | 0 | | 44@0 | monetdb | 2016-05-03 00:06:48.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | 2016-05-03 00:06:48.000000 | 2016-05-03 00:06:48.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 104 | 0 | 0 | 0 | | 45@0 | monetdb | 2016-05-03 00:06:50.000000 | select 1; | default_pipe | user.s7_1 | 21 | 273 | 2016-05-03 00:06:50.000000 | 2016-05-03 00:06:50.000000 | user.s7_1{autoCommit=true}(A0:bte):void; | 1 | 66 | 1 | 0 | 0 | | 46@0 | monetdb | 2016-05-03 00:06:56.000000 | select * from sys.querylog_catalog; | default_pipe | user.s8_1 | 68 | 665 | 2016-05-03 00:06:56.000000 | 2016-05-03 00:06:56.000000 | user.s8_1{autoCommit=true}():void; | 8 | 886 | 0 | 50 | 0 | | 47@0 | monetdb | 2016-05-03 00:07:33.000000 | select * from sys.querylog_calls; | default_pipe | user.s9_1 | 73 | 282 | 2016-05-03 00:07:33.000000 | 2016-05-03 00:07:34.000000 | user.s9_1{autoCommit=true}():void; | 9 | 2515 | 0 | 0 | 0 | +------+---------+----------------------------+-------------------------------------+--------------+-----------+------+----------+----------------------------+----------------------------+------------------------------------------+--------+------+------+------+------+ 6 tuples (152.709ms)
Hence, maybe the documentation should be updated to remove the former?
Also, two questions remain unanswered by the current documentation:
1) What is the unit of "mal integer, -- size of MAL plan"? bytes? lines? statements?
2) What exactly does "optimize bigint -- time in microseconds" measure? Only the time taken by MAL optimizers (i.e., after SQL parsing, relational optimization and relational-to-MAL translation, but before actual execution)? If so, is there still a way to measure the time(s) for SQL parsing, relational optimization, and (or) relational-to-MAL translation?
Thanks!
Stefan
participants (1)
-
Stefan Manegold