Transaction_log not properly capturing relevant data for UPDATE statements

[Patrick Crews]

The transaction_log is somehow missing data from certain UPDATE statements.

Up until this query, we have been successfully replicating from the transaction_log via transaction_reader output.
However, the query below causes problems.

Query:
UPDATE `bb` SET `col_bigint` = 0 WHERE `col_bigint_key` != 8 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 7

This affects two rows:
drizzle> select pk, col_bigint from bb where col_bigint = 0;
+----+------------+
| pk | col_bigint |
+----+------------+
| 3 | 0 |
| 11 | 0 |
+----+------------+
2 rows in set (0 sec)

The transaction_log looks borked:
Note how there is no value for pk=11. And despite the fact that the log contains an 'after' value for pk=3, we still get this output from transaction_reader after calling it against the log (no value to SET to)
START TRANSACTION;
UPDATE `test`.`bb` SET WHERE `pk`=11;
UPDATE `test`.`bb` SET WHERE `pk`=3;
COMMIT;

Transaction_log output
drizzle> select print_transaction_message('transaction_log', 86221);
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| print_transaction_message('transaction_log', 86221) |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| transaction_context {
  server_id: 1
  transaction_id: 86
  start_timestamp: 1285087911494163
  end_timestamp: 1285087911553174
}
statement {
  type: UPDATE
  start_timestamp: 1285087911494166
  end_timestamp: 1285087911553173
  update_header {
    table_metadata {
      schema_name: "test"
      table_name: "bb"
    }
    key_field_metadata {
      type: INTEGER
      name: "pk"
    }
  }
  update_data {
    segment_id: 1
    end_segment: true
    record {
      key_value: "11"
    }
    record {
      key_value: "3"
      after_value: "0"
      is_null: false
    }
  }
}
 |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

[Patrick Crews (patrick-crews)]

Linked branch contains a test case for this in plugin/transaction_log/tests/t/bug644529.test
There is a .result file recorded, but it is incorrect.

./test-run --suite=transaction_log bug644529

The test case only has the state of table 'bb' just before the UPDATE that causes bad logs. All queries up to that point had passed / master and slave matched.

If you would like the full list of queries executed against the server from the randgen run, just let me know and I'll provide it (it is a bit verbose though)

[Joe Daly (skinny.moey)]

the test case does not look to be checked in to the branch

[Joe Daly (skinny.moey)]

This can be simplified to:

CREATE TABLE `bb` (
  `pk` INT NOT NULL AUTO_INCREMENT,
  `col_bigint` BIGINT DEFAULT NULL,
  `col_bigint_key` BIGINT DEFAULT NULL,
  PRIMARY KEY (`pk`),
  KEY `col_bigint_key` (`col_bigint_key`)
) ENGINE=InnoDB COLLATE = utf8_general_ci;

INSERT INTO `bb` VALUES (11,NULL,6);

UPDATE `bb` SET `col_bigint` = 0 WHERE `col_bigint_key` != 8;

The offending problem looks to be from the col_bigint_key being set to NULL, setting it to a value yields the correct results in the transaction log.

[David Shrewsbury (dshrews)]

This *might* be a duplicate of bug 645330. A fix for this one should be checked to see if it fixes the other.

[Joe Daly (skinny.moey)]

This is failing because of the memcmp call below in TransactionServices::updateRecord a value of 0 or NULL for a field will be treated the same. A check will need to be added to check is_null() on the record.

    const unsigned char *old_ptr= (const unsigned char *) old_record + (ptrdiff_t) (current_field->ptr - in_table->getInsertRecord());
    const unsigned char *new_ptr= (const unsigned char *) new_record + (ptrdiff_t) (current_field->ptr - in_table->getInsertRecord());

    uint32_t field_length= current_field->pack_length(); /** @TODO This isn't always correct...check varchar diffs. */

    if (memcmp(old_ptr, new_ptr, field_length) != 0)

[Joe Daly (skinny.moey)]

I should have paraphrased my last comment with "I think" as I have not yet tested out the suggested is_null check. It would be worthwhile to still check this test case, with your fixes as I may have misinterpreted.

[Patrick Crews (patrick-crews)]

Also fixes Bug645330.
Closed out the other bug as a duplicate of this one.