Re: [Maria-developers] b1a1e5b: MDEV-6058 MySQL Bug #11766693: LOG-SLOW-ADMIN-STATEMENTS AND LOG-SLOW-SLAVE-STATEMENTS NOT DISPLAYED.
Hi, Alexey! On Mar 18, Alexey Botchkov wrote:
revision-id: b1a1e5b3d3d5ab95c596580de07daf38a3efa039 (mariadb-10.1.12-19-gb1a1e5b) parent(s): 4aac51db9a55a11574cbfa60484d4329d35b6f2c committer: Alexey Botchkov timestamp: 2016-03-18 11:47:05 +0400 message:
MDEV-6058 MySQL Bug #11766693: LOG-SLOW-ADMIN-STATEMENTS AND LOG-SLOW-SLAVE-STATEMENTS NOT DISPLAYED. These parameters were moved from the command line options to the system variables section. Treatment of the opt_log_slow_slave_statements changed to let the dynamic change of the variable.
--- mysql-test/r/variables.result | 10 ++ mysql-test/suite/rpl/r/rpl_slow_query_log.result | 10 ++ mysql-test/suite/rpl/t/rpl_slow_query_log.test | 43 ++++++++ .../r/log_slow_admin_statements_basic.result | 76 ++++++++++++++ .../r/log_slow_admin_statements_func.result | 46 +++++++++ .../r/log_slow_slave_statements_basic.result | 76 ++++++++++++++ .../t/log_slow_admin_statements_basic.test | 110 +++++++++++++++++++++ .../sys_vars/t/log_slow_admin_statements_func.test | 61 ++++++++++++ .../t/log_slow_slave_statements_basic.test | 110 +++++++++++++++++++++ mysql-test/t/variables.test | 11 +++
I suppose you didn't run the full test suite. Otherwise you would've noticed that sysvar_* results were changed. Also, because we have sysvar_* tests, we no longer create <varname>_basic tests for every new variable, they are no longer useful. Starting from 10.1 you only need to test the functionality of new variables, not their basic properties.
sql/log_event.cc | 10 ++ sql/mysqld.cc | 8 -- sql/sys_vars.cc | 13 +++ 13 files changed, 576 insertions(+), 8 deletions(-)
diff --git a/mysql-test/r/variables.result b/mysql-test/r/variables.result index fef3e4a..e46e65f 100644 --- a/mysql-test/r/variables.result +++ b/mysql-test/r/variables.result @@ -1797,3 +1797,13 @@ select * from information_schema.session_variables where variable_name='sql_mode VARIABLE_NAME VARIABLE_VALUE SQL_MODE ANSI_QUOTES End of 5.5 tests +show variables like 'log_slow%statements'; +Variable_name Value +log_slow_admin_statements OFF +log_slow_slave_statements OFF +select * from information_schema.global_variables where variable_name like 'log_slow_admin_statements'; +VARIABLE_NAME VARIABLE_VALUE +LOG_SLOW_ADMIN_STATEMENTS OFF +select * from information_schema.global_variables where variable_name like 'log_slow_slave_statements'; +VARIABLE_NAME VARIABLE_VALUE +LOG_SLOW_SLAVE_STATEMENTS OFF
You can remove this test.
diff --git a/mysql-test/suite/rpl/t/rpl_slow_query_log.test b/mysql-test/suite/rpl/t/rpl_slow_query_log.test index faf037a..de336fc 100644 --- a/mysql-test/suite/rpl/t/rpl_slow_query_log.test +++ b/mysql-test/suite/rpl/t/rpl_slow_query_log.test @@ -299,6 +299,49 @@ if ($master_slow_query == $slave_slow_query) -- echo ### same number of queries in slow log: $master_slow_query }
+-- echo ******************************************************************** +-- echo **** TRUNCATE the slow log then check whether runtime changes of +-- echo **** log_slow_slave_statements work without slave restart. +-- echo ******************************************************************** + +SET @old_log_slow_slave_statements= @@global.log_slow_slave_statements; +SET @@global.log_slow_slave_statements = off; +TRUNCATE mysql.slow_log; + +-- connection master + +--disable_warnings +-- eval $slow_query; +--enable_warnings +sync_slave_with_master; + +-- connection slave + +let $slave_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; +if ($slave_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query FOUND in slow query log. Bailing out!"; +}
please, NO! If you want to test whether a certain row is present in a certain table you do SELECT columns FROM table; may be with a WHERE clause. But never if (`SELECT`) { die; }
+ +SET @@global.log_slow_slave_statements = on; + +-- connection master + +--disable_warnings +-- eval $slow_query; +--enable_warnings +sync_slave_with_master; + +-- connection slave + +let $slave_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; +if (!$slave_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!"; +}
Same.
+ -- connection master SET @@global.log_output= @old_log_output; SET @@global.long_query_time= @old_long_query_time; diff --git a/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result b/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result new file mode 100644 index 0000000..1cd9135 --- /dev/null +++ b/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result
Remove this useless test, please
diff --git a/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result b/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result new file mode 100644 index 0000000..b9e88ce --- /dev/null +++ b/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result @@ -0,0 +1,76 @@
And this one, too.
diff --git a/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test new file mode 100644 index 0000000..78e4d35 --- /dev/null +++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test + +# ALTER, OPTIMIZE, CHECK and DROP operations should be logged in slow query log. +SELECT sql_text FROM mysql.slow_log WHERE sql_text LIKE '%TABLE log_slow_admin_statements%';
this is how one checks whether a query was logged.
diff --git a/sql/log_event.cc b/sql/log_event.cc index e99ef16..9793f7d 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -4428,6 +4428,16 @@ int Query_log_event::do_apply_event(rpl_group_info *rgi, if (thd->m_digest != NULL) thd->m_digest->reset(thd->m_token_array, max_digest_length);
+ if (thd->slave_thread && + (thd->variables.sql_log_slow != opt_log_slow_slave_statements)) + { + /* + The log_slow_slave_statements variable can be changed dynamically, + so we have to set the sql_log_slow respectively. + */ + thd->variables.sql_log_slow= opt_log_slow_slave_statements; + }
Really? Why not if (thd->slave_thread) thd->variables.sql_log_slow= opt_log_slow_slave_statements; Regards, Sergei Chief Architect MariaDB and security@mariadb.org
Dear Mr Sergei Sorry for a careless mistake I thought prototype is working but it is working only for InnoDB not for MyIsam because if we look at table creation which I send you MariaDB [sachin]> create table tbl(int_key int primary key , blob_key blob unique); Query OK, 0 rows affected (0.03 sec) Here I forgot to add engine =myisam . If we the same table creation for myisam table get created but at the time of insert we get this message ERROR 1030 (HY000): Got error 190 "Incompatible key or row definition between the MariaDB .frm file and the information in the storage engine. You have to dump an" from storage engine MyISAM We are getting this becuase in mi_create for each unique_def it creates one keydef and writes it.And this creates two problem 1. frm keydef algorithm is different from saved kefdef algorithm(always zero) for the time I have solved this problem . 2.Mismatch between keydef's keysegs the reason for this is when mi_create creates keyseg for unique_def it did not keeps the orignal uniquedef's keyseg parameters in mind like language start length which creates problem in check_definition function in ha_myisam.cc.I am currently working on it Once again sorry for this foolish mistake. Regars sachin On Fri, Mar 18, 2016 at 3:16 PM, Sergei Golubchik <serg@mariadb.org> wrote:
Hi, Alexey!
On Mar 18, Alexey Botchkov wrote:
revision-id: b1a1e5b3d3d5ab95c596580de07daf38a3efa039 (mariadb-10.1.12-19-gb1a1e5b) parent(s): 4aac51db9a55a11574cbfa60484d4329d35b6f2c committer: Alexey Botchkov timestamp: 2016-03-18 11:47:05 +0400 message:
MDEV-6058 MySQL Bug #11766693: LOG-SLOW-ADMIN-STATEMENTS AND LOG-SLOW-SLAVE-STATEMENTS NOT DISPLAYED. These parameters were moved from the command line options to the system variables section. Treatment of the opt_log_slow_slave_statements changed to let the dynamic change of the variable.
--- mysql-test/r/variables.result | 10 ++ mysql-test/suite/rpl/r/rpl_slow_query_log.result | 10 ++ mysql-test/suite/rpl/t/rpl_slow_query_log.test | 43 ++++++++ .../r/log_slow_admin_statements_basic.result | 76 ++++++++++++++ .../r/log_slow_admin_statements_func.result | 46 +++++++++ .../r/log_slow_slave_statements_basic.result | 76 ++++++++++++++ .../t/log_slow_admin_statements_basic.test | 110 +++++++++++++++++++++ .../sys_vars/t/log_slow_admin_statements_func.test | 61 ++++++++++++ .../t/log_slow_slave_statements_basic.test | 110 +++++++++++++++++++++ mysql-test/t/variables.test | 11 +++
I suppose you didn't run the full test suite. Otherwise you would've noticed that sysvar_* results were changed.
Also, because we have sysvar_* tests, we no longer create <varname>_basic tests for every new variable, they are no longer useful. Starting from 10.1 you only need to test the functionality of new variables, not their basic properties.
sql/log_event.cc | 10 ++ sql/mysqld.cc | 8 -- sql/sys_vars.cc | 13 +++ 13 files changed, 576 insertions(+), 8 deletions(-)
diff --git a/mysql-test/r/variables.result b/mysql-test/r/variables.result index fef3e4a..e46e65f 100644 --- a/mysql-test/r/variables.result +++ b/mysql-test/r/variables.result @@ -1797,3 +1797,13 @@ select * from information_schema.session_variables where variable_name='sql_mode VARIABLE_NAME VARIABLE_VALUE SQL_MODE ANSI_QUOTES End of 5.5 tests +show variables like 'log_slow%statements'; +Variable_name Value +log_slow_admin_statements OFF +log_slow_slave_statements OFF +select * from information_schema.global_variables where variable_name like 'log_slow_admin_statements'; +VARIABLE_NAME VARIABLE_VALUE +LOG_SLOW_ADMIN_STATEMENTS OFF +select * from information_schema.global_variables where variable_name like 'log_slow_slave_statements'; +VARIABLE_NAME VARIABLE_VALUE +LOG_SLOW_SLAVE_STATEMENTS OFF
You can remove this test.
diff --git a/mysql-test/suite/rpl/t/rpl_slow_query_log.test b/mysql-test/suite/rpl/t/rpl_slow_query_log.test index faf037a..de336fc 100644 --- a/mysql-test/suite/rpl/t/rpl_slow_query_log.test +++ b/mysql-test/suite/rpl/t/rpl_slow_query_log.test @@ -299,6 +299,49 @@ if ($master_slow_query == $slave_slow_query) -- echo ### same number of queries in slow log: $master_slow_query }
+-- echo
+-- echo **** TRUNCATE the slow log then check whether runtime changes of +-- echo **** log_slow_slave_statements work without slave restart. +-- echo
+ +SET @old_log_slow_slave_statements= @@global.log_slow_slave_statements; +SET @@global.log_slow_slave_statements = off; +TRUNCATE mysql.slow_log; + +-- connection master + +--disable_warnings +-- eval $slow_query; +--enable_warnings +sync_slave_with_master; + +-- connection slave + +let $slave_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; +if ($slave_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query FOUND in slow query log. Bailing out!"; +}
please, NO! If you want to test whether a certain row is present in a certain table you do
SELECT columns FROM table;
may be with a WHERE clause. But never if (`SELECT`) { die; }
+ +SET @@global.log_slow_slave_statements = on; + +-- connection master + +--disable_warnings +-- eval $slow_query; +--enable_warnings +sync_slave_with_master; + +-- connection slave + +let $slave_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; +if (!$slave_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!"; +}
Same.
+ -- connection master SET @@global.log_output= @old_log_output; SET @@global.long_query_time= @old_long_query_time; diff --git a/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result b/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result new file mode 100644 index 0000000..1cd9135 --- /dev/null +++ b/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result
Remove this useless test, please
diff --git a/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result b/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result new file mode 100644 index 0000000..b9e88ce --- /dev/null +++ b/mysql-test/suite/sys_vars/r/log_slow_slave_statements_basic.result @@ -0,0 +1,76 @@
And this one, too.
diff --git a/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test new file mode 100644 index 0000000..78e4d35 --- /dev/null +++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_func.test + +# ALTER, OPTIMIZE, CHECK and DROP operations should be logged in slow query log. +SELECT sql_text FROM mysql.slow_log WHERE sql_text LIKE '%TABLE log_slow_admin_statements%';
this is how one checks whether a query was logged.
diff --git a/sql/log_event.cc b/sql/log_event.cc index e99ef16..9793f7d 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -4428,6 +4428,16 @@ int Query_log_event::do_apply_event(rpl_group_info *rgi, if (thd->m_digest != NULL) thd->m_digest->reset(thd->m_token_array, max_digest_length);
+ if (thd->slave_thread && + (thd->variables.sql_log_slow != opt_log_slow_slave_statements)) + { + /* + The log_slow_slave_statements variable can be changed dynamically, + so we have to set the sql_log_slow respectively. + */ + thd->variables.sql_log_slow= opt_log_slow_slave_statements; + }
Really? Why not
if (thd->slave_thread) thd->variables.sql_log_slow= opt_log_slow_slave_statements;
Regards, Sergei Chief Architect MariaDB and security@mariadb.org
_______________________________________________ Mailing list: https://launchpad.net/~maria-developers Post to : maria-developers@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-developers More help : https://help.launchpad.net/ListHelp
Hi, Sachin! On Mar 18, Sachin Setia wrote:
ERROR 1030 (HY000): Got error 190 "Incompatible key or row definition between the MariaDB .frm file and the information in the storage engine. You have to dump an" from storage engine MyISAM
We are getting this becuase in mi_create for each unique_def it creates one keydef and writes it.And this creates two problem 1. frm keydef algorithm is different from saved kefdef algorithm(always zero) for the time I have solved this problem .
2.Mismatch between keydef's keysegs the reason for this is when mi_create creates keyseg for unique_def it did not keeps the orignal uniquedef's keyseg parameters in mind like language start length which creates problem in check_definition function in ha_myisam.cc.I am currently working on it Once again sorry for this foolish mistake. Regars sachin
No problem, everyone makes mistakes :) It's a prototype, after all. It's much more important that you understand how the code works and why it doesn't work. Regards, Sergei Chief Architect MariaDB and security@mariadb.org
participants (2)
-
Sachin Setia -
Sergei Golubchik