Not the answer you need?
Register and ask your own question!

MEMORY DELETE query takes more than 60 seconds of time with 100% CPU load

ChavyChavy ContributorInactive User Role Beginner
SHOW TABLE STATUS IN `db` WHERE `NAME` LIKE 'db_test_table';
Name: db_test_table
Engine: MEMORY
Version: 10
Row_format: Fixed
Rows: 137969
Avg_row_length: 1266
Data_length: 170,11 MB (178 368 800)
Max_data_length: 1,69 GB (1 818 536 838)
Index_length: 17,77 MB (18 636 748)
Data_free: 1,26 MB (1 316 640)
Auto_increment: NULL

SHOW FULL PROCESSLIST;
Query | 52 | updating | DELETE FROM `db_test_table` WHERE 'regtime` != 1407657002 :
Time: 52
Rows_sent: 0
Rows_examined: 129071349

Usually DELETE query takes less than 1 milliseconds, but sometimes this time increases to 60,200,300 seconds or more with 100% CPU load. Is this normal and what can I do to speed up DELETE query execution?
I can upload table and query, on which it is possible to repeat this problem, on Monday.

Comments

  • ChavyChavy Contributor Inactive User Role Beginner
    On uploading file forum displays "Your file of 422779 bytes exceeds the limit of 100000. db_test_table.zip". Filesize 412 Kb.
    Where can I upload the table dump?
  • ChavyChavy Contributor Inactive User Role Beginner
    http://rghost.ru/57449917

    Try to execute query
    DELETE FROM `db_test_table_copy` WHERE `bid`=2 AND `regtime`!=1407760802;
    
    on this 9.8 Mb memory table. On my server it takes 1 minute and 35 seconds with 100% CPU loading all this time
    Server version: 5.6.19
  • psongpsong Contributor Inactive User Role Beginner
    For the original query: DELETE FROM `db_test_table` WHERE 'regtime` != 1407657002, Rows_examined: 129071349 suggested that there was no index on regtime column, and 129Million rows were scanned sequentially which will take some time. Did you know how many rows got deleted?

    The command "show create table db_test_table\G" will show the table and index definition.

    Since the table is memory storage engine, no IO needed, it is not surprising to have the CPU running at full speed. Note that in 'top', 100% CPU means one core is fully occupied, not all cores.
  • ChavyChavy Contributor Inactive User Role Beginner
    psong wrote: »
    Since the table is memory storage engine, no IO needed, it is not surprising to have the CPU running at full speed. Note that in 'top', 100% CPU means one core is fully occupied, not all cores.
    For me it is a problem because it blocks all other queries on connection. And I think this query should take no more than 10 milliseconds, and usually what happens.

    Ok, let's look on this table:
    CREATE TABLE `db_test_table` (
    `bid` smallint(5) unsigned NOT NULL,
    `pid` smallint(5) unsigned NOT NULL,
    `regtime` bigint(20) unsigned NOT NULL,
    `vid` mediumint(9) NOT NULL AUTO_INCREMENT,
    PRIMARY KEY (`vid`),
    KEY `idx` (`regtime`,`bid`) USING BTREE
    ) ENGINE=MEMORY AUTO_INCREMENT=142064 DEFAULT CHARSET=binary ROW_FORMAT=DYNAMIC;
    Table ​Data Length: 2,20 MB (2 303 264)
    Index Length: 7,89 MB (8 269 910)
    Rows in table: 142063, not 129Million

    Table dump: ​db_test_table.sql (9.8 МБ):

    Query:
    DELETE FROM `db_test_table` WHERE `regtime`!=1407760802 AND `bid`=2;

    mysql-slow.log:
    # Time: 140815 18:21:21
    # [email protected]: db_admin[db_admin] @ nntro [192.168.1.2] Id: 849
    # Schema: db Last_errno: 0 Killed: 0
    # Query_time: 65.480393 Lock_time: 0.000103 Rows_sent: 0 Rows_examined: 371240031 Rows_affected: 2775
    # Bytes_sent: 13
    # Profile_starting: 0.000049
    Profile_starting_cpu: 0.000049
    Profile_checking_permissions: 0.000006
    Profile_checking_permissions_cpu: 0.000005
    Profile_Opening_tables: 0.000023
    Profile_Opening_tables_cpu: 0.000023
    Profile_init: 0.000026
    Profile_init_cpu: 0.000026
    Profile_System_lock: 0.000065
    Profile_System_lock_cpu: 0.000065
    Profile_updating: 65.480188
    Profile_updating_cpu: 65.449760
    Profile_end: 0.000007
    Profile_end_cpu: 0.000006
    Profile_query_end: 0.000002
    Profile_query_end_cpu: 0.000002
    Profile_closing_tables: 0.000007
    Profile_closing_tables_cpu: 0.000007
    Profile_freeing_items: 0.000022
    Profile_freeing_items_cpu: 0.000022
    Profile_logging_slow_query: 0.000001
    Profile_logging_slow_query_cpu: 0.000001
    # Profile_total: 65.480396 Profile_total_cpu: 65.449965
    SET timestamp=1408112481;
    DELETE FROM `db_test_table` WHERE `regtime`!=1407760802 AND `bid`=2;
    ...

    CPU:
    model name : Intel(R) Pentium(R) CPU G3420 @ 3.20GHz
    cpu MHz : 3200.000
    cache size : 3072 KB
    Can you try to execute a query on your pc? Table dump u can download from this urls:
    Maybe it's btree index bug? Or configuration problems?
  • psongpsong Contributor Inactive User Role Beginner
    Chavy, thanks for the update. I tried with the data and agreed that there is a bug with DELETE query when the WHERE clause has conditions on >1 columns. I would suggest you to open a bug with MySQL at http://bugs.mysql.com.

    Here are what I observed on community v5.6.19. The EXPLAIN plan to find the rows to delete is:
    mysql> explain select * from db_test_table where regtime != 1407760802 and bid = 2;
      +----+-------------+---------------+-------+---------------+------+---------+------+--------+-------------+
      | id | select_type | table         | type  | possible_keys | key  | key_len | ref  | rows   | Extra       |
      +----+-------------+---------------+-------+---------------+------+---------+------+--------+-------------+
      |  1 | SIMPLE      | db_test_table | range | idx           | idx  | 8       | NULL | 139179 | Using where |
      +----+-------------+---------------+-------+---------------+------+---------+------+--------+-------------+
      1 row in set (0.00 sec)
    

    The SELECT query ran fast and examined relevant rows as expected:
      # Query_time: 1.023239  Lock_time: 0.000159 Rows_sent: 1  Rows_examined: 135667
      SET timestamp=1409205734;
      select count(*) from db_test_table where regtime != 1407760802 and bid = 2;
    

    DELETE query took a long time and examined hundreds of millions of rows, same as you observed. I guess there is a faulty repeat of loops. However DELETE with only one criteria rans fast:
    # Query_time: 1.922281  Lock_time: 0.000127 Rows_sent: 0  Rows_examined: 135551
      SET timestamp=1409205948;
      delete from db_test_table where regtime != 1407760802;
    
    I suspected the culprit had to do with composite index, but problem remained after I changed the composite index to a single column index.
    mysql> show create table db_test_table\G                                                                                   *************************** 1. row ***************************
             Table: db_test_table
      Create Table: CREATE TABLE `db_test_table` (
        `bid` smallint(5) unsigned NOT NULL,
        `pid` smallint(5) unsigned NOT NULL,
        `regtime` bigint(20) unsigned NOT NULL,
        `vid` mediumint(9) NOT NULL AUTO_INCREMENT,
        PRIMARY KEY (`vid`),
        KEY `idx` (`regtime`) USING BTREE
      ) ENGINE=MEMORY AUTO_INCREMENT=142064 DEFAULT CHARSET=binary ROW_FORMAT=DYNAMIC;
    
    ------ Kill the query since it took too long
      # Query_time: 266.423611  Lock_time: 0.000125 Rows_sent: 0  Rows_examined: 38114863
      SET timestamp=1409207983;
      delete from db_test_table where regtime != 1407760802 and bid = 2;
    
    -------- Delete on single column remains fast
      # Query_time: 2.225477  Lock_time: 0.000119 Rows_sent: 0  Rows_examined: 136506
      SET timestamp=1409206867;
      delete from db_test_table where regtime != 1407760802;
    
Sign In or Register to comment.

MySQL, InnoDB, MariaDB and MongoDB are trademarks of their respective owners.
Copyright ©2005 - 2020 Percona LLC. All rights reserved.