[MDEV-14956] Slow deletes if number of deleted rows smaller then LIMIT Created: 2018-01-16  Updated: 2018-02-14  Resolved: 2018-02-14

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Delete, Optimizer
Affects Version/s: 10.2.10
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Thomas Huppertz Assignee: Alice Sherepa
Resolution: Not a Bug Votes: 0
Labels: delete, long, performance
Environment:

Windows

Attachments: File my.ini     File rlog_rrec_create.sql    
Issue Links:
Relates
relates to MDEV-7487 Semi-join optimization for single-tab... Closed

 Description   

Have two tables RLOG, RREC which basically Looks like this:

 
 
CREATE TABLE rrec (
 
  RREC_TIMESTAMP_DT varchar(25) NOT NULL,
 
  RREC_SESSION_UID varchar(70) NOT NULL,
 
  ... (shorten) ...
 
  PRIMARY KEY (RREC_SESSION_UID),
 
 ...
 
    )
 
ENGINE = INNODB
 
AVG_ROW_LENGTH = 197
 
CHARACTER SET latin1
 
COLLATE latin1_general_cs
 
ROW_FORMAT = COMPRESSED;

and 

CREATE TABLE rlog (
 
  RLOG_ID varchar(70) NOT NULL,
 
  RLOG_LOGENTRY longtext DEFAULT NULL,
 
  PRIMARY KEY (RLOG_ID),
 
  UNIQUE INDEX IDX_UK_rlog (RLOG_ID),
 
  CONSTRAINT RLOG_RREC_FK FOREIGN KEY (RLOG_ID)
 
  REFERENCES rrec (RREC_SESSION_UID) ON DELETE CASCADE ON UPDATE CASCADE
 
)
 
ENGINE = INNODB
 
AVG_ROW_LENGTH = 2343
 
CHARACTER SET latin1
 
COLLATE latin1_general_cs
 
ROW_FORMAT = COMPRESSED;

(see attachments for full table creation SQL)

Both tables have several rows:

RLOG: 1 MIO
RREC: 1,3 MIO

From time to time i want to delete some entrys from RLOG table:

 DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-01-01') LIMIT 1000;

As long as at least 1000 rows are deleted everything is fine:

1000 rows deleted [0,107s]

but if i delete less then 1000 rows the delete Operation takes very long time:

847 rows deleted [24,270s]

and even worse if nothing is deleted it takes Long time also:

0 rows deleted [24,090s]

Profiling of such a statement shows the following:

Step Time Percent

updating |51,634785 |99,86|
query end |0,033120 |0,06|
statistics |0,014102 |0,03|
end |0,009650 |0,02|
Unlocking tables |0,005223 |0,01|
freeing items |0,003979 |0,01|
updating status |0,001728 |0,00|
starting |0,001212 |0,00|
init |0,001178 |0,00|
Opening tables |0,000821 |0,00|
preparing |0,000791 |0,00|
closing tables |0,000760 |0,00|
After opening tables |0,000380 |0,00|
checking permissions |0,000288 |0,00|
Table lock |0,000227 |0,00|
cleaning up |0,000024 |0,00|
System lock |0,000020 |0,00|
optimizing |0,000013 |0,00|

If you like I can provide you my testdata (6GB).

 Comments   
Comment by Alice Sherepa [ 2018-01-18 ]

Hi Thomas, please explain why you consider it is a bug.
As I understood, you deleted 1000 rows, it was fast, then repeated DELETE .. LIMIT 1000 ->it resulted to 847 rows and 24s(so we scanned whole table and found only 847 rows). Third execution - we scanned again whole table and found no rows, so execution time is nearly the same as in a second case.

Comment by Thomas Huppertz [ 2018-01-19 ]

From my original post
---------
As long as at least 1000 rows are deleted everything is fine:

SQL2.sql: 1000 rows deleted [0,107s]

but if i delete less then 1000 rows the delete Operation takes very long time:

SQL2.sql: 847 rows deleted [24,270s]

--------------

So why does deletion of 847 rows takes longer then deleting 1000 rows.
Investigating the problem a little bit further. It turns out that

Assume you have 1124 rows you want to delete:

1. Case: BAD

DELETE FROM RLOG .... LIMIT 1000;
 
SQL2.sql: 1000 rows deleted [0,270s]
 
 
 
DELETE FROM RLOG .... LIMIT 1000;
 
SQL2.sql: 124 rows deleted [24,270s]

2. Case: BAD

DELETE FROM RLOG .... LIMIT 1000;
 
SQL2.sql: 1000 rows deleted [0,270s]
 
 
 
