[MDEV-26531] mtr shows some hunks failed Created: 2021-09-03  Updated: 2022-01-21  Resolved: 2022-01-21

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: None
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Anel Husakovic Assignee: Sergei Golubchik
Resolution: Won't Fix Votes: 0
Labels: None


 Description   

As an result of the patch invokation and probably some wrong .rdiff files, there is an error of applied patch.
Example can be seen in buildbot :

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]    432
1 out of 1 hunk FAILED -- saving rejects to file -

or other example in buildbot

main.mysql_upgrade_ssl 'innodb'          w2 [ pass ]   6362
2 out of 2 hunks FAILED
main.mysqldump-system 'innodb,win'       w2 [ skipped ]  Need auth socket plugin
main.old-mode                            w3 [ pass ]    104

At may happen that the error occurs because return error after patch invocation is not checked in the caller.



 Comments   
Comment by Sergei Golubchik [ 2021-09-04 ]

This was kind of intentional, because normally if patch fails to apply the patch, then *.result~ file will be incorrect and the test will fails. So patch failures will always be detected.

Comment by Anel Husakovic [ 2021-09-06 ]

Well in my case I got the false result.
When patch failed and after if --record is applied, error is not visible on stdout, meaning command was successful, but since there is an error, result file is not created.
Here is the example bb-10.7-anel-MDEV-12459-temp-table

#
# Run the test - output: error - comment: OK:
#
anel@anel:~/mariadb/builds/10.7-debug-type/mysql-test$ ./mtr default_row_format_create
Logging: /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl  default_row_format_create
vardir: /home/anel/mariadb/builds/10.7-debug-type/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/anel/mariadb/builds/10.7-debug-type/mysql-test/var'...
Checking supported features...
MariaDB Version 10.7.0-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]    139
innodb.default_row_format_create 'dynamic,innodb' [ fail ]
        Test ended at 2021-09-06 08:11:11
 
CURRENT_TEST: innodb.default_row_format_create
--- /home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row_format_create,dynamic.result~	2021-09-06 08:10:50.319627772 +0200
+++ /home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row_format_create,dynamic.reject	2021-09-06 08:11:11.047887735 +0200
@@ -1,7 +1,7 @@
 CREATE TABLE t1(c1 TEXT,c2 BLOB) ENGINE=InnoDB;
 SHOW TABLE STATUS LIKE 't1';
 Name	Engine	Version	Row_format	Rows	Avg_row_length	Data_length	Max_data_length	Index_length	Data_free	Auto_increment	Create_time	Update_time	Check_time	Collation	Checksum	Create_options	Comment	Max_index_length
-t1	InnoDB	#	Compact	#	#	#	#	#	#	NULL	#	NULL	NULL	latin1_swedish_ci	NULL			0
+t1	InnoDB	#	Dynamic	#	#	#	#	#	#	NULL	#	NULL	NULL	latin1_swedish_ci	NULL			0
 DROP TABLE t1;
 CREATE TABLE t1(c1 TEXT,c2 BLOB) ENGINE=InnoDB ROW_FORMAT=DYNAMIC;
 SHOW TABLE STATUS LIKE 't1';
 
mysqltest: Result content mismatch
 
 - saving '/home/anel/mariadb/builds/10.7-debug-type/mysql-test/var/log/innodb.default_row_format_create-dynamic,innodb/' to '/home/anel/mariadb/builds/10.7-debug-type/mysql-test/var/log/innodb.default_row_format_create-dynamic,innodb/'
 
Only  2  of 3 completed.
--------------------------------------------------------------------------
The servers were restarted 1 times
Spent 0.139 of 5 seconds executing testcases
 
Failure: Failed 1/2 tests, 50.00% were successful.
 
Failing test(s): innodb.default_row_format_create

#
# Record the test - output: no errors shown  - comment: seems as OK, but is NOT OK:
#
anel@anel:~/mariadb/builds/10.7-debug-type/mysql-test$ ./mtr default_row_format_create --record
Logging: /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl  default_row_format_create --record
vardir: /home/anel/mariadb/builds/10.7-debug-type/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/anel/mariadb/builds/10.7-debug-type/mysql-test/var'...
Checking supported features...
MariaDB Version 10.7.0-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]    149
1 out of 1 hunk FAILED
innodb.default_row_format_create 'dynamic,innodb' [ pass ]    141
2 out of 2 hunks FAILED
innodb.default_row_format_create 'innodb,redundant' [ pass ]    121
--------------------------------------------------------------------------
The servers were restarted 2 times
Spent 0.411 of 6 seconds executing testcases
 
Completed: All 3 tests were successful.

