Tables Not Synced

[elkhedewy]

Hello,

I’ve database name “sms” and three cluster nodes version 8.0
The sms row become out of sync…Look at the rows number in the attached pictures between 3 nodes.
Node 1:

Node 2:

Node 3:

Node1 Log:

/var/lib/mysql/innobackup.backup.log:Allocated tablespace ID 542 for sms/sms, old maximum was 0
/var/lib/mysql/innobackup.backup.log:220426 20:25:19 [04] Streaming ./sms/failed_jobs.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:25:19 [01] Streaming ./sms/migrations.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:25:19 [02] Streaming ./sms/password_resets.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:25:19 [03] Streaming ./sms/sms.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:25:19 [01] Streaming ./sms/users.ibd
/var/lib/mysql/innobackup.move.log:220426 20:20:53 [01] Moving ./sms/sms.ibd to /var/lib/mysql//sms/sms.ibd
/var/lib/mysql/innobackup.move.log:220426 20:20:53 [01] Moving ./sms/users.ibd to /var/lib/mysql//sms/users.ibd
/var/lib/mysql/innobackup.move.log:220426 20:20:53 [01] Moving ./sms/migrations.ibd to /var/lib/mysql//sms/migrations.ibd
/var/lib/mysql/innobackup.move.log:220426 20:20:53 [01] Moving ./sms/failed_jobs.ibd to /var/lib/mysql//sms/failed_jobs.ibd
/var/lib/mysql/innobackup.move.log:220426 20:20:53 [01] Moving ./sms/password_resets.ibd to /var/lib/mysql//sms/password_resets.ibd
/var/lib/mysql/innobackup.prepare.log:Extending tablespace : 542 space name: sms/sms to new size: 3328 pages during recovery.
/var/lib/mysql/slow-queries.log:# Schema: sms Last_errno: 1681 Killed: 0
/var/lib/mysql/slow-queries.log:use sms;

/var/log/mysqld.log:MySQL thread id 170042, OS thread handle 139684821899008, query id 955490 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:23:40’ where id = 227781
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:23:40’ where id = 227781
/var/log/mysqld.log:MySQL thread id 175715, OS thread handle 139684821014272, query id 961229 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175719, OS thread handle 139684821014272, query id 962421 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175722, OS thread handle 139684819375872, query id 962717 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175734, OS thread handle 139684819375872, query id 963489 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175735, OS thread handle 139684821014272, query id 963547 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175755, OS thread handle 139684819375872, query id 964778 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175765, OS thread handle 139684819670784, query id 965334 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175796, OS thread handle 139684819375872, query id 966351 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175810, OS thread handle 139684819670784, query id 967358 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175831, OS thread handle 139684819375872, query id 968006 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175845, OS thread handle 139684821014272, query id 970500 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175870, OS thread handle 139684819375872, query id 971809 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175925, OS thread handle 139684819670784, query id 972955 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 175933, OS thread handle 139684819375872, query id 973231 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 170042, OS thread handle 139684821899008, query id 1000633 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:57:50’ where id = 230850
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:57:50’ where id = 230850
/var/log/mysqld.log:MySQL thread id 185246, OS thread handle 139684819375872, query id 1187235 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 185417, OS thread handle 139684819965696, query id 1196592 10.151.158.72 sms wsrep: replicating and certifying write set(-1)

Node2 Log:

