Bug #17876 Truncating mysql.slow_log in a SP after using cursor locks the thread
Submitted: 2 Mar 2006 21:16 Modified: 2 Aug 2007 17:20
Reporter: Andrey Hristov Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.1.8 BK OS:Linux (Suse Linux 10)
Assigned to: Marc ALFF CPU Architecture:Any

[2 Mar 2006 21:16] Andrey Hristov
Description:
Try the SP attached

Console 1:
mysql> call archiveSlowLog();

Console 2:
mysql> show processlist;
+----+-----------------+-----------+----------+---------+------+----------+-------------------------+
| Id | User            | Host      | db       | Command | Time | State    | Info                    |
+----+-----------------+-----------+----------+---------+------+----------+-------------------------+
|  1 | root            | localhost | slow_log | Sleep   |   16 |          | NULL                    |
|  3 | event_scheduler | localhost | NULL     | Connect |   16 | Sleeping | NULL                    |
|  5 | root            | localhost | slow_log | Connect |   16 | Locked   | TRUNCATE mysql.slow_log |
|  6 | root            | localhost | NULL     | Query   |    0 | NULL     | show processlist        |
+----+-----------------+-----------+----------+---------+------+----------+-------------------------+
4 rows in set (0.02 sec)

How to repeat:
CREATE DATABASE IF NOT EXISTS low_log;

CREATE TABLE IF NOT EXISTS `slow_log.slow_log_data` (
  `start_time` timestamp  default CURRENT_TIMESTAMP on update CURRENT_TIMESTAMP,
  `user_host` mediumtext ,
  `query_time` time ,
  `lock_time` time ,
  `rows_sent` int(11) ,
  `rows_examined` int(11) ,
  `db` varchar(512) default NULL,
  `last_insert_id` int(11) default NULL,
  `insert_id` int(11) default NULL,
  `server_id` int(11) default NULL,
  `sql_text` mediumtext 
)

DELIMITER //
DROP procedure archiveSlowLog //

CREATE procedure archiveSlowLog()
BEGIN
  DECLARE start_time, query_time, lock_time CHAR(20);
  DECLARE user_host MEDIUMTEXT;
  DECLARE rows_set, rows_examined, last_insert_id, insert_id, server_id INT;
  DECLARE dbname MEDIUMTEXT;
  DECLARE sql_text BLOB;
  DECLARE done INT DEFAULT 0;
  DECLARE cur1 CURSOR FOR SELECT * FROM mysql.slow_log WHERE start_time < (NOW() - INTERVAL 4 MINUTE) ;
  DECLARE CONTINUE HANDLER FOR SQLSTATE '02000' SET done = 1;

  OPEN cur1;
  
  REPEAT
    FETCH cur1 INTO
       start_time, user_host, query_time, lock_time,
       rows_set, rows_examined, dbname, last_insert_id,
       insert_id, server_id, sql_text;
    IF NOT done THEN
    BEGIN
      INSERT INTO
        slow_log.slow_log_data
      VALUES(start_time, user_host, query_time, lock_time, rows_set, rows_examined,
             dbname, last_insert_id,  insert_id, server_id, sql_text);
     END;
     END IF;
  UNTIL done END REPEAT;

  CLOSE cur1;
  TRUNCATE mysql.slow_log;
END //

DELIMITER ;
[8 Mar 2006 8:58] Magnus BlÄudd
Seems related to bug#17878
[14 Mar 2006 23:49] MySQL Verification Team
Thank you for the bug report.
Correct the test case the create database and create table not matches.

CREATE DATABASE IF NOT EXISTS low_log;
CREATE TABLE IF NOT EXISTS `slow_log.slow_log_data`
[24 Jul 2007 2:40] Marc ALFF
Fixed by bug#25422
[27 Jul 2007 18:39] Marc ALFF
Fixed by Bug#25422
[1 Aug 2007 23:29] Konstantin Osipov
Fixed in 5.1.21
[2 Aug 2007 17:20] Paul DuBois
Noted in 5.1.21 changelog.

Log table locking was redesigned, eliminating several
lock-related problems:
  - Truncating mysql.slow_log in a stored procedure
    after use of a cursor caused the thread to lock.
    (Bug #17876) 
  - Flushing a log table resulted in warnings.
    (Bug #23044)
  - The server would hang when performing concurrent
    ALTER TABLE or TRUNCATE TABLE statements against the 
    log tables. (Bug #25422) 
  - Changing the value of the general_log system
    variable while a global read lock was in place
    resulted in deadlock. (Bug #29129)