LP #1722442: Could not execute Write/Delete_rows event,Node consistency compromized, aborting
General
Escalation
General
Escalation
Description
Environment
None
relates to
Smart Checklist
Activity
Show:
Lalit Choudhary September 4, 2018 at 2:12 PM
Hello Sampson,
Thank you for the report.
The issue looks similar to https://jira.percona.com/browse/PXC-935
At this issue is fixed in 5.7.19, please do upgrade the latest version.
lpjirasync January 14, 2018 at 7:16 PM
**Comment from Launchpad by: Krunal Bauskar on: 12-10-2017 05:22:27
Normally an error like that suggest some inconsitency with cluster node.
This can happen if there is local trx that is not replicated.
If above is not the case wondering if you can still reproduce it at will and can share the steps for us to investigate it locally.
Done
Details
Details
Assignee
Lalit Choudhary
Lalit ChoudharyReporter
lpjirasync
lpjirasync(Deactivated)Labels
Fix versions
Priority
LowSmart Checklist
Open Smart Checklist
Smart Checklist
Open Smart Checklist
Created January 14, 2018 at 7:16 PM
Updated December 25, 2018 at 5:25 PM
Resolved September 4, 2018 at 2:14 PM
**Reported in Launchpad by sampson,li last update 12-10-2017 05:22:28
OS: Red Hat Enterprise Linux Server release 7.2 (Maipo)
Software: Percona XtraDB Cluster 5.7.18-29.20
Cluster: we have three nodes==>node85 for write;node86 and node87 for read only.
there are a pressure test at that time,table cart & shopcart had many insert & delete operation.
The node86(read node) aborted at 2017-09-28T10:00:11 and node85(write node) aborted at 2017-09-28T10:28:49.
we start these nodes by .../bin/mysqld later,the cluster recovery.
error log for node86
017-09-28T10:00:11.095242Z 2 [ERROR] Slave SQL: Could not execute Write_rows event on table shopcart.cart; Duplicate entry '2005485142-1-20064' for key 'PRIMARY', Error_code: 1062; handler e
rror HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 207, Error_code: 1062
2017-09-28T10:00:11.095285Z 2 [Warning] WSREP: RBR event 3 Write_rows apply warning: 121, 163162
2017-09-28T10:00:11.095823Z 2 [Warning] WSREP: Failed to apply app buffer: seqno: 163162, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 2th time
2017-09-28T10:00:11.095999Z 2 [ERROR] Slave SQL: Could not execute Write_rows event on table shopcart.cart; Duplicate entry '2005485142-1-20064' for key 'PRIMARY', Error_code: 1062; handler e
rror HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 207, Error_code: 1062
2017-09-28T10:00:11.096012Z 2 [Warning] WSREP: RBR event 3 Write_rows apply warning: 121, 163162
2017-09-28T10:00:11.096301Z 2 [Warning] WSREP: Failed to apply app buffer: seqno: 163162, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 3th time
2017-09-28T10:00:11.096459Z 2 [ERROR] Slave SQL: Could not execute Write_rows event on table shopcart.cart; Duplicate entry '2005485142-1-20064' for key 'PRIMARY', Error_code: 1062; handler e
rror HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 207, Error_code: 1062
2017-09-28T10:00:11.096471Z 2 [Warning] WSREP: RBR event 3 Write_rows apply warning: 121, 163162
2017-09-28T10:00:11.096984Z 2 [Warning] WSREP: Failed to apply app buffer: seqno: 163162, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 4th time
2017-09-28T10:00:11.097163Z 2 [ERROR] Slave SQL: Could not execute Write_rows event on table shopcart.cart; Duplicate entry '2005485142-1-20064' for key 'PRIMARY', Error_code: 1062; handler e
rror HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 207, Error_code: 1062
2017-09-28T10:00:11.097175Z 2 [Warning] WSREP: RBR event 3 Write_rows apply warning: 121, 163162
2017-09-28T10:00:11.097824Z 2 [ERROR] WSREP: Failed to apply trx: source: 59a4e002-921c-11e7-b4f7-6bbb8bd5aa20 version: 3 local: 0 state: APPLYING flags: 1 conn_id: 5434 trx_id: 3319435 seqno
s (l: 165942, g: 163162, s: 163161, d: 163027, ts: 13749441138646984)
2017-09-28T10:00:11.097838Z 2 [ERROR] WSREP: Failed to apply trx 163162 4 times
2017-09-28T10:00:11.097845Z 2 [ERROR] WSREP: Node consistency compromized, aborting...
error log for node85
2017-09-28T10:28:49.729606Z 3 [ERROR] Slave SQL: Could not execute Delete_rows event on table shopcart.shopcart; Can't find record in 'shopcart', Error_code: 1032; handler error HA_ERR_KEY_NO
T_FOUND; the event's master log FIRST, end_log_pos 497, Error_code: 1032
2017-09-28T10:28:49.729649Z 3 [Warning] WSREP: RBR event 3 Delete_rows apply warning: 120, 456024
2017-09-28T10:28:49.730282Z 3 [Warning] WSREP: Failed to apply app buffer: seqno: 456024, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 2th time
2017-09-28T10:28:49.730514Z 3 [ERROR] Slave SQL: Could not execute Delete_rows event on table shopcart.shopcart; Can't find record in 'shopcart', Error_code: 1032; handler error HA_ERR_KEY_NO
T_FOUND; the event's master log FIRST, end_log_pos 497, Error_code: 1032
2017-09-28T10:28:49.730535Z 3 [Warning] WSREP: RBR event 3 Delete_rows apply warning: 120, 456024
2017-09-28T10:28:49.730883Z 3 [Warning] WSREP: Failed to apply app buffer: seqno: 456024, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 3th time
2017-09-28T10:28:49.731080Z 3 [ERROR] Slave SQL: Could not execute Delete_rows event on table shopcart.shopcart; Can't find record in 'shopcart', Error_code: 1032; handler error HA_ERR_KEY_NO
T_FOUND; the event's master log FIRST, end_log_pos 497, Error_code: 1032
2017-09-28T10:28:49.731093Z 3 [Warning] WSREP: RBR event 3 Delete_rows apply warning: 120, 456024
2017-09-28T10:28:49.731619Z 3 [Warning] WSREP: Failed to apply app buffer: seqno: 456024, status: 1
at galera/src/trx_handle.cpp:apply():351
Retrying 4th time
2017-09-28T10:28:49.731786Z 3 [ERROR] Slave SQL: Could not execute Delete_rows event on table shopcart.shopcart; Can't find record in 'shopcart', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 497, Error_code: 1032
2017-09-28T10:28:49.731816Z 3 [Warning] WSREP: RBR event 3 Delete_rows apply warning: 120, 456024
2017-09-28T10:28:49.733146Z 3 [ERROR] WSREP: Failed to apply trx: source: fe22378c-921d-11e7-a0b5-9b2d6f4fa17c version: 3 local: 0 state: APPLYING flags: 1 conn_id: 437 trx_id: 11638955 seqnos (l: 463391, g: 456024, s: 456023, d: 455947, ts: 13751156325301172)
2017-09-28T10:28:49.733160Z 3 [ERROR] WSREP: Failed to apply trx 456024 4 times
2017-09-28T10:28:49.733168Z 3 [ERROR] WSREP: Node consistency compromized, aborting...
here are the two tables:
system@localhost 11:40: [shopcart]> show create table cart\G
*************************** 1. row ***************************
Table: cart
Create Table: CREATE TABLE `cart` (
`sku_id` int(10) unsigned NOT NULL,
`quantity` smallint(5) unsigned NOT NULL,
`user_id` bigint(10) unsigned NOT NULL,
`channel` varchar(100) DEFAULT NULL,
`type` tinyint(3) unsigned NOT NULL,
`checked` varchar(10) NOT NULL DEFAULT '1' COMMENT '1,0-',
`create_time` timestamp NULL DEFAULT NULL ON UPDATE CURRENT_TIMESTAMP,
`last_update` timestamp NULL DEFAULT NULL ON UPDATE CURRENT_TIMESTAMP,
PRIMARY KEY (`user_id`,`type`,`sku_id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)
system@localhost 11:40: [shopcart]> show create table shopcart\G
*************************** 1. row ***************************
Table: shopcart
Create Table: CREATE TABLE `shopcart` (
`id` varchar(50) NOT NULL,
`user_id` bigint(20) NOT NULL COMMENT 'ID',
`type` tinyint(4) NOT NULL COMMENT ' 1-- 2-- 3--',
`order_id` varchar(50) DEFAULT NULL COMMENT '',
`total_amount` decimal(20,2) NOT NULL DEFAULT '0.00' COMMENT '',
`total_adjustment` decimal(20,2) NOT NULL DEFAULT '0.00' COMMENT '',
`shipping` decimal(20,2) NOT NULL DEFAULT '0.00' COMMENT '',
`shipping_adjustment` decimal(20,2) NOT NULL DEFAULT '0.00' COMMENT '',
`pay_method` varchar(50) DEFAULT NULL COMMENT ' ONLINE_PAY COD',
`channel` varchar(50) DEFAULT NULL COMMENT ' PCMOBILEAPPWECHATO2O',
`warp_part` varchar(64) DEFAULT NULL COMMENT '',
`wrap_price` decimal(20,2) DEFAULT NULL COMMENT '',
`comments` text COMMENT '',
`gift_comments` varchar(50) DEFAULT NULL COMMENT '',
`address_id` bigint(20) DEFAULT NULL COMMENT '',
`invoice_type` varchar(50) DEFAULT '' COMMENT '',
`delivery_info` varchar(500) DEFAULT NULL COMMENT '',
`PAYMENT_CODE` varchar(32) DEFAULT NULL COMMENT '',
`BANK_CODE` varchar(19) DEFAULT NULL COMMENT '',
`create_time` timestamp NOT NULL COMMENT '',
`update_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '',
`create_user` varchar(50) NOT NULL,
`update_user` varchar(50) NOT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COMMENT=''
1 row in set (0.00 sec)
my.cnf:
node85:
root@dpsvstadbs02 11:49:49:~$ cat /etc/my.cnf
#
##mysql configure file my.cnf
#
[client]
port = 3306
socket = /tmp/mysql.sock
default-character-set = utf8mb4
[mysql]
prompt="\u@\h \R:\m:\s [\d]> "
no-auto-rehash
default-character-set = utf8mb4
[mysqld]
user = mysql
port = 3306
basedir = /usr/local/mysql
datadir = /docker/mysql/mysql_3306/data
socket = /tmp/mysql.sock
pid-file = dpppnewdbs04.sephora.cn.pid
character-set-server = utf8mb4
skip_name_resolve = 1
log_bin_trust_function_creators=1
lower_case_table_names = 1
open_files_limit = 65535
back_log = 1024
server-id = 853306
#binlog
log-bin = /docker/mysql/mysql_3306/logs/binlog/mysql-bin
binlog_format = row
sync_binlog = 1
binlog_cache_size = 512M
expire_logs_days = 3
max_binlog_cache_size = 2G
max_binlog_size = 1G
master_info_repository = TABLE
relay_log_info_repository = TABLE
gtid_mode = on
enforce_gtid_consistency = 1
log_slave_updates
#slow & error log
slow_query_log = 1
slow_query_log_file = /docker/mysql/mysql_3306/logs/slow.log
log-error = /docker/mysql/mysql_3306/logs/error.log
long_query_time = 0.1
#general_log=on
#general_log_file=/docker/mysql/mysql_3306/logs/general_85.log
max_connections = 10000
max_connect_errors = 1000000
table_open_cache = 128
table_definition_cache = 128
table_open_cache_instances = 64
thread_stack = 512K
external-locking = FALSE
max_allowed_packet = 64M
sort_buffer_size = 8M
join_buffer_size = 8M
thread_cache_size = 1500
query_cache_size = 0
query_cache_type = 0
interactive_timeout = 600
wait_timeout = 600
tmp_table_size = 64M
max_heap_table_size = 32M
relay_log_recovery = 1
relay-log-purge = 1
key_buffer_size = 32M
read_buffer_size = 8M
read_rnd_buffer_size = 4M
bulk_insert_buffer_size = 64M
myisam_sort_buffer_size = 128M
myisam_max_sort_file_size = 10G
myisam_repair_threads = 1
lock_wait_timeout = 3600
explicit_defaults_for_timestamp = 1
transaction_isolation = READ-COMMITTED
#innodb
default_storage_engine=Innodb
innodb_thread_concurrency = 0
innodb_sync_spin_loops = 100
innodb_spin_wait_delay = 30
#innodb_additional_mem_pool_size = 16M
innodb_buffer_pool_size = 20480M
innodb_buffer_pool_instances = 8
innodb_buffer_pool_load_at_startup = 1
innodb_buffer_pool_dump_at_shutdown = 1
innodb_data_file_path = ibdata1:1G:autoextend
innodb_flush_log_at_trx_commit = 1
innodb_log_buffer_size = 32M
innodb_log_file_size = 2G
innodb_log_files_in_group = 2
innodb_max_undo_log_size = 4G
innodb_io_capacity = 4000
innodb_io_capacity_max = 8000
innodb_write_io_threads = 8
innodb_read_io_threads = 16
innodb_purge_threads = 4
innodb_page_cleaners = 4
innodb_open_files = 65535
innodb_max_dirty_pages_pct = 50
innodb_flush_method = O_DIRECT
innodb_lru_scan_depth = 4000
innodb_checksum_algorithm = crc32
#innodb_file_format = Barracuda
#innodb_file_format_max = Barracuda
innodb_lock_wait_timeout = 10
innodb_rollback_on_timeout = 1
innodb_print_all_deadlocks = 1
innodb_file_per_table = 1
innodb_online_alter_log_max_size = 4G
internal_tmp_disk_storage_engine = InnoDB
innodb_stats_on_metadata = 0
innodb_status_file = 1
: innodb_status_output & innodb_status_output_locks , log-error
innodb_status_output = 0
innodb_status_output_locks = 0
#performance_schema
#performance_schema = 1
#performance_schema_instrument = '%=on'
#innodb monitor
#innodb_monitor_enable="module_innodb"
#innodb_monitor_enable="module_server"
#innodb_monitor_enable="module_dml"
#innodb_monitor_enable="module_ddl"
#innodb_monitor_enable="module_trx"
#innodb_monitor_enable="module_os"
#innodb_monitor_enable="module_purge"
#innodb_monitor_enable="module_log"
#innodb_monitor_enable="module_lock"
#innodb_monitor_enable="module_buffer"
#innodb_monitor_enable="module_index"
#innodb_monitor_enable="module_ibuf_system"
#innodb_monitor_enable="module_buffer_page"
#innodb_monitor_enable="module_adaptive_hash"
#pxc
wsrep_provider = /usr/local/mysql/lib/libgalera_smm.so
wsrep_cluster_address = gcomm://10.157.24.85,10.157.24.86,10.157.24.87
wsrep_node_name = node85
wsrep_node_address = 10.157.24.85
wsrep_cluster_name = pxc_stage
wsrep_sst_auth = sst:sst123
wsrep_sst_method = xtrabackup-v2
wsrep_slave_threads = 8
pxc_strict_mode = ENFORCING
innodb_autoinc_lock_mode = 2
wsrep_provider_options = "gcache.size=4G"
[mysqldump]
quick
max_allowed_packet = 1024M
node86
root@dpsvstadbs03 11:50:22:~$ cat /etc/my.cnf
#
##mysql configure file my.cnf
#
[client]
port = 3306
socket = /tmp/mysql.sock
default-character-set = utf8mb4
[mysql]
prompt="\u@\h \R:\m:\s [\d]> "
no-auto-rehash
default-character-set = utf8mb4
[mysqld]
user = mysql
port = 3306
basedir = /usr/local/mysql
datadir = /docker/mysql/mysql_3306/data
socket = /tmp/mysql.sock
pid-file = dpppnewdbs04.sephora.cn.pid
character-set-server = utf8mb4
skip_name_resolve = 1
log_bin_trust_function_creators=1
lower_case_table_names = 1
open_files_limit = 65535
back_log = 1024
server-id = 863306
#binlog
log-bin = /docker/mysql/mysql_3306/logs/binlog/mysql-bin
binlog_format = row
sync_binlog = 1
binlog_cache_size = 512M
expire_logs_days = 7
max_binlog_cache_size = 2G
max_binlog_size = 1G
master_info_repository = TABLE
relay_log_info_repository = TABLE
gtid_mode = on
enforce_gtid_consistency = 1
log_slave_updates
#slow & error log
slow_query_log = 1
slow_query_log_file = /docker/mysql/mysql_3306/logs/slow.log
log-error = /docker/mysql/mysql_3306/logs/error.log
long_query_time = 0.1
#general_log=on
#general_log_file=/docker/mysql/mysql_3306/logs/general_86.log
max_connections = 10000
max_connect_errors = 1000000
table_open_cache = 128
table_definition_cache = 128
table_open_cache_instances = 64
thread_stack = 512K
external-locking = FALSE
max_allowed_packet = 64M
sort_buffer_size = 8M
join_buffer_size = 8M
thread_cache_size = 1500
query_cache_size = 0
query_cache_type = 0
interactive_timeout = 600
wait_timeout = 600
tmp_table_size = 64M
max_heap_table_size = 32M
relay_log_recovery = 1
relay-log-purge = 1
key_buffer_size = 32M
read_buffer_size = 8M
read_rnd_buffer_size = 4M
bulk_insert_buffer_size = 64M
myisam_sort_buffer_size = 128M
myisam_max_sort_file_size = 10G
myisam_repair_threads = 1
lock_wait_timeout = 3600
explicit_defaults_for_timestamp = 1
transaction_isolation = READ-COMMITTED
#innodb
default_storage_engine=Innodb
innodb_thread_concurrency = 0
innodb_sync_spin_loops = 100
innodb_spin_wait_delay = 30
#innodb_additional_mem_pool_size = 16M
innodb_buffer_pool_size = 20480M
innodb_buffer_pool_instances = 8
innodb_buffer_pool_load_at_startup = 1
innodb_buffer_pool_dump_at_shutdown = 1
innodb_data_file_path = ibdata1:1G:autoextend
innodb_flush_log_at_trx_commit = 1
innodb_log_buffer_size = 32M
innodb_log_file_size = 2G
innodb_log_files_in_group = 2
innodb_max_undo_log_size = 4G
innodb_io_capacity = 4000
innodb_io_capacity_max = 8000
innodb_write_io_threads = 8
innodb_read_io_threads = 16
innodb_purge_threads = 4
innodb_page_cleaners = 4
innodb_open_files = 65535
innodb_max_dirty_pages_pct = 50
innodb_flush_method = O_DIRECT
innodb_lru_scan_depth = 4000
innodb_checksum_algorithm = crc32
#innodb_file_format = Barracuda
#innodb_file_format_max = Barracuda
innodb_lock_wait_timeout = 10
innodb_rollback_on_timeout = 1
innodb_print_all_deadlocks = 1
innodb_file_per_table = 1
innodb_online_alter_log_max_size = 4G
internal_tmp_disk_storage_engine = InnoDB
innodb_stats_on_metadata = 0
innodb_status_file = 1
: innodb_status_output & innodb_status_output_locks , log-error
innodb_status_output = 0
innodb_status_output_locks = 0
#performance_schema
#performance_schema = 1
#performance_schema_instrument = '%=on'
#innodb monitor
#innodb_monitor_enable="module_innodb"
#innodb_monitor_enable="module_server"
#innodb_monitor_enable="module_dml"
#innodb_monitor_enable="module_ddl"
#innodb_monitor_enable="module_trx"
#innodb_monitor_enable="module_os"
#innodb_monitor_enable="module_purge"
#innodb_monitor_enable="module_log"
#innodb_monitor_enable="module_lock"
#innodb_monitor_enable="module_buffer"
#innodb_monitor_enable="module_index"
#innodb_monitor_enable="module_ibuf_system"
#innodb_monitor_enable="module_buffer_page"
#innodb_monitor_enable="module_adaptive_hash"
#pxc
wsrep_provider = /usr/local/mysql/lib/libgalera_smm.so
wsrep_cluster_address = gcomm://10.157.24.85,10.157.24.86,10.157.24.87
wsrep_node_name = node86
wsrep_node_address = 10.157.24.86
wsrep_cluster_name = pxc_stage
wsrep_sst_auth = sst:sst123
wsrep_sst_method = xtrabackup-v2
wsrep_slave_threads = 8
pxc_strict_mode = ENFORCING
innodb_autoinc_lock_mode = 2
wsrep_provider_options = "gcache.size=4G"
[mysqldump]
quick
max_allowed_packet = 1024M