/var/lib/mysql/innobackup.backup.log:Allocated tablespace ID 542 for sms/sms, old maximum was 0
/var/lib/mysql/innobackup.backup.log:220426 20:19:52 [02] Streaming ./sms/failed_jobs.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:19:52 [03] Streaming ./sms/migrations.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:19:52 [01] Streaming ./sms/password_resets.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:19:52 [04] Streaming ./sms/sms.ibd
/var/lib/mysql/innobackup.backup.log:220426 20:19:52 [03] Streaming ./sms/users.ibd
/var/lib/mysql/innobackup.move.log:220426 16:43:31 [01] Moving ./sms/sms.ibd to /var/lib/mysql//sms/sms.ibd
/var/lib/mysql/innobackup.move.log:220426 16:43:31 [01] Moving ./sms/users.ibd to /var/lib/mysql//sms/users.ibd
/var/lib/mysql/innobackup.move.log:220426 16:43:31 [01] Moving ./sms/migrations.ibd to /var/lib/mysql//sms/migrations.ibd
/var/lib/mysql/innobackup.move.log:220426 16:43:31 [01] Moving ./sms/failed_jobs.ibd to /var/lib/mysql//sms/failed_jobs.ibd
/var/lib/mysql/innobackup.move.log:220426 16:43:31 [01] Moving ./sms/password_resets.ibd to /var/lib/mysql//sms/password_resets.ibd
/var/lib/mysql/slow-queries.log:# User@Host: sms[sms] @ [10.151.158.72] Id: 156
/var/lib/mysql/slow-queries.log:# Schema: sms Last_errno: 0 Killed: 0
/var/lib/mysql/slow-queries.log:use sms;
/var/lib/mysql/slow-queries.log:insert into sms (app_id, request_ip, message, phone_number, message_tag, updated_at, created_at) values (10, ‘127.0.0.1’, 'شكرا لتبرعك ل57 بـ 50.00 جنيه مصرى مساهمتك هاتوفر الأدوية لعلاج اطفالنا المرضي ', ‘010139903054’, NULL, ‘2022-04-26 14:46:28’, ‘2022-04-26 14:46:28’);
/var/lib/mysql/slow-queries.log:# User@Host: sms[sms] @ [10.151.158.71] Id: 312
/var/lib/mysql/slow-queries.log:# Schema: sms Last_errno: 1160 Killed: 0

/var/log/mysqld.log:MySQL thread id 191428, OS thread handle 140596761970432, query id 1026835 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 191437, OS thread handle 140596765083392, query id 1027711 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 191444, OS thread handle 140596425225984, query id 1029374 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 191471, OS thread handle 140596422866688, query id 1030261 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 191532, OS thread handle 140596425225984, query id 1031471 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 185885, OS thread handle 140596764493568, query id 1032474 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:34:00’ where id = 251796
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:34:00’ where id = 251796
/var/log/mysqld.log:MySQL thread id 186026, OS thread handle 140596424636160, query id 1059847 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:54:10’ where id = 234604
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:54:10’ where id = 234604
/var/log/mysqld.log:MySQL thread id 201723, OS thread handle 140596424341248, query id 1227122 10.151.158.72 sms wsrep: replicating and certifying write set(-1)

Node3 Log:

/var/lib/mysql/innobackup.move.log:220426 20:27:14 [01] Moving ./sms/sms.ibd to /var/lib/mysql//sms/sms.ibd
/var/lib/mysql/innobackup.move.log:220426 20:27:14 [01] Moving ./sms/users.ibd to /var/lib/mysql//sms/users.ibd
/var/lib/mysql/innobackup.move.log:220426 20:27:14 [01] Moving ./sms/migrations.ibd to /var/lib/mysql//sms/migrations.ibd
/var/lib/mysql/innobackup.move.log:220426 20:27:14 [01] Moving ./sms/failed_jobs.ibd to /var/lib/mysql//sms/failed_jobs.ibd
/var/lib/mysql/innobackup.move.log:220426 20:27:14 [01] Moving ./sms/password_resets.ibd to /var/lib/mysql//sms/password_resets.ibd
/var/lib/mysql/slow-queries.log:# Schema: sms Last_errno: 1681 Killed: 0
/var/lib/mysql/slow-queries.log:use sms;
/var/lib/mysql/slow-queries.log:SELECT /*!40001 SQL_NO_CACHE */ * FROM sms;

/var/log/mysqld.log:MySQL thread id 170037, OS thread handle 140109754021632, query id 1132732 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:23:20’ where id = 227927
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:23:20’ where id = 227927
/var/log/mysqld.log:MySQL thread id 170037, OS thread handle 140109754021632, query id 1150111 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:28:30’ where id = 225914
/var/log/mysqld.log: SQL: update sms set validation_status = ‘valid’, result_description = ‘“SUCCESS”’, message_status = ‘SUCCESS’, status_code = 200, sms.updated_at = ‘2022-04-28 10:28:30’ where id = 225914
/var/log/mysqld.log:MySQL thread id 187601, OS thread handle 140109887354624, query id 1159420 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 187631, OS thread handle 140109752678144, query id 1162548 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 187636, OS thread handle 140109887354624, query id 1163294 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 187744, OS thread handle 140109752678144, query id 1166672 10.151.158.72 sms wsrep: replicating and certifying write set(-1)
/var/log/mysqld.log:MySQL thread id 187745, OS thread handle 140110066689792, query id 1167014 10.151.158.72 sms wsrep: replicating and certifying write set(-1)

