mariadb/mysql-test/t/log_tables.test

# this test needs multithreaded mysqltest
-- source include/not_embedded.inc
#
# Basic log tables test
#

# check that CSV engine was compiled in
--source include/have_csv.inc

--disable_ps_protocol
use mysql;

#
# Check that log tables work and we can do basic selects. This also
# tests truncate, which works in a special mode with the log tables
#

truncate table general_log;
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from general_log;
truncate table slow_log;
--replace_column 1 TIMESTAMP 2 USER_HOST
select * from slow_log;

#
# We want to check that a record newly written to a log table shows up for
# the query: since log tables use concurrent insert machinery and log tables
# are always locked by artificial THD, this feature requires additional
# check in ha_tina::write_row. This simple test should prove that the
# log table flag in the table handler is triggered and working.
#

truncate table general_log;
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from general_log where argument like '%general_log%';


#
# Check some basic queries interfering with the log tables.
# In our test we'll use a tbale with verbose comments to the short
# command type names, used in the tables
#

create table join_test (verbose_comment varchar (80), command_type varchar(64));

insert into join_test values ("User performed a usual SQL query", "Query");
insert into join_test values ("New DB connection was registered", "Connect");
insert into join_test values ("Get the table info", "Field List");

--replace_column 2 USER_HOST
select verbose_comment, user_host, argument
  from  mysql.general_log join join_test
    on (mysql.general_log.command_type = join_test.command_type);

drop table join_test;

#
# check that flush of the log table work fine
#

flush logs;

#
# check locking of the log tables
#

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.general_log WRITE;

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.slow_log WRITE;

#
# This attemts to get TL_READ_NO_INSERT lock, which is incompatible with
# TL_WRITE_CONCURRENT_INSERT. This should fail. We issue this error as log
# tables are always opened and locked by the logger.
#

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.general_log READ;

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.slow_log READ;

#
# This call should result in TL_READ lock on the log table.
# This is not ok and should fail.
#

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.slow_log READ LOCAL, mysql.general_log READ LOCAL;

# Misc locking tests

show create table mysql.general_log;
show fields from mysql.general_log;

show create table mysql.slow_log;
show fields from mysql.slow_log;

#
# check that FLUSH LOGS does not flush the log tables
#

flush logs;
flush tables;

SET GLOBAL GENERAL_LOG=ON;
SET GLOBAL SLOW_QUERY_LOG=ON;

show open tables;
flush logs;
show open tables;

#
# check that FLUSH TABLES does flush the log tables
#

flush tables;
# Since the flush is logged, mysql.general_log will be in the cache
show open tables;

SET GLOBAL GENERAL_LOG=OFF;
SET GLOBAL SLOW_QUERY_LOG=OFF;

flush tables;
# Here the table cache is empty
show open tables;

SET GLOBAL GENERAL_LOG=ON;
SET GLOBAL SLOW_QUERY_LOG=ON;

#
# Bug #16905    Log tables: unicode statements are logged incorrectly
#

truncate table mysql.general_log;
set names utf8;
create table bug16905 (s char(15) character set utf8 default 'пусто');
insert into bug16905 values ('новое');
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from mysql.general_log;
drop table bug16905;

#
# Bug #17600: Invalid data logged into mysql.slow_log
#

truncate table mysql.slow_log;
set session long_query_time=1;
select sleep(2);
--replace_column 1 TIMESTAMP 2 USER_HOST 3 QUERY_TIME
select * from mysql.slow_log;

#
# Bug #18559 log tables cannot change engine, and gets deadlocked when
# dropping w/ log on
#

# check that appropriate error messages are given when one attempts to alter
# or drop a log tables, while corresponding logs are enabled
--error ER_BAD_LOG_STATEMENT
alter table mysql.general_log engine=myisam;
--error ER_BAD_LOG_STATEMENT
alter table mysql.slow_log engine=myisam;

--error ER_BAD_LOG_STATEMENT
drop table mysql.general_log;
--error ER_BAD_LOG_STATEMENT
drop table mysql.slow_log;