DELETE FROM RLOG .... LIMIT 124;
 
SQL2.sql: 124 rows deleted [24,270s]

3. CASE: GOOD

DELETE FROM RLOG .... LIMIT 1000;
 
SQL2.sql: 1000 rows deleted [0,270s]
 
 
 
DELETE FROM RLOG .... LIMIT 123;
 
SQL2.sql: 123 rows deleted [0,170s]
 
 
 
DELETE FROM RLOG .... LIMIT 1;
 
SQL2.sql: 1 rows deleted [0,0170s]

So you now see the problem?
In order to do a optimal deletion process ... i have to:

  1. estimate the rows to delete
  2. eelete rows in potions of 1000 as Long as there are more then 1000 rows still to delete
  3. delete all rows but 1
  4. delete the last row

All other deletion attemps result in a execution time which is factor 240 times slower.

Comment by Alice Sherepa [ 2018-01-23 ]

Thomas Huppertz , please provide output of

EXPLAIN DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-01-01') LIMIT 1000;

as a workaround:

 DELETE rlog.* FROM rlog JOIN rrec ON (rlog.rlog_ID = rrec.rrec_SESSION_UID)
 
  WHERE (rrec.rrec_TIMESTAMP_DT < '2016-01-01') ;

Comment by Thomas Huppertz [ 2018-01-23 ]

Form 

EXPLAIN DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-01-01') LIMIT 1000;

the output is:

+------+--------------------+-------+-----------------+-------------------------------------------------+---------+---------+------+--------+-------------+
 
| id   | select_type        | table | type            | possible_keys                                   | key     | key_len | ref  | rows   | Extra       |
 
+------+--------------------+-------+-----------------+-------------------------------------------------+---------+---------+------+--------+-------------+
 
|    1 | PRIMARY            | RLOG  | ALL             | NULL                                            | NULL    | NULL    | NULL | 920314 | Using where |
 
|    2 | DEPENDENT SUBQUERY | RREC  | unique_subquery | PRIMARY,RREC_IDX_TIME,RREC_IDX_SL,RREC_IDX_RLOG | PRIMARY | 72      | func |      1 | Using where |
 
+------+--------------------+-------+-----------------+-------------------------------------------------+---------+---------+------+--------+-------------+
 
2 rows in set (0.11 sec)

and from

 DELETE rlog.* FROM rlog JOIN rrec ON (rlog.rlog_ID = rrec.rrec_SESSION_UID)
 
  WHERE (rrec.rrec_TIMESTAMP_DT < '2016-01-01') ;

the output is:

+------+-------------+-------+--------+-------------------------------------------------+-------------+---------+---------------------------------+-------+--------------------------+
 
| id   | select_type | table | type   | possible_keys                                   | key         | key_len | ref                             | rows  | Extra                    |
 
+------+-------------+-------+--------+-------------------------------------------------+-------------+---------+---------------------------------+-------+--------------------------+
 
|    1 | SIMPLE      | rrec  | range  | PRIMARY,RREC_IDX_TIME,RREC_IDX_SL,RREC_IDX_RLOG | RREC_IDX_SL | 27      | NULL                            | 49304 | Using where; Using index |
 
|    1 | SIMPLE      | rlog  | eq_ref | PRIMARY,IDX_UK_rlog                             | PRIMARY     | 72      | cmdsystem.rrec.RREC_SESSION_UID |     1 |                          |
 
+------+-------------+-------+--------+-------------------------------------------------+-------------+---------+---------------------------------+-------+--------------------------+
 
2 rows in set (0.07 sec)

Comment by Alice Sherepa [ 2018-01-23 ]

Please provide a testcase. It looks like a bug from your description, but I can not reproduce it.
I want to check if I understand correct:
DELETE ... LIMIT 124 ---takes 24s
and then on the same data if we execute: DELETE ... LIMIT 123, DELETE ... LIMIT 1 - is very fast?

Another case, if we have 124 matching rows, and then DELETE ... LIMIT 123, DELETE ... LIMIT 1 - and we were so lucky, that we met matching rows right from the start of the table, so queries were fast. If we execute DELETE ... LIMIT 1 again and there are no matching rows, we scan the whole table, get result - 0 rows deleted and long query execution. The problem here is, that semi-join optimization for DELETE is not yet implemented(MDEV-7487). From execution plan -920314 rows to scan, and using where, so not index. The best solution, for now, is to rewrite the query using join.

Comment by Thomas Huppertz [ 2018-01-25 ]

In order to provide a test case i Need to upload a fairly large data set. It´s 160MB Zip-File.
Where can i upload this file?

