Arbitrary disruption of replication Percona Server for MySQL 8.0.32

MySQL & MariaDB Percona Server for MySQL 8.0
1

Hello.

I use a self-compiled Percona Server for Mysql for ARM architecture.

Operating system: Debian 11 (bullseye)
Architecture: aarch64
EC2 instance type: m7g.4xlarge

Percona Server version:

mysql  Ver 8.0.32-24 for Linux on aarch64 (Percona Server (GPL), Release '24', Revision 'e5c6e9d2')

Connection id:		2642214
Current database:
Current user:		root@localhost
SSL:			Not in use
Current pager:		stdout
Using outfile:		''
Using delimiter:	;
Server version:		8.0.32-24 Percona Server (GPL), Release '24', Revision 'e5c6e9d2'
Protocol version:	10
Connection:		Localhost via UNIX socket
Server characterset:	utf8mb4
Db     characterset:	utf8mb4
Client characterset:	utf8mb4
Conn.  characterset:	utf8mb4
UNIX socket:		/var/run/mysqld/mysqld.sock
Binary data as:		Hexadecimal
Uptime:			7 days 4 hours 22 min 22 sec

Threads: 50  Questions: 491141528  Slow queries: 266  Opens: 55761503  Flush tables: 3  Open tables: 384  Queries per second avg: 791.471

Configuration my.cnf:

my.cnf 
[client]
port                                = 3306
socket                              = /var/run/mysqld/mysqld.sock
default-character-set               = utf8mb4

[mysqld_safe]
open-files-limit                    = 32384
socket                              = /var/run/mysqld/mysqld.sock
nice                                = 0

[mysqld]
open-files-limit                    = 32384
log_error_verbosity                 = 2
back_log                            = 1500
performance_schema                  = ON
explicit_defaults_for_timestamp     = TRUE
secure-file-priv                    = ""
sql_mode                            = NO_ENGINE_SUBSTITUTION,STRICT_ALL_TABLES,NO_ZERO_DATE,NO_ZERO_IN_DATE,ERROR_FOR_DIVISION_BY_ZERO

character-set-server                = utf8mb4
collation-server                    = utf8mb4_unicode_ci
skip-character-set-client-handshake
default_authentication_plugin       = mysql_native_password

port                                = 3306
pid-file                            = /var/run/mysqld/mysqld.pid
socket                              = /var/run/mysqld/mysqld.sock
user                                = mysql
basedir                             = /usr
datadir                             = /home/db/mysql
tmpdir                              = /home/db/tmp
skip_external_locking               = ON
skip_name_resolve                   = ON

bind_address                        = 0.0.0.0

thread_stack                        = 256K
thread_cache_size                   = 512

max_allowed_packet                  = 32M
max_connections                     = 10000
max_connect_errors                  = 10000
sync_binlog                         = 0

innodb_buffer_pool_size             = 44G
innodb_file_per_table               = 1
innodb_flush_method                 = O_DIRECT
innodb_flush_log_at_trx_commit      = 0
innodb_autoinc_lock_mode            = 2
innodb_flush_neighbors              = 0
innodb_redo_log_capacity            = 1G
innodb_log_group_home_dir           = /home/db/mysql
innodb_buffer_pool_dump_at_shutdown = ON
innodb_buffer_pool_load_at_startup  = ON
innodb_io_capacity                  = 2000
innodb_io_capacity_max              = 4000

slow_query_log                      = 1
slow-query-log-file                 = /home/db/mysql/slow.log
log_error                           = /home/db/mysql/mysql.err
long_query_time                     = 1

server_id                           = 4221
log_replica_updates                 = ON
binlog_format                       = ROW
log_bin                             = binlog
binlog_expire_logs_seconds          = 86400
max_binlog_size                     = 500M

replicate-wild-do-table             = foo%.%
replicate-wild-do-table             = bar%.%
replicate-wild-do-table             = baz%.%
skip-replica-start                  = ON
relay_log_recovery                  = ON

gtid_mode                           = ON
enforce_gtid_consistency            = ON

table_open_cache_instances          = 64
table_open_cache                    = 5000

tmp-table-size                      = 128M   
max-heap-table-size                 = 128M   

wait_timeout                        = 86400

[mysqldump]
quick
quote-names
max_allowed_packet                  = 16M

[mysql]
default-character-set               = utf8mb4

Almost every 1-2 days I get the following replication failure error:

