LP #1709759: Make MTR catch server error log mishandling automatically

Description

**Reported in Launchpad by Laurynas Biveinis last update 17-08-2017 12:14:17

  • 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)

Environment

None

Smart Checklist

Activity

Show:

Julia Vural March 4, 2025 at 9:03 PM

It appears that this issue is no longer being worked on, so we are closing it for housekeeping purposes. If you believe the issue still exists, please open a new ticket after confirming it's present in the latest release.

lpjirasync January 23, 2018 at 4:19 PM

**Comment from Launchpad by: Laurynas Biveinis on: 17-08-2017 12:14:08

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

lpjirasync January 23, 2018 at 4:19 PM

**Comment from Launchpad by: Laurynas Biveinis on: 17-08-2017 08:18:45

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

lpjirasync January 23, 2018 at 4:18 PM

**Comment from Launchpad by: Laurynas Biveinis on: 17-08-2017 08:14:57

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

lpjirasync January 23, 2018 at 4:18 PM

**Comment from Launchpad by: Laurynas Biveinis on: 17-08-2017 08:13:42

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

Won't Do

Details

Assignee

Reporter

Affects versions

Priority

Smart Checklist

Created January 23, 2018 at 4:18 PM
Updated March 4, 2025 at 9:03 PM
Resolved March 4, 2025 at 9:03 PM