MySQL Bugs: #39003: mtr's diff_files command failed in pushbuild without printing a result diff

Bug #39003	mtr's diff_files command failed in pushbuild without printing a result diff
Submitted:	25 Aug 2008 11:34	Modified:	18 Dec 2009 13:19
Reporter:	Sven Sandberg	Email Updates:
Status:	Closed	Impact on me:	None
Category:	Tools: MTR / mysql-test-run	Severity:	S7 (Test Cases)
Version:	5.1, 5.4	OS:	Any
Assigned to:	Bjørn Munch	CPU Architecture:	Any
Tags:	diff, diff_files, diff_tables.inc, mtr, pushbuild, test failure

Description:
In the following pushbuild failure, the test language command "diff_files" failed, but did not compute any result diff. It is not clear what happened, but I'm guessing one of:

 (1) the 'diff' command was not available
 (2) one of the files to compare did not exist
 (3) diff was available but failed
 (4) mtr has a bug preventing it from running 'diff'

Note that this bug report is not about the failure in the test, but about mtr's way to handle diff_commands. The test failure is likely an instance of BUG#37884.

rpl.rpl_row_basic_2myisam                [ fail ]

CURRENT_TEST: rpl.rpl_row_basic_2myisam
mysqltest: In included file "./include/diff_tables.inc": At line 117: command "diff_files" failed with error 2

The result from queries just before the failure was:
< snip >
j INT NOT NULL);
[expecting slave to replicate correctly]
INSERT INTO t1 VALUES (1, "", 1);
INSERT INTO t1 VALUES (2, repeat(_utf8'a', 16), 2);
Comparing tables master:test.t1 and slave:test.t1
[expecting slave to replicate correctly]
INSERT INTO t2 VALUES (1, "", 1);
INSERT INTO t2 VALUES (2, repeat(_utf8'a', 16), 2);
Comparing tables master:test.t2 and slave:test.t2
[expecting slave to stop]
INSERT INTO t3 VALUES (1, "", 1);
INSERT INTO t3 VALUES (2, repeat(_utf8'a', 128), 2);
Last_SQL_Error
Table definition on master and slave does not match: Column 1 size mismatch - master has size 384, test.t3 on slave has size 49. Master's column size should be <= the slave's column size.
SET GLOBAL SQL_SLAVE_SKIP_COUNTER=8;
START SLAVE;
[expecting slave to replicate correctly]
INSERT INTO t4 VALUES (1, "", 1);
INSERT INTO t4 VALUES (2, repeat(_utf8'a', 128), 2);
Comparing tables master:test.t4 and slave:test.t4

More results from queries before failure can be found in /dev/shm/var-ps_row-101/2/log/rpl_row_basic_2myisam.log

 - saving '/dev/shm/var-ps_row-101/2/log/rpl.rpl_row_basic_2myisam/' to '/dev/shm/var-ps_row-101/log/rpl.rpl_row_basic_2myisam/'

Retrying test, attempt(2/3)...

How to repeat:
https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-rpl&order=32 debx86-b/ps_row

Suggested fix:
If (1), (2), or (3), mtr should have printed a better error message. If (4), the bug should be fixed.

This fails in many trees:
http://tinyurl.com/4y5w3z

diff_files is designed to fail in the event the two items being compared differ:
http://dev.mysql.com/doc/mysqltest/en/mysqltest-commands.html

diff_files file_name1 file_name2

Compare the two files. The command succeeds if the files are the same, and fails if they are different or either file does not exist. The file name arguments are subject to variable substitution.

In my experiments, I could not get diff_files to fail w/ errno 2, but I did verify that diff_files will fail when passed two differing files as inputs or a non-existent input.

It is likely that the two files being passed are different, however, I have not been able to repeat any of these errors on my own machine for further troubleshooting.  Perhaps Magnus would be better suited to let us know if errno2 has any significance.

This is not failing for lack of diff, but more likely a bug in the server - the two "should match" files do not, thus the test case fails.

Lars Thalmann wrote:
> I don't see how you can deduce that the files are different.

