Description:
On our master-master system, we have experienced an issue where the slave occasionally deadlock and all subsequent retries will fail. When this happens, it always fails when applying a user variable event that precedes the actual transaction.
An extract of an actual failure is:
# at 95929638
#100303 15:57:09 server id 1 end_log_pos 125556422 Xid = 150148149
COMMIT/*!*/;
# at 95929665
#100303 15:57:09 server id 1 end_log_pos 125556550 User_var
SET @`current_date`:=_binary 0x323031302D30332D30332030343A35373A3039 COLLATE `binary`/*!*/;
# at 95929729
#100303 15:57:09 server id 1 end_log_pos 125556603 User_var
SET @`current_node`:=2/*!*/;
# at 95929782
#100303 15:57:09 server id 1 end_log_pos 125556650 User_var
SET @`seqnum`:=0/*!*/;
# at 95929829
#100303 15:57:09 server id 1 end_log_pos 125557055 Query thread_id=2265390 exec_time=0 error_code=0
SET TIMESTAMP=1267592229/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
BEGIN
/*!*/;
In the above example the deadlock happened in the transaction starting a position 95929905, however the SQL thread started the next attempt at position 95929665 and it then failed setting @`current_date`. Failing to set a user variable doesn't change thd->net.last_errno, so the retry algorithm will keep retrying until slave_trans_retries attempts has been made.
A "START SLAVE SQL_THREAD" will make the slave start again and at this time all works.
There are three issues with the above example:
1: Why does the slave fail to apply the user variable when it is inside the retry loop?
2: Why is it jumping back further than to the start of the transaction? I know it should be harmless to re-apply the user variables, but the principle seems wrong.
3: It can't be seen from the relay log extract above, but the user variable events between the COMMIT and the BEGIN events actually originated on the slave itself. When a user variable event is replicated, the slave writes the event into its binlog with the server id of the slave instead of the one of the originating server (see patch suggestion below).
How to repeat:
Unfortunately I do now have a simple case of how to replicate the issue with the deadlock retry not being able to resolve. If we put the server under heavy load and on purpose ensure updates to the same tables/records happen at both server, then we are usually able to replicate it.
The wrong server id for the user var events can be replicated by enabling logging of slave updates and issue a query that uses a user variable on the master.
Suggested fix:
Attached is a proposed fix for the server id for the user variable events. Making this change will also make it behave the same way as intvar and rand events. The attached fix is for 5.0.77, but it should be simple enough to port to other versions.
It appears that this stops the deadlock retries from breaking, however I am not really convinced that it takes care of the underlying issue(s) - more that it hides it.
