Details
-
New Feature
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
None
-
None
-
None
Description
This table:
CREATE TABLE `fakeo` (
|
`order_id` int(11) NOT NULL DEFAULT 0,
|
`customer_id` int(11) DEFAULT NULL,
|
`order_date` date DEFAULT NULL,
|
`status` varchar(20) DEFAULT 'PENDING'
|
) ENGINE=InnoDB DEFAULT CHARSET=latin1 COLLATE=latin1_swedish_ci
|
Has 200k rows.
This is the delete on Master:
MariaDB [db02]> delete from fakeo where customer_id=1;
|
Query OK, 98304 rows affected (0.165 sec)
|
MariaDB [db_handlers]> select count(*) from db02.fakeo;
|
+----------+
|
| count(*) |
|
+----------+
|
| 98304 |
|
+----------+
|
The same DELETE will take 1 hour on Replica.
These are the relevant handlers pre-post DELETE:
MariaDB [db_handlers]> SELECT variable_name, GROUP_CONCAT(variable_value ORDER BY snaptime) AS ordered_values, GROUP_CONCAT(snaptime ORDER BY snaptime) AS ordered_snaptimes FROM status_master GROUP BY variable_name;
|
+----------------------------+----------------+-----------------------------------------+
|
| variable_name | ordered_values | ordered_snaptimes |
|
+----------------------------+----------------+-----------------------------------------+
|
| HANDLER_COMMIT | 77,80 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_DELETE | 65538,163842 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_DISCOVER | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_EXTERNAL_LOCK | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_ICP_ATTEMPTS | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_ICP_MATCH | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_MRR_INIT | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_MRR_KEY_REFILLS | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_MRR_ROWID_REFILLS | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_PREPARE | 56,58 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_FIRST | 3,3 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_KEY | 40,40 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_LAST | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_NEXT | 2,2 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_PREV | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_RETRY | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_RND | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_RND_DELETED | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_READ_RND_NEXT | 787075,983712 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_ROLLBACK | 2,2 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_SAVEPOINT | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_SAVEPOINT_ROLLBACK | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_TMP_DELETE | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_TMP_UPDATE | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_TMP_WRITE | 262519,262546 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_UPDATE | 0,0 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
| HANDLER_WRITE | 262299,262326 | 2025-11-03 09:31:10,2025-11-03 09:31:34 |
|
+----------------------------+----------------+-----------------------------------------+
|
|
The replica takes 1~ hour to execute a DELETE that took (0.165 sec) on primary.
SQL thread state:
Seconds_Behind_Master: 3059
|
Slave_SQL_Running_State: Delete_rows_log_event::find_row(-1) on table `fakeo`
|
Handlers on replica pre-post:
MariaDB [db_handlers]> SELECT variable_name, GROUP_CONCAT(variable_value ORDER BY snaptime) AS ordered_values, GROUP_CONCAT(snaptime ORDER BY snaptime) AS ordered_snaptimes FROM status_slave GROUP BY variable_name;
|
+----------------------------+-----------------------+-----------------------------------------+
|
| variable_name | ordered_values | ordered_snaptimes |
|
+----------------------------+-----------------------+-----------------------------------------+
|
| HANDLER_COMMIT | 473,507 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_DELETE | 16873,164167 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_DISCOVER | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_EXTERNAL_LOCK | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_ICP_ATTEMPTS | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_ICP_MATCH | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_MRR_INIT | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_MRR_KEY_REFILLS | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_MRR_ROWID_REFILLS | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_PREPARE | 256,270 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_FIRST | 3,3 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_KEY | 119,128 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_LAST | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_NEXT | 1,1 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_PREV | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_RETRY | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_RND | 677,3647 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_RND_DELETED | 0,702 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_READ_RND_NEXT | 420116481,11275195407 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_ROLLBACK | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_SAVEPOINT | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_SAVEPOINT_ROLLBACK | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_TMP_DELETE | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_TMP_UPDATE | 0,0 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_TMP_WRITE | 190,379 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_UPDATE | 1,1 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
| HANDLER_WRITE | 262692,262967 | 2025-11-03 09:31:38,2025-11-03 10:36:47 |
|
|
10.85 Billions HANDLER_READ_RND_NEXT vs 196637 on Primary.
Also interesting:
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| Id | User | Host | db | Command | Time | State | Info | Progress |
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| 9 | system user | | NULL | Slave_IO | 4949 | Waiting for master to send event | NULL | 0.000 |
|
| 13 | root | localhost | db_handlers | Query | 0 | starting | show processlist | 0.000 |
|
| 15 | system user | | db02 | Slave_SQL | 11 | Delete_rows_log_event::find_row(-1) on table `fakeo` | delete from fakeo where customer_id=1 | 0.000 |
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
3 rows in set (0.000 sec)
|
|
|
MariaDB [db_handlers]> show processlist;
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| Id | User | Host | db | Command | Time | State | Info | Progress |
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| 9 | system user | | NULL | Slave_IO | 4949 | Waiting for master to send event | NULL | 0.000 |
|
| 13 | root | localhost | db_handlers | Query | 0 | starting | show processlist | 0.000 |
|
| 15 | system user | | db02 | Slave_SQL | 12 | Delete_rows_log_event::find_row(-1) on table `fakeo` | delete from fakeo where customer_id=1 | 0.000 |
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
3 rows in set (0.000 sec)
|
|
|
MariaDB [db_handlers]> show processlist;
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| Id | User | Host | db | Command | Time | State | Info | Progress |
|
+----+-------------+-----------+-------------+-----------+------+------------------------------------------------------+---------------------------------------+----------+
|
| 9 | system user | | NULL | Slave_IO | 4950 | Waiting for master to send event | NULL | 0.000 |
|
| 13 | root | localhost | db_handlers | Query | 0 | starting | show processlist | 0.000 |
|
| 15 | system user | | db02 | Slave_SQL | 0 | Delete_rows_log_event::find_row(-1) on table `fakeo` | delete from fakeo where customer_id=1 | 0.000 |
|
I guess that's each row lookup doing a table scan.
I think this is the most underestimated and less understood performance problem with replication and Galera.
Attachments
Issue Links
- relates to
-
MDEV-21181 Automatic invisible primary key
-
- Open
-
-
MDEV-24001 Implement hidden PK for RBR of no-unique key table
-
- Open
-
-
MDEV-24830 Write a warning to error log if Galera replicates InnoDB table with no primary key
-
- Closed
-
-
MDEV-28412 Introduce sql_require_primary_key
-
- Open
-