Wrong ticks in TRACE

[monetdb-team]

Date: 2014-08-22 16:11:14 +0200
From: @swingbit
To: MonetDB5 devs <>
Version: 11.17.21 (Jan2014-SP3)
CC: @mlkersten, @njnes

Last updated: 2014-10-31 14:15:00 +0100

Comment 20082

Date: 2014-08-22 16:11:14 +0200
From: @swingbit

User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/36.0.1985.143 Safari/537.36
Build Identifier:

This happens on a checkout of the (not yet released) Oct2014 branch.

I have a 1-column table of 3M strings:

sql>\d s
CREATE TABLE "sys"."s" (
"value" CHARACTER LARGE OBJECT
);

sql>select count(*) from s;
+---------+
| L1 |
+=========+
| 3077225 |
+---------+
1 tuple (3.096ms)

In the following query, the ticks reported for X_16 (13412564) are clearly too many.
Notice that the total ticks (1959352) are correct (the query does take 1.9s).

sql>trace select * from s where lcase(value) = 'roberto';
+-------+
| value |
+=======+
+-------+
0 tuples (1.9s)
+----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ticks | stmt |
+==========+===================================================================================================================================================================+
| 8 | X_3 := sql.mvc(); |
| 75 | X_7=<tmp_1100>[3077225] := sql.bind(X_3=0,"sys","s","value",0); |
| 46 | (X_10=<tmp_22>[0],r1_10=<tmp_36>[0]) := sql.bind(X_3=0,"sys","s","value",2); |
| 19 | X_13=<tmp_36>[0] := sql.bind(X_3=0,"sys","s","value",1); |
| 12 | X_15=<tmp_1100>[3077225] := sql.delta(X_7=<tmp_1100>[3077225],X_10=<tmp_22>[0],r1_10=<tmp_36>[0],X_13=<tmp_36>[0]); |
| 8 | X_16=<tmp_1100>[3077225] := X_15=<tmp_1100>[3077225]; |
| 13412564 | X_17:bat[:oid,:str] =<tmp_613>[3077225] := batstr.toLower(X_16=<tmp_1100>[3077225]); |
| 88 | X_4:bat[:oid,:oid] =<tmp_1071>[3077225] := sql.tid(X_3=0,"sys","s"); |
| 316194 | X_18=<tmp_1061>[0] := algebra.subselect(X_17=<tmp_613>:bat[:oid,:str][3077225],X_4=<tmp_1071>:bat[:oid,:oid][3077225],A0="roberto",A0="roberto",true,true,false); |
| 133 | X_20=<tmp_1071>[0] := sql.projectdelta(X_18=<tmp_1061>[0],X_7=<tmp_1100>[3077225],X_10=<tmp_22>[0],r1_10=<tmp_36>[0],X_13=<tmp_36>[0]); |
| 28 | X_21 := sql.resultSet(1,1,X_20=<tmp_1071>[0]); |
| 27 | sql.rsColumn(X_21=13,"sys.s","value","clob",0,0,X_20=<tmp_1071>[0]); |
| 2 | X_25 := io.stdout(); |
| 105 | sql.exportResult(X_25=="104d2":streams,X_21=13); |
| 2 | end s4_1; |
| 13856253 | function user.s4_1(A0="roberto"); |
| 1959352 | X_5:void := user.s4_1("roberto"); |
+----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+
17 tuples (1.9s)

Reproducible: Always

$ mserver5 --version
MonetDB 5 server v11.19.0 (64-bit, 64-bit oids)
This is an unreleased version
Copyright (c) 1993-July 2008 CWI
Copyright (c) August 2008-2014 MonetDB B.V., all rights reserved
Visit http://www.monetdb.org/ for further information
Found 15.6GiB available memory, 8 available cpu cores
Libraries:
libpcre: 8.33 2013-05-28 (compiled with 8.33)
openssl: OpenSSL 1.0.1e 11 Feb 2013 (compiled with OpenSSL 1.0.1e-fips 11 Feb 2013)
libxml2: 2.9.1 (compiled with 2.9.1)
Compiled by: roberto@photon.spinque.com (x86_64-unknown-linux-gnu)
Compilation: gcc -g -Werror -Wall -Wextra -W -Werror-implicit-function-declaration -Wpointer-arith -Wdeclaration-after-statement -Wundef -Wformat=2 -Wno-format-nonliteral -Winit-self -Winvalid-pch -Wmissing-declarations -Wmissing-format-attribute -Wmissing-prototypes -Wold-style-definition -Wpacked -Wunknown-pragmas -Wvariadic-macros -fstack-protector-all -Wstack-protector -Wpacked-bitfield-compat -Wsync-nand -Wjump-misses-init -Wmissing-include-dirs -Wlogical-op -Wunreachable-code
Linking : /usr/bin/ld -m elf_x86_64

Comment 20091

Date: 2014-08-25 19:29:36 +0200
From: @njnes

this is handled on a lower level than sql...

Comment 20248

Date: 2014-10-04 23:19:06 +0200
From: @mlkersten

Fixed in mal_runtime.c
The pci->ticks were double accounted for.

Comment 20401

Date: 2014-10-31 14:15:00 +0100
From: @sjoerdmullender

Oct2014 has been released.