We are running a MySQL DB master server version 8.0.36-0ubuntu0.22.04.1 and MySQL DB slave server version 8.0.39-0ubuntu0.22.04.1, where replication fails after a few hours with this in /var/log/mysql/error.log. It essentially states that a DELETE failed because the data to be deleted is already gone:
2024-08-14T06:06:17.465912Z 4713 [ERROR] [MY-010584] [Repl] Replica SQL for channel '': Worker 2 failed executing transaction 'ANONYMOUS' at source log mysql-bin.000004, end_log_pos 400124893; Could not execute Delete_rows event on table studip.files_search_index; Can't find record in 'files_search_index', Error_code: 1032; Can't find record in 'files_search_index', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's source log mysql-bin.000004, end_log_pos 400124893, Error_code: MY-001032
2024-08-14T06:06:17.485692Z 4711 [ERROR] [MY-010586] [Repl] Error running query, replica SQL thread aborted. Fix the problem, and restart the replica SQL thread with "START REPLICA". We stopped at log 'mysql-bin.000004' position 399886012
The corresponding binlog for the DELETE is as follows:
#240807 10:03:52 server id 43810 end_log_pos 400124460 CRC32 0xe04896d7 Anonymous_GTID last_committed=165526 sequence_number=165528 rbr_only=yes original_committed_timestamp=1723017832033182 immediate_commit_timestamp=1723017832033182 transaction_length=543
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1723017832033182 (2024-08-07 10:03:52.033182 CEST)
# immediate_commit_timestamp=1723017832033182 (2024-08-07 10:03:52.033182 CEST)
/*!80001 SET @@session.original_commit_timestamp=1723017832033182*//*!*/;
/*!80014 SET @@session.original_server_version=80036*//*!*/;
/*!80014 SET @@session.immediate_server_version=80036*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 400124460
#240807 10:03:52 server id 43810 end_log_pos 400124537 CRC32 0xc1595468 Query thread_id=270960 exec_time=0 error_code=0
SET TIMESTAMP=1723017832/*!*/;
BEGIN
/*!*/;
# at 400124537
#240807 10:03:52 server id 43810 end_log_pos 400124613 CRC32 0x04bf430a Table_map: `studip`.`files_search_index` mapped to number 1810
# has_generated_invisible_primary_key=0
# at 400124613
#240807 10:03:52 server id 43810 end_log_pos 400124893 CRC32 0xe5c70d05 Delete_rows: table id 1810 flags: STMT_END_F
### DELETE FROM `studip`.`files_search_index`
### WHERE
### @1='cb866f5c9f049fe6ce7bca65761aae70'
### @2='1.0 Einführung.mp4'
### @3=0.992793
### DELETE FROM `studip`.`files_search_index`
### WHERE
### @1='cb866f5c9f049fe6ce7bca65761aae70'
### @2=''
### @3=0.939031
### DELETE FROM `studip`.`files_search_index`
### WHERE
### @1='cb866f5c9f049fe6ce7bca65761aae70'
### @2='dozent'
### @3=0.953527
### DELETE FROM `studip`.`files_search_index`
### WHERE
### @1='cb866f5c9f049fe6ce7bca65761aae70'
### @2='Logistics Management (Vorlesung)'
### @3=0.85378
# at 400124893
#240807 10:03:52 server id 43810 end_log_pos 400124924 CRC32 0x9f3edfda Xid = 27543716
COMMIT/*!*/;
# at 400124924
However, the data which the DELETE fails to find and delete is there, when you do a manual lookup:
mysql> select * from files_search_index where file_ref_id='cb866f5c9f049fe6ce7bca65761aae70';
+----------------------------------+------------------------------------+-----------+
| file_ref_id | text | relevance |
+----------------------------------+------------------------------------+-----------+
| cb866f5c9f049fe6ce7bca65761aae70 | 1.0 Einführung.mp4 | 0.992793 |
| cb866f5c9f049fe6ce7bca65761aae70 | | 0.939031 |
| cb866f5c9f049fe6ce7bca65761aae70 | dozent | 0.953527 |
| cb866f5c9f049fe6ce7bca65761aae70 | Logistics Management (Vorlesung) | 0.85378 |
+----------------------------------+------------------------------------+-----------+
4 rows in set (0.00 sec)
If we delete this record manually, we run into a similar problem later, always in the same table, files_search_index.
Any ideas?