The SQL for table creation is already attached

I want to check if I understand correct:
 
DELETE ... LIMIT 124 ---takes 24s
 
and then on the same data if we execute: DELETE ... LIMIT 123, DELETE ... LIMIT 1 - is very fast?

Yes, this is correct

Comment by Alice Sherepa [ 2018-01-26 ]

please upload it to ftp://ftp.askmonty.org/private/

Comment by Thomas Huppertz [ 2018-01-26 ]

Uploaded as mdev-14956.zip

Comment by Thomas Huppertz [ 2018-02-01 ]

Hi Alice,
did you recieve my testdata?

Comment by Alice Sherepa [ 2018-02-02 ]

Yes, thank you. please provide also exact command, that you execute, what is in SQL2.sql? if I execute 

DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-01-01') LIMIT 1000;

there are no matching rows, do I have data after you deleted this rows?

Comment by Thomas Huppertz [ 2018-02-07 ]

Sorry for the late response, missed the mal from JIRA somehow.

SQL2.sql - this was only from the sqltool i used ... you have multiple SQL-Tabs in there. So you can just ignore this.

I have checked the testdata. You could perform the following Statement to reproduce the test case:

First test case: no data deletion
==============================

 
 
DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2014-03-01') LIMIT 1000;
 
Query OK, 0 rows affected (3 min 29.06 sec)
 
 
 
MariaDB [CMDSYSTEM]> SELECT COUNT(*) FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2014-03-01') LIMIT 1000;
 
+----------+
 
| COUNT(*) |
 
+----------+
 
|        0 |
 
+----------+
 
1 row in set (0.11 sec)

As you can see ... the select delivers in 0.11 sec that tehere are no rows to delete.
The delete takes 3 minutes to do the same Job.

Second test case: with data deleteion:
================================

MariaDB [CMDSYSTEM]> SELECT COUNT(*) FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-03-01') LIMIT 1000;
 
+----------+
 
| COUNT(*) |
 
+----------+
 
|     2834 |
 
+----------+
 
1 row in set (0.24 sec)
 
 
 
MariaDB [CMDSYSTEM]> DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-03-01') LIMIT 1000;
 
Query OK, 1000 rows affected (0.31 sec)
 
 
 
MariaDB [CMDSYSTEM]> DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-03-01') LIMIT 1000;
 
Query OK, 1000 rows affected (1.12 sec)
 
 
 
MariaDB [CMDSYSTEM]> DELETE FROM RLOG WHERE RLOG_ID in (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT < '2016-03-01') LIMIT 1000;
 
Query OK, 834 rows affected (3 min 28.75 sec)

Think you can figure out the whole problem with this test cases.

As Long as you know how many rows to delete - you are fast. Otherwise you are slow.

Comment by Alice Sherepa [ 2018-02-14 ]

Hi Thomas,
I'm afraid that is expected behavior, as long as single-table UPDATE/DELETE statements do not use the advantage of semi-join optimizations (as in SELECT statements) We have a task for that, MDEV-7487, but it is not implemented as for now. Please use suggested workaround to use multi-table UPDATE/DELETE syntax.
To demonstrate it on your data, I deleted rows with latest dates (so they are probably closer to the end of the table), so it is clear that the reason is not that limit is bigger, then the count of deleted rows. 

MariaDB [test]> SELECT COUNT(*) FROM RLOG WHERE RLOG_ID IN (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT > '2017-03-01');
 
+----------+
 
| COUNT(*) |
 
+----------+
 
|    10524 |
 
+----------+
 
1 row in set (5.02 sec)
 
MariaDB [test]> START TRANSACTION;
 
Query OK, 0 rows affected (0.00 sec)
 
MariaDB [test]> DELETE FROM RLOG WHERE RLOG_ID IN (SELECT RREC_SESSION_UID FROM RREC WHERE RREC_TIMESTAMP_DT > '2017-03-01') LIMIT 10524;
 
Query OK, 10524 rows affected (3 min 54.94 sec)
 
MariaDB [test]> ROLLBACK;
 
Query OK, 0 rows affected (7.99 sec)
 
--  rewriting query,  to use multi-table UPDATE/DELETE syntax:
 
MariaDB [test]> DELETE RLOG.* FROM RLOG JOIN RREC ON (RLOG.RLOG_ID = RREC.RREC_SESSION_UID)
 
    -> WHERE (RREC.RREC_TIMESTAMP_DT> '2017-03-01');
 
Query OK, 10524 rows affected (11.36 sec)

Generated at Thu Feb 08 08:17:36 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.