Monday, July 07, 2008

Writing to the MySQL error log

In almost all application development situations, one needs to log debug information now and then. In almost all production systems, one needs to log serious error events somewhere too.

So, what can you do? Create a log table? Sprinkle your code with SELECT 'Debug: ...' statements?

At the UDF Repository for MySQL, we now have a solution to log messages to the MySQL error log: a user-defined function called log_error().

Currently it is all very crude: the log_error function takes one argument and writes it to the mysql_error log, appending a line terminator.

Please try it out, and let us know if you have comments or suggestions to improve. Thanks in advance,

Roland

18 comments:

Andrew Dashin said...

Hi!

Looks interesting, but useless :(
I can't imaging a situation when it is impossible to use log4j (or anything you use for your language). For my opinion rdms isn't the best place we can do logging from.

rpbouman said...

Hi Andrew,

"Looks interesting, but useless :("

Really? mm, can you explain?

"For my opinion rdms isn't the best place we can do logging from."

The point is, if you have a stored procedure, function, or trigger and you want to debug it, how do you do it? I don't see how you can get past adding some kind of notification proc or function call inside the code.

The usual methods are
1) insert into a log table
2) do an 'orhpan' select

the problem with 1)
- hassle to set up a table
- need to set up something to monitor the table (chances are that something was set up for the error log already)
- it has side effects such as influencing the result of ROW_COUNT() or LAST_INSERT_ID()

The problem with 2) is that it is not valid inside triggers, functions and events.

So, I thought this would be a welcome addition to the repetoire.

pabloj said...

That's a very nice and useful function, but, let's face it, it's just an hack.
Proper solution would be real error handling in MySQL (for stored procs, functions and triggers) and hooks for a debugger like the one in PostgreSQL (Firebird seem to have something similar in the works thanks to a company that uses it commercially).

rpbouman said...

Hi pabloj,

thanks for your comment.

I'm not sure why you think it's 'just a hack'. I mentioned debugging as one purpose, and error logging as a second. To the best of my knowledge, an error log file is a widely used mechanism to report system and application errors; why would it suddenly be a hack when applied to database stored procedures?

I agree that for debugging purposes a separate debugging hook would be nice, but the proposed solution does not pretend to be anything more than a logging facility. ("That's a nice bike, pity that it's not a speedboat" :p)

As for your remark about MySQL error handling: well, the real problem is not so much error *handling*. The HANDLER syntax is IMO pretty useful and clean. Things that are direly missing are:
- ability to get info on the specific error code and message inside a general handler like SQLException
- ability to raise or signal an error

Both these issues are being worked on and are currently scheduled to be added to mysql 6.1. Their implementation will follow the SQL standard syntax SIGNAL and GET DIAGNOSTICS

Andrew Dashin said...

May be, may be.
Anyway I believe database should only store a data and make sure for data integrity. :)

rpbouman said...

Andrew,

ok, now I understand. You mean, you feel there should be no need to log anything as there should not be any stored procedures.

That is a fair point.

Just a question to find out how pure your stance is ;)

How do you feel about functions? Should users add their own functions to a database?

(genuine question - not trying to trick you into a discussion)

kind regards,

Roland

Anonymous said...

Can you help me please?
I'm using MySQL Server 5.1 and I searched the internet, for about 6 hours now, for a way to log broken queries but I didn't find anything, does MySQL 5.1 provides something like that(it should is basic)?

rpbouman said...

Hi Theodor,

what do you mean "broken"? You can use the general log to log *everything*, including queries with syntax errors.

see: http://dev.mysql.com/doc/refman/5.1/en/query-log.html

The easiest way to work with it is to add these to lines to you my.cnf (or my.ini on windows):

general_log=off
general_log_file=general.log

This makes sure there is a general log file, but disables logging (this is because logging slows things down considerably)

Then, you start the server. When you feel like monitoring for a while, you issue an SQL statement like:

set global general_log = on;

and from then all all queries will be logged to the file you specified (if you specified a relative path for the general_log_file option, the file will by default be in the data directory)

When done logging, simply do:

set global general_log = off;

I hope this helps!

kind regards

Roland

Anonymous said...

Thanks for providing log_error -- I am using it to debug some triggers. Very glad I didn't have to write it myself.

Anonymous said...

Another thing this UDF could be useful for is for writing an error log monitoring script. The script could use this to write some kind of token and timestamp to the log to denote how far the log has been monitored thus far. This way when it wakes up again in the future, it can tell where it left off the prior run.

Anonymous said...

The comments about "hacks" and "logging from stored procs being useless" are coming from web monkeys who never wrote a serious DB application in their life. A single query people who than deal with the data in their PHP/Java.

Say you have a complex query that needs to create a temporary table. By their logic you would drag that result set across the wire, deal with it in your code, than build an SQL as a string and submit it to the DB. Etc.

RDBMS apps existed at least 30 years prior to web and all your objections are childish.

Thanks for sharing your stuff.

rpbouman said...

Hi All!

@Robert: Great! So glad to see its useful for you ;)

@Larry: Interesting point! Thanks for commenting.

@Anonymous: Thanks for the support...that said, I don't think its very polite to post anonymously and call the other comment contributors "web monkeys". Really, I respect pabloj and Andrew a great deal, and I would appreciate it if you show some basic politeness to the other commenters on this blog. You can vehemently disagree with anyone you like and even call them names, but please have the courtesy to post with your real name if you do. Thank you.

Joey said...

Hi,

I'm finding this interesting, as I am creating a an addon to Expression Engine and I need to output logs to track problems in my code as I cannot use the standard php output due to it being in a templating system.

Theres always a need to log custom error at different layers of a system. So this is useful.

Jeremy Donson said...

I am blown away by the extensibility of MySQL Server... VERY impressive!

We support 5.0.7.x / 5.1 and 5.5 where I work.

I see that 5.0.7.x supports plug-ins, though less elegantly.

Is it ok to support UDF's in 5.0.7.x and above?

Also, how do I know whether I need a UDF or a plug-in?

Thank you!

rpbouman said...

Hi Jeremy!

The UDF feature is in existence since version 3.21 if I am not mistaken - you can certainly use them in 5.0 (and above).

The question whether you need a plugin or a UDF is interesting. Generally you should write a UDF if you really need to have a new function, and you're best advised to write it as a true function (without side effects and without touching server internals). Plugins typically have more opportunities to touch deeply into the server. You should really look at the different available plugin types and decide if there is anything there that matches your needs.

I can recommend the excellen tbook by Andrew Hutchins and Sergei Golubchik. See:

http://www.packtpub.com/mysql-51-plugin-development/book

webber Man said...

How to log stored procedure and function sql error into log table... When error raised it will insert the row with SQLSTATE error..

rpbouman said...

webber Man: you'd think something this trivial would be possible right? not so :(

http://bugs.mysql.com/bug.php?id=11660

There is a "workaround" which basically relies on catching all known errors explicitly:

http://blogs.mysql.com/peterg/2009/06/17/get-the-error-return-value-in-a-variable/

Apart from the significant price in terms of code maintenance, you incur substantial cost in terms of performance too with this method:

http://rpbouman.blogspot.com/2009/06/mysql-stored-functions-impact-of.html

MassiveInfo said...

thanks for the reply...

DuckDB bag of tricks: Processing PGN chess games with DuckDB - Rolling up each game's lines into a single game row (6/6)

DuckDB bag of tricks is the banner I use on this blog to post my tips and tricks about DuckDB . This post is the sixth installment of a s...