Date: 2011-10-20 13:55:04 +0200
From: Viktor Rosenfeld <<24hesk>>
To: SQL devs <>
Version: 11.5.3 (Aug2011-SP1) [obsolete]
CC: @mlkersten

Last updated: 2011-10-26 13:22:03 +0200

Comment 16449

Date: 2011-10-20 13:55:04 +0200
From: Viktor Rosenfeld <<24hesk>>

User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8) AppleWebKit/535.1 (KHTML, like Gecko) Chrome/14.0.835.202 Safari/535.1
Build Identifier:

The query log feature as described in [1] is broken. Queries run when history is true show an error message and not the expected result. This problem persists after history is set back to false for some queries and not for others.

[1] http://www.monetdb.org/Documentation/Cookbooks/SQLrecipies/History

Reproducible: Always

Steps to Reproduce:

1. Start mclient
2. set history = true;
3. select 1;

Actual Results:

invalid/unknown response from server, ignoring output
? = 0:0 profiler.setFootprintFlag();
? = 0:0 profiler.setMemoryFlag();
? = 0:0 inblock := profiler.getDiskReads();
? = 0:0 oublock := profiler.getDiskWrites();
? = 0:0 xtime := alarm.usec();
(remaining output omitted, use \fraw to examine in detail)

Expected Results:

single value 1

Pasted below is a log demonstrating the errors.

$ mclient -d demo -u monetdb
password:
Welcome to mclient, the MonetDB/SQL interactive terminal (Aug2011-SP1)
Database: MonetDB v11.5.3, 'demo'
Type \q to quit, ? for a list of available commands
auto commit mode: on
sql>call resetHistory();
sql>set history=true;
sql>select 1;
invalid/unknown response from server, ignoring output
? = 0:0 profiler.setFootprintFlag();
? = 0:0 profiler.setMemoryFlag();
? = 0:0 inblock := profiler.getDiskReads();
? = 0:0 oublock := profiler.getDiskWrites();
? = 0:0 xtime := alarm.usec();
(remaining output omitted, use \fraw to examine in detail)
sql>select * from querylog;
invalid/unknown response from server, ignoring output
? = 0:0 profiler.setFootprintFlag();
? = 0:0 profiler.setMemoryFlag();
? = 0:0 inblock := profiler.getDiskReads();
? = 0:0 oublock := profiler.getDiskWrites();
? = 0:0 xtime := alarm.usec();
(remaining output omitted, use \fraw to examine in detail)
sql>set history=false;
invalid/unknown response from server, ignoring output
? = 0:0 profiler.setFootprintFlag();
? = 0:0 profiler.setMemoryFlag();
? = 0:0 inblock := profiler.getDiskReads();
? = 0:0 oublock := profiler.getDiskWrites();
? = 0:0 xtime := alarm.usec();
(remaining output omitted, use \fraw to examine in detail)
sql>select 1;
invalid/unknown response from server, ignoring output
? = 0:0 profiler.setFootprintFlag();
? = 0:0 profiler.setMemoryFlag();
? = 0:0 inblock := profiler.getDiskReads();
? = 0:0 oublock := profiler.getDiskWrites();
? = 0:0 xtime := alarm.usec();
(remaining output omitted, use \fraw to examine in detail)
sql>select * from querylog;
+---------+-------------+---------+-------------+------+------+-------------+-------------+-----------+------+--------+
| id | defined | name | query | pars | opti | ctime | arguments | execute | resu | foot |>
: : : : : e : mize : : : : lt : :>
+=========+=============+=========+=============+======+======+=============+=============+===========+======+========+
| 1006155 | 2011-10-20 | monetdb | select 1; | 609 | 356 | 2011-10-20 | user.s4_1(= | 5 | 24 | 0 |
: : 11:53:03.00 : : : : : 11:53:03.00 : 1); : : : :
: : 0000 : : : : : 0000 : : : : :
| 1006265 | 2011-10-20 | monetdb | select * fr | 662 | 1748 | 2011-10-20 | user.s5_1() | 2748 | 97 | 206498 |
: : 11:53:06.00 : : om querylog : : : 11:53:06.00 : ; : : : :
: : 0000 : : ; : : : 0000 : : : : :
| 1006570 | 2011-10-20 | monetdb | set history | 187 | 492 | 2011-10-20 | user.s6_1() | 166133530 | 0 | 0 |
: : 11:53:11.00 : : =false; : : : 11:53:11.00 : ; : : : :
: : 0000 : : : : : 0000 : : : : :
| 1006155 | 2011-10-20 | monetdb | select 1; | 609 | 356 | 2011-10-20 | user.s4_1(= | 11 | 49 | 0 |
: : 11:53:03.00 : : : : : 11:53:12.00 : 1); : : : :
: : 0000 : : : : : 0000 : : : : :
+---------+-------------+---------+-------------+------+------+-------------+-------------+-----------+------+--------+
4 tuples (11.588ms) !4 columns dropped!
note: to disable dropping columns and/or truncating fields use \w-1
sql>

Comment 16450

Date: 2011-10-20 15:07:37 +0200
From: @mlkersten

The output you see is the debugger trace information.
A patch is pending.

Comment 16451

Date: 2011-10-20 16:39:38 +0200
From: @mlkersten

Changeset 97580c62c2b8 made by Martin Kersten mk@cwi.nl in the MonetDB repo, refers to this bug.

For complete details, see http//devmonetdborg/hg/MonetDB?cmd=changeset;node=97580c62c2b8

Changeset description:

Fix for bug #2909
Check if we are in debugging mode, before dumping
the trace information.

Comment 16452

Date: 2011-10-20 16:41:23 +0200
From: @mlkersten

fixed using minor patch in mal_interpreter.

Comment 16454

Date: 2011-10-20 17:12:44 +0200
From: @mlkersten

Changeset 4fd414abd988 made by Martin Kersten mk@cwi.nl in the MonetDB repo, refers to this bug.

For complete details, see http//devmonetdborg/hg/MonetDB?cmd=changeset;node=4fd414abd988

Changeset description:

Fix for bug #2909
Check if we are in debugging mode, before dumping
the trace information.
(transplanted from 97580c62c2b8654096a66350d9de564c49f20410)

Comment 16457

Date: 2011-10-20 17:32:36 +0200
From: @sjoerdmullender

Changeset 86e4f56d87bf made by Sjoerd Mullender sjoerd@acm.org in the MonetDB repo, refers to this bug.

For complete details, see http//devmonetdborg/hg/MonetDB?cmd=changeset;node=86e4f56d87bf

Changeset description:

Added test for bug #2909.

Comment 17381

Date: 2012-06-26 09:43:39 +0200
From: @drstmane

Changeset 8d4d1a6c3440 made by Stefan Manegold Stefan.Manegold@cwi.nl in the MonetDB repo, refers to this bug.

For complete details, see http//devmonetdborg/hg/MonetDB?cmd=changeset;node=8d4d1a6c3440

Changeset description:

opt_history.c: fixed typo in changeset [7f20c97e8ce3](https://dev.monetdb.org/hg/MonetDB?cmd=changeset;node=7f20c97e8ce3)  "Optimizer de-mx step"

Found by test sql/test/BugTracker-2011/Tests/history.Bug-2909.sql (!)