# check that one can alter log tables to MyISAM
set global general_log='OFF';

# cannot convert another log table
--error ER_BAD_LOG_STATEMENT
alter table mysql.slow_log engine=myisam;

# alter both tables
set global slow_query_log='OFF';
# check that both tables use CSV engine
show create table mysql.general_log;
show create table mysql.slow_log;

alter table mysql.general_log engine=myisam;
alter table mysql.slow_log engine=myisam;

# check that the tables were converted
show create table mysql.general_log;
show create table mysql.slow_log;

# enable log tables and chek that new tables indeed work
set global general_log='ON';
set global slow_query_log='ON';

--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from mysql.general_log;

# check that flush of myisam-based log tables work fine
flush logs;

# check locking of myisam-based log tables

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.general_log WRITE;

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.slow_log WRITE;

#
# This attemts to get TL_READ_NO_INSERT lock, which is incompatible with
# TL_WRITE_CONCURRENT_INSERT. This should fail. We issue this error as log
# tables are always opened and locked by the logger.
#

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.general_log READ;

--error ER_CANT_LOCK_LOG_TABLE
lock tables mysql.slow_log READ;

# check that we can drop them
set global general_log='OFF';
set global slow_query_log='OFF';

# check that alter table doesn't work for other engines
set @save_storage_engine= @@session.storage_engine;
set storage_engine= MEMORY;
--error ER_UNSUPORTED_LOG_ENGINE
alter table mysql.slow_log engine=ndb;
--error ER_UNSUPORTED_LOG_ENGINE
alter table mysql.slow_log engine=innodb;
--error ER_UNSUPORTED_LOG_ENGINE
alter table mysql.slow_log engine=archive;
--error ER_UNSUPORTED_LOG_ENGINE
alter table mysql.slow_log engine=blackhole;
set storage_engine= @save_storage_engine;

drop table mysql.slow_log;
drop table mysql.general_log;

# check that table share cleanup is performed correctly (double drop)

--error ER_BAD_TABLE_ERROR
drop table mysql.general_log;
--error ER_BAD_TABLE_ERROR
drop table mysql.slow_log;

# recreate tables and enable logs

use mysql;

