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

Assertion `Handlerton: error == 0 ' fails on concurrent ALTER and ANALYZE on TokuDB table

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 5.5.36, 10.0.8
    • Fix Version/s: 5.5.38, 10.0.11
    • Component/s: None
    • Labels:

      Description

      Version: '10.0.8-MariaDB-debug-log'  socket: 'mysql.sock'  port: 19300  Source distribution
      10.0/storage/tokudb/tokudb_card.h:122 set_card_in_status: Assertion `Handlerton: error == 0 ' failed (errno=2)
      : No such file or directory
      Backtrace: (Note: toku_do_assert=0x0x7f6250928cc7)
      
      # 2014-02-10T23:11:17 [27290] #6  0x00007f6250928a40 in toku_do_backtrace_abort () at 10.0/storage/tokudb/ft-index/portability/toku_assert.cc:191
      # 2014-02-10T23:11:17 [27290] #7  0x00007f6250928b2f in toku_do_assert_fail (expr_as_string=0x7f623e769d90 "Handlerton: error == 0 ", function=0x7f625096ba40 "set_card_in_status", file=0x7f6250965038 "10.0/storage/tokudb/tokudb_card.h", line=122, caller_errno=2) at 10.0/storage/tokudb/ft-index/portability/toku_assert.cc:212
      # 2014-02-10T23:11:17 [27290] #8  0x00007f625084975d in env_crash (db_env=0x7f6279c25d80, msg=0x7f623e769d90 "Handlerton: error == 0 ", fun=0x7f625096ba40 "set_card_in_status", file=0x7f6250965038 "10.0/storage/tokudb/tokudb_card.h", line=122, caller_errno=2) at 10.0/storage/tokudb/ft-index/src/ydb.cc:2236
      # 2014-02-10T23:11:17 [27290] #9  0x00007f6250837e1f in toku_hton_assert_fail (expr_as_string=0x7f625096508e "error == 0", fun=0x7f625096ba40 "set_card_in_status", file=0x7f6250965038 "10.0/storage/tokudb/tokudb_card.h", line=122, caller_errno=2) at 10.0/storage/tokudb/hatoku_hton.cc:196
      # 2014-02-10T23:11:17 [27290] #10 0x00007f625080ea3c in tokudb::set_card_in_status (status_db=0x7f623fb6d540, txn=0x7f6240022800, rec_per_keys=5, rec_per_key=0x7f623e76a230) at 10.0/storage/tokudb/tokudb_card.h:122
      # 2014-02-10T23:11:17 [27290] #11 0x00007f6250827954 in ha_tokudb::analyze (this=0x7f6240076088, thd=0x7f6256e50070, check_opt=0x7f6256e54b60) at 10.0/storage/tokudb/ha_tokudb_admin.cc:169
      # 2014-02-10T23:11:17 [27290] #12 0x000000000085c8f1 in handler::ha_analyze (this=0x7f6240076088, thd=0x7f6256e50070, check_opt=0x7f6256e54b60) at 10.0/sql/handler.cc:4002
      # 2014-02-10T23:11:17 [27290] #13 0x00000000007944de in mysql_admin_table(THD *, TABLE_LIST *, HA_CHECK_OPT *, const char *, thr_lock_type, bool, bool, uint, int (*)(THD *, TABLE_LIST *, HA_CHECK_OPT *), struct {...}, int (*)(THD *, TABLE_LIST *)) (thd=0x7f6256e50070, tables=0x7f6240026168, check_opt=0x7f6256e54b60, operator_name=0x102806f "analyze", lock_type=TL_READ_NO_INSERT, open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0, operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x85c870 <handler::ha_analyze(THD*, st_ha_check_opt*)>, view_operator_func=0) at 10.0/sql/sql_admin.cc:722
      # 2014-02-10T23:11:17 [27290] #14 0x0000000000795ac3 in Sql_cmd_analyze_table::execute (this=0x7f6240026740, thd=0x7f6256e50070) at 10.0/sql/sql_admin.cc:1134
      # 2014-02-10T23:11:17 [27290] #15 0x0000000000673e5b in mysql_execute_command (thd=0x7f6256e50070) at 10.0/sql/sql_parse.cc:5104
      # 2014-02-10T23:11:17 [27290] #16 0x0000000000676f6b in mysql_parse (thd=0x7f6256e50070, rawbuf=0x7f6240026088 "ANALYZE TABLE `t1`", length=18, parser_state=0x7f623e76b630) at 10.0/sql/sql_parse.cc:6447
      # 2014-02-10T23:11:17 [27290] #17 0x0000000000669d39 in dispatch_command (command=COM_QUERY, thd=0x7f6256e50070, packet=0x7f6256e56071 "", packet_length=18) at 10.0/sql/sql_parse.cc:1308
      # 2014-02-10T23:11:17 [27290] #18 0x00000000006690db in do_command (thd=0x7f6256e50070) at 10.0/sql/sql_parse.cc:1005
      # 2014-02-10T23:11:17 [27290] #19 0x0000000000783341 in do_handle_one_connection (thd_arg=0x7f6256e50070) at 10.0/sql/sql_connect.cc:1379
      # 2014-02-10T23:11:17 [27290] #20 0x0000000000783094 in handle_one_connection (arg=0x7f6256e50070) at 10.0/sql/sql_connect.cc:1293
      # 2014-02-10T23:11:17 [27290] #21 0x0000000000aab59d in pfs_spawn_thread (arg=0x7f6256be3c10) at 10.0/storage/perfschema/pfs.cc:1853
      # 2014-02-10T23:11:17 [27290] #22 0x00007f627bc87b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
      # 2014-02-10T23:11:17 [27290] #23 0x00007f627a7d6a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
      
      revision-id: knielsen@knielsen-hq.org-20140210141217-2cfvmgwxoqfybhc2
      revno: 3995
      branch-nick: 10.0
      

      RQG grammar:

      query_init:
         CREATE TABLE IF NOT EXISTS t1 (
            `pk` INT AUTO_INCREMENT PRIMARY KEY, 
            `a` BIGINT, `b` VARCHAR(64), `c` SMALLINT, `d` VARCHAR(10), `e` BIGINT, 
            INDEX(`b`), INDEX(`c`), INDEX(`d`), INDEX(`e`)
         ) ENGINE=TokuDB
       ; INSERT INTO t1 VALUES 
         (NULL, 0, 'Texas', 0, 'Alabama', -5),(NULL, 8, 'Florida', 2, 'Arizona', 6),
         (NULL, -9, 'Ohio', -2, 'Nevada', 4),(NULL, 1, 'Georgia', NULL, 'Florida', NULL),
         (NULL, 5, 'New Hampshire', 2, 'Kentucky', 0),(NULL, NULL, 'Colorado', 5, 'Ohio', 9),
         (NULL, 2, 'Alaska', 58728, 'Arizona', 5),(NULL, 8, 'Florida', 7, 'Oklahoma', -4)
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`
       ; INSERT INTO `t1` SELECT NULL,`a`,`b`,`c`,`d`,`e` FROM `t1`; 
      
      query:
      	ANALYZE TABLE `t1`;
      
      thread1:
      	ALTER TABLE `t1` ADD KEY `key1` (`pk`,`a`) | ALTER TABLE `t1` DROP KEY `key1`;
      
      

      Command line (assuming the server is running on port 3306 with plugin-load=ha_tokudb):
      perl ./gentest.pl --grammar=mdev5646.yy --dsn=dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test --threads=2 --queries=100M --duration=300

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            serg Sergei Golubchik added a comment -

            Sorry, I cannot repeat that, tried many times, both with debug and optimized builds.

            Show
            serg Sergei Golubchik added a comment - Sorry, I cannot repeat that, tried many times, both with debug and optimized builds.
            Hide
            elenst Elena Stepanova added a comment -

            I've installed cmake 2.8.12 and gcc 4.8.1 on perro, pulled the recent 10.0 tree, recompiled with TokuDB.
            Hope now it will be possible to debug on perro.
            Here is the new stack trace from revno 4017:

            #5  0x00007f50c45ecb8b in __GI_abort () at abort.c:91
            #6  0x00007f50a2928a0c in toku_do_backtrace_abort() () from 10.0/storage/tokudb/ha_tokudb.so
            #7  0x00007f50a2928b0a in toku_do_assert_fail(char const*, char const*, char const*, int, int) () from 10.0/storage/tokudb/ha_tokudb.so
            #8  0x00007f50a2845307 in env_crash(__toku_db_env*, char const*, char const*, char const*, int, int) () at 10.0/storage/tokudb/ft-index/src/ydb.cc:2236
            #9  0x00007f50a283319b in toku_hton_assert_fail(char const*, char const*, char const*, int, int) () at 10.0/storage/tokudb/hatoku_hton.cc:196
            #10 0x00007f50a2809149 in tokudb::set_card_in_status(__toku_db*, __toku_db_txn*, unsigned int, unsigned long*) () at 10.0/storage/tokudb/tokudb_card.h:122
            #11 0x00007f50a2822981 in ha_tokudb::analyze(THD*, st_ha_check_opt*) () at 10.0/storage/tokudb/ha_tokudb_admin.cc:169
            #12 0x00000000008512c5 in handler::ha_analyze(THD*, st_ha_check_opt*) () at 10.0/sql/handler.cc:4006
            #13 0x0000000000784712 in mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*)) () at 10.0/sql/sql_admin.cc:722
            #14 0x0000000000785e90 in Sql_cmd_analyze_table::execute(THD*) () at 10.0/sql/sql_admin.cc:1134
            #15 0x000000000065996c in mysql_execute_command(THD*) () at 10.0/sql/sql_parse.cc:5104
            #16 0x000000000065ca88 in mysql_parse(THD*, char*, unsigned int, Parser_state*) () at 10.0/sql/sql_parse.cc:6447
            #17 0x000000000064f581 in dispatch_command(enum_server_command, THD*, char*, unsigned int) () at 10.0/sql/sql_parse.cc:1308
            #18 0x000000000064e8dc in do_command(THD*) () at 10.0/sql/sql_parse.cc:1005
            #19 0x0000000000772cfa in do_handle_one_connection(THD*) () at 10.0/sql/sql_connect.cc:1379
            #20 0x0000000000772a60 in handle_one_connection () at 10.0/sql/sql_connect.cc:1293
            #21 0x0000000000dc4e47 in pfs_spawn_thread () at 10.0/storage/perfschema/pfs.cc:1853
            #22 0x00007f50c57a3e9a in start_thread (arg=0x7f50c6325700) at pthread_create.c:308
            #23 0x00007f50c46a6cbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
            

            It was also reproducible on my local Wheezy.
            I'm not sure why it doesn't fail on your machine, but I think TokuDB is very sensitive to the environment, so it doesn't sound very surprising.

            Show
            elenst Elena Stepanova added a comment - I've installed cmake 2.8.12 and gcc 4.8.1 on perro, pulled the recent 10.0 tree, recompiled with TokuDB. Hope now it will be possible to debug on perro. Here is the new stack trace from revno 4017: #5 0x00007f50c45ecb8b in __GI_abort () at abort.c:91 #6 0x00007f50a2928a0c in toku_do_backtrace_abort() () from 10.0/storage/tokudb/ha_tokudb.so #7 0x00007f50a2928b0a in toku_do_assert_fail(char const*, char const*, char const*, int, int) () from 10.0/storage/tokudb/ha_tokudb.so #8 0x00007f50a2845307 in env_crash(__toku_db_env*, char const*, char const*, char const*, int, int) () at 10.0/storage/tokudb/ft-index/src/ydb.cc:2236 #9 0x00007f50a283319b in toku_hton_assert_fail(char const*, char const*, char const*, int, int) () at 10.0/storage/tokudb/hatoku_hton.cc:196 #10 0x00007f50a2809149 in tokudb::set_card_in_status(__toku_db*, __toku_db_txn*, unsigned int, unsigned long*) () at 10.0/storage/tokudb/tokudb_card.h:122 #11 0x00007f50a2822981 in ha_tokudb::analyze(THD*, st_ha_check_opt*) () at 10.0/storage/tokudb/ha_tokudb_admin.cc:169 #12 0x00000000008512c5 in handler::ha_analyze(THD*, st_ha_check_opt*) () at 10.0/sql/handler.cc:4006 #13 0x0000000000784712 in mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*)) () at 10.0/sql/sql_admin.cc:722 #14 0x0000000000785e90 in Sql_cmd_analyze_table::execute(THD*) () at 10.0/sql/sql_admin.cc:1134 #15 0x000000000065996c in mysql_execute_command(THD*) () at 10.0/sql/sql_parse.cc:5104 #16 0x000000000065ca88 in mysql_parse(THD*, char*, unsigned int, Parser_state*) () at 10.0/sql/sql_parse.cc:6447 #17 0x000000000064f581 in dispatch_command(enum_server_command, THD*, char*, unsigned int) () at 10.0/sql/sql_parse.cc:1308 #18 0x000000000064e8dc in do_command(THD*) () at 10.0/sql/sql_parse.cc:1005 #19 0x0000000000772cfa in do_handle_one_connection(THD*) () at 10.0/sql/sql_connect.cc:1379 #20 0x0000000000772a60 in handle_one_connection () at 10.0/sql/sql_connect.cc:1293 #21 0x0000000000dc4e47 in pfs_spawn_thread () at 10.0/storage/perfschema/pfs.cc:1853 #22 0x00007f50c57a3e9a in start_thread (arg=0x7f50c6325700) at pthread_create.c:308 #23 0x00007f50c46a6cbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112 It was also reproducible on my local Wheezy. I'm not sure why it doesn't fail on your machine, but I think TokuDB is very sensitive to the environment, so it doesn't sound very surprising.
            Hide
            prohaska7 Rich Prohaska added a comment - - edited

            We reproduced the problem at Tokutek on 10.0.9. It exists on all other TokuDB versions. I created an issue in our bug tracking system:https://github.com/Tokutek/mariadb/issues/50
            Both the analyze and alter add index need to write the cardinality data for the table. Only one can succeed.

            Show
            prohaska7 Rich Prohaska added a comment - - edited We reproduced the problem at Tokutek on 10.0.9. It exists on all other TokuDB versions. I created an issue in our bug tracking system: https://github.com/Tokutek/mariadb/issues/50 Both the analyze and alter add index need to write the cardinality data for the table. Only one can succeed.
            Hide
            prohaska7 Rich Prohaska added a comment -

            Fixed on Tokutek's github ft-engine master branch.
            https://github.com/Tokutek/ft-engine/commit/a95eb9505dfe28d538ff0020a33e164fa241bab1
            Will be rolled into tokudb 7.1.6.

            Show
            prohaska7 Rich Prohaska added a comment - Fixed on Tokutek's github ft-engine master branch. https://github.com/Tokutek/ft-engine/commit/a95eb9505dfe28d538ff0020a33e164fa241bab1 Will be rolled into tokudb 7.1.6.
            Hide
            prohaska7 Rich Prohaska added a comment -

            Fixed in tokudb 7.1.6

            Show
            prohaska7 Rich Prohaska added a comment - Fixed in tokudb 7.1.6

              People

              • Assignee:
                serg Sergei Golubchik
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: