maria-developers team mailing list archive

[Sergei Golubchik <serg@xxxxxxxxxxx>]

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@xxxxxxxxxxx