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

ALTER TABLE proceeds despite reporting ER_TOO_LONG_KEY error

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Fixed
    • 10.2.3
    • 10.2.6
    • Server

    Description

      How to repeat:
      1. Start server with --sql_mode='STRICT_TRANS_TABLES'
      2. Execute the following commands:

      MariaDB [test]> create table t1(a TEXT not null) ROW_FORMAT=DYNAMIC;
      Query OK, 0 rows affected (0.02 sec)
       
      MariaDB [test]> create index idx1 on t1(a(3073));
      ERROR 2013 (HY000): Lost connection to MySQL server during query
      

      Stacktrace:

      2017-02-04 21:32:18 140557726610176 [Note] InnoDB: Online DDL : Start applying row log
      2017-02-04 21:32:18 140557726610176 [Note] InnoDB: Online DDL : End of applying row log
      2017-02-04 21:32:18 140557726610176 [Note] InnoDB: Online DDL : Completed
      mysqld: /home/nirbhay/project/git-repo/mariadb/10.2/sql/sql_error.cc:380: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.
      170204 21:32:18 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.2.4-MariaDB-debug
      key_buffer_size=134217728
      read_buffer_size=131072
      max_used_connections=1
      max_threads=153
      thread_count=7
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467287 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x7fd604417070
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7fd6255d6a80 thread_stack 0x48c00
      ./bin/mysqld(my_print_stacktrace+0x38)[0x558e471ce1cb]
      addr2line: './bin/mysqld': No such file
      ./bin/mysqld(handle_fatal_signal+0x3a3)[0x558e46a3b896]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fd62390b390]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7fd622cc5428]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fd622cc702a]
      /lib/x86_64-linux-gnu/libc.so.6(+0x2dbd7)[0x7fd622cbdbd7]
      /lib/x86_64-linux-gnu/libc.so.6(+0x2dc82)[0x7fd622cbdc82]
      ./bin/mysqld(_ZN16Diagnostics_area13set_ok_statusEyyPKc+0x89)[0x558e467a7961]
      ./bin/mysqld(_Z5my_okP3THDyyPKc+0x4e)[0x558e4675cd0d]
      ./bin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2931)[0x558e468a5893]
      ./bin/mysqld(_Z21mysql_execute_commandP3THD+0x2f9a)[0x558e467d5366]
      ./bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x29d)[0x558e467e184b]
      ./bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0xf2f)[0x558e467cf6a1]
      ./bin/mysqld(_Z10do_commandP3THD+0x712)[0x558e467ce092]
      ./bin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1ca)[0x558e469165b1]
      ./bin/mysqld(handle_one_connection+0x30)[0x558e46916331]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7fd6239016ba]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fd622d9682d]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7fd604461088): create index idx1 on t1(a(3073))
      Connection ID (thread ID): 7
      Status: NOT_KILLED
       
      Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
       
      The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
      information that should help you find out what is causing the crash.
      Aborted (core dumped)
      

      Attachments

        Issue Links

          Activity

            In 10.2, ha_innobase::prepare_inplace_alter_table() is invoked with a truncated key_length (3072 instead of the requested 3073):

            (gdb) p ha_alter_info->key_info_buffer[0]
            $4 = {key_length = 3072, flags = 65576, user_defined_key_parts = 1, 
              usable_key_parts = 0, ext_key_parts = 0, ext_key_flags = 0, 
              ext_key_part_map = 0, block_size = 0, name_length = 0, 
              algorithm = HA_KEY_ALG_UNDEF, is_statistics_from_stat_tables = false, {
                parser = 0x0, parser_name = 0x0}, key_part = 0x62b0000015b0, 
              name = 0x62b000000340 "idx1", cache_name = 0x0, rec_per_key = 0x0, 
              read_stats = 0x0, collected_stats = 0x0, handler = {bdb_return_if_eq = 0}, 
              table = 0x0, comment = {str = 0x0, length = 0}, option_list = 0x0, 
              option_struct = 0x0}
            

            Had it been invoked with the correct key_length, InnoDB would have returned an error in one of these places, by invoking my_error() and returning true:

            		if (innobase_check_column_length(max_col_len, key)) {
            			my_error(ER_INDEX_COLUMN_TOO_LONG, MYF(0),
            				 max_col_len);
            			goto err_exit_no_heap;
            		}
            …
            			if (field->prefix_len > max_col_len) {
            				my_error(ER_INDEX_COLUMN_TOO_LONG, MYF(0),
            					 max_col_len);
            				goto err_exit_no_heap;
            			}
            

            Instead, ha_innobase::prepare_inplace_alter_table() and ha_innobase::inplace_alter_table() returned false, indicating success. Inside InnoDB, the index stub was created according to the supplied wrong information:

            p *m_prebuilt->table->indexes.end->fields@2
            $11 = {{col = 0x61c00004f908, name = {m_name = 0x61c00004f990 "a"}, 
                prefix_len = 3072, fixed_len = 0}, {col = 0x61c00004f914, name = {
                  m_name = 0x61c00004f992 "DB_ROW_ID"}, prefix_len = 0, fixed_len = 6}}
            

            The problem appears to be that we have

            (gdb) p thd->m_stmt_da->m_status
            $17 = Diagnostics_area::DA_ERROR
            

            already when ha_innobase::prepare_inplace_alter_table() is invoked. That is a clear error. The SQL layer should have aborted the ALTER TABLE shortly after setting the flag:

            #2  0x000055555620a402 in push_warning (thd=0x62a000078270, 
                level=Sql_condition::WARN_LEVEL_WARN, code=1071, 
                msg=0x7fffdf272ca0 "Specified key was too long; max key length is 3072 bytes") at /mariadb/server/sql/sql_error.cc:765
            #3  0x000055555620a6d6 in push_warning_printf (thd=0x62a000078270, 
                level=Sql_condition::WARN_LEVEL_WARN, code=1071, 
                format=0x63100002b5d0 "Specified key was too long; max key length is %d bytes") at /mariadb/server/sql/sql_error.cc:800
            #4  0x0000555556458dd7 in mysql_prepare_create_table (thd=0x62a000078270, 
                create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, 
                db_options=0x7fffdf273b30, file=0x62b000000db8, 
                key_info_buffer=0x7fffdf275b10, key_count=0x7fffdf275a10, 
                create_table_mode=-2) at /mariadb/server/sql/sql_table.cc:3959
            #5  0x000055555645d7c8 in mysql_create_frm_image (thd=0x62a000078270, 
                db=0x62b000000988 "test", table_name=0x62b000000348 "t1", 
                create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, 
                , key_info=0x7fffdf275b10, key_count=0x7fffdf275a10, 
                frm=0x7fffdf275b90) at /mariadb/server/sql/sql_table.cc:4634
            #6  0x000055555645eb44 in create_table_impl (thd=0x62a000078270, 
                orig_db=0x62b000000988 "test", orig_table_name=0x62b000000348 "t1", 
                db=0x62b000000988 "test", table_name=0x7fffdf276bd0 "#sql-7265_7", 
                path=0x7fffdf27743c "./test/#sql-7265_7", options=..., 
                create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, 
                create_table_mode=-2, is_trans=0x0, key_info=0x7fffdf275b10, 
                key_count=0x7fffdf275a10, frm=0x7fffdf275b90)
                at /mariadb/server/sql/sql_table.cc:4878
            #7  0x0000555556477c93 in mysql_alter_table (thd=0x62a000078270, 
                new_db=0x62b000000988 "test", new_name=0x62b000000348 "t1", 
                create_info=0x7fffdf277de0, table_list=0x62b000000380, 
                alter_info=0x7fffdf277d00, order_num=0, order=0x0, ignore=false)
                at /mariadb/server/sql/sql_table.cc:9076
            

            marko Marko Mäkelä added a comment - In 10.2, ha_innobase::prepare_inplace_alter_table() is invoked with a truncated key_length (3072 instead of the requested 3073): (gdb) p ha_alter_info->key_info_buffer[0] $4 = {key_length = 3072, flags = 65576, user_defined_key_parts = 1, usable_key_parts = 0, ext_key_parts = 0, ext_key_flags = 0, ext_key_part_map = 0, block_size = 0, name_length = 0, algorithm = HA_KEY_ALG_UNDEF, is_statistics_from_stat_tables = false, { parser = 0x0, parser_name = 0x0}, key_part = 0x62b0000015b0, name = 0x62b000000340 "idx1", cache_name = 0x0, rec_per_key = 0x0, read_stats = 0x0, collected_stats = 0x0, handler = {bdb_return_if_eq = 0}, table = 0x0, comment = {str = 0x0, length = 0}, option_list = 0x0, option_struct = 0x0} Had it been invoked with the correct key_length, InnoDB would have returned an error in one of these places, by invoking my_error() and returning true: if (innobase_check_column_length(max_col_len, key)) { my_error(ER_INDEX_COLUMN_TOO_LONG, MYF(0), max_col_len); goto err_exit_no_heap; } … if (field->prefix_len > max_col_len) { my_error(ER_INDEX_COLUMN_TOO_LONG, MYF(0), max_col_len); goto err_exit_no_heap; } Instead, ha_innobase::prepare_inplace_alter_table() and ha_innobase::inplace_alter_table() returned false, indicating success. Inside InnoDB, the index stub was created according to the supplied wrong information: p *m_prebuilt->table->indexes.end->fields@2 $11 = {{col = 0x61c00004f908, name = {m_name = 0x61c00004f990 "a"}, prefix_len = 3072, fixed_len = 0}, {col = 0x61c00004f914, name = { m_name = 0x61c00004f992 "DB_ROW_ID"}, prefix_len = 0, fixed_len = 6}} The problem appears to be that we have (gdb) p thd->m_stmt_da->m_status $17 = Diagnostics_area::DA_ERROR already when ha_innobase::prepare_inplace_alter_table() is invoked. That is a clear error. The SQL layer should have aborted the ALTER TABLE shortly after setting the flag: #2 0x000055555620a402 in push_warning (thd=0x62a000078270, level=Sql_condition::WARN_LEVEL_WARN, code=1071, msg=0x7fffdf272ca0 "Specified key was too long; max key length is 3072 bytes") at /mariadb/server/sql/sql_error.cc:765 #3 0x000055555620a6d6 in push_warning_printf (thd=0x62a000078270, level=Sql_condition::WARN_LEVEL_WARN, code=1071, format=0x63100002b5d0 "Specified key was too long; max key length is %d bytes") at /mariadb/server/sql/sql_error.cc:800 #4 0x0000555556458dd7 in mysql_prepare_create_table (thd=0x62a000078270, create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, db_options=0x7fffdf273b30, file=0x62b000000db8, key_info_buffer=0x7fffdf275b10, key_count=0x7fffdf275a10, create_table_mode=-2) at /mariadb/server/sql/sql_table.cc:3959 #5 0x000055555645d7c8 in mysql_create_frm_image (thd=0x62a000078270, db=0x62b000000988 "test", table_name=0x62b000000348 "t1", create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, , key_info=0x7fffdf275b10, key_count=0x7fffdf275a10, frm=0x7fffdf275b90) at /mariadb/server/sql/sql_table.cc:4634 #6 0x000055555645eb44 in create_table_impl (thd=0x62a000078270, orig_db=0x62b000000988 "test", orig_table_name=0x62b000000348 "t1", db=0x62b000000988 "test", table_name=0x7fffdf276bd0 "#sql-7265_7", path=0x7fffdf27743c "./test/#sql-7265_7", options=..., create_info=0x7fffdf277de0, alter_info=0x7fffdf277d00, create_table_mode=-2, is_trans=0x0, key_info=0x7fffdf275b10, key_count=0x7fffdf275a10, frm=0x7fffdf275b90) at /mariadb/server/sql/sql_table.cc:4878 #7 0x0000555556477c93 in mysql_alter_table (thd=0x62a000078270, new_db=0x62b000000988 "test", new_name=0x62b000000348 "t1", create_info=0x7fffdf277de0, table_list=0x62b000000380, alter_info=0x7fffdf277d00, order_num=0, order=0x0, ignore=false) at /mariadb/server/sql/sql_table.cc:9076

            I cannot repeat it with the latest 10.2.5, must've been fixed meanwhile.

            serg Sergei Golubchik added a comment - I cannot repeat it with the latest 10.2.5, must've been fixed meanwhile.

            It still crashes for me:

            --source include/have_innodb.inc
            SET SQL_MODE='STRICT_TRANS_TABLES';
             
            CREATE TABLE t1(a TEXT NOT NULL) ENGINE=InnoDB ROW_FORMAT=DYNAMIC DEFAULT CHARSET latin1;
            CREATE INDEX idx1 ON t1(a(3073));
            DROP TABLE t1;
            

            with the following assertion failure in CREATE INDEX:

            sql/sql_error.cc:381: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.
            

            marko Marko Mäkelä added a comment - It still crashes for me: --source include/have_innodb.inc SET SQL_MODE='STRICT_TRANS_TABLES';   CREATE TABLE t1(a TEXT NOT NULL) ENGINE=InnoDB ROW_FORMAT=DYNAMIC DEFAULT CHARSET latin1; CREATE INDEX idx1 ON t1(a(3073)); DROP TABLE t1; with the following assertion failure in CREATE INDEX: sql/sql_error.cc:381: void Diagnostics_area::set_ok_status(ulonglong, ulonglong, const char*): Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed.

            The fix (issuing a note for a truncated column prefix instead of a warning or error) caused a result difference for the test innodb.innodb_mysql:

            CURRENT_TEST: innodb.innodb_mysql
            --- /mariadb/10.2/mysql-test/suite/innodb/r/innodb_mysql.result	2017-03-30 14:33:52.956081571 +0300
            +++ /mariadb/10.2/mysql-test/suite/innodb/r/innodb_mysql.reject	2017-04-17 03:14:01.995075307 +0300
            @@ -1547,7 +1547,7 @@
             set statement sql_mode = 'NO_ENGINE_SUBSTITUTION' for
             alter table t1 add index(a(1024));
             Warnings:
            -Warning	1071	Specified key was too long; max key length is 767 bytes
            +Note	1071	Specified key was too long; max key length is 767 bytes
             show create table t1;
             Table	Create Table
             t1	CREATE TABLE `t1` (
            

            I fixed that by re-recording the result.
            I do not fully agree with this change in behaviour. Not issuing a warning during DDL may cause surprises or break replication to older versions:

            • For UNIQUE INDEX, INSERT or UPDATE may unexpectedly fail due to duplicate key error (when the originally specified key prefix is unique, but the truncated one is not)
            • For all indexes, LIKE 'prefix%' may unexpectedly skip the index when the prefix is longer than what the index was truncated to, but not longer than what was specified.
            • When older-version replication slaves are running in strict mode, they would refuse the DDL operation, instead of silently changing the table schema.
            marko Marko Mäkelä added a comment - The fix (issuing a note for a truncated column prefix instead of a warning or error) caused a result difference for the test innodb.innodb_mysql: CURRENT_TEST: innodb.innodb_mysql --- /mariadb/10.2/mysql-test/suite/innodb/r/innodb_mysql.result 2017-03-30 14:33:52.956081571 +0300 +++ /mariadb/10.2/mysql-test/suite/innodb/r/innodb_mysql.reject 2017-04-17 03:14:01.995075307 +0300 @@ -1547,7 +1547,7 @@ set statement sql_mode = 'NO_ENGINE_SUBSTITUTION' for alter table t1 add index(a(1024)); Warnings: -Warning 1071 Specified key was too long; max key length is 767 bytes +Note 1071 Specified key was too long; max key length is 767 bytes show create table t1; Table Create Table t1 CREATE TABLE `t1` ( I fixed that by re-recording the result. I do not fully agree with this change in behaviour. Not issuing a warning during DDL may cause surprises or break replication to older versions: For UNIQUE INDEX, INSERT or UPDATE may unexpectedly fail due to duplicate key error (when the originally specified key prefix is unique, but the truncated one is not) For all indexes, LIKE 'prefix%' may unexpectedly skip the index when the prefix is longer than what the index was truncated to, but not longer than what was specified. When older-version replication slaves are running in strict mode, they would refuse the DDL operation, instead of silently changing the table schema.

            marko, the index is never truncated for UNIQUE indexes, that would change the semantics of the constraint. But a non-UNIQUE index is merely a non-standard optimization technique, it does not affect correctness of results. The message should've always been a note, it's never an error to truncate a non-unique index.

            The case with LIKE 'prefix%' with a 3072-byte long prefix is technically possible, but practically unlikely. Anyway, I think that LIKE should be able to use the index in cases when the index length is smaller than the prefix length.

            serg Sergei Golubchik added a comment - marko , the index is never truncated for UNIQUE indexes, that would change the semantics of the constraint. But a non-UNIQUE index is merely a non-standard optimization technique, it does not affect correctness of results. The message should've always been a note, it's never an error to truncate a non-unique index. The case with LIKE 'prefix%' with a 3072-byte long prefix is technically possible, but practically unlikely. Anyway, I think that LIKE should be able to use the index in cases when the index length is smaller than the prefix length.

            People

              serg Sergei Golubchik
              nirbhay_c Nirbhay Choubey (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.