GET 24/7 LIVE HELP NOW

Announcement

Announcement Module
Collapse
No announcement yet.

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

Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

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

    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.
    Thanks.
    Last edited by Chavy; 08-10-2014, 07:32 AM.
    -

  • #2
    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?
    -

    Comment


    • #3
      http://rghost.ru/57449917

      Try to execute query
      Code:
      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
      -

      Comment


      • #4
        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.

        Comment


        • #5
          Originally posted by psong View Post
          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
          # User@Host: 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?
          -

          Comment


          • #6
            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:
            Code:
             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:
            Code:
              # 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:
            Code:
             # 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.

            Code:
             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;

            Comment

            Working...
            X