Usability Report Table Logs
Contents |
[edit] Using the General log in MySQL 5.1
Sample Usability report written by Giuseppe Maxia on 07-Aug-2006
[edit] Expectations
Logging the server input according to needs, to either a OS file or a database table. Stopping and starting the logging at will.
[edit] Clarity of documentation
I couldn't find these features explained in the manual. There is a section explaining how to switch from table to file and vice versa, but not how to activate or deactivate it at will.
I don't remember where I saw it. It was some blog entry from a MySQL developer some weeks ago. It said that these features were going to be introduced, so I kept looking for it every time I built a new snapshot from the development tree. With 5.1.12 the feature was there, even though it wasn't mentioned in the changelog.
[edit] Ease of use
Looks really easy. If I don't set any parameter in the configuration file, the server will start with log disabled, storage defaulting to a database table. There are two variables, GENERAL_LOG and LOG_OUTPUT. The first one controls whether the log is active or not, while the second one can switch between table and file, or it can enable both.
[edit] In the real world
I tried some silly things on the general_log table, just to see how much I can fiddle with it. So I tried to convert it to a BLACKHOLE table, but it was refused. I have mixed feelings about that. It's good, because I should not mingle with log tables. It's bad, because having a blackhole table would allow me to filter the logs and send them to some tables of my choice.
Next I tried to add a trigger to the general_log table, and it was rejected as well. So it seems that I must play by the book.
Then, let's see how well the system works. As noted before, if I start the server without any option, it will be ready to log to a table and the log will be off by default.
mysql> show variables
where Variable_name in ('version', 'log', 'general_log', 'general_log_file', 'log_output');
+------------------+---------------------------------------+
| Variable_name | Value |
+------------------+---------------------------------------+
| general_log | OFF |
| general_log_file | /usr/local/mysql/data/datacharmer.log |
| log | OFF |
| log_output | TABLE |
| version | 5.1.12-beta |
+------------------+---------------------------------------+
[edit] Simple logs
The first thing I want to try is the simplest one.
mysql> set global general_log=ON;
Query OK, 0 rows affected (0.00 sec)
mysql> select * from mysql.general_log\G
*************************** 1. row ***************************
event_time: 2006-08-07 23:11:22
user_host: datacharmer[datacharmer] @ localhost []
thread_id: 3
server_id: 0
command_type: Query
argument: select * from mysql.general_log
1 rows in set (0.00 sec)
Then I will switch from table to file.
mysql> truncate mysql.general_log; mysql> set global log_output='FILE'; Query OK, 0 rows affected (0.00 sec) mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 1 | +----------+ mysql> set global log_output='TABLE'; mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 2 | +----------+
Next, let's try the combination of both table and file
mysql> set global log_output='TABLE,FILE';
Now I can see that both '/usr/local/mysql/data/datacharmer.log' and the general_log table get my queries.
[edit] Stopping logs by session
Both the general log and the table log respond well to the local setting of the SQL_LOG_OFF system variable. When setting that variable, logging for the current session is suspended.
mysql> truncate mysql.general_log; Query OK, 0 rows affected (0.01 sec) mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 1 | +----------+ 1 row in set (0.00 sec) mysql> set sql_log_off=1; Query OK, 0 rows affected (0.01 sec) mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 2 | +----------+ 1 row in set (0.00 sec) mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 2 | +----------+ 1 row in set (0.00 sec) mysql> set sql_log_off=0; Query OK, 0 rows affected (0.00 sec) mysql> select count(*) from mysql.general_log; +----------+ | count(*) | +----------+ | 3 | +----------+ 1 row in set (0.00 sec)
[edit] multiple logs
One interesting variation is the capability of setting the log name on the fly. For example, if I need to test the output of my CMS application, I can do this:
mysql> set global general_log_file = '/usr/local/mysql/data/cms.log';
mysql> # all the queries related to CMS
# and then back to normal logging
mysql> set global general_log_file = '/usr/local/mysql/data/datacharmer.log';
Unfortunately, the same flexibility can't be achieved for log tables, which, however, have the advantage of allowing SQL selection.
[edit] logs and replication
As I was expecting, the general log, either to file or to table, does not affect replication.
This behavior must be intentional, because it would be most inconvenient to duplicate the general log to a slave. One may say that, when you log to a table, master and slave are no longer the same.
I can't see how it would matter in the real world, except if you do a filesystem backup. In this particular case only, copying the data from master or slave can make a huge difference.
[edit] Test units
[edit] testing general logs and procedures
use test;
delimiter $$
drop procedure if exists start_log $$
create procedure start_log()
deterministic
begin
set global general_log = 1;
select schema() as `schema from procedure`;
end $$
delimiter ;
set global general_log = 0;
truncate mysql.general_log;
call start_log();
select argument from mysql.general_log;
select @@general_log;
[edit] expected result
Database changed Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.01 sec) Query OK, 0 rows affected (0.00 sec) +-----------------------+ | schema from procedure | +-----------------------+ | test | +-----------------------+ 1 row in set (0.00 sec) Query OK, 0 rows affected (0.00 sec) +---------------------------------+ | argument | +---------------------------------+ | select * from mysql.general_log | +---------------------------------+ 1 row in set (0.00 sec) +---------------+ | @@general_log | +---------------+ | 1 | +---------------+ 1 row in set (0.01 sec)
[edit] bugs
None so far.
The following behavior may look like a bug, but it's not. When I set the GENERAL_LOG variable inside a stored procedure, it does activate the log, but the server will not log the statements issued by the SP itself. It is not a bug because the general log records all the requests coming through the client/server protocol. Within a stored procedure there is no exchange of requests between client and server.
[edit] Missing pieces
Some docs would improve this very useful feature. I am not concerned because the feature is not easy to use. It is, actually, but I would like it to be written down in stone, so that it is not likely to change.
[edit] Level of satisfaction
Despite the lack of docs, I am very pleased.