Description:
Several parts of main.mysql_upgrade_grant test search the server error log for expected patterns. But they do so without restarting the server with some custom error log path, as a result, the log contains everything from the MTR run on the same worker so far.
This is bad because now the searches can find output of the preceding tests. This breaks --repeat option, retry on failure, and should any previous test caused same output in the server log, the corresponding part of the test stops working and just passes silently.
How to repeat:
1) Copy main.mysql_upgrade_grant to main.mysql_upgrade_grant2:
$ cd mysql-test/
$ cp t/mysql_upgrade_grant.test t/mysql_upgrade_grant2.test
$ cp r/mysql_upgrade_grant.result r/mysql_upgrade_grant2.result
2) Break mysql_upgrade_grant2 test intentionally by removing the command which later causes the expected error log output:
$ diff -u t/mysql_upgrade_grant.test t/mysql_upgrade_grant2.test
--- t/mysql_upgrade_grant.test 2017-06-27 14:00:43.000000000 +0300
+++ t/mysql_upgrade_grant2.test 2017-08-02 10:17:20.000000000 +0300
@@ -52,9 +52,9 @@
--source include/user_58_to_57.inc
--source include/user_57_to_56.inc
-INSERT INTO mysql.user VALUES
-('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'),
-('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N');
+# INSERT INTO mysql.user VALUES
+# ('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'),
+# ('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N');
call mtr.add_suppression("Some of the user accounts with SUPER");
call mtr.add_suppression("1. Stop");
@@ -96,14 +96,14 @@
--exec $MYSQL_UPGRADE --skip-verbose --force 2>&1
--echo # expect mysql_native_password
-SELECT plugin FROM mysql.user WHERE user='B19011337_nhash';
+# SELECT plugin FROM mysql.user WHERE user='B19011337_nhash';
--echo # expect empty plugin
-SELECT plugin FROM mysql.user WHERE user='B19011337_ohash';
+# SELECT plugin FROM mysql.user WHERE user='B19011337_ohash';
--echo # cleanup
-DROP USER B19011337_nhash@localhost;
-DROP USER B19011337_ohash@localhost;
+# DROP USER B19011337_nhash@localhost;
+# DROP USER B19011337_ohash@localhost;
# Restore the saved contents of mysql.user and mysql.tables_priv
--let $restore= 1
$ diff -u r/mysql_upgrade_grant.result r/mysql_upgrade_grant2.result
--- r/mysql_upgrade_grant.result 2017-06-27 14:00:43.000000000 +0300
+++ r/mysql_upgrade_grant2.result 2017-08-02 10:26:51.000000000 +0300
@@ -110,9 +110,6 @@
ALTER TABLE mysql.user DROP COLUMN password_last_changed;
ALTER TABLE mysql.user DROP COLUMN password_lifetime;
ALTER TABLE mysql.user DROP COLUMN account_locked;
-INSERT INTO mysql.user VALUES
-('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'),
-('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N');
call mtr.add_suppression("Some of the user accounts with SUPER");
call mtr.add_suppression("1. Stop");
call mtr.add_suppression("2. Run");
@@ -126,7 +123,6 @@
# let's check for the presense of the warning
# end of check for the presense of the warning
# repair the user's plugin
-mysql_upgrade: (non fatal) [WARNING] 1642: Pre-4.1 password hash found. It is deprecated and will be removed in a future release. Please upgrade it to a new format.
mysql.columns_priv OK
mysql.component OK
mysql.db OK
@@ -166,16 +162,8 @@
mtr.test_suppressions OK
sys.sys_config OK
# expect mysql_native_password
-SELECT plugin FROM mysql.user WHERE user='B19011337_nhash';
-plugin
-mysql_native_password
# expect empty plugin
-SELECT plugin FROM mysql.user WHERE user='B19011337_ohash';
-plugin
-
# cleanup
-DROP USER B19011337_nhash@localhost;
-DROP USER B19011337_ohash@localhost;
TRUNCATE TABLE mysql.tables_priv;
INSERT INTO mysql.tables_priv (SELECT * FROM mysql.tmp_backup_tables_priv);
DROP TABLE mysql.tmp_backup_tables_priv;
3) Verify that the test is broken by missing error log output:
$ ./mtr --debug-server mysql_upgrade_grant2
...
main.mysql_upgrade_grant2 [ fail ]
Test ended at 2017-08-02 10:37:54
CURRENT_TEST: main.mysql_upgrade_grant2
# ERROR: The file '/Users/laurynas/percona/obj-mysql-8.0.2-asan-debug-openssl/mysql-test/var/log/mysqld.1.err' does not contain the expected pattern User entry 'B19011337_ohash'@'localhost' has a deprecated pre-4.1 password. The user will be ignored and no one can login with this user anymore.
-><-
mysqltest: In included file ./include/search_pattern_in_file.inc at line 74:
included from /Users/laurynas/percona/mysql-8.0.2/mysql-test/t/mysql_upgrade_grant2.test at line 78:
At line 57: command "perl" failed with error 255. my_errno=2
4) Now run mysql_upgrade_grant followed by mysql_upgrade_grant2, and see a false positive pass:
$ ./mtr --debug-server mysql_upgrade_grant mysql_upgrade_grant2
...
main.mysql_upgrade_grant [ pass ] 236993
main.mysql_upgrade_grant2 [ pass ] 246627
...
Suggested fix:
Restart the server at the start of the testcase with custom error log, grep that, restart again at the end with the default log, remove the custom log.
Description: Several parts of main.mysql_upgrade_grant test search the server error log for expected patterns. But they do so without restarting the server with some custom error log path, as a result, the log contains everything from the MTR run on the same worker so far. This is bad because now the searches can find output of the preceding tests. This breaks --repeat option, retry on failure, and should any previous test caused same output in the server log, the corresponding part of the test stops working and just passes silently. How to repeat: 1) Copy main.mysql_upgrade_grant to main.mysql_upgrade_grant2: $ cd mysql-test/ $ cp t/mysql_upgrade_grant.test t/mysql_upgrade_grant2.test $ cp r/mysql_upgrade_grant.result r/mysql_upgrade_grant2.result 2) Break mysql_upgrade_grant2 test intentionally by removing the command which later causes the expected error log output: $ diff -u t/mysql_upgrade_grant.test t/mysql_upgrade_grant2.test --- t/mysql_upgrade_grant.test 2017-06-27 14:00:43.000000000 +0300 +++ t/mysql_upgrade_grant2.test 2017-08-02 10:17:20.000000000 +0300 @@ -52,9 +52,9 @@ --source include/user_58_to_57.inc --source include/user_57_to_56.inc -INSERT INTO mysql.user VALUES -('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'), -('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'); +# INSERT INTO mysql.user VALUES +# ('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'), +# ('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'); call mtr.add_suppression("Some of the user accounts with SUPER"); call mtr.add_suppression("1. Stop"); @@ -96,14 +96,14 @@ --exec $MYSQL_UPGRADE --skip-verbose --force 2>&1 --echo # expect mysql_native_password -SELECT plugin FROM mysql.user WHERE user='B19011337_nhash'; +# SELECT plugin FROM mysql.user WHERE user='B19011337_nhash'; --echo # expect empty plugin -SELECT plugin FROM mysql.user WHERE user='B19011337_ohash'; +# SELECT plugin FROM mysql.user WHERE user='B19011337_ohash'; --echo # cleanup -DROP USER B19011337_nhash@localhost; -DROP USER B19011337_ohash@localhost; +# DROP USER B19011337_nhash@localhost; +# DROP USER B19011337_ohash@localhost; # Restore the saved contents of mysql.user and mysql.tables_priv --let $restore= 1 $ diff -u r/mysql_upgrade_grant.result r/mysql_upgrade_grant2.result --- r/mysql_upgrade_grant.result 2017-06-27 14:00:43.000000000 +0300 +++ r/mysql_upgrade_grant2.result 2017-08-02 10:26:51.000000000 +0300 @@ -110,9 +110,6 @@ ALTER TABLE mysql.user DROP COLUMN password_last_changed; ALTER TABLE mysql.user DROP COLUMN password_lifetime; ALTER TABLE mysql.user DROP COLUMN account_locked; -INSERT INTO mysql.user VALUES -('localhost','B19011337_nhash','*46ABF58B20022A84DF7B2E8B1AC8219C8DA71553','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'), -('localhost','B19011337_ohash','0f0ea7602c473904','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','Y','','','','',0,0,0,0,'','','N'); call mtr.add_suppression("Some of the user accounts with SUPER"); call mtr.add_suppression("1. Stop"); call mtr.add_suppression("2. Run"); @@ -126,7 +123,6 @@ # let's check for the presense of the warning # end of check for the presense of the warning # repair the user's plugin -mysql_upgrade: (non fatal) [WARNING] 1642: Pre-4.1 password hash found. It is deprecated and will be removed in a future release. Please upgrade it to a new format. mysql.columns_priv OK mysql.component OK mysql.db OK @@ -166,16 +162,8 @@ mtr.test_suppressions OK sys.sys_config OK # expect mysql_native_password -SELECT plugin FROM mysql.user WHERE user='B19011337_nhash'; -plugin -mysql_native_password # expect empty plugin -SELECT plugin FROM mysql.user WHERE user='B19011337_ohash'; -plugin - # cleanup -DROP USER B19011337_nhash@localhost; -DROP USER B19011337_ohash@localhost; TRUNCATE TABLE mysql.tables_priv; INSERT INTO mysql.tables_priv (SELECT * FROM mysql.tmp_backup_tables_priv); DROP TABLE mysql.tmp_backup_tables_priv; 3) Verify that the test is broken by missing error log output: $ ./mtr --debug-server mysql_upgrade_grant2 ... main.mysql_upgrade_grant2 [ fail ] Test ended at 2017-08-02 10:37:54 CURRENT_TEST: main.mysql_upgrade_grant2 # ERROR: The file '/Users/laurynas/percona/obj-mysql-8.0.2-asan-debug-openssl/mysql-test/var/log/mysqld.1.err' does not contain the expected pattern User entry 'B19011337_ohash'@'localhost' has a deprecated pre-4.1 password. The user will be ignored and no one can login with this user anymore. -><- mysqltest: In included file ./include/search_pattern_in_file.inc at line 74: included from /Users/laurynas/percona/mysql-8.0.2/mysql-test/t/mysql_upgrade_grant2.test at line 78: At line 57: command "perl" failed with error 255. my_errno=2 4) Now run mysql_upgrade_grant followed by mysql_upgrade_grant2, and see a false positive pass: $ ./mtr --debug-server mysql_upgrade_grant mysql_upgrade_grant2 ... main.mysql_upgrade_grant [ pass ] 236993 main.mysql_upgrade_grant2 [ pass ] 246627 ... Suggested fix: Restart the server at the start of the testcase with custom error log, grep that, restart again at the end with the default log, remove the custom log.