MySQL Bugs: #94053: Replication failed trying to update foreign keys for delete statement

Bug #94053	Replication failed trying to update foreign keys for delete statement
Submitted:	25 Jan 2019 4:00	Modified:	7 Mar 2019 4:04
Reporter:	monty solomon	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.7.23	OS:	CentOS
Assigned to:	MySQL Verification Team	CPU Architecture:	Any

Description:
RBR replication failed on both slaves with the following error

Could not execute Delete_rows event on table CustomerServices.services; Cannot delete or update a parent row: a foreign key constraint fails (`CustomerServices`.`current_owners`, CONSTRAINT `fk_current_owner_service_id` FOREIGN KEY (`service_id`) REFERENCES `services` (`id`)), Error_code: 1451; handler error HA_ERR_ROW_IS_REFERENCED; the event's master log vt-0416819500-bin.137743, end_log_pos 845144

We created a new slave from backup and started replication and it failed with the same error.

How to repeat:
A DELETE statement was executed on master but it failed when executed on the slaves.

Contents of my.cnf file

[mysqld]
auto_increment_increment = 1
auto_increment_offset = 1
back_log = 2048
basedir = /usr
bind_address = 0.0.0.0
binlog-format = ROW
binlog_cache_size = 262144
character-set-server = utf8mb4
collation-server = utf8mb4_general_ci
connect_timeout = 30
default-storage-engine = InnoDB
enforce-gtid-consistency = 1
event-scheduler = OFF
expire_logs_days = 2
general-log = 1
gtid_mode = ON
innodb_autoinc_lock_mode = 1
innodb_buffer_pool_dump_at_shutdown = 1
innodb_buffer_pool_dump_pct = 100
innodb_buffer_pool_instances = 1
innodb_buffer_pool_load_at_startup = 1
innodb_buffer_pool_size = 393216000
innodb_data_file_path = ibdata1:10M:autoextend
innodb_file_format = Barracuda
innodb_file_format_check = 1
innodb_file_per_table = 1
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_io_capacity = 200
innodb_io_capacity_max = 2000
innodb_large_prefix = 1
innodb_lock_wait_timeout = 50
innodb_log_buffer_size = 1048576
innodb_log_file_size = 2047M
innodb_log_files_in_group = 2
innodb_monitor_enable = all
innodb_open_files = 300
innodb_purge_threads = 4
innodb_stats_on_metadata = 0
innodb_stats_transient_sample_pages = 20
innodb_status_file = false
innodb_status_output = 0
innodb_status_output_locks = 0
innodb_strict_mode = 1
innodb_thread_concurrency = 0
interactive_timeout = 1000
join_buffer_size = 134217
key_buffer_size = 67108864
log-queries-not-using-indexes = OFF
log_bin_trust_function_creators = 1
log_error_verbosity = 3
log_slave_updates = 1
log_slow_slave_statements = 1
long_query_time = 0.1
loose-log_slow_verbosity = full
loose-slow_query_log_use_global_control = long_query_time,log_slow_verbosity
loose-userstat = 1
loose-audit-log = OFF
master-verify-checksum = 1
max_allowed_packet = 67108864
max_binlog_size = 1G
max_connect_errors = 1000000
max_connections = 235
max_execution_time = 300000
max_heap_table_size = 67108864
max_user_connections = 215
myisam-recover-options = FORCE,BACKUP
myisam_sort_buffer_size = 8M
net_write_timeout = 60
open-files-limit = 65535
performance-schema-instrument = memory/%=COUNTED
performance_schema = 1
query_cache_limit = 0
query_cache_size = 0
query_cache_type = 0
read_buffer_size = 134217
read-only = 1
read_rnd_buffer_size = 268435
relay-log-info-repository = TABLE
relay_log_recovery = 1
secure-file-priv = /vt/tmp
skip-external-locking = 1
skip-networking = 0
skip-slave-start = 1
slave-sql-verify-checksum = 1
slave_compressed_protocol = 0
slave_net_timeout = 30
slow-query-log = 1
sort_buffer_size = 262144
sql_mode = STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_AUTO_VALUE_ON_ZERO,NO_ENGINE_SUBSTITUTION,NO_ZERO_DATE,NO_ZERO_IN_DATE,ONLY_FULL_GROUP_BY
ssl = 1
ssl-ca = /secrets/vault/mysql-client.ca
ssl-cert = /secrets/vault/mysql-server.cert
ssl-key = /secrets/vault/mysql-server.key
sync_binlog = 0
sync_master_info = 10000
sync_relay_log = 10000
sync_relay_log_info = 10000
table_definition_cache = 2048
table_open_cache = 2048
thread_stack = 205520
thread_cache_size = 48
tmp_table_size = 33554432
transaction-isolation = READ-COMMITTED
plugin-load = rpl_semi_sync_master=semisync_master.so;rpl_semi_sync_slave=semisync_slave.so

rpl_semi_sync_master_timeout = 1000000000000000000
rpl_semi_sync_master_wait_no_slave = 1

general_log_file = /vt/tablet/logs/general.log
slow-query-log-file = /vt/tablet/logs/slow.log
socket = /vt/tablet/mysql.sock                                                                                                                               

tmpdir = /vt/tablet/tmp
slave_load_tmpdir = /vt/tablet/tmp
server-id = 1588247908
log-bin = /vt/tablet/bin-logs/vt-0416819500-bin
datadir = /vt/tablet/data
innodb_log_group_home_dir = /vt/tablet/innodb/logs
innodb_data_home_dir = /vt/tablet/innodb/data
log-bin-index = /vt/tablet/bin-logs/vt-0416819500-bin.index
master-info-file = /vt/tablet/master.info
pid-file = /vt/tablet/mysql.pid
port = 3306
relay-log = /vt/tablet/relay-logs/vt-0416819500-relay-bin
relay-log-index =  /vt/tablet/relay-logs/vt-0416819500-relay-bin.index
relay-log-info-file =  /vt/tablet/relay-logs/relay-log.info

report-host = 172.18.24.118

Hi Monty,

I spent a while on this report but I can't reproduce this. I do am using 5.7.25 but it should not make a difference. I am using table descriptions you sent I simulate insert of random data, delete data, nothing breaks replication.

Can you extract the insert/delete combination from your actual unredacted log that will reproduce this behavior, as I can't manually recreate it.

Thanks
Bogdan