Bug #63184 Query on mysql.slow_log using WHERE returns strange results
Submitted: 10 Nov 2011 12:39 Modified: 2 Oct 2012 20:29
Reporter: Daniël van Eeden Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Command-line Clients Severity:S3 (Non-critical)
Version:5.5.16 OS:Windows (Windows 7)
Assigned to: CPU Architecture:Any

[10 Nov 2011 12:39] Daniël van Eeden
Description:
mysql> CHECK TABLE mysql.slow_log;
+----------------+-------+----------+----------+
| Table          | Op    | Msg_type | Msg_text |
+----------------+-------+----------+----------+
| mysql.slow_log | check | status   | OK       |
+----------------+-------+----------+----------+
1 row in set (0.00 sec)

mysql> SELECT VERSION();
+-----------+
| VERSION() |
+-----------+
| 5.5.16    |
+-----------+
1 row in set (0.00 sec)

mysql> select sql_text from mysql.slow_log where sql_text like 'cr%' order by start_time DESC limit 10\G
*************************** 1. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8INCREMENT,
*************************** 2. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8IE),EMENT,
*************************** 3. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8EMANDATEERD_DOOR),
*************************** 4. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8EMANDATEERD_DOOR),
*************************** 5. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8ULT 0,ENT,
*************************** 6. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8),0,DEFAULT 0,
*************************** 7. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8INCREMENT,
*************************** 8. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8INCREMENT,
*************************** 9. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8GESLOTEN)T 0,
*************************** 10. row ***************************
engine = InnoDB DEFAULT CHARSET=utf8INCREMENT,
10 rows in set (0.00 sec)

The rows returned are not full SQL statements, which is weird. And the row doesn't start with a 'c' as asked for in the where statement. 

How to repeat:
A client app in Omnis uses MySQL C API to create tables.

This happens for both the slow log and general log.

These are two entries from the .CSV file with the private data removed.

"2011-11-10 12:32:26","approot[approot] @ localhost [127.0.0.1]",57,0,"Prepare","create table if not exists XXXX\r (\rXXXX_XXX INT UNSIGNED NOT NULL AUTO_INCREMENT,\rXXXX_CREAT_DAT DATETIME,\rXXXX_MOD_DAT DATETIME,\rXXXX_XXXXX_XX VARCHAR(4),\rXXXX_XXX_XX VARCHAR(4),\rXXXXX VARCHAR(500),\rprimary key (XXXX_XXX),\runique (XXXX_NR)\r)\rengine = InnoDB DEFAULT CHARSET=utf8"

"2011-11-10 12:32:26","approot[approot] @ localhost [127.0.0.1]",57,0,"Execute","create table if not exists XXXX\r (\rXXXX_XXX INT UNSIGNED NOT NULL AUTO_INCREMENT,\rXXXX_CREAT_DAT DATETIME,\rXXXX_MOD_DAT DATETIME,\rXXXX_XXXXX_XX VARCHAR(4),\rXXXX_XXX_XX VARCHAR(4),\rXXXXX VARCHAR(500),\rprimary key (XXXX_XXX),\runique (XXXX_NR)\r)\rengine = InnoDB DEFAULT CHARSET=utf8"
[10 Nov 2011 13:40] Peter Laursen
Is "\r" supposed to be 'newlines'? I think that the log tables and MySQL CSV tables in general use "\n" (Linux type linebreads) on all platforms? 

Peter
(not a MySQL person - and forgive me if it is a stupid and misunderstood remark)
[10 Nov 2011 20:46] MySQL Verification Team
Can you verify the table structures are correct?  For 5.5.16 it should look like:

mysql> show create table slow_log\G
*************************** 1. row ***************************
       Table: slow_log
Create Table: CREATE TABLE `slow_log` (
  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext NOT NULL,
  `query_time` time NOT NULL,
  `lock_time` time NOT NULL,
  `rows_sent` int(11) NOT NULL,
  `rows_examined` int(11) NOT NULL,
  `db` varchar(512) NOT NULL,
  `last_insert_id` int(11) NOT NULL,
  `insert_id` int(11) NOT NULL,
  `server_id` int(10) unsigned NOT NULL,
  `sql_text` mediumtext NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log';

As a test, please try isolate the problem more.  Remove the ORDER BY and/or the LIMIT as a start.  Does a plain SELECT * FROM slow_log produce good results?

If the problem is only happening with ORDER BY, try a tiny or large sort_buffer_size to see if it helps...
[15 Nov 2011 8:11] Daniël van Eeden
Here is the table structure (copy-paste from MySQL Workbench)

CREATE TABLE `slow_log` (

  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,

  `user_host` mediumtext NOT NULL,

  `query_time` time NOT NULL,

  `lock_time` time NOT NULL,

  `rows_sent` int(11) NOT NULL,

  `rows_examined` int(11) NOT NULL,

  `db` varchar(512) NOT NULL,

  `last_insert_id` int(11) NOT NULL,

  `insert_id` int(11) NOT NULL,

  `server_id` int(10) unsigned NOT NULL,

  `sql_text` mediumtext NOT NULL

) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'
[15 Nov 2011 8:23] Daniël van Eeden
Screenshot of WB and cmd clients

Attachment: slow_log_bug.png (image/png, text), 238.34 KiB.

[14 Jan 2012 11:31] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior. Please try with current version 5.5.20 and inform us if problem still exists.
[30 Jan 2012 20:37] Daniël van Eeden
Sorry as I don't have access to a Windows 7 system it's not possible for me to test this now.
[2 Oct 2012 20:29] MySQL Verification Team
Please reopen this bug report when you are able to repeat with the last released version. Thanks.