crash on internal temporary table creating error

Bug #1353115 reported by Vlad Lesin
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
New
Undecided
Vlad Lesin
5.6
New
Undecided
Vlad Lesin
5.7
New
Undecided
Vlad Lesin

Bug Description

Here is initial backtrace:

=====
#0 __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1 0x0000000000644c7f in handle_fatal_signal (sig=11)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/signal_handler.cc:254
#2 <signal handler called>
#3 handler::ha_statistic_increment (this=0x7ecb85645810, offset=&system_status_var::ha_write_count)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/handler.cc:2612
#4 0x00000000008a47b7 in ha_myisam::write_row (this=0x7ecb85645810, buf=0x7ecd0b664010 "")
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/storage/myisam/ha_myisam.cc:815
#5 0x00000000005a6057 in handler::ha_write_row (this=0x7ecb85645810, buf=0x7ecd0b664010 "")
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/handler.cc:7639
#6 0x00000000006a0b09 in end_write (join=0x7ecd7da77540, join_tab=0x7ecda1b3b8d8, end_of_records=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:3002
#7 0x000000000069ce56 in evaluate_join_record (join=join@entry=0x7ecd7da77540, join_tab=join_tab@entry=0x7ecda1b3b5d8)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1601
#8 0x000000000069d132 in sub_select (join=0x7ecd7da77540, join_tab=0x7ecda1b3b5d8, end_of_records=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1276
#9 0x000000000069ce56 in evaluate_join_record (join=join@entry=0x7ecd7da77540, join_tab=join_tab@entry=0x7ecda1b3b2d8)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1601
#10 0x000000000069d132 in sub_select (join=0x7ecd7da77540, join_tab=0x7ecda1b3b2d8, end_of_records=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1276
#11 0x000000000069be66 in do_select (join=0x7ecd7da77540)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:933
#12 JOIN::exec (this=0x7ecd7da77540)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:194
#13 0x00000000006df1c5 in mysql_execute_select (free_join=true, select_lex=0x7ecf7d4cec08, thd=0x7ecf7d4cc000)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:1101
#14 mysql_select (thd=thd@entry=0x7ecf7d4cc000, tables=0x7ecd7d80a4c8, wild_num=1, fields=..., conds=<optimized out>,
    order=order@entry=0x7ecf7d4cedd0, group=group@entry=0x7ecf7d4ced08, having=0x0, select_options=2147781376,
    result=result@entry=0x7ecd7da77518, unit=0x7ecf7d4ce5c0, select_lex=select_lex@entry=0x7ecf7d4cec08)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:1222
#15 0x00000000006df465 in handle_select (thd=0x7ecf7d4cc000, result=0x7ecd7da77518, setup_tables_done_option=0)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:111
#16 0x000000000056c01f in execute_sqlcom_select (thd=thd@entry=0x7ecf7d4cc000, all_tables=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_parse.cc:5570
#17 0x00000000006bdc52 in mysql_execute_command (thd=thd@entry=0x7ecf7d4cc000)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_parse.cc:2955
#18 0x00000000006c01d8 in mysql_parse (thd=thd@entry=0x7ecf7d4cc000, rawbuf=<optimized out>, length=<optimized out>,
    parser_state=parser_state@entry=0x7ecea2b54220)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_parse.cc:6746
#19 0x00000000006c169b in dispatch_command (command=COM_QUERY, thd=0x7ecf7d4cc000, packet=0x7ecf7d4d0001 "", packet_length=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_parse.cc:1434
#20 0x00000000006934fd in do_handle_one_connection (thd_arg=thd_arg@entry=0x7ecf7d4cc000)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_connect.cc:1532
#21 0x0000000000693582 in handle_one_connection (arg=arg@entry=0x7ecf7d4cc000)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_connect.cc:1443
#22 0x0000000000add1d0 in pfs_spawn_thread (arg=0x7ecbb5369ac0)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/storage/perfschema/pfs.cc:1860
#23 0x00007f0577472e9a in start_thread (arg=0x7ecea2b55700) at pthread_create.c:308
#24 0x00007f0576ba33fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#25 0x0000000000000000 in ?? ()
=====

