MySQL Bugs: #27857: Log tables supplies the wrong value for generating AUTO

Bug #27857	Log tables supplies the wrong value for generating AUTO_INCREMENT numbers
Submitted:	16 Apr 2007 17:59	Modified:	11 Jul 2007 16:45
Reporter:	Tobias Asplund	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S3 (Non-critical)
Version:	5.1.18	OS:	Linux
Assigned to:	Marc ALFF	CPU Architecture:	Any

Description:
When using AUTO_INC columns in log tables, it seems to not use the right code to generate numbers.

mysql> SET GLOBAL LOG_OUTPUT = 'TABLE';
Query OK, 0 rows affected (0.00 sec)

mysql> ALTER TABLE mysql.general_log ENGINE = MyISAM;
Query OK, 0 rows affected (0.05 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> ALTER TABLE mysql.general_log ADD COLUMN seq BIGINT UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY;
Query OK, 0 rows affected (0.03 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> SET GLOBAL general_log = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM mysql.general_log;
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
| event_time          | user_host                     | thread_id | server_id | command_type | argument                        | seq                  |
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
| 2007-04-16 19:40:16 | flupps[flupps] @ localhost [] |         2 |         0 | Query        | SELECT * FROM mysql.general_log | 11936128518282651045 | 
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
1 row in set (0.00 sec)

mysql> SELECT * FROM mysql.general_log;
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
| event_time          | user_host                     | thread_id | server_id | command_type | argument                        | seq                  |
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
| 2007-04-16 19:40:16 | flupps[flupps] @ localhost [] |         2 |         0 | Query        | SELECT * FROM mysql.general_log | 11936128518282651045 | 
+---------------------+-------------------------------+-----------+-----------+--------------+---------------------------------+----------------------+
1 row in set (0.00 sec)

As you can see the first insert into the log logs the maximum available number for the BIGINT column, not the next available.

Since triggers aren't available for mysql.* tables, there's really no available workaround to get statements in execution order since event_time is only second granularity.

How to repeat:
-- Cut and paste friendly:

SET GLOBAL LOG_OUTPUT = 'TABLE';
-- Query OK, 0 rows affected (0.00 sec)

ALTER TABLE mysql.general_log ENGINE = MyISAM;
-- Query OK, 0 rows affected (0.05 sec)
-- Records: 0  Duplicates: 0  Warnings: 0

ALTER TABLE mysql.general_log ADD COLUMN seq BIGINT UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY;
-- Query OK, 0 rows affected (0.03 sec)
-- Records: 0  Duplicates: 0  Warnings: 0

SET GLOBAL general_log = 1;
-- Query OK, 0 rows affected (0.00 sec)

SELECT * FROM mysql.general_log;
SELECT * FROM mysql.general_log;
-- Second time should have generated another row here.

-- Let's clean up...
SET GLOBAL general_log = 0;
-- Query OK, 0 rows affected (0.00 sec)

ALTER TABLE mysql.general_log DROP COLUMN seq;
-- Query OK, 1 row affected (0.02 sec)
-- Records: 1  Duplicates: 0  Warnings: 0

Suggested fix:
Like I'm mentioning above, there's no way to see the order queries are written to the log file, in a physical file, you know the order is guaranteed (at least within the same session, maybe not server-execution order, but that goes a long way at least).
Adding a sequence/counter would be a very nice thing here, even if it had to be done manually, it would be nice if it wouldn't break on a simple addition of a column like this.

Thank you for the bug report. Verified as described.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/28708

ChangeSet@1.2551, 2007-06-13 22:05:22-06:00, malff@weblab.(none) +3 -0
  Bug#27857 (Log tables supplies the wrong value for generating AUTO_INCREMENT
  numbers)
  
  Before this patch, the code in the class Log_to_csv_event_handler, which is
  used by the global LOGGER object to write to the tables mysql.slow_log and
  mysql_general_log, was supporting only records of the format defined for
  these tables in the database creation scripts.
  
  Also before this patch, the server would allow, with certain limitations,
  to perform ALTER TABLE on the LOG TABLES.
  
  As implemented, the behavior of the server, with regards to LOG TABLES,
  is inconsistent:
  - either ALTER TABLES on LOG TABLES should be prohibited,
  and the code writing to these tables can make assumptions on the record
  format,
  - or ALTER TABLE on LOG TABLES is permitted, in which case the code
  writing a record to these tables should be more flexible and honor
  new fields.
  
  In particular, adding an AUTO_INCREMENT column to the logs,
  does not work as expected (per the bug report).
  
  Given that the ALTER TABLE on log tables statement has been explicitly
  implemented to check that the log should be off to perform the operation,
  and that current test cases already cover this, the user expectation is
  already set that this is a "feature" and should be supported.
  
  With this patch, the server will:
  - populate AUTO INCREMENT columns if present,
  - populate any additional column with it's default value
  when writing a record to the LOG TABLES.
  
  Tests are provided, that detail the precise sequence of statements
  a SUPER user might want to perform to add more columns to the log tables.

Pushed into 5.1.20-beta

Noted in 5.1.20 changelog.

The server made strong assumptions about the structure 
of the general_log and slow_log log tables: It supported
only the table structure defined in the mysql database
creation scripts. The server also allowed limited
ALTER TABLE operations on the log tables, but adding an
AUTO_INCREMENT column did not properly initialize the
column, and subsequent inserts into the table could fail 
to generate correct sequence numbers. Now an ALTER TABLE
statement that adds an AUTO_INCREMENT column populates
the column correctly. In addition, when the server writes
a log table row, it will set columns not present in the
original table structure to their default values.