2023-11-22T15:58:24.113662Z 1165057 [ERROR] [MY-010596] [Repl] Error reading relay log event for channel '': corrupted data in log event
2023-11-22T15:58:24.113706Z 1165057 [ERROR] [MY-013121] [Repl] Replica SQL for channel '': Relay log read failure: Could not parse relay log event entry. The possible reasons are: the source's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the replica's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, the server was unable to fetch a keyring key required to open an encrypted relay log file, or a bug in the source's or replica's MySQL code. If you want to check the source's binary log or replica's relay log, you will be able to know their names by issuing 'SHOW REPLICA STATUS' on this replica. Error_code: MY-013121
2023-11-22T15:58:24.113789Z 1165057 [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 'binlog.000236' position 260832362

After executing the START REPLICA command, replication continues.

What was done?

  • Checked binlog and relaylog for corruption or errors using mysqlbinlog. All files are intact. No problems were found.
  • Tried decreasing the replica_parallel_workers parameter from the default value of 4 to 1. Also increasing it to 8. It didn’t work.

I have 7 other databases with the same settings and they work fine.

I would appreciate any ideas on finding possible causes for this behavior.

2

Hi schiller,

Do you have any other replica (from the same primary) that did NOT fail?
If you execute “start replica” does it fail?
Write down the replication coords and remove replication and start replicating again from the last known replication coords. Does it work?

What values do you have for innodb_flush_logs_at_trx_commit and sync_binlog ? I.e are they 1 or you relaxed them?
Did any of the servers (primary or replica) crash or restarted abruptly?

Last. How did you check if the binlog is not corrupted with mysqlbinlog?

Regards

3

Hi @CTutte,

Thank you for paying attention to my problem.

Do you have any other replica (from the same primary) that did NOT fail?

No, I don’t have other replicas from the source. I using one source and a single replica.
My replication scheme looks like this: Source → Replica

If you execute “start replica” does it fail?

After I start the replication with the START REPLICA; command. Replication starts working, and in some cases, it can work without interruption for several days. But sometimes it can stop after a few minutes.

Write down the replication coords and remove replication and start replicating again from the last known replication coords. Does it work?

It’s been about a month since I started using transaction-based replication using Global Transaction Identifiers (GTIDs), so I no longer need to know the position of the binary log to start replication.
But I have already tried to recreate the replication several times and it did not give any visible result. An example of the commands I use for this:

# on the Replica
STOP REPLICA;
RESET REPLICA ALL;

CHANGE REPLICATION SOURCE TO SOURCE_HOST = 'x.x.x.x', \
SOURCE_PORT = 3306, SOURCE_USER = 'replica', \
SOURCE_PASSWORD = '<password>', SOURCE_AUTO_POSITION = 1;

START REPLICA;

What values do you have for innodb_flush_logs_at_trx_commit and sync_binlog ? I.e are they 1 or you relaxed them?

My values on the source and replica are the same:

mysql> SHOW VARIABLES LIKE 'innodb_flush_log_at_trx_commit';
+--------------------------------+-------+
| Variable_name                  | Value |
+--------------------------------+-------+
| innodb_flush_log_at_trx_commit | 0     |
+--------------------------------+-------+

mysql> SHOW VARIABLES LIKE 'sync_binlog';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| sync_binlog   | 0     |
+---------------+-------+

These settings affect the performance of the disk subsystem, so these settings are configured to improve performance. I understand that this reduces reliability.

Did any of the servers (primary or replica) crash or restarted abruptly?

There was a failure sometime before the problems with stopping replication started, there was a failure at the source. But after that, the database was rebuilt from a backup copy, and the ec2 instance type was changed to a more powerful one.

Last. How did you check if the binlog is not corrupted with mysqlbinlog?

I checked the binlog from the source and the relaylog from the replica by running the mysqldump utility. There were no errors in the logs. Also, the journal entry and global transaction identifiers were the same. Perhaps you could give some advice on what to pay attention to?

Additionally, every time replication breaks I see the next, the Replica_SQL_Running: No

mysql> SHOW REPLICA STATUS\G
          . . .
       Replica_IO_Running: Yes
      Replica_SQL_Running: No
4

Hi again!

What values do you have for innodb_flush_logs_at_trx_commit and sync_binlog ? I.e are they 1 or you relaxed them?

What are the values of the above? I.e if you set a value different than one then you are relaxing durability for improved performance but in case of issues the binlog can be corrupted.

I checked the binlog from the source and the relaylog from the replica by running the mysqldump utility. There were no errors in the logs. Also, the journal entry and global transaction identifiers were the same. Perhaps you could give some advice on what to pay attention to?

The mysqlbinlog utility will decode the binlog but won’t tell you if there is an error.
It will decode the hex charaters into human readable strings. If you check the last part of the output you should verify that there is no half written command.
As an example this is the latter snippet from a mysqlbinlog output from a test instance:

at 731

#231127 13:04:59 server id 1 end_log_pos 779 CRC32 0x97a4283e Table_map: test.t1 mapped to number 93

has_generated_invisible_primary_key=0

at 779

#231127 13:04:59 server id 1 end_log_pos 819 CRC32 0xd9f29127 Write_rows: table id 93 flags: STMT_END_F

INSERT INTO test.t1

SET

@1=1

at 819

#231127 13:04:59 server id 1 end_log_pos 850 CRC32 0xb6a1f9bc Xid = 16
COMMIT/!/;
SET @@SESSION.GTID_NEXT= ‘AUTOMATIC’ /* added by mysqlbinlog / /!*/;
DELIMITER ;

End of log file

If the latter part of the binlog does not look like this then it’s likely corrupt.

If the replica complains the binlog is corrupt then likely it is. Maybe it’s the binlog on the source or maybe the relay log on the replica so you should check both.

Regards

5

@schiller Did you figure out the issue?

I’m seeing the same thing, oddly, on an RDS instance (mysql community edition 8.0.32) with sync_binlog=1 and innodb_flush_log_at_trx_commit=1. The commonality is that it’s on an ARM processor. (db.r7g class).

Replication starts back just fine (RDS automatically restarts it), but these errors are encountered every so often.

The error hasn’t been seen on an intel based replica, leading me to believe this may be some type of bug in the ARM version of MySQL 8.0.32 that persists in the percona variant of the same minor version.

I’m waiting for the next error so that I can look at the binlog and see what statement was executing to find out of there’s anything odd about the running statement. One thing we did verify is that there was no long running query which may have triggered innodb_lock_wait_timeout.

I’m curious if you analyzed your binlog with mysqlbinlog -vvv and looked at statements executing before and at the same log position and found anything interesting about the statement. This may be a good opportunity to file a bug for ARM architecture.