Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-4846

SQL_ERROR_LOG plugin doesn't log errors produced with SIGNAL

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 10.0.3
    • Fix Version/s: 10.0.8
    • Component/s: None
    • Labels:
      None

      Description

      Since SQL_ERROR_LOG logs all errors that happen withing a stored procedure (while only the last one is returned to the user), it can be a useful debug tool. Thus I've tried to use SIGNAL to add debug messages to my procedures during development, but it seems that the SIGNALed errors are not logged:

      DELIMITER ||
      DROP PROCEDURE IF EXISTS t;
      CREATE PROCEDURE t()
      BEGIN
      	DECLARE n TINYINT UNSIGNED DEFAULT rand();
      	DECLARE CONTINUE HANDLER
      		FOR SQLSTATE '01000'
      		DO NULL;
      	IF n <= 1 THEN
      		SET @dbug_msg = CONCAT('n=', n);
      		SIGNAL SQLSTATE '01000' SET
      			MYSQL_ERRNO = 1644,
      			MESSAGE_TEXT = @dbug_msg;
      	ELSE
      		SIGNAL SQLSTATE '01000' SET
      			MYSQL_ERRNO = 1644,
      			MESSAGE_TEXT = 'Hey... how did this happen??';
      	END IF;
      	DO 'something';
      END;
      ||
      DELIMITER ;
      CALL t();
      

      If you replace SIGNAL with SELECT 1 FROM not_existing_table, the error is logged (DECLARE HANDLER doesn't interfer with SQL_ERRORS_LOG, and this is good).

      I used '01000' SQL STATE and 1644 code because they are not warnings.

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

              Hide
              f_razzoli Federico Razzoli added a comment - - edited

              Sorry, I forgot that SIGNAL can be used outside stored procedures. So, reproducing the bug is simpler:

              MariaDB [(none)]> x;
              ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that
              corresponds to your MariaDB server version for the right syntax to use near 'x'
              at line 1
              MariaDB [(none)]> SIGNAL SQLSTATE '03000';
              ERROR 1644 (03000): Unhandled user-defined exception condition
              MariaDB [(none)]>

              The error log will only contain:

              2013-08-07 2:17:50 root[root] @ localhost [127.0.0.1] ERROR 1064: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'x' at line 1 : x

              So, SiGNAL exception has not been logged.

              Show
              f_razzoli Federico Razzoli added a comment - - edited Sorry, I forgot that SIGNAL can be used outside stored procedures. So, reproducing the bug is simpler: MariaDB [(none)] > x; ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'x' at line 1 MariaDB [(none)] > SIGNAL SQLSTATE '03000'; ERROR 1644 (03000): Unhandled user-defined exception condition MariaDB [(none)] > The error log will only contain: 2013-08-07 2:17:50 root [root] @ localhost [127.0.0.1] ERROR 1064: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'x' at line 1 : x So, SiGNAL exception has not been logged.
              Hide
              f_razzoli Federico Razzoli added a comment -

              I dont know if this is the same bug or another bug or even not a bug, so I'm sorry if I'm writing in a wrong place.

              I found out that, while RESIGNALed errors are logged, the log contains their original sqlstate + errno + message. If RESIGNAL changes some of these properties, the changes seem to be ignored by the plugin.

              You can verify this by running this procedure:

              CREATE PROCEDURE test_error()
              BEGIN
              DECLARE CONTINUE HANDLER
              FOR 1146
              BEGIN
              RESIGNAL SQLSTATE '40000' SET
              MYSQL_ERRNO = 1000,
              MESSAGE_TEXT = 'new message';
              END;
              SELECT `c` FROM `temptab`;
              END;

              The log entry is:

              2013-08-14 2:22:08 root[root] @ localhost [127.0.0.1] ERROR 1146: Table 'test.temptab' doesn't exist : SELECT `c` FROM `temptab`

              In case this is not a bug, please consider that changing an error message/number can make debug easier, if a procedure can produce the same bug in several lines (or in a loop).

              Show
              f_razzoli Federico Razzoli added a comment - I dont know if this is the same bug or another bug or even not a bug, so I'm sorry if I'm writing in a wrong place. I found out that, while RESIGNALed errors are logged, the log contains their original sqlstate + errno + message. If RESIGNAL changes some of these properties, the changes seem to be ignored by the plugin. You can verify this by running this procedure: CREATE PROCEDURE test_error() BEGIN DECLARE CONTINUE HANDLER FOR 1146 BEGIN RESIGNAL SQLSTATE '40000' SET MYSQL_ERRNO = 1000, MESSAGE_TEXT = 'new message'; END; SELECT `c` FROM `temptab`; END; The log entry is: 2013-08-14 2:22:08 root [root] @ localhost [127.0.0.1] ERROR 1146: Table 'test.temptab' doesn't exist : SELECT `c` FROM `temptab` In case this is not a bug, please consider that changing an error message/number can make debug easier, if a procedure can produce the same bug in several lines (or in a loop).
              Show
              holyfoot Alexey Botchkov added a comment - Fixing patch: http://lists.askmonty.org/pipermail/commits/2013-December/005775.html

                People

                • Assignee:
                  holyfoot Alexey Botchkov
                  Reporter:
                  f_razzoli Federico Razzoli
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  3 Start watching this issue

                  Dates

                  • Due:
                    Created:
                    Updated:
                    Resolved:

                    Time Tracking

                    Estimated:
                    Original Estimate - Not Specified
                    Not Specified
                    Remaining:
                    Remaining Estimate - 0 minutes
                    0m
                    Logged:
                    Time Spent - 1 hour
                    1h