Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-19552

DROP TABLE locks SHOW CREATE TABLE and SELECT with sorting since 10.1.34

    XMLWordPrintable

Details

    Description

      After upgrade from 10.1.30 to 10.1.34 (10.1.40 affected too) we discovery that drop table locks many queries like 'show create table ....' on working server (15-25 Krps).
      Drop of just created table works unexpected long for table about 250Krows, 80 Mb on server with SSD and big buffer pool (140Gb and 400Gb):

      • about 0.1 sec on empty 140G buffer pool (after start)
      • about 1 sec on full 140G buffer pool
      • about 3 sec on full 400G buffer pool

      Script to reproduce:

      #!/bin/bash                                                                              
                                                                                               
      tmp=`mktemp`
      tmp1=`mktemp`                                                                            
      tmp2=`mktemp`                                                                            
                                                                                               
      mysql -h server >$tmp <<EOF
      use tmp;
      drop table if exists sss1, sss2, sss3;
      create table sss1 like  search.company_search_summary_table;                             
      insert into sss1 select * from search.company_search_summary_table ;                     
      EOF
                                                                                               
                                                                                               
      (
      mysql -t -h server >$tmp1 <<EOF                                                        
      select "drop";
      set profiling = 1;
      drop table tmp.sss1;
      show profile source;
      status;                                                                                  
      EOF
      ) &
          
      (
      mysql -t -h server >$tmp2  <<EOF                                                       
      set profiling = 1;
      show create table sys.date_time;                                                         
      show profile source;
      show create table sys.date_time;                                                         
      show profile source;                                                                     
      show create table sys.date_time;                                                         
      show profile source;                                                                     
      show create table sys.date_time;                                                         
      show profile source;
      status;
      EOF
      ) &
       
      wait
      head -n400 $tmp $tmp1 $tmp2 
      /bin/rm -f $tmp $tmp1 $tmp2
      

      Output

      $ cat /tmp/aa
      ==> /tmp/tmp.Fn4nIpaTFj <==
       
      ==> /tmp/tmp.L9qGfzb24e <==
      +------+
      | drop |
      +------+
      | drop |
      +------+
      +----------------------+----------+-----------------------+--------------+-------------+
      | Status               | Duration | Source_function       | Source_file  | Source_line |
      +----------------------+----------+-----------------------+--------------+-------------+
      | starting             | 0.000035 | NULL                  | NULL         |        NULL |
      | checking permissions | 0.000028 | check_access          | sql_parse.cc |        6154 |
      | Opening tables       | 0.000039 | open_tables           | sql_base.cc  |        4532 |
      | After opening tables | 0.000024 | open_tables           | sql_base.cc  |        4779 |
      | System lock          | 0.000024 | mysql_lock_tables     | lock.cc      |         308 |
      | Table lock           | 0.000066 | mysql_lock_tables     | lock.cc      |         313 |
      | closing tables       | 0.000023 | close_thread_tables   | sql_base.cc  |         919 |
      | Unlocking tables     | 1.101685 | mysql_unlock_tables   | lock.cc      |         396 |
      | query end            | 0.000102 | mysql_execute_command | sql_parse.cc |        5706 |
      | closing tables       | 0.000059 | close_thread_tables   | sql_base.cc  |         919 |
      | freeing items        | 0.000050 | mysql_parse           | sql_parse.cc |        7466 |
      | updating status      | 0.000062 | dispatch_command      | sql_parse.cc |        1954 |
      | cleaning up          | 0.000049 | dispatch_command      | sql_parse.cc |        1973 |
      +----------------------+----------+-----------------------+--------------+-------------+
      --------------
      mysql  Ver 15.1 Distrib 10.1.37-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
       
      Connection id:          3742891
      Current database:
      Current user:           user@10.10.8.36
      SSL:                    Not in use
      Current pager:          stdout
      Using outfile:          ''
      Using delimiter:        ;
      Server:                 MariaDB
      Server version:         10.1.34-MariaDB MariaDB Server
      Protocol version:       10
      Connection:             server via TCP/IP
      Server characterset:    utf8
      Db     characterset:    utf8
      Client characterset:    utf8
      Conn.  characterset:    utf8
      TCP port:               3306
      Uptime:                 42 min 35 sec
       
      Threads: 688  Questions: 55997878  Slow queries: 0  Opens: 8070  Flush tables: 1  Open tables: 2033  Queries per second avg: 21916.977
      --------------
       
       
      ==> /tmp/tmp.RX2wgWmf9w <==
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | Table     | Create Table                                                                                                                                                                                                |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | date_time | CREATE TABLE `date_time` (
        `date` int(10) unsigned NOT NULL DEFAULT '0',
        `name` varchar(255) NOT NULL DEFAULT 'unknown',
        PRIMARY KEY (`name`)
      ) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      +----------------------+----------+-----------------------+--------------+-------------+
      | Status               | Duration | Source_function       | Source_file  | Source_line |
      +----------------------+----------+-----------------------+--------------+-------------+
      | starting             | 0.000084 | NULL                  | NULL         |        NULL |
      | checking permissions | 0.000041 | check_access          | sql_parse.cc |        6154 |
      | Opening tables       | 0.000036 | open_tables           | sql_base.cc  |        4532 |
      | After opening tables | 0.000044 | open_tables           | sql_base.cc  |        4779 |
      | closing tables       | 0.000042 | close_thread_tables   | sql_base.cc  |         919 |
      | query end            | 0.000025 | mysql_execute_command | sql_parse.cc |        5706 |
      | closing tables       | 0.000024 | close_thread_tables   | sql_base.cc  |         919 |
      | freeing items        | 0.000030 | mysql_parse           | sql_parse.cc |        7466 |
      | updating status      | 0.000034 | dispatch_command      | sql_parse.cc |        1954 |
      | cleaning up          | 0.000037 | dispatch_command      | sql_parse.cc |        1973 |
      +----------------------+----------+-----------------------+--------------+-------------+
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | Table     | Create Table                                                                                                                                                                                                |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | date_time | CREATE TABLE `date_time` (
        `date` int(10) unsigned NOT NULL DEFAULT '0',
        `name` varchar(255) NOT NULL DEFAULT 'unknown',
        PRIMARY KEY (`name`)
      ) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      +----------------------+----------+-----------------------+--------------+-------------+
      | Status               | Duration | Source_function       | Source_file  | Source_line |
      +----------------------+----------+-----------------------+--------------+-------------+
      | starting             | 0.000039 | NULL                  | NULL         |        NULL |
      | checking permissions | 0.000025 | check_access          | sql_parse.cc |        6154 |
      | Opening tables       | 0.000027 | open_tables           | sql_base.cc  |        4532 |
      | After opening tables | 1.100046 | open_tables           | sql_base.cc  |        4779 |
      | closing tables       | 0.000155 | close_thread_tables   | sql_base.cc  |         919 |
      | query end            | 0.000103 | mysql_execute_command | sql_parse.cc |        5706 |
      | closing tables       | 0.000060 | close_thread_tables   | sql_base.cc  |         919 |
      | freeing items        | 0.000051 | mysql_parse           | sql_parse.cc |        7466 |
      | updating status      | 0.000072 | dispatch_command      | sql_parse.cc |        1954 |
      | cleaning up          | 0.000068 | dispatch_command      | sql_parse.cc |        1973 |
      +----------------------+----------+-----------------------+--------------+-------------+
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | Table     | Create Table                                                                                                                                                                                                |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | date_time | CREATE TABLE `date_time` (
        `date` int(10) unsigned NOT NULL DEFAULT '0',
        `name` varchar(255) NOT NULL DEFAULT 'unknown',
        PRIMARY KEY (`name`)
      ) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      +----------------------+----------+-----------------------+--------------+-------------+
      | Status               | Duration | Source_function       | Source_file  | Source_line |
      +----------------------+----------+-----------------------+--------------+-------------+
      | starting             | 0.000090 | NULL                  | NULL         |        NULL |
      | checking permissions | 0.000047 | check_access          | sql_parse.cc |        6154 |
      | Opening tables       | 0.000043 | open_tables           | sql_base.cc  |        4532 |
      | After opening tables | 0.084826 | open_tables           | sql_base.cc  |        4779 |
      | closing tables       | 0.000127 | close_thread_tables   | sql_base.cc  |         919 |
      | query end            | 0.000054 | mysql_execute_command | sql_parse.cc |        5706 |
      | closing tables       | 0.000041 | close_thread_tables   | sql_base.cc  |         919 |
      | freeing items        | 0.000036 | mysql_parse           | sql_parse.cc |        7466 |
      | updating status      | 0.000066 | dispatch_command      | sql_parse.cc |        1954 |
      | cleaning up          | 0.000053 | dispatch_command      | sql_parse.cc |        1973 |
      +----------------------+----------+-----------------------+--------------+-------------+
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | Table     | Create Table                                                                                                                                                                                                |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | date_time | CREATE TABLE `date_time` (
        `date` int(10) unsigned NOT NULL DEFAULT '0',
        `name` varchar(255) NOT NULL DEFAULT 'unknown',
        PRIMARY KEY (`name`)
      ) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
      +-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      +----------------------+----------+-----------------------+--------------+-------------+
      | Status               | Duration | Source_function       | Source_file  | Source_line |
      +----------------------+----------+-----------------------+--------------+-------------+
      | starting             | 0.000356 | NULL                  | NULL         |        NULL |
      | checking permissions | 0.000059 | check_access          | sql_parse.cc |        6154 |
      | Opening tables       | 0.000050 | open_tables           | sql_base.cc  |        4532 |
      | After opening tables | 0.000103 | open_tables           | sql_base.cc  |        4779 |
      | closing tables       | 0.000048 | close_thread_tables   | sql_base.cc  |         919 |
      | query end            | 0.000039 | mysql_execute_command | sql_parse.cc |        5706 |
      | closing tables       | 0.000039 | close_thread_tables   | sql_base.cc  |         919 |
      | freeing items        | 0.000043 | mysql_parse           | sql_parse.cc |        7466 |
      | updating status      | 0.000054 | dispatch_command      | sql_parse.cc |        1954 |
      | cleaning up          | 0.000050 | dispatch_command      | sql_parse.cc |        1973 |
      +----------------------+----------+-----------------------+--------------+-------------+
      --------------
      mysql  Ver 15.1 Distrib 10.1.37-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
       
      Connection id:          3742892
      Current database:
      Current user:           user@10.10.8.36
      SSL:                    Not in use
      Current pager:          stdout
      Using outfile:          ''
      Using delimiter:        ;
      Server:                 MariaDB
      Server version:         10.1.34-MariaDB MariaDB Server
      Protocol version:       10
      Connection:             server via TCP/IP
      Server characterset:    utf8
      Db     characterset:    utf8
      Client characterset:    utf8
      Conn.  characterset:    utf8
      TCP port:               3306
      Uptime:                 42 min 35 sec
       
      Threads: 462  Questions: 56002787  Slow queries: 0  Opens: 8070  Flush tables: 1  Open tables: 2033  Queries per second avg: 21918.899
      --------------
      

      One of 'show create' locks on 1 seconds (10.1.34-NN - files with results of serveral script calling):

      # egrep 'After|unlock|Uptime'  10.1.34-*
      10.1.34-82:| After opening tables | 0.000033 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-82:| Unlocking tables     | 1.117436 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.34-82:Uptime:                      41 min 35 sec
      10.1.34-82:| After opening tables | 0.000035 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-82:| After opening tables | 0.000029 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-82:| After opening tables | 0.000051 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-82:| After opening tables | 1.113856 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-82:Uptime:                      41 min 35 sec
       
      10.1.34-83:| After opening tables | 0.000039 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-83:| Unlocking tables     | 1.100278 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.34-83:Uptime:                      42 min 5 sec
      10.1.34-83:| After opening tables | 1.098836 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-83:| After opening tables | 0.089455 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-83:| After opening tables | 0.000078 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-83:| After opening tables | 0.000076 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-83:Uptime:                      42 min 5 sec
       
      10.1.34-84:| After opening tables | 0.000024 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-84:| Unlocking tables     | 1.101685 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.34-84:Uptime:                      42 min 35 sec
      10.1.34-84:| After opening tables | 0.000044 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-84:| After opening tables | 1.100046 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-84:| After opening tables | 0.084826 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-84:| After opening tables | 0.000103 | open_tables           | sql_base.cc  |        4779 |
      10.1.34-84:Uptime:                      42 min 35 sec
      

      On version 10.1.33 max time not so high:

      10.1.33-96:| After opening tables | 0.000024 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-96:| Unlocking tables     | 0.131976 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.33-96:Uptime:                      49 min 35 sec
      10.1.33-96:| After opening tables | 0.000038 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-96:| After opening tables | 0.032584 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-96:| After opening tables | 0.000044 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-96:| After opening tables | 0.000038 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-96:Uptime:                      49 min 34 sec
      10.1.33-97:| After opening tables | 0.000022 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-97:| Unlocking tables     | 0.035330 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.33-97:Uptime:                      50 min 1 sec
      10.1.33-97:| After opening tables | 0.000051 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-97:| After opening tables | 0.027047 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-97:| After opening tables | 0.000030 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-97:| After opening tables | 0.000044 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-97:Uptime:                      50 min 1 sec
      10.1.33-98:| After opening tables | 0.000023 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-98:| Unlocking tables     | 0.141847 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.33-98:Uptime:                      50 min 27 sec
      10.1.33-98:| After opening tables | 0.000040 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-98:| After opening tables | 0.031896 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-98:| After opening tables | 0.000036 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-98:| After opening tables | 0.000063 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-98:Uptime:                      50 min 27 sec
      10.1.33-99:| After opening tables | 0.000041 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-99:| Unlocking tables     | 0.042536 | mysql_unlock_tables   | lock.cc      |         396 |
      10.1.33-99:Uptime:                      50 min 54 sec
      10.1.33-99:| After opening tables | 0.000045 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-99:| After opening tables | 0.000040 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-99:| After opening tables | 0.000039 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-99:| After opening tables | 0.000033 | open_tables           | sql_base.cc  |        4769 |
      10.1.33-99:Uptime:                      50 min 55 sec
      

      MariaDB [search]> show table status like 'company_search_summary_table'\G
      *************************** 1. row ***************************
                 Name: company_search_summary_table
               Engine: InnoDB
              Version: 10
           Row_format: Compact
                 Rows: 267016
       Avg_row_length: 332
          Data_length: 88719360
      Max_data_length: 0
         Index_length: 0
            Data_free: 6291456
       Auto_increment: NULL
          Create_time: 2019-05-22 16:21:40
          Update_time: NULL
           Check_time: NULL
            Collation: utf8_general_ci
             Checksum: NULL
       Create_options: 
              Comment: 
      

      This server has 140G buffer pool, on out main server with buffer pool 400G locks duration more than 3 seconds.

      Attachments

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              chernomorets Sergey Chernomorets
              Votes:
              2 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.