Bug #10015 | Crash in InnoDB if SPs and Triggers are used | ||
---|---|---|---|
Submitted: | 19 Apr 2005 21:31 | Modified: | 11 Jun 2005 2:05 |
Reporter: | Jan Kneschke | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server | Severity: | S1 (Critical) |
Version: | 5.0.4 | OS: | Linux (Linux/x86) |
Assigned to: | Dmitry Lenev | CPU Architecture: | Any |
[19 Apr 2005 21:31]
Jan Kneschke
[19 Apr 2005 22:01]
MySQL Verification Team
Also tested on Windows server 5.0.5 BK: lock0lock.c --489-- /* NOTE that we call this function while holding the search system latch. To obey the latching order we must NOT reserve the kernel mutex here! */ trx_id = row_get_rec_trx_id(rec, index, offsets); if (read_view_sees_trx_id(view, trx_id)) { ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ return(TRUE); } return(FALSE); } mysqld-debug.exe!read_view_sees_trx_id(read_view_struct * view=0x00000000, dulint_struct trx_id={...}) Line 53 + 0x3 C > mysqld-debug.exe!lock_clust_rec_cons_read_sees(unsigned char * rec=0x01e6809c, dict_index_struct * index=0x01d2dda0, const unsigned long * offsets=0x03eee504, read_view_struct * view=0x00000000) Line 495 + 0x11 C mysqld-debug.exe!row_search_for_mysql(unsigned char * buf=0x00f3fbf8, unsigned long mode=1, row_prebuilt_struct * prebuilt=0x01d2b8a0, unsigned long match_mode=0, unsigned long direction=1) Line 3736 + 0x31 C mysqld-debug.exe!ha_innobase::general_fetch(unsigned char * buf=0x00f3fbf8, unsigned int direction=1, unsigned int match_mode=0) Line 3634 + 0x17 C++ mysqld-debug.exe!ha_innobase::index_next(unsigned char * buf=0x00f3fbf8) Line 3672 C++ mysqld-debug.exe!join_read_next(st_read_record * info=0x030355b0) Line 9801 + 0x18 C++ mysqld-debug.exe!sub_select(JOIN * join=0x030012f8, st_join_table * join_tab=0x03035570, int end_of_records=0) Line 9313 + 0xa C++ mysqld-debug.exe!do_select(JOIN * join=0x030012f8, List<Item> * fields=0x02fef6f8, st_table * table=0x00000000, Procedure * procedure=0x00000000) Line 8989 + 0xf C++ mysqld-debug.exe!JOIN::exec() Line 1644 + 0x19 C++ mysqld-debug.exe!mysql_select(THD * thd=0x02fef420, Item * * * rref_pointer_array=0x02fef790, st_table_list * tables=0x03000cd0, unsigned int wild_num=0, List<Item> & fields={...}, Item * conds=0x00000000, unsigned int og_num=0, st_order * order=0x00000000, st_order * group=0x00000000, Item * having=0x00000000, st_order * proc_param=0x00000000, unsigned long select_options=2158250496, select_result * result=0x030012e8, st_select_lex_unit * unit=0x02fef480, st_select_lex * select_lex=0x02fef688) Line 2064 C++ mysqld-debug.exe!handle_select(THD * thd=0x02fef420, st_lex * lex=0x02fef468, select_result * result=0x030012e8, unsigned long setup_tables_done_option=0) Line 240 + 0x83 C++ mysqld-debug.exe!mysql_execute_command(THD * thd=0x02fef420) Line 2387 + 0x13 C++ mysqld-debug.exe!mysql_parse(THD * thd=0x02fef420, char * inBuf=0x030004e0, unsigned int length=35) Line 5172 + 0x9 C++ mysqld-debug.exe!dispatch_command(enum_server_command command=COM_QUERY, THD * thd=0x02fef420, char * packet=0x02ff8421, unsigned int packet_length=36) Line 1647 + 0x1d C++ mysqld-debug.exe!do_command(THD * thd=0x02fef420) Line 1453 + 0x31 C++ mysqld-debug.exe!handle_one_connection(void * arg=0x02fef420) Line 1110 + 0x9 C++ mysqld-debug.exe!pthread_start(void * param=0x02fed1b0) Line 63 + 0x7 C mysqld-debug.exe!_threadstart(void * ptd=0x02ff52c0) Line 173 + 0xd C kernel32.dll!7c80b50b() kernel32.dll!7c8399f3()
[20 Apr 2005 2:16]
Heikki Tuuri
Hi! I would guess that since the procedure is run in the AUTOCOMMIT=1 mode (?), the cursor is NOT preserved, and the crash happens because there is no longer a consistent read snapshot to continue reading from the cursor! That is, 'view' is NULL. MySQL should return an error if a cursor is used over a transaction commit. Or, we should implement cursors that can exist over a commit. That would require that an InnoDB 'read view' is associated with a cursor (which would then be a 'transaction' of its own), not with a transaction. But that is for 5.1 or later. For now, MySQL should return an error. Regards, Heikki
[25 Apr 2005 9:44]
Dmitry Lenev
Hi, Jan and Heikki! Actually this crash is not something specifically related to cursors. Current implemantation of SQL-cursors is pretty dumb and basically boils down to executing query then cursor is opened and storing obtained result-set for later fetches. Much simpler test case for this crash looks like: drop table if exists t1; drop function if exists t1; create table t1 (id int) engine=innodb; insert into t1 values (1),(2),(3); create function f1() returns int return (select count(*) from t1); select *, f1() from t1; # This crashes server... So here we have more general problems of interaction between transactions and new SP-locking scheme and execution of substatements in stored functions... I'll dig in this further...
[28 May 2005 5:43]
Heikki Tuuri
Dmitri, I stepped through the simple example in gdb. Looks like it calls commit when it has done something with the stored function. That closes the consistent read snapshot ('view'). But it then continues to read from t1! This is run in the AUTOCOMMIT=1 mode. It should call commit only after the whole SQL statement has been processed. Regards, Heikki mysql> select *, f1() from t1; Starting program: /home/heikki/mysql-5.0/sql/mysqld [New Thread 16384 (LWP 9325)] [New Thread 32769 (LWP 9326)] [New Thread 16386 (LWP 9327)] [New Thread 32771 (LWP 9328)] [New Thread 49156 (LWP 9329)] [New Thread 65541 (LWP 9330)] [New Thread 81926 (LWP 9331)] [New Thread 98311 (LWP 9332)] [New Thread 114696 (LWP 9333)] [New Thread 131081 (LWP 9334)] 050528 7:43:25 InnoDB: Started; log sequence number 1 3004410732 [New Thread 147466 (LWP 9335)] 050528 7:43:25 [Warning] mysql.user table is not updated to new password format ; Disabling new password usage until mysql_fix_privilege_tables is run 050528 7:43:25 [Note] /home/heikki/mysql-5.0/sql/mysqld: ready for connections. Version: '5.0.7-beta-debug' socket: '/home/heikki/bugsocket' port: 3307 Sourc e distribution [New Thread 163851 (LWP 9349)] [Switching to Thread 163851 (LWP 9349)] Breakpoint 1, ha_innobase::store_lock(THD*, st_thr_lock_data**, thr_lock_type) (this=0x8c82170, thd=0x8c59798, to=0x8c576c8, lock_type=TL_READ) at ha_innodb.cc:6418 6418 row_prebuilt_t* prebuilt = (row_prebuilt_t*) innobase_pre built; Current language: auto; currently c++ (gdb) c Continuing. Breakpoint 1, ha_innobase::store_lock(THD*, st_thr_lock_data**, thr_lock_type) (this=0x8c82bd0, thd=0x8c59798, to=0x8c576cc, lock_type=TL_READ) at ha_innodb.cc:6418 6418 row_prebuilt_t* prebuilt = (row_prebuilt_t*) innobase_pre built; (gdb) Continuing. Breakpoint 2, ha_innobase::external_lock(THD*, int) (this=0x8c82170, thd=0x8c59798, lock_type=0) at ha_innodb.cc:5898 5898 row_prebuilt_t* prebuilt = (row_prebuilt_t*) innobase_prebuilt; (gdb) Continuing. Breakpoint 2, ha_innobase::external_lock(THD*, int) (this=0x8c82bd0, thd=0x8c59798, lock_type=0) at ha_innodb.cc:5898 5898 row_prebuilt_t* prebuilt = (row_prebuilt_t*) innobase_prebuilt; (gdb) Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82298 '¥' <repeats 16 times>, mode=1, prebuilt=0x40ace668, match_mode=0, direction=0) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; Current language: auto; currently c (gdb) Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82cf8 '¥' <repeats 16 times>, mode=1, prebuilt=0x40ad2868, match_mode=0, direction=0) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; (gdb) Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82cf8 '¥' <repeats 16 times>, mode=0, prebuilt=0x40ad2868, match_mode=0, direction=1) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; (gdb) Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82cf8 '¥' <repeats 16 times>, mode=0, prebuilt=0x40ad2868, match_mode=0, direction=1) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; (gdb) Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82cf8 '¥' <repeats 16 times>, mode=0, prebuilt=0x40ad2868, match_mode=0, direction=1) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; (gdb) Continuing. Breakpoint 4, innobase_commit_low(trx_struct*) (trx=0x40acb068) at ha_innodb.cc:1417 1417 if (trx->conc_state == TRX_NOT_STARTED) { Current language: auto; currently c++ (gdb) bt #0 innobase_commit_low(trx_struct*) (trx=0x40acb068) at ha_innodb.cc:1417 #1 0x08257502 in innobase_commit (thd=0x8c59798, all=false) at ha_innodb.cc:1549 #2 0x0824a766 in ha_commit_one_phase(THD*, bool) (thd=0x8c59798, all=false) at handler.cc:659 #3 0x0824a5d6 in ha_commit_trans(THD*, bool) (thd=0x8c59798, all=false) at handler.cc:629 #4 0x081c2a2b in close_thread_tables(THD*, bool, bool, st_table*) ( thd=0x8c59798, lock_in_use=false, skip_derived=false, stopper=0x0) at sql_base.cc:452 #5 0x082bc52e in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned*, bool, sp_instr*) (this=0x8c87f8c, thd=0x8c59798, nextp=0x63292d1c, open_tables=true, instr=0x8c87f70) at sp_head.cc:1378 #6 0x082bd04b in sp_instr_freturn::execute(THD*, unsigned*) (this=0x8c87f70, thd=0x8c59798, nextp=0x63292d1c) at sp_head.cc:1703 #7 0x082ba574 in sp_head::execute(THD*) (this=0x8c87640, thd=0x8c59798) at sp_head.cc:624 #8 0x082baab7 in sp_head::execute_function(THD*, Item**, unsigned, Item**) ( this=0x8c87640, thd=0x8c59798, argp=0xa5a5a5a5, argcount=0, resp=0x63292f0c) at sp_head.cc:739 #9 0x08127812 in Item_func_sp::execute(Item**) (this=0x8c7c210, itp=0x63292f0c) at item_func.cc:4803 #10 0x081274ee in Item_func_sp::execute(Field**) (this=0x8c7c210, flp=0x8c7c288) at item_func.cc:4735 #11 0x0812b2c6 in Item_func_sp::val_int() (this=0x8c7c210) at item_func.h:1325 #12 0x081052cb in Item::send(Protocol*, String*) (this=0x8c7c210, protocol=0x8c5a19c, buffer=0x63292ffc) at item.cc:3858 #13 0x08174898 in select_send::send_data(List<Item>&) (this=0x8c7cd10, items=@0x8c59a3c) at sql_class.cc:873 #14 0x081e8a12 in end_send (join=0x8c7cd20, join_tab=0x8c7dff8, end_of_records=false) at sql_select.cc:10021 #15 0x081e734c in evaluate_join_record (join=0x8c7cd20, join_tab=0x8c7de90, error=0, report_error=0x8c5a174 "") at sql_select.cc:9352 #16 0x081e70c7 in sub_select (join=0x8c7cd20, join_tab=0x8c7de90, end_of_records=false) at sql_select.cc:9237 #17 0x081e6c44 in do_select (join=0x8c7cd20, fields=0x8c59a3c, table=0x0, procedure=0x0) at sql_select.cc:9000 #18 0x081d564c in JOIN::exec() (this=0x8c7cd20) at sql_select.cc:1658 #19 0x081d64e2 in mysql_select(THD*, Item***, st_table_list*, unsigned, List<Ite ---Type <return> to continue, or q <return> to quit--- m>&, Item*, unsigned, st_order*, st_order*, Item*, st_order*, unsigned long, sel ect_result*, st_select_lex_unit*, st_select_lex*) (thd=0x8c59798, rref_pointer_array=0x8c59adc, tables=0x8c7c9a0, wild_num=1, fields=@0x8c59a3c, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2158250496, result=0x8c7cd10, unit=0x8c597e8, select_lex=0x8c599cc) at sql_select.cc:2052 #20 0x081d0e98 in handle_select(THD*, st_lex*, select_result*, unsigned long) ( thd=0x8c59798, lex=0x8c597d8, result=0x8c7cd10, setup_tables_done_option=0) at sql_select.cc:242 #21 0x0819c64c in mysql_execute_command(THD*) (thd=0x8c59798) at sql_parse.cc:2400 #22 0x081a3c74 in mysql_parse(THD*, char*, unsigned) (thd=0x8c59798, inBuf=0x8c7c100 "select *, f1() from t1", length=22) at sql_parse.cc:5260 #23 0x0819aa7f in dispatch_command(enum_server_command, THD*, char*, unsigned) (command=COM_QUERY, thd=0x8c59798, packet=0x8c740a1 "", packet_length=23) at sql_parse.cc:1653 #24 0x0819a36f in do_command(THD*) (thd=0x8c59798) at sql_parse.cc:1456 #25 0x081995c1 in handle_one_connection (arg=0x8c59798) at sql_parse.cc:1114 #26 0x40062f60 in pthread_start_thread () from /lib/i686/libpthread.so.0 #27 0x400630fe in pthread_start_thread_event () from /lib/i686/libpthread.so.0 #28 0x401f5327 in clone () from /lib/i686/libc.so.6 (gdb) c Continuing. Breakpoint 3, row_search_for_mysql (buf=0x8c82298 "¥\001", mode=0, prebuilt=0x40ace668, match_mode=0, direction=1) at row0sel.c:3041 3041 dict_index_t* index = prebuilt->index; Current language: auto; currently c (gdb) next 3042 dtuple_t* search_tuple = prebuilt->search_tuple; (gdb) 3043 btr_pcur_t* pcur = prebuilt->pcur; (gdb) 3044 trx_t* trx = prebuilt->trx; (gdb) 3051 ulint err = DB_SUCCESS; (gdb) 3056 ibool unique_search = FALSE; (gdb) 3057 ibool unique_search_from_clust_index = FALSE; (gdb) 3058 ibool mtr_has_extra_clust_latch = FALSE; (gdb) 3059 ibool moves_up = FALSE; (gdb) 3060 ibool set_also_gap_locks = TRUE; (gdb) 3067 ulint cnt = 0; (gdb) 3070 mem_heap_t* heap = NULL; (gdb) 3072 ulint* offsets = offsets_; (gdb) 3073 *offsets_ = (sizeof offsets_) / sizeof *offsets_; (gdb) 3078 if (prebuilt->table->ibd_file_missing) { (gdb) 3092 if (prebuilt->magic_n != ROW_PREBUILT_ALLOCATED) { (gdb) 3105 if (trx->n_mysql_tables_in_use == 0 (gdb) 3129 if (trx->has_search_latch (gdb) 3146 if (direction == 0) { (gdb) 3158 trx->op_info = "fetching rows"; (gdb) 3160 if (prebuilt->n_rows_fetched == 0) { (gdb) 3161 prebuilt->fetch_direction = direction; (gdb) print *prebuilt->table $1 = {id = {high = 0, low = 56172}, type = 1, heap = 0x40ace428, name = 0x40acdc68 "test/t1", dir_path_of_temp_table = 0x0, space = 0, ibd_file_missing = 0, tablespace_discarded = 0, comp = 1, name_hash = 0x0, id_hash = 0x0, n_def = 5, n_cols = 5, cols = 0x40acdc70, indexes = { count = 1, start = 0x40ad1c68, end = 0x40ad1c68}, foreign_list = { count = 0, start = 0x0, end = 0x0}, referenced_list = {count = 0, start = 0x0, end = 0x0}, table_LRU = {prev = 0x0, next = 0x40acd668}, mem_fix = 0, n_mysql_handles_opened = 2, n_foreign_key_checks_running = 0, cached = 1, auto_inc_lock = 0x40acdd78, query_cache_inv_trx_id = {high = 0, low = 0}, locks = {count = 0, start = 0x0, end = 0x0}, mix_id = {high = 0, low = 0}, mix_len = 0, mix_id_len = 0, mix_id_buf = '\0' <repeats 11 times>, cluster_name = 0x0, does_not_fit_in_memory = 0, stat_n_rows = 3, stat_clustered_index_size = 1, stat_sum_of_other_index_sizes = 0, stat_initialized = 1, stat_modified_counter = 0, autoinc_mutex = {lock_word = 0, os_fast_mutex = { global = {__m_reserved = 0, __m_count = 0, __m_owner = 0x0, __m_kind = 2, __m_lock = {__status = 0, __spinlock = 0}}, mutex = { __m_reserved = 0, __m_count = 0, __m_owner = 0x0, __m_kind = 3, __m_lock = {__status = 0, __spinlock = 0}}, file = 0x84e0d96 "os0sync.c", line = 574, count = 0, thread = 0}, waiters = 0, list = {prev = 0x40ad20cc, next = 0x40ad1acc}, level = 999, cfile_name = 0x84beddd "dict0mem.c", cline = 89, magic_n = 979585, count_using = 0, count_spin_loop = 0, count_spin_rounds = 0, count_os_wait = 0, count_os_yield = 0, lspent_time = 0, lmax_spent_time = 0, cmutex_name = 0x84bede8 "&(table->autoinc_mutex)", mutex_type = 0}, autoinc_inited = 0, autoinc = 0, magic_n = 76333786} (gdb)
[7 Jun 2005 10:51]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/internals/25691
[7 Jun 2005 12:16]
Dmitry Lenev
Fixed in 5.0.7
[11 Jun 2005 2:05]
Paul DuBois
Noted in 5.0.7 changelog.