CREATE TABLE `general_log` (
  `event_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP
                         ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext,
  `thread_id` int(11) DEFAULT NULL,
  `server_id` int(11) DEFAULT NULL,
  `command_type` varchar(64) DEFAULT NULL,
  `argument` mediumtext
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='General log';

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) DEFAULT NULL,
  `last_insert_id` int(11) DEFAULT NULL,
  `insert_id` int(11) DEFAULT NULL,
  `server_id` int(11) DEFAULT NULL,
  `sql_text` mediumtext NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log';

set global general_log='ON';
set global slow_query_log='ON';
use test;

#
# Bug #20139 Infinite loop after "FLUSH" and "LOCK tabX, general_log"
#

flush tables with read lock;
unlock tables;
use mysql;
--error ER_CANT_LOCK_LOG_TABLE
lock tables general_log read local, help_category read local;
unlock tables;

#
# Bug #17544 Cannot do atomic log rotate and
# Bug #21785 Server crashes after rename of the log table
#

use mysql;
# Should result in error
--error ER_CANT_RENAME_LOG_TABLE
RENAME TABLE general_log TO renamed_general_log;
--error ER_CANT_RENAME_LOG_TABLE
RENAME TABLE slow_log TO renamed_slow_log;

#check rotate logs
truncate table general_log;
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from general_log;

truncate table slow_log;
--replace_column 1 TIMESTAMP 2 USER_HOST
select * from slow_log;

create table general_log_new like general_log;
rename table general_log TO renamed_general_log, general_log_new TO general_log;

create table slow_log_new like slow_log;
rename table slow_log TO renamed_slow_log, slow_log_new TO slow_log;

# check that rename checks more then first table in the list
--error ER_CANT_RENAME_LOG_TABLE
rename table general_log TO general_log_new, renamed_general_log TO general_log, slow_log to renamed_slow_log;

# now check the content of tables
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from general_log;
--replace_column 1 TIMESTAMP 2 USER_HOST 3 THREAD_ID
select * from renamed_general_log;

# the content of the slow log is empty, but we will try a select anyway
--replace_column 1 TIMESTAMP 2 USER_HOST
select * from slow_log;
--replace_column 1 TIMESTAMP 2 USER_HOST
select * from renamed_slow_log;

# check that we can do whatever we want with disabled log
set global general_log='OFF';
RENAME TABLE general_log TO general_log2;

set global slow_query_log='OFF';
RENAME TABLE slow_log TO slow_log2;

# this should fail
--error ER_NO_SUCH_TABLE
set global general_log='ON';
--error ER_NO_SUCH_TABLE
set global slow_query_log='ON';

RENAME TABLE general_log2 TO general_log;
RENAME TABLE slow_log2 TO slow_log;

# this should work
set global general_log='ON';
set global slow_query_log='ON';
# now check flush logs
flush logs;
flush logs;
drop table renamed_general_log, renamed_slow_log;
use test;

#
# Bug #21966 Strange warnings on repair of the log tables
#

use mysql;
# check that no warning occurs on repair of the log tables
repair table general_log;
repair table slow_log;
# check that no warning occurs on "create like" for the log tables
create table general_log_new like general_log;
create table slow_log_new like slow_log;
show tables like "%log%";
drop table slow_log_new, general_log_new;
use test;

#
# Bug#27857 (Log tables supplies the wrong value for generating
#            AUTO_INCREMENT numbers)
#

SET GLOBAL LOG_OUTPUT = 'TABLE';

## test the general log

SET GLOBAL general_log = 0;
FLUSH LOGS;

TRUNCATE TABLE mysql.general_log;
ALTER TABLE mysql.general_log ENGINE = MyISAM;
ALTER TABLE mysql.general_log
  ADD COLUMN seq BIGINT UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY;

SET GLOBAL general_log = 1;
FLUSH LOGS;

--replace_column 1 EVENT_TIME 2 USER_HOST 3 THREAD_ID 4 SERVER_ID
SELECT * FROM mysql.general_log;
--replace_column 1 EVENT_TIME 2 USER_HOST 3 THREAD_ID 4 SERVER_ID
SELECT * FROM mysql.general_log;
SELECT "My own query 1";
SELECT "My own query 2";
--replace_column 1 EVENT_TIME 2 USER_HOST 3 THREAD_ID 4 SERVER_ID
SELECT * FROM mysql.general_log;

SET GLOBAL general_log = 0;
FLUSH LOGS;

ALTER TABLE mysql.general_log DROP COLUMN seq;
ALTER TABLE mysql.general_log ENGINE = CSV;

## test the slow query log

SET @old_long_query_time:=@@long_query_time;

SET GLOBAL slow_query_log = 0;
FLUSH LOGS;

TRUNCATE TABLE mysql.slow_log;
ALTER TABLE mysql.slow_log ENGINE = MyISAM;

ALTER TABLE mysql.slow_log
  ADD COLUMN seq BIGINT UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY;

SET SESSION long_query_time = 1;
SET GLOBAL slow_query_log = 1;
FLUSH LOGS;

## FLUSH LOGS above might be slow, so the following is
## logged as either seq 1-4 or seq 2-5
SELECT "My own slow query", sleep(2);
SELECT "My own slow query", sleep(2);
SELECT "My own slow query", sleep(2);
SELECT "My own slow query", sleep(2);

## So we look for seq 2-4
--replace_column 1 START_TIME 2 USER_HOST 3 QUERY_TIME
SELECT * FROM mysql.slow_log WHERE seq >= 2 LIMIT 3;

SET GLOBAL slow_query_log = 0;
SET SESSION long_query_time =@old_long_query_time;
FLUSH LOGS;

ALTER TABLE mysql.slow_log DROP COLUMN seq;
ALTER TABLE mysql.slow_log ENGINE = CSV;

#
# Bug#25422 (Hang with log tables)
#

--disable_warnings
drop procedure if exists proc25422_truncate_slow;
drop procedure if exists proc25422_truncate_general;
drop procedure if exists proc25422_alter_slow;
drop procedure if exists proc25422_alter_general;
--enable_warnings

delimiter //;

use test//
create procedure proc25422_truncate_slow (loops int)
begin
  declare v1 int default 0;
  declare continue handler for sqlexception /* errors from truncate */
    begin end;
  while v1 < loops do
    truncate mysql.slow_log;
    set v1 = v1 + 1;
    end while;
end//

create procedure proc25422_truncate_general (loops int)
begin
  declare v1 int default 0;
  declare continue handler for sqlexception /* errors from truncate */
    begin end;
  while v1 < loops do
    truncate mysql.general_log;
    set v1 = v1 + 1;
    end while;
end//

create procedure proc25422_alter_slow (loops int)
begin
  declare v1 int default 0;
  declare ER_BAD_LOG_STATEMENT condition for 1575;
  declare continue handler for ER_BAD_LOG_STATEMENT begin end;

  while v1 < loops do
    set @old_log_state = @@global.slow_query_log;
    set global slow_query_log = 'OFF';
    alter table mysql.slow_log engine = CSV;
    set global slow_query_log = @old_log_state;
    set v1 = v1 + 1;
    end while;
end//

create procedure proc25422_alter_general (loops int)
begin
  declare v1 int default 0;
  declare ER_BAD_LOG_STATEMENT condition for 1575;
  declare continue handler for ER_BAD_LOG_STATEMENT begin end;

  while v1 < loops do
    set @old_log_state = @@global.general_log;
    set global general_log = 'OFF';
    alter table mysql.general_log engine = CSV;
    set global general_log = @old_log_state;
    set v1 = v1 + 1;
    end while;
end//

delimiter ;//

set @iterations=100;

--echo "Serial test (proc25422_truncate_slow)"
call proc25422_truncate_slow(@iterations);
--echo "Serial test (proc25422_truncate_general)"
call proc25422_truncate_general(@iterations);
--echo "Serial test (proc25422_alter_slow)"
call proc25422_alter_slow(@iterations);
--echo "Serial test (proc25422_alter_general)"
call proc25422_alter_general(@iterations);

--echo "Parallel test"

# ER_BAD_LOG_STATEMENT errors will occur,
# since concurrent threads do SET GLOBAL general_log= ...
# This is silenced by handlers and will not affect the test

connect (addconroot1, localhost, root,,);
connect (addconroot2, localhost, root,,);
connect (addconroot3, localhost, root,,);
connect (addconroot4, localhost, root,,);
connect (addconroot5, localhost, root,,);
connect (addconroot6, localhost, root,,);
connect (addconroot7, localhost, root,,);
connect (addconroot8, localhost, root,,);

connection addconroot1;
send call proc25422_truncate_slow(@iterations);
connection addconroot2;
send call proc25422_truncate_slow(@iterations);

connection addconroot3;
send call proc25422_truncate_general(@iterations);
connection addconroot4;
send call proc25422_truncate_general(@iterations);

connection addconroot5;
send call proc25422_alter_slow(@iterations);
connection addconroot6;
send call proc25422_alter_slow(@iterations);

connection addconroot7;
send call proc25422_alter_general(@iterations);
connection addconroot8;
send call proc25422_alter_general(@iterations);

connection addconroot1;
reap;
connection addconroot2;
reap;
connection addconroot3;
reap;
connection addconroot4;
reap;
connection addconroot5;
reap;
connection addconroot6;
reap;
connection addconroot7;
reap;
connection addconroot8;
reap;

connection default;

disconnect addconroot1;
disconnect addconroot2;
disconnect addconroot3;
disconnect addconroot4;
disconnect addconroot5;
disconnect addconroot6;
disconnect addconroot7;
disconnect addconroot8;

drop procedure proc25422_truncate_slow;
drop procedure proc25422_truncate_general;
drop procedure proc25422_alter_slow;
drop procedure proc25422_alter_general;

--enable_ps_protocol


#
# Bug#23044 (Warnings on flush of a log table)
#

FLUSH TABLE mysql.general_log;
show warnings;

FLUSH TABLE mysql.slow_log;
show warnings;

#
# Bug#17876 (Truncating mysql.slow_log in a SP after using cursor locks the
#            thread)
#

--disable_warnings
DROP TABLE IF EXISTS `db_17876.slow_log_data`;
DROP TABLE IF EXISTS `db_17876.general_log_data`;
DROP PROCEDURE IF EXISTS `db_17876.archiveSlowLog`;
DROP PROCEDURE IF EXISTS `db_17876.archiveGeneralLog`;
DROP DATABASE IF EXISTS `db_17876`;
--enable_warnings

CREATE DATABASE db_17876;

CREATE TABLE `db_17876.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 
);