#
# Run tests again - output: no error,  comment: seems like `result` file is applied sine there is no error, but not:
#
anel@anel:~/mariadb/builds/10.7-debug-type/mysql-test$ ./mtr default_row_format_create
Logging: /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl  default_row_format_create
vardir: /home/anel/mariadb/builds/10.7-debug-type/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/anel/mariadb/builds/10.7-debug-type/mysql-test/var'...
Checking supported features...
MariaDB Version 10.7.0-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]    140
innodb.default_row_format_create 'dynamic,innodb' [ pass ]    143
innodb.default_row_format_create 'innodb,redundant' [ pass ]    127
--------------------------------------------------------------------------
The servers were restarted 2 times
Spent 0.410 of 7 seconds executing testcases
 
Completed: All 3 tests were successful.

 
#
# Inspect files in source directory , comment: No result file of test innodb.default_*
#
anel@anel:~/mariadb/10.7$ git status
On branch bb-10.7-anel-MDEV-12459-temp-tables-v3
Changes not staged for commit:
  (use "git add <file>..." to update what will be committed)
  (use "git checkout -- <file>..." to discard changes in working directory)
 
	modified:   mysql-test/main/temp_table_is.result
	modified:   mysql-test/main/temp_table_is.test
 
no changes added to commit (use "git add" and/or "git commit -a")

#
# Check the resulting files
#
 
anel@anel:~/mariadb/10.7$ find .|grep default_row_format_create
./mysql-test/suite/innodb/r/default_row_format_create,redundant.reject
./mysql-test/suite/innodb/r/default_row_format_create,redundant.result~
./mysql-test/suite/innodb/r/default_row_format_create,redundant.rdiff
./mysql-test/suite/innodb/r/default_row_format_create,dynamic.rdiff
./mysql-test/suite/innodb/r/default_row_format_create.result
./mysql-test/suite/innodb/r/default_row_format_create,dynamic.result~
./mysql-test/suite/innodb/r/default_row_format_create,dynamic.reject
./mysql-test/suite/innodb/t/default_row_format_create.test

Assuming that the error exists in the test case and when patch is applied we got the error, why --record lied about, showing good result on stdout while not generating the result file?

Shouldn't we prevent such behavior by generating the error on the place of occurrence ?
Suggested patch bb-10.7-anel-MDEV-26531-mtr-hunks :f f0ece7085590a52cd did the following in above example:

==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]    133
1 out of 1 hunk FAILED
system(patch -r - -f -s -o /home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row_format_create,dynamic.result~ /home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row_format_create.result /home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row_format_create,dynamic.rdiff) : 256 at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 3282.
 
Only  1  of 3 completed.
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.133 of 4 seconds executing testcases
 
Completed: All 1 tests were successful.
 
mysql-test-run: *** ERROR: Not all tests completed (only 1 of 3)

The child error signal is 256 (or 2).
When using the patch:

+use autodie qw( system );

