A very old version of the MySQL site contained a nice header: Speed, Power, Ease of Use. I don’t think that stored programs (routines, triggers, events) were supported, at that time. Now they are, and… developing them is amazingly hard.
There are many problems, for example the language is not flexible and the execution is sloooow. But the biggest problem is that there is no debug API.
In details, one of the biggest problems is that, if you have complex procedures (accessing multiple tables, having error handling, and/or calling other procedures) in practice you have no idea of what warnings occur within your procedures.
MariaDB 10.0 makes things much easier by adding the
SQL_ERROR_LOG plugin. Well, I don’t think that they had stored programs in mind when they developed it. But what’s important for us is that… it makes stored programs debug decent.
This article explains how. Its use in application debugging is not covered here, because it seems to me quite obvious and I want to focus on stored procedures.
We will use the
SQL_ERROR_LOG plugin. Its purpose is to log SQL errors into a text file. To enable it:
INSTALL SONAME 'sql_errlog';
Note that specifying the file extension is not necessary; this makes the statement platform-independent. The MySQL syntax is still supported.
When the plugin is installed, the logging is always active. To stop the logging, uninstall the plugin:
UNINSTALL PLUGIN SQL_ERROR_LOG;
Unfortunately, you might see a warning like this:
Warning (Code 1620): Plugin is busy and will be uninstalled on shutdown
I don’t know any way to avoid this. But I don’t think that
SQL_ERROR_LOG is meant to be ran on a production server, I consider it as a development tool. However, if this is a problem for you, just ask the list or file a bug.
Errors are written in a file called
sql_errors.log, in the data directory:
MariaDB [test]> SELECT CONCAT(@@global.datadir, @@global.sql_error_log_filename) AS sql_errlog; +--------------------------------------+ | sql_errlog | +--------------------------------------+ | /usr/local/mysql/data/sql_errors.log | +--------------------------------------+ 1 row in set (0.00 sec)
To make debug and life easier, I rotate the files very often:
SET @@global.sql_error_log_rotate = 1;
The format is the following:
2014-06-30 1:22:30 root[root] @ localhost  ERROR 1051: Unknown table 'test.unknown_table' : DROP TABLE `unknown_table`
- The session id is not written to the log. The hostname and the user account are written, but they don't help us distinguishing one session from another. I suppose it is meant for being executed by application developers on their local machines.
- In theory, only errors are logged - no warnings, no notes. But keep on reading.
- The file format is not safely parseable. It's designed for humans.
Look at the following procedure:
DROP PROCEDURE IF EXISTS do_something; DELIMITER || CREATE PROCEDURE do_something(IN p TEXT) READS SQL DATA BEGIN DECLARE CONTINUE HANDLER FOR SQLSTATE '45000' BEGIN END; IF @debug = TRUE THEN SET GLOBAL sql_error_log_rotate = 1; END IF; IF @debug = TRUE THEN SET @error = CONCAT('p = ', IF(p IS NULL, 'NULL', QUOTE(p))); SIGNAL SQLSTATE '45000' SET MYSQL_ERRNO = 9999, MESSAGE_TEXT = @error; END IF; -- why do something? let's do nothing! DO NULL; END || DELIMITER ; SET @debug = TRUE; CALL do_something('x');
Got the trick? If the
@debug variable is set to
TRUE, an error is produced. The error is immediately suppressed by an empty
CONTINUE HANDLER, so the procedure's execution continues and nothing happens. Well, almost nothing: the error is logged!
- Write your
Look at this example:
DROP PROCEDURE IF EXISTS do_something; DELIMITER || CREATE PROCEDURE do_something() READS SQL DATA BEGIN DECLARE CONTINUE HANDLER FOR SQLWARNING BEGIN DECLARE CONTINUE HANDLER FOR SQLSTATE '45000' BEGIN END; GET DIAGNOSTICS CONDITION 1 @errno = MYSQL_ERRNO , @error = MESSAGE_TEXT ; IF @debug = TRUE THEN SIGNAL SQLSTATE '45000' SET MYSQL_ERRNO = @errno, MESSAGE_TEXT = @error; END IF; RESIGNAL; END; IF @debug = TRUE THEN SET GLOBAL sql_error_log_rotate = 1; END IF; -- here goes the 'real' procedure. -- let's produce a warning to trigger the main HANDLER... DO 1/0; END || DELIMITER ;
I know: this is tricky. Writing this has been hard. But don't worry: reusing this template will be quite easy.
HANDLER catches the warnings (in this case division by 0, if you have a good
SQL_MODE). Then we get the warning properties (
GET DIAGNOSTICS) and we use them to issue an error (
SIGNAL). The error is suppressed by the internal empty
HANDLER, but it is logged. Finally, the error is
RESIGNAL'd, because we don't want the debug code to suppress warnings.
A final note. Do you want to log warnings only if they appear within a particular portion of your procedure? You can. Just enclose those lines in a
BEGIN ... END construct, and define your handlers inside the construct.