CREATE TABLE `db_17876.general_log_data` (
  `event_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext,
  `thread_id` int(11) DEFAULT NULL,
  `server_id` int(11) DEFAULT NULL,
  `command_type` varchar(64) DEFAULT NULL,
  `argument` mediumtext
);

DELIMITER //;

CREATE procedure `db_17876.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 ER_SP_FETCH_NO_DATA CONDITION for 1329;

  DECLARE cur1 CURSOR FOR SELECT * FROM mysql.slow_log;

  OPEN cur1;
  
  REPEAT
    BEGIN
      BEGIN
        DECLARE CONTINUE HANDLER FOR ER_SP_FETCH_NO_DATA SET done = 1;

        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;
      END;

      IF NOT done THEN
        BEGIN
          INSERT INTO
            `db_17876.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;
    END;
  UNTIL done END REPEAT;

  CLOSE cur1;
  TRUNCATE mysql.slow_log;
END //

CREATE procedure `db_17876.archiveGeneralLog`()
BEGIN
  DECLARE event_time CHAR(20);
  DECLARE user_host, argument MEDIUMTEXT;
  DECLARE thread_id, server_id INT;
  DECLARE sql_text BLOB;
  DECLARE done INT DEFAULT 0;
  DECLARE command_type VARCHAR(64);
  DECLARE ER_SP_FETCH_NO_DATA CONDITION for 1329;

  DECLARE cur1 CURSOR FOR SELECT * FROM mysql.general_log;

  OPEN cur1;
  
  REPEAT
    BEGIN
      BEGIN
        DECLARE CONTINUE HANDLER FOR ER_SP_FETCH_NO_DATA SET done = 1;

        FETCH cur1 INTO
          event_time, user_host, thread_id, server_id,
          command_type, argument;
      END;

      IF NOT done THEN
        BEGIN
          INSERT INTO
            `db_17876.general_log_data`
            VALUES(event_time, user_host, thread_id, server_id,
            command_type, argument);
        END;
      END IF;
    END;
  UNTIL done END REPEAT;

  CLOSE cur1;
  TRUNCATE mysql.general_log;
END //

DELIMITER ;//

SET @old_general_log_state = @@global.general_log;
SET @old_slow_log_state = @@global.slow_query_log;

SET GLOBAL general_log = ON;
SET GLOBAL slow_query_log = ON;

select "put something into general_log";
select "... and something more ...";

call `db_17876.archiveSlowLog`();
call `db_17876.archiveGeneralLog`();

SET GLOBAL general_log = OFF;
SET GLOBAL slow_query_log = OFF;

call `db_17876.archiveSlowLog`();
call `db_17876.archiveGeneralLog`();

DROP TABLE `db_17876.slow_log_data`;
DROP TABLE `db_17876.general_log_data`;
DROP PROCEDURE IF EXISTS `db_17876.archiveSlowLog`;
DROP PROCEDURE IF EXISTS `db_17876.archiveGeneralLog`;
DROP DATABASE IF EXISTS `db_17876`;

SET GLOBAL general_log = @old_general_log_state;
SET GLOBAL slow_query_log = @old_slow_log_state;