Assertion `inited == INDEX' failed.

[Roel Van de Paar]

mysqld: /git/PS-5.7.19_dbg/sql/handler.cc:3226: int handler::ha_index_read_map(uchar*, const uchar*, key_part_map, ha_rkey_function): Assertion `inited == INDEX' failed.

Core was generated by `/sda/PS240817-percona-server-5.7.19-17-linux-x86_64-debug/bin/mysqld --no-defau'.
Program terminated with signal 6, Aborted.
#0 0x00007f1a428ee741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61 val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) t
[Current thread is 1 (Thread 0x7f1a42eda700 (LWP 31553))]
(gdb) bt
#0 0x00007f1a428ee741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1 0x0000000001862e06 in my_write_core (sig=6) at /git/PS-5.7.19_dbg/mysys/stacktrace.c:249
#2 0x0000000000e8a2af in handle_fatal_signal (sig=6) at /git/PS-5.7.19_dbg/sql/signal_handler.cc:223
#3 <signal handler called>
#4 0x00007f1a40c821d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5 0x00007f1a40c838c8 in __GI_abort () at abort.c:90
#6 0x00007f1a40c7b146 in __assert_fail_base (fmt=0x7f1a40dcc3a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0x1ddb0fd "inited == INDEX", file=file@entry=0x1dda1f0 "/git/PS-5.7.19_dbg/sql/handler.cc",
    line=line@entry=3226,
    function=function@entry=0x1ddd720 <handler::ha_index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function)::__PRETTY_FUNCTION__> "int handler::ha_index_read_map(uchar*, const uchar*, key_part_map, ha_rkey_function)") at assert.c:92
#7 0x00007f1a40c7b1f2 in __GI___assert_fail (assertion=0x1ddb0fd "inited == INDEX",
    file=0x1dda1f0 "/git/PS-5.7.19_dbg/sql/handler.cc", line=3226,
    function=0x1ddd720 <handler::ha_index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function)::__PRETTY_FUNCTION__> "int handler::ha_index_read_map(uchar*, const uchar*, key_part_map, ha_rkey_function)") at assert.c:101
#8 0x0000000000f1c641 in handler::ha_index_read_map (this=0x7f19cdc2a830, buf=0x7f19cdefe040 "\377\376",
    key=0x7f19cdef2032 "tW\267\255)\016\232\207\005", keypart_map=18446744073709551615, find_flag=HA_READ_KEY_EXACT)
    at /git/PS-5.7.19_dbg/sql/handler.cc:3226
#9 0x00000000014e8190 in check_unique_constraint (table=0x7f19ce171030) at /git/PS-5.7.19_dbg/sql/sql_executor.cc:3333
#10 0x00000000014e1c35 in end_sj_materialize (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a4a0, end_of_records=false)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:622
#11 0x00000000014e3cad in evaluate_join_record (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a328)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1639
#12 0x00000000014e30ed in sub_select (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a328, end_of_records=false)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1291
#13 0x00000000014e6007 in join_materialize_semijoin (tab=0x7f19cdc7a1b0) at /git/PS-5.7.19_dbg/sql/sql_executor.cc:2533
#14 0x00000000014e31cd in QEP_TAB::prepare_scan (this=0x7f19cdc7a1b0) at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1325
#15 0x00000000014e2d2f in sub_select_op (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a1b0, end_of_records=false)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1068
#16 0x00000000014e3cad in evaluate_join_record (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a038)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1639
#17 0x00000000014e30ed in sub_select (join=0x7f19cdcf8828, qep_tab=0x7f19cdc7a038, end_of_records=false)
    at /git/PS-5.7.19_dbg/sql/sql_executor.cc:1291
#18 0x00000000014e296e in do_select (join=0x7f19cdcf8828) at /git/PS-5.7.19_dbg/sql/sql_executor.cc:944
#19 0x00000000014e08ef in JOIN::exec (this=0x7f19cdcf8828) at /git/PS-5.7.19_dbg/sql/sql_executor.cc:199
#20 0x000000000157d9b9 in handle_query (thd=0x7f19cdc12000, lex=0x7f19cdc145e8, result=0x7f19cdf3fd38, added_options=0,
    removed_options=0) at /git/PS-5.7.19_dbg/sql/sql_select.cc:185
#21 0x00000000015313fc in execute_sqlcom_select (thd=0x7f19cdc12000, all_tables=0x7f19cdf3f268)
#22 0x000000000152a551 in mysql_execute_command (thd=0x7f19cdc12000, first_level=true) at /git/PS-5.7.19_dbg/sql/sql_parse.cc:2942
#23 0x0000000001532408 in mysql_parse (thd=0x7f19cdc12000, parser_state=0x7f1a42ed94e0) at /git/PS-5.7.19_dbg/sql/sql_parse.cc:5891
#24 0x0000000001526fe7 in dispatch_command (thd=0x7f19cdc12000, com_data=0x7f1a42ed9c90, command=COM_QUERY)
    at /git/PS-5.7.19_dbg/sql/sql_parse.cc:1493
#25 0x0000000001525e2d in do_command (thd=0x7f19cdc12000) at /git/PS-5.7.19_dbg/sql/sql_parse.cc:1021
#26 0x000000000166583a in handle_connection (arg=0x7f19cdc11040)
    at /git/PS-5.7.19_dbg/sql/conn_handler/connection_handler_per_thread.cc:312
#27 0x00000000018919e5 in pfs_spawn_thread (arg=0x7f1a34fec520) at /git/PS-5.7.19_dbg/storage/perfschema/pfs.cc:2188
#28 0x00007f1a428e9dc5 in start_thread (arg=0x7f1a42eda700) at pthread_create.c:308
#29 0x00007f1a40d4473d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

# mysqld options required for replay: --sql_mode=
DROP DATABASE test; CREATE DATABASE test; USE test;
SET @@join_buffer_size=8192;
SET @@tmp_table_size=1024;
CREATE TABLE t1(a NATIONAL VARCHAR(16382)) ROW_FORMAT=COMPRESSED ENGINE=InnoDB;
INSERT INTO t1 VALUES(0xA7FB);
INSERT INTO t1 VALUES('a');
INSERT INTO t1 VALUES(22387);
SELECT * FROM t1 WHERE a IN(SELECT * FROM t1);

[Roel Van de Paar (roel11)]

Discussed with Laurynas. Changing the testcase to (only last line changed);
SELECT SQL_BIG_RESULT * FROM (SELECT * FROM t1) AS ta;
Does not crash.

His conclusion;
1) not a showstopper but High triage
2) likely not upstream
3) it’s a MEMORY engine VARCHAR patch, default config will not hit easily (max tmp table size of 1KB) with several workarounds

[Roel Van de Paar (roel11)]

Also see https://bugs.mysql.com/bug.php?id=75690

[Oleg Smirnov (olernov)]

Looks like upstream violates tmp_table_size setting since it does not have this check in heap_write function (hp_write.c) that Percona server has:

 if ((share->records >= share->max_records && share->max_records) ||
      (share->recordspace.total_data_length + share->index_length >=
       share->max_table_size))
  {
    set_my_errno(HA_ERR_RECORD_FILE_FULL);
    DBUG_RETURN(HA_ERR_RECORD_FILE_FULL);
  }

Adding such check to upstream makes it crash the same way as Percona does on DBUG_ASSERT(inited == INDEX) at handler::ha_index_read_map (handler.cc). Disabling the check in Percona prevents crash accordingly.

MySQL manual says: "If an in-memory temporary table exceeds the limit, MySQL automatically converts it to an on-disk temporary table." Actually looks like only Percona does, not MySQL.
After that something wrong happens (maybe the table is still being treated as a heap table), I cannot figure it out yet.

Could it be the subject for upstream bug report?

[Laurynas Biveinis (laurynas-biveinis)]

Oleg - the MySQL manual remark on memory-to-disk conversion only applies to the internal temp tables used by query optimizer, not CREATE TEMPORARY TABLE user ones.

[Laurynas Biveinis (laurynas-biveinis)]

Still seen on 5.7 at 0e607234423

[Oleg Smirnov (olernov)]

But here is exactly that case: internal temp table exceeds tmp_table_size but MySQL server increases it and does not convert to on-disk.

What about the bug fix, please look at https://github.com/percona/percona-server/pull/1979.
As I can see from mysqld.trace when executing the query server performs join_materialize_semijoin, creates temp heap table and initializes index access on it. Then at end_sj_materialize stage size of this table is exceeded and the table is converted to on-disk. After this conversion no index initialization is done though there is a note on create_ondisk_from_heap function:
  @note that any index/scan access initialized on the MEMORY table is not
  replicated to the on-disk table - it's the caller's responsibility.
The patch adds ha_index_init call after create_ondisk_from_heap.

The code is duplicated but I don't know how to avoid it with minimal changes to codebase.

[Laurynas Biveinis (laurynas-biveinis)]

Oleg - the upstream has a corresponding check in next_free_record_pos in hp_write.c - does it change anything?

[Oleg Smirnov (olernov)]

Laurynas, you're right. Size evaluation exists but upstream does it only when allocating new blocks, not for every record. So a slightly different test case needed to reproduce the crash on upstream:

CREATE TABLE t1(a VARCHAR(16382));
insert into t1 values ('111');
insert into t1 values ('222');
insert into t1 values ('333');
insert into t1 values ('444');
insert into t1 values ('555');
insert into t1 values ('666');
insert into t1 values ('777');
insert into t1 values ('888');
insert into t1 values ('999');
insert into t1 values ('000');
SET @@tmp_table_size=1024;
SET @@join_buffer_size=8192;
SELECT * FROM t1 WHERE a IN(SELECT * FROM t1);

[Laurynas Biveinis (laurynas-biveinis)]

Ack - if you decide to file an upstream bug, please post its link here

[Oleg Smirnov (olernov)]

https://bugs.mysql.com/bug.php?id=88601

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1114