Make MTR catch server error log mishandling automatically

[Laurynas Biveinis]

- For each worker, note the 1st test name running there. After each testcase, head -n 1 the server error log for "CURRENT_TEST: foo" in order to catch the testcases that delete the error log
- For mysql-test/include/ grep helpers, die if the file being searched is the error log in its default name and not e.g. $assert_only_after is set in case of assert_grep.inc. This would catch false negatives by finding output of previous testcases on the same worker. Check if $assert_only_after and friends actually work with --repeat.
- In testcase warning checker, list tmp and log dirs before and after a testcase run and add the diff to the warning checker output, to catch stray custom server error logs (which again break --repeat and possibly other testcases if the name happens to be shared)

[Laurynas Biveinis (laurynas-biveinis)]

The 1st item could be hacked in an unportable way by marking error logs as append-only (chflags unappnd on mac, chattr +a on Linux)

[Laurynas Biveinis (laurynas-biveinis)]

5.5:

main.mysql_client_test w1 [ pass ] 42218

MTR's internal check of the test case 'main.mysql_client_test' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13001 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/1/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.result 2017-08-17 10:55:46.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.reject 2017-08-17 10:56:29.000000000 +0300
@@ -41,6 +41,8 @@
 $MYSQL_TMP_DIR:
 mysqld.1
 mysqld.1.sock
+test_wl4435.out.log
+test_wl4435_2.out.log
 $MYSQLTEST_VARDIR:
 log
 my.cnf

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

main.percona_outfile_fifosocket w1 [ pass ] 2256

MTR's internal check of the test case 'main.percona_outfile_fifosocket' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13001 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/1/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.result 2017-08-17 11:01:20.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/1/tmp/check-mysqld_1.reject 2017-08-17 11:01:23.000000000 +0300
@@ -39,8 +39,10 @@
 Replicate_Ignore_Server_Ids
 Master_Server_Id #
 $MYSQL_TMP_DIR:
+fifo
 mysqld.1
 mysqld.1.sock
+regular
 $MYSQLTEST_VARDIR:
 log
 my.cnf

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

main.percona_bug1416582 w5 [ pass ] 216

MTR's internal check of the test case 'main.percona_bug1416582' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13041 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/5/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.result 2017-08-17 11:03:20.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.reject 2017-08-17 11:03:21.000000000 +0300
@@ -42,6 +42,7 @@
 mysqld.1
 mysqld.1.sock
 $MYSQLTEST_VARDIR:
+abcd.000001
 log
 my.cnf
 mysqld.1

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

main.percona_slowlog_size_limits w5 [ pass ] 3749

MTR's internal check of the test case 'main.percona_slowlog_size_limits' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13041 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/5/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.result 2017-08-17 11:04:53.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/5/tmp/check-mysqld_1.reject 2017-08-17 11:04:58.000000000 +0300
@@ -42,13 +42,22 @@
 mysqld.1
 mysqld.1.sock
 $MYSQLTEST_VARDIR:
-abcd.000001
+abcd.000063
+abcd.000064
+abcd.000065
+abcd.000066
+abcd.000067
 log
 my.cnf
 mysqld.1
 run
 std_data
 tmp
+zxcv.000063
+zxcv.000064
+zxcv.000065
+zxcv.000066
+zxcv.000067
 VARIABLE_NAME VARIABLE_VALUE
 AUTOCOMMIT ON
 AUTOMATIC_SP_PRIVILEGES ON

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

main.mysqltest w2 [ pass ] 25762

MTR's internal check of the test case 'main.mysqltest' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/2/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/2/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13011 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/2/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/2/tmp/check-mysqld_1.result 2017-08-17 11:08:34.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/2/tmp/check-mysqld_1.reject 2017-08-17 11:09:00.000000000 +0300
@@ -48,6 +48,7 @@
 run
 std_data
 tmp
+tmpmGbX9w
 VARIABLE_NAME VARIABLE_VALUE
 AUTOCOMMIT ON
 AUTOMATIC_SP_PRIVILEGES ON

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

main.mysqld--help-notwin w4 [ pass ] 377

MTR's internal check of the test case 'main.mysqld--help-notwin' failed.
This means that the test case does not preserve the state that existed
before the test case was executed. Most likely the test case did not
do a proper clean-up. It could also be caused by the previous test run
by this thread, if the server wasn't restarted.
This is the diff of the states of the servers before and after the
test case was executed:
mysqltest: Logging to '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/4/tmp/check-mysqld_1.log'.
mysqltest: Results saved in '/Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/4/tmp/check-mysqld_1.result'.
mysqltest: Connecting to server localhost:13021 (socket /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/tmp/4/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-testcase.test' ...
mysqltest: ... Done processing test commands.
--- /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/4/tmp/check-mysqld_1.result 2017-08-17 11:18:24.000000000 +0300
+++ /Users/laurynas/percona/obj-percona-5.5-release-openssl/mysql-test/var/4/tmp/check-mysqld_1.reject 2017-08-17 11:18:26.000000000 +0300
@@ -39,6 +39,7 @@
 Replicate_Ignore_Server_Ids
 Master_Server_Id #
 $MYSQL_TMP_DIR:
+mysqld--help.txt
 mysqld.1
 mysqld.1.sock
 $MYSQLTEST_VARDIR:

mysqltest: Result content mismatch

[Laurynas Biveinis (laurynas-biveinis)]

An incomplete 5.5 prototype at https://github.com/laurynas-biveinis/percona-server/tree/bug1709759-5.5

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2507