MySQL Bugs: #39714: mtr.check_warnings can be painfully slow if error log file is large

Bug #39714	mtr.check_warnings can be painfully slow if error log file is large
Submitted:	29 Sep 2008 5:20	Modified:	30 Jan 2009 17:34
Reporter:	Zhenxing He	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Tests	Severity:	S3 (Non-critical)
Version:	6.0-rpl	OS:	Any
Assigned to:	Zhenxing He	CPU Architecture:	Any

Description:
When we enabled debug trace, the error log (mysqld.err) can be very large(more than 1MB), then stored procedure mtr.check_warnings can be very slow to process it. This can make the execution of a such test case hang like forever.

How to repeat:
We can use the following simplified version of mtr.check_warnings to test on a very large error log file (more than 1MB):

CREATE PROCEDURE check_warnings()
BEGIN
   CREATE TEMPORARY TABLE error_log (
    row INT AUTO_INCREMENT PRIMARY KEY,
    line mediumtext NULL
  ) ENGINE=MyISAM;

  SELECT variable_value INTO @log_error
    FROM information_schema.global_variables
      WHERE variable_name='LOG_ERROR';

  SET @text= load_file(@log_error);

  WHILE LOCATE('\n', @text) DO
    INSERT error_log (line)
      VALUES (
       SUBSTR(@text, 1, LOCATE('\n', @text)-1)
      );
    SET @text= SUBSTR(@text FROM LOCATE('\n', @text)+1);
  END WHILE;
END||

Suggested fix:
I would be nice if LOAD DATA is allowed in SP, but unfortunately this is not possible now, so we probably have to rewrite mtr.check_warnings, move the part that insert all error log lines in to the table out of the SP and use LOAD DATA statement to speed it up.

Many thanks for writing a feature request. We will discuss this.

1. It is weird that he mysqld's error log file gets big when we run "./mtr.pl --debug", is it the .trace file that ends up there. In that case I understand it. Please check _why_ it grows large.

2. I would suggest that we turn off check-warnings when running with --debug, that is the easiest solution to this problem. It is actually already possible to use "./mtr.pl --no-warnings" as a workaround, but I think we can add three lines of code in 'command_line_setup'

Something like:
if ($opt_debug){

}

if ($opt_debug){
  mtr_report("Turning off check warnings when using --debug");
  $opt_warnings= 0;
}

Please fix in 5.1-rpl

Hi Magnus

When run mtr with --debug option, the debug messages are written to mysqld.*.trace file, not to the mysqld.*.err file, so there is no problem to use --debug option for the new mtr script.

The problem I described here is actually cause by a test case (main.backup_logs) that enables debug output by using:

SET SESSION debug="d";

This will cause the debug output be written into mysqld.*.err and cause the mtr.check_warnings to hang for a long time. After examine the test case more carefully, I think this is a mistake to enable all debug output in the test case, so I think we can solve this problem by fixing the test case.

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/57259

2714 He Zhenxing	2008-10-29
      BUG#39714 mtr.check_warnings can be painfully slow if error log file is large
      
      Test backup_logs.test mistakenly turned on debug output to error log
      by setting debug="d", which caused the error log to be very large (> 1M)
      and mtr.check_warnings would spend a long time to process the error log,
      and can cause the test fail because of timeout. The test case does not
      need to enable debug output, what it need is to reset the debug action
      it set before.
      
      This patch fixed the problem by resetting debug to "" instead of "d".

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/57666

2720 He Zhenxing	2008-11-03 [merge]
      Merge BUG#39714

pushed to mysql-6.0-rpl

Pushed into 6.0.10-alpha (revid:luis.soares@sun.com-20090129165607-wiskabxm948yx463) (version source revid:luis.soares@sun.com-20090129163120-e2ntks4wgpqde6zt) (merge vers: 6.0.10-alpha) (pib:6)

Test case changes. No changelog entry needed.