Reproducibility issue: stored procedures/functions not correctly prefixed with delimiters in query log

[Roel Van de Paar]

The bug:
Stored procedures and functions executed from within RQG may execute correctly from RQG/Perl, but they do not execute correctly when the query log is executed directly. They need proper delimiter prefixing. This could be a major cause for non-reproducibility of issues seen during runs.

How to reproduce:
- Use any RQG run which employs stored procedures or stored functions
- Use --sqltrace
- Check the RQG log (containing the queries) after the run

An example:
=> In the yy file:
proc_func:
        DROP PROCEDURE IF EXISTS _letter[invariant] ; CREATE PROCEDURE _letter[invariant] ( proc_param ) BEGIN SELECT COUNT( _field ) INTO @a FROM _table ; END ; CALL _letter[invariant](@a); |
=> resulting in the following query being logged (copy/paste from the RQG log):
        DROP PROCEDURE IF EXISTS n ; CREATE PROCEDURE n ( IN v BLOB ) BEGIN SELECT COUNT( `c70` ) INTO @a FROM `view_table500_innodb_default_int_autoinc` ; END ; CALL n(@a);;

Executing this at the command line (fails):
mysql> DROP PROCEDURE IF EXISTS n ; CREATE PROCEDURE n ( IN v BLOB ) BEGIN SELECT COUNT( `c70` ) INTO @a FROM `view_table500_innodb_default_int_autoinc` ; END ; CALL n(@a);;
Query OK, 0 rows affected (0.01 sec)
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '' at line 1
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'END' at line 1
ERROR 1305 (42000): PROCEDURE test.n does not exist
ERROR: No query specified

Executing this with the proper prefix/append DELIMITER statements (works):
mysql> DELIMITER |
mysql> DROP PROCEDURE IF EXISTS n ; CREATE PROCEDURE n ( IN v BLOB ) BEGIN SELECT COUNT( `c70` ) INTO @a FROM `view_table500_innodb_default_int_autoinc` ; END ; CALL n(@a);;
    -> |
Query OK, 0 rows affected, 1 warning (0.00 sec)
Query OK, 0 rows affected (0.01 sec)
Query OK, 1 row affected (0.51 sec)
mysql> DELIMITER ;

Proposed fix:
Auto-prefix and auto-append the following items:
- Prefix the procedure/function line with "DELIMITER |"
- End the actual procedure/function line with "|"
- Change the delimiter back with "DELIMITER ;" afterwards

Again, this may be a major cause for non-reproducibility.

[Roel Van de Paar (roel11)]

The fix may be as easy as a regex looking for 'PROCEDURE' and 'FUNCTION' in a line. If found, auto-add 'DELIMITER |' before that line and 'DELIMITER ;' after that line in the sqltrace log.

[Roel Van de Paar (roel11)]

Proposed patch

=== modified file 'lib/GenTest/Executor/MySQL.pm'
--- lib/GenTest/Executor/MySQL.pm 2012-10-01 09:56:06 +0000
+++ lib/GenTest/Executor/MySQL.pm 2012-11-02 21:05:34 +0000
@@ -645,7 +645,13 @@
          $trace_query =~ s/\n/\n# [sqltrace] /g;
          print '# [sqltrace] ERROR '.$err.": $trace_query;\n";
      } else {
- print "$query;\n";
+ if ($query =~ m{(procedure|function)}sgio) {
+ pring "DELIMITER |\n";
+ print "$query|\n";
+ pring "DELIMITER ;\n";
+ } else {
+ print "$query;\n";
+ }
      }
  }

[Roel Van de Paar (roel11)]

Another option is to fix up the trace on RQG completion:

cat out.sql | sed 's/^\(.*\)PROCEDURE\(.*\)$/DELIMITER |\n\1PROCEDURE\2 |\nDELIMITER ;/' > out_fixed.sql

Fixes the problem. What would be the best place to fix this (presumably runall.pl)?

[Roel Van de Paar (roel11)]

A better sed, looks for procedures or functions, uses word boundaries etc.

sed 's/^\(.*\)\(\bPROCEDURE\|FUNCTION\b\)\(.*\)$/DELIMITER |\n\1\2\3 |\nDELIMITER ;/i'

[Bernt M Johnsen (bernt-johnsen)]

On 11/02/2012 10:28 PM, RoelV wrote:
> Another option is to fix up the trace on RQG completion:
>
> cat out.sql | sed 's/^\(.*\)PROCEDURE\(.*\)$/DELIMITER |\n\1PROCEDURE\2
> |\nDELIMITER ;/' > out_fixed.sql
>
> Fixes the problem. What would be the best place to fix this (presumably
> runall.pl)?
>
No. It _*has*_ to be fixed in gentest.pl or preferrably in the
appropriate module. We are using RQG from other testing frameworks and
there we don't use runall-new.pl/runall.pl.

[Roel Van de Paar (roel11)]

Applied this patch:

=== modified file 'lib/GenTest/Executor/MySQL.pm'
--- lib/GenTest/Executor/MySQL.pm 2012-10-01 09:56:06 +0000
+++ lib/GenTest/Executor/MySQL.pm 2013-01-30 09:37:34 +0000
@@ -645,7 +645,11 @@
                $trace_query =~ s/\n/\n# [sqltrace] /g;
                print '# [sqltrace] ERROR '.$err.": $trace_query;\n";
            } else {
- print "$query;\n";
+ if ($query =~ m{(procedure|function)}sgio) {
+ print "DELIMITER |\n$query|\nDELIMITER ;\n";
+ } else {
+ print "$query;\n";
+ }
            }
        }