As it can be seen the crash happens during attempt to update MyISAM statistics on row writing. The following code updates statistics:

void handler::ha_statistic_increment(ulonglong SSV::*offset) const
{
  status_var_increment(table->in_use->status_var.*offset);
}

As we can see the code use handler::table pointer which is null:

=====
(gdb) fr 3
#3 handler::ha_statistic_increment (this=0x7ecb85645810, offset=&system_status_var::ha_write_count)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/handler.cc:2612
2612 /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/handler.cc: No such file or directory.
(gdb) p table
$51 = (TABLE *) 0x0
=====

Let's try to find out something about the table:

=====
(gdb) fr 6
#6 0x00000000006a0b09 in end_write (join=0x7ecd7da77540, join_tab=0x7ecda1b3b8d8, end_of_records=<optimized out>)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:3002
3002 /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc: No such file or directory.
(gdb) p join_tab->table->file->table
$53 = (TABLE *) 0x0
(gdb) p join_tab->table->temp_pool_slot
$54 = 22
(gdb) p join_tab->table->s.path
$55 = {str = 0x7ece14459538 "/data/mysql_ssd/tmp/#sql_249c_22", length = 32}
(gdb) p join_tab->table->s.table_category
$57 = TABLE_CATEGORY_TEMPORARY
(gdb) p join_tab->table->s.tmp_table
$58 = INTERNAL_TMP_TABLE
=====

The table is temporary. If we look at the current query (thd->query_string in any frame which has access to thd) we will see the following:

SELECT `a`.* FROM `a` INNER JOIN `b` ON `b`.`id` = `b`.`a_id` WHERE `b`.`b_id` = '10' AND (a.is_p = 1) ORDER BY p_at desc LIMIT 25

The temporary table is used here to store "JOIN" result for the further sorting.

The main questions are: 1) where table->file->table must be initialized; 2) why it was not initialized.

To answer the first question it enough to run the similar query and set up watchpoint in debugger. The result is here:

=====
#0 handler::ha_open (this=0x7ff23cb1a5f0, table_arg=0x7ff23cb01d30, name=0x7ff23cb03258 "/data/mysql_ssd/tmp/#sql_6338_0", mode=2,
    test_if_locked=516)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/handler.cc:2681
#1 0x00000000007e4afa in open_tmp_table (table=0x7ff23cb01d30)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_tmp_table.cc:1601
#2 0x00000000007e5482 in instantiate_tmp_table (table=0x7ff23cb01d30, keyinfo=0x7ff23cb02b08, start_recinfo=0x7ff23cb02b98,
    recinfo=0x7ff23cb0bf90, options=2147748608, big_tables=0 '\000', trace=0x52ad4ad8)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_tmp_table.cc:1831
#3 0x000000000074adf1 in QEP_tmp_table::prepare_tmp_table (this=0x7ff23cb0c770)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:4254
#4 0x000000000074af6c in QEP_tmp_table::put_record (this=0x7ff23cb0c770, end_of_records=false)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:4295
#5 0x000000000074b9e3 in QEP_tmp_table::put_record (this=0x7ff23cb0c770)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.h:241
#6 0x00000000007445e0 in sub_select_op (join=0x7ff23cb09178, join_tab=0x7ff23cb01608, end_of_records=false)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1067
#7 0x0000000000744fde in evaluate_join_record (join=0x7ff23cb09178, join_tab=0x7ff23cb01308)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1601
#8 0x0000000000744844 in sub_select (join=0x7ff23cb09178, join_tab=0x7ff23cb01308, end_of_records=false)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1276
#9 0x0000000000744fde in evaluate_join_record (join=0x7ff23cb09178, join_tab=0x7ff23cb01008)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1601
#10 0x0000000000744844 in sub_select (join=0x7ff23cb09178, join_tab=0x7ff23cb01008, end_of_records=false)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:1276
#11 0x0000000000744361 in do_select (join=0x7ff23cb09178)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:933
#12 0x0000000000742891 in JOIN::exec (this=0x7ff23cb09178)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_executor.cc:194
#13 0x0000000000797b14 in mysql_execute_select (thd=0x52ad2600, select_lex=0x52ad5208, free_join=true)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:1101
#14 0x0000000000797d84 in mysql_select (thd=0x52ad2600, tables=0x7ff23c0078c8, wild_num=1, fields=..., conds=0x7ff23cb08eb8, order=0x52ad53d0,
    group=0x52ad5308, having=0x0, select_options=2147748608, result=0x7ff23c0094a8, unit=0x52ad4bc0, select_lex=0x52ad5208)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:1222