we can get full stack trace:

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
innodb.default_row_format_create 'compact,innodb' [ pass ]     30
1 out of 1 hunk FAILED
"patch" unexpectedly returned exit value 1 at /usr/share/perl5/IPC/System/Simple.pm line 566.
	IPC::System::Simple::_check_exit("patch", 1, ARRAY(0x55a8650f6fa0)) called at /usr/share/perl5/IPC/System/Simple.pm line 538
	IPC::System::Simple::_process_child_error(256, "patch", ARRAY(0x55a8650f6fa0)) called at /usr/share/perl5/IPC/System/Simple.pm line 205
	IPC::System::Simple::runx(ARRAY(0x55a8650f6fa0), "patch", "-r", "-", "-f", "-s", "-o", "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., ...) called at /usr/share/perl5/IPC/System/Simple.pm line 163
	IPC::System::Simple::run("patch", "-r", "-", "-f", "-s", "-o", "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., ...) called at (eval 27) line 12
	eval {...} called at (eval 27) line 11
	Fatal::__ANON__("patch", "-r", "-", "-f", "-s", "-o", "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., ...) called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 4895
	main::run_system("patch", "-r", "-", "-f", "-s", "-o", "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., "/home/anel/mariadb/10.7/mysql-test/suite/innodb/r/default_row"..., ...) called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 3284
	main::do_before_run_mysqltest(My::Test=HASH(0x55a865127530)) called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 3911
	main::run_testcase(My::Test=HASH(0x55a865127530), IO::Socket::INET=GLOB(0x55a86502b700)) called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 963
	main::run_worker(44095, 1) called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 476
	main::main() called at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 348
 at /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl line 4895
 
Only  1  of 3 completed.
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.030 of 2 seconds executing testcases
 
Completed: All 1 tests were successful.
 
mysql-test-run: *** ERROR: Not all tests completed (only 1 of 3)

However I don't know how to solve this bug.

Also noted that generated files are not visible, but are cleaned:

$ git status
On branch bb-10.7-anel-MDEV-12459-temp-tables-v3
nothing to commit, working tree clean
$ git clean -dffx
Removing mysql-test/suite/innodb/r/default_row_format_create,dynamic.reject
Removing mysql-test/suite/innodb/r/default_row_format_create,dynamic.result~
Removing mysql-test/suite/innodb/r/default_row_format_create,redundant.result~

Comment by Vladislav Vaintroub [ 2021-09-07 ]

serg there is a bug in checking the system return code in mtr.
as per https://perldoc.perl.org/functions/system
system() return code should be 0, and only then you can check $? >> 8

Comment by Sergei Golubchik [ 2022-01-11 ]

anel, I don't understand the problem. What does --record has to do with all that? It doesn't work with patches and rdiffs anyway. What is the bug you're trying to fix?

Comment by Anel Husakovic [ 2022-01-20 ]

Hi serg

  • The patch is trying to expose the error in the case of `patch` failure, like this amd64-debian-sid:

    1 out of 1 hunk FAILED
    system(patch -r - -f -s -o /buildbot/amd64-debian-sid/build/mysql-test/suite/innodb/r/instant_alter_purge,release.result~ /buildbot/amd64-debian-sid/build/mysql-test/suite/innodb/r/instant_alter_purge.result /buildbot/amd64-debian-sid/build/mysql-test/suite/innodb/r/instant_alter_purge,release.rdiff) : 256 at mysql-test-run.pl line 3283.
    

    Or for amd64-windows:

    missing header for unified diff at line 1 of patch
    1 out of 1 hunk FAILED -- saving rejects to file -
    system(patch --binary -r - -f -s -o D:/Buildbot/amd64-windows/build/mysql-test/suite/innodb/r/instant_alter_debug,dynamic.result~ D:/Buildbot/amd64-windows/build/mysql-test/suite/innodb/r/instant_alter_debug.result D:/Buildbot/amd64-windows/build/mysql-test/suite/innodb/r/instant_alter_debug,dynamic.rdiff) : 256 at mysql-test-run.pl line 3283.
    innodb.innodb-alter-tempfile '8k,innodb' w4 [ pass ]   6223
    

However,

  • I was working on the clean 10.7 trying to reproduce again the failure, but I could only once, but nondeterministic IMHO.

    $ ./mtr instant_alter_debug 
    Logging: /home/anel/mariadb/10.7/mysql-test/mariadb-test-run.pl  instant_alter_debug
    VS config: 
    vardir: /home/anel/mariadb/builds/10.7/mysql-test/var
    Checking leftover processes...
    Removing old var directory...
     - WARNING: Using the 'mysql-test/var' symlink
    Creating var directory '/home/anel/mariadb/builds/10.7/mysql-test/var'...
    Checking supported features...
    MariaDB Version 10.7.2-MariaDB-debug
     - SSL connections supported
     - binaries are debug compiled
     - binaries built with wsrep patch
    Collecting tests...
    Installing system database...
     
    ==============================================================================
     
    TEST                                      RESULT   TIME (ms) or COMMENT
    --------------------------------------------------------------------------
     
    worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
    1 out of 1 hunk FAILED
    innodb.instant_alter_debug 'dynamic,innodb' [ pass ]   1039
    innodb.instant_alter_debug 'innodb,redundant' [ pass ]   1030
    --------------------------------------------------------------------------
    The servers were restarted 1 times
    Spent 2.069 of 4 seconds executing testcases
     
    Completed: All 2 tests were successful.
    

  • Also have tried with other successive tests (bug again couldn't reproduce):

    $ ./mtr innodb.innodb-change-buffer-recovery instant_alter_debug
    $ ./mtr innodb.blob-crash innodb.innodb_bug30113362 default_row_format_create instant_alter_purge --verbose-restart --vardir=/dev/shm/var --parallel=4 --force --retry=3 --max-save-core=0 --max-save-datadir=1
    

    Also tried to do the same on windows based on windowsx64-debug builds

    D:\server\bld_10.7\mysql-test>perl mariadb-test-run.pl innodb.innodb_bug30113362
    Logging: D:/server/mysql-test/mariadb-test-run.pl  innodb.innodb_bug30113362
    VS config: Debug
    vardir: D:/server/bld_10.7/mysql-test/var
    Removing old var directory...
    Creating var directory 'D:/server/bld_10.7/mysql-test/var'...
    Checking supported features...
    MariaDB Version 10.7.2-MariaDB-debug
     - SSL connections supported
     - binaries are debug compiled
    Collecting tests...
    Installing system database...
     
    ==============================================================================
     
    TEST                                      RESULT   TIME (ms) or COMMENT
    --------------------------------------------------------------------------
     
    worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
    innodb.innodb_bug30113362 'innodb'       [ pass ]  57483
    --------------------------------------------------------------------------
    The servers were restarted 0 times
    Spent 57.483 of 1497 seconds executing testcases
     
    Completed: All 1 tests were successful.
    

  • Conclusion: I'm ok if you think this is not important at all.
Generated at Thu Feb 08 09:46:00 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.