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 -- | Stefan.Manegold@CWI.nl | DB Architectures (DA) | | www.CWI.nl/~manegold/ | Science Park 123 (L321) | | +31 (0)20 592-4212 | 1098 XG Amsterdam (NL) |
participants (1)
-
Stefan Manegold