#15 0x0000000000796182 in handle_select (thd=0x52ad2600, result=0x7ff23c0094a8, setup_tables_done_option=0)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_select.cc:111
#16 0x000000000077415c in execute_sqlcom_select (thd=0x52ad2600, all_tables=0x7ff23c0078c8)
    at /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-precise-64bit/percona-server-5.6-5.6.19-67.0/sql/sql_parse.cc:5570
#17 0x000000000076d490 in mysql_execute_command (thd=0x52ad2600)
#18 0x00000000007761f6 in mysql_parse (thd=0x52ad2600,
...
=====

handler::ha_open() sets up our file->table pointer without any conditions.

To answer the second question we can just go down the stack-trace and find out on what conditions handler::ha_open() will not be invoked. open_tmp_table() invokes handler::ha_open() without any conditions. But instantiate_tmp_table() invokes open_tmp_table() only if create_myisam_tmp_table() returns "success". In the case if create_myisam_tmp_table() does not return "success" handler::table will not be initialized and if we try to write row in this table we will get the above crash.

If create_myisam_tmp_table() terminates with error then instantiate_tmp_table() terminates with error too. If we go down the stack trace we will see QEP_tmp_table::prepare_tmp_table() also terminates with error in this case. But QEP_tmp_table::put_record() does not check the return value of QEP_tmp_table::prepare_tmp_table() and in the case temporary table can not be created QEP_tmp_table::put_record() will silently continue execution.

So as we can see if internal temporary table can not be created the code will just continue execution and this can lead to the crash on attempt to write row in the table.

I would propose the following patch:
--- sql/sql_executor.cc
+++ sql/sql_executor.cc
@@ -4291,8 +4291,8 @@
 QEP_tmp_table::put_record(bool end_of_records)
 {
   // Lasy tmp table creation/initialization
- if (!join_tab->table->file->inited)
- prepare_tmp_table();
+ if (!join_tab->table->file->inited && prepare_tmp_table())
+ return NESTED_LOOP_ERROR;

PS: in the case if there was error on temporary table creating there must be error message:

bool create_myisam_tmp_table(TABLE *table, KEY *keyinfo,
                             MI_COLUMNDEF *start_recinfo,
                             MI_COLUMNDEF **recinfo,
                             ulonglong options, my_bool big_tables)
{
...
  if ((error=mi_create(share->table_name.str, share->keys, &keydef,
                       (uint) (*recinfo - start_recinfo),
                       start_recinfo,
                       share->uniques, &uniquedef,
                       &create_info,
                       HA_CREATE_TMP_TABLE | HA_CREATE_INTERNAL_TABLE |
                       ((share->db_create_options & HA_OPTION_PACK_RECORD) ?
                        HA_PACK_RECORD : 0)
                       )))
  {
    table->file->print_error(error,MYF(0)); /* purecov: inspected */
    table->db_stat=0;
    goto err;
  }
...
}

Vlad Lesin (vlad-lesin)
Changed in percona-server:
assignee: nobody → Vlad Lesin (vlad-lesin)
Vlad Lesin (vlad-lesin)
summary: - silent behavior on temporary table creating error
+ crash on internal temporary table creating error
Vlad Lesin (vlad-lesin)
description: updated
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

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

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.