On Mon, Jan 26, 2009 at 12:14:18PM -0500, Patrick Crews wrote:
> Well, the test that was referenced in the original bug ran the same  
> comparison routine against two other sets of tables:
> from the included file extra/rpl_test/rpl_row_basic.test
> <snip>
> let $diff_table_1=master:test.t1;
> let $diff_table_2=slave:test.t1;
> source include/diff_tables.inc;
>
> --echo [expecting slave to replicate correctly]
> connection master;
> INSERT INTO t2 VALUES (1, "", 1);
> INSERT INTO t2 VALUES (2, repeat(_utf8'a', 16), 2);
> sync_slave_with_master;
>
> let $diff_table_1=master:test.t2;
> let $diff_table_2=slave:test.t2;
> source include/diff_tables.inc;
> <snip>
> connection master;
> INSERT INTO t4 VALUES (1, "", 1);
> INSERT INTO t4 VALUES (2, repeat(_utf8'a', 128), 2);
> sync_slave_with_master;
>
> let $diff_table_1=master:test.t4;
> let $diff_table_2=slave:test.t4;
> source include/diff_tables.inc;
> <snip>
>
> From this, we can see that t1 and t2 were able to be compared without a  
> problem (or I might be assuming this, since the snippet out output ends  
> at the 'Comparing tables master:test.t4... line).
>
> Based on this and the defined behavior or mtr's diff_files, is where I  
> came to the conclusion that something was amiss with one of these two 
> files.
>
> As a result, we know that
> 1)  diff was available and working at least intermittently
>  This eliminates #1 and #4 from Sven's possibilities.
> 2)  It doesn't seem as likely for there to be a sporadic diff error as a  
>  difference between the files under comparison or the absence of one of  
> the files.

Neither the docs nor the code indicate that diff_files is supposed to produce the diff, it only tests the files.  Error 2 means there was a length mismatch, in which case it doesn't bother to check the contents.  OK the error message could have been better.

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".

It can't be true that mtr does not compute a diff if the .result and .reject file have different sizes - then we would almost never get any diff at all. In any case, we need a result diff in all cases, even if the docs say something else. Without that, we can't debug our product.
Setting back to verified.

There's a misunderstanding here. diff_files is a command in the test language, and is used within the test to check if two files produced during the test are identical. It succeeds or not but will not output a diff.

This has nothing to do with comparing the result files after the test is finished. In this case, the test fails because diff_files sees that the files are not identical in size.

You are right, sorry about my previous comment, this is about diff_files.

But in any case, I think diff_files should print a result diff. There is no point in suppressing that, the user always wants to know why a test fails if it fails. So please remove the check for file sizes and always invoke diff.

There are several reasons why I don't this is worth doing:

1. It's counter to the nature of mysqltest to produce a diff; mysqltest is meant to produce predictable output from commands and queries, not additional info for debugging. We have no "natural" place to output this diff.

2. There are many cases where a command may fail and you may need to rerun with debug etc. to find out what really happened. This can also be done in the case of diff_files, by modifying the test to keep the file content, then you can inspect manually.

3. diff isn't necessarily available.

Looks like this was in fact supposed to be implemented after all, but the output of diff was discarded, presumably unintentionally. Will see about fixing this, it should now be only a few lines.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/81063

2819 Bjorn Munch	2009-08-19
      Bug #39003 mtr's diff_files command failed in pushbuild without printing a result diff
      diff was actually called but result never outputted before exiting
      Added extra code to dump output *unless* failure was expected

Note that we don't want to just print the diff out (it might be huge). With this solution, MTR will just output the last 20 lines of the diff.

Pushed to azalea-mtr (soon ro be renamed next-mtr) and 5.1-mtr

Pushed into 5.1.40 (revid:bjorn.munch@sun.com-20090903170735-679d64zp580wl39j) (version source revid:bjorn.munch@sun.com-20090903170735-679d64zp580wl39j) (merge vers: 5.1.40) (pib:11)

Test suite change. No changelog entry needed.

Setting report to NDI pending push into 5.4.x.

Pushed into 6.0.14-alpha (revid:alik@sun.com-20090929093622-1mooerbh12e97zux) (version source revid:alik@sun.com-20090922182109-vs5ign07cwht12z6) (merge vers: 6.0.14-alpha) (pib:11)

Pushed into 5.4.5-beta (revid:alik@sun.com-20090925094254-tjl9eajkzwzgthoe) (version source revid:alik@sun.com-20090922142453-x275o41whpyezh4q) (merge vers: 5.4.4-beta) (pib:11)

Test suite change. No changelog entry needed.

Pushed into 5.1.41-ndb-7.1.0 (revid:jonas@mysql.com-20091218102229-64tk47xonu3dv6r6) (version source revid:jonas@mysql.com-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)

Pushed into 5.1.41-ndb-6.2.19 (revid:jonas@mysql.com-20091218100224-vtzr0fahhsuhjsmt) (version source revid:jonas@mysql.com-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)

Pushed into 5.1.41-ndb-6.3.31 (revid:jonas@mysql.com-20091218100616-75d9tek96o6ob6k0) (version source revid:jonas@mysql.com-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)

Pushed into 5.1.41-ndb-7.0.11 (revid:jonas@mysql.com-20091218101303-ga32mrnr15jsa606) (version source revid:jonas@mysql.com-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)

Test suite change. No changelog entry needed.