Transaction log losing data when a bad query (ERROR 1093) is encountered mid-transaction.

Attached is trimmed randgen output. For clarity, I have removed all bad queries (impossible WHERE's, etc) and SELECT's (I doubt they contributed to this).

What I have tried to do is compare randgen queries to the SQL generated by transaction_reader when called against the server's transaction log.

From my analysis, it appears that a block of queries was somehow missed / ignored by the log as queries that came before and after this block are visible in the transaction_reader output.

I can provide assistance with running the randgen test if you are interested in duplicating things yourself that way. Otherwise, we can work on trying to produce a test-run'able test case.

FYI: I want to completely kill implicit commit.. it's just dumb.

--
Stewart Smith

Yes, definitely need a test case. :)

I tried to cook up a test case based on my filtered randgen output, but for whatever reason, the bug didn't present itself.
I will try to make a test-suite .test file based on all of the executed queries, but in the mean time you can duplicate this via the randgen command line:
perl ./gentest.pl --dsn=dbi:drizzle:host=localhost:port=9306:user=root:password="":database=test --gendata=conf/drizzle/translog.zz --grammar=conf/drizzle/transaction_log_single_thread_drizzle.yy --queries=50 --threads=1 --debug --Validator=DrizzleTransactionLog

To use the Validator, you will need another drizzle server up and running. The Validator expects the server to be listening on port 9307, but you can edit randgen/lib/GenTest/Validator/DrizzleTransactionLog.pm and set the $validator_port variable to whatever you would like.

You can expect to see output like:
# 2010-09-22T17:42:34 Differences between the two servers were found after comparing dumpfiles
# 2010-09-22T17:42:34 diff command: diff --unified /tmp//translog_rpl_dump_9484_9306.sql /tmp//translog_rpl_dump_9484_9307.sql
# 2010-09-22T17:42:34 Master dumpfile: /tmp//translog_rpl_dump_9484_9306.sql
# 2010-09-22T17:42:34 Slave dumpfile: /tmp//translog_rpl_dump_9484_9307.sql
# 2010-09-22T17:42:35 Killing periodic reporting process with pid 9483...
# 2010-09-22T17:42:35 Kill GenTest::ErrorFilter(9482)
# 2010-09-22T17:42:35 Test completed with failure status STATUS_REPLICATION_FAILURE (103)

I've linked a branch with a test - transaction_log.bug644670, that will result in a buggy log.

./test-run --suite=transaction_log bug64470

If parsing the print_transaction_message() output is tough (I find it is on long entries), you can call transaction_reader against the transaction_log to get SQL output.

As noted in the original description, there should be an entry for UPDATE'ing table c, but none will be present in the generated SQL.

from the /tests dir:
../drizzled/message/transaction_reader var/master-data/transaction.log

The bug is being caused by this query (line 387 in the test case).

It would appear that encountering the 1093 ERROR is causing log data to be lost.

#--error ER_UPDATE_TABLE_USED
#DELETE FROM `c` WHERE `col_char_10_not_null_key` IN ( SELECT `col_enum_key` FROM `c` WHERE `pk` = 112 ) ORDER BY `col_bigint`,`col_bigint_key`,`col_bigint_not_null`,`col_bigint_not_null_key`,`col_char_10`,`col_char_1024`,`col_char_1024_key`,`col_char_1024_not_null`,`col_char_1024_not_null_key`,`col_char_10_key`,`col_char_10_not_null`,`col_char_10_not_null_key`,`col_enum`,`col_enum_key`,`col_enum_not_null`,`col_enum_not_null_key`,`col_int`,`col_int_key`,`col_int_not_null`,`col_int_not_null_key`,`col_text`,`col_text_key`,`col_text_not_null`,`col_text_not_null_key`,`pk` LIMIT 4 ;
# 2010-09-20T13:05:55 Query: DELETE FROM `c` WHERE `col_char_10_not_null_key` IN ( SELECT `col_enum_key` FROM `c` WHERE `pk` = 112 ) ORDER BY `col_bigint`,`col_bigint_key`,`col_bigint_not_null`,`col_bigint_not_null_key`,`col_char_10`,`col_char_1024`,`col_char_1024_key`,`col_char_1024_not_null`,`col_char_1024_not_null_key`,`col_char_10_key`,`col_char_10_not_null`,`col_char_10_not_null_key`,`col_enum`,`col_enum_key`,`col_enum_not_null`,`col_enum_not_null_key`,`col_int`,`col_int_key`,`col_int_not_null`,`col_int_not_null_key`,`col_text`,`col_text_key`,`col_text_not_null`,`col_text_not_null_key`,`pk` LIMIT 4 failed: 1093 You can't specify target table '%s' for update in FROM clause. Further errors of this kind will be suppressed.;

For my sanity, inserting a complete test. All statements added to the transaction before the error are being removed:

use test;
create table t (a int not null auto_increment primary key, b varchar(20));

start transaction;
insert into t (b) values ('a'), ('b'), ('c'), ('d'), ('e');
commit;

SET GLOBAL transaction_log_truncate_debug= true;

start transaction;
update t set b = 'z' where a in (1,3,5);
delete from t where a in (select a from t where a < 3);
update t set b = 'y' where a in (2,4);
commit;

select print_transaction_message('transaction.log', ENTRY_OFFSET) from data_dictionary.transaction_log_entries\G