I don’t know what is the root cause of this problem and how to troubleshoot?

[matthewb]

Check wsrep_cluster_size and ensure you do have a 3 node cluster. Make sure wsrep_on=on as well. You might either need to erase node2 and node3 and let them re-SST, or use a tool like pt-table-sync to synchronize them.

[elkhedewy]

@matthewb

wsrep_cluster_size

Hello,

Here is the result on the 3 nodes:
mysql> show status like ‘wsrep_cluster_size’;
±-------------------±------+
| Variable_name | Value |
±-------------------±------+
| wsrep_cluster_size | 3 |
±-------------------±------+

How do i check wsrep_on=on ?
I tried
show status like ’ wsrep_on';
and
mysqladmin var|grep wsrep
but no result found for wsrep_on

Should i add it to my.cnf file? and what is this option do?

I removed /var/lib/mysql from 2 nodes and made the sync again from the node that have the largest number of rows but after 2 days the problem happened again.

One last thing how to use pt-table-sync if node 1 is the correct data?

[matthewb]

@elkhedewy

I removed /var/lib/mysql from 2 nodes and made the sync again from the node that have the largest number of rows but after 2 days the problem happened again.

Are you 100% positive these tables are InnoDB? (SHOW CREATE TABLE...)

One last thing how to use pt-table-sync if node 1 is the correct data?

You specify node1 as the source and node2 as the destination.

[elkhedewy]

@matthewb

SHOW CREATE TABLE

Yes it is innodb.
| sms | CREATE TABLE sms (
id bigint unsigned NOT NULL AUTO_INCREMENT,
app_id int unsigned NOT NULL,
request_ip varchar(255) COLLATE utf8mb4_unicode_ci NOT NULL,
message text COLLATE utf8mb4_unicode_ci,
phone_number varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
message_tag varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
validation_status varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
validation_message json DEFAULT NULL,
result_description json DEFAULT NULL,
message_status varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
status_code varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
created_at timestamp NULL DEFAULT NULL,
updated_at timestamp NULL DEFAULT NULL,
PRIMARY KEY (id)
) ENGINE=InnoDB AUTO_INCREMENT=266349 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci |

Will try the pt-table-sync after solving the problem

[matthewb]

You can put node2 and node3 in read_only=ON mode and see where things start failing. This is the only table with this issue?

[elkhedewy]

I guess yes it is the only table with this issue. I’ve 5 other databases but no one complain except for sms db.

[Alexander_Bezpyatov]

Hi, @elkhedewy

First of all, please do not stick to the PhpMyAdmin evaluation count. Make select count(*) ... explicitly, since the real results and PMA evaluation are took from different sources:

while the real count:

mysql> select count(*) from users_devices;
+----------+
| count(*) |
+----------+
|  3955306 |
+----------+
1 row in set (5.19 sec)

Second: please provide full output for show status like '%wsrep%'; for each node respectively here + wsrep_% variable values from config file.

[elkhedewy]

@Alexander_Bezpyatov

show status like '%wsrep%';

Hello,

First here is the result of select count () from sms; on the 3 node
±---------+
| count() |
±---------+
| 148827 |
±---------+
±---------+
| count() |
±---------+
| 148827 |
±---------+
±---------+
| count() |
±---------+
| 148827 |
±---------+

And here is the result from phpmyadmin:
select * from sms;
130811 total
130761 total
130780 total

Its the same results from mysql command line, and different values in phpmyadmin

The result of show status like '%wsrep%'; is attached

Node 1.txt (14.6 KB)
Node 2.txt (14.6 KB)
Node 3.txt (14.6 KB)

[Alexander_Bezpyatov]

@elkhedewy

±---------+
| count( ) |
±---------+
| 148827 |
±---------+
±---------+
| count( ) |
±---------+
| 148827 |
±---------+
±---------+
| count( ) |
±---------+
| 148827 |
±---------+

If you meant, that those three query results was from 1st, 2nd and 3rd nodes respectively, and from command line they are same on all nodes then cluster consistency is OK.

What is not OK is PHPmyAdmin results, since you are not doing count(*) there. Therefore phpMyAdmin uses table metadata to get “evaluated” rows count. Table metadata row count estimations are not precise and even up to date, so I recommend not to take them into account.