| Bug #37936 | ASSERT_COLUMN_MARKED_FOR_WRITE in Field_datetime::store , Field_varstring::store | ||
|---|---|---|---|
| Submitted: | 7 Jul 2008 16:07 | Modified: | 29 Jan 2009 19:57 |
| Reporter: | Philip Stoev | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Optimizer | Severity: | S1 (Critical) |
| Version: | 5.1.28-bzr, 6.0, 6.0.7-bzr | OS: | Any |
| Assigned to: | Georgi Kodinov | CPU Architecture: | Any |
| Tags: | regression | ||
[14 Jul 2008 17:35]
Philip Stoev
Grammar file for bug 37936
Attachment: bug37936.yy (application/octet-stream, text), 4.85 KiB.
[14 Jul 2008 17:40]
Philip Stoev
To reproduce this bug, please clone the mysql-test-extra-6.0 tree and execute: $ cd mysql-test-extra-6.0/mysql-test/gentest $ ./runall.pl --basedir=/path/to/mysql-6.0 --grammar=/location/of/bug37936.yy --threads=1 This should crash shortly with the same assertion in Field_varstring::store.
[14 Jul 2008 17:44]
Philip Stoev
Unsimplified non-concurrent test case for bug 37936
Attachment: bug37936.test (application/octet-stream, text), 19.31 KiB.
[19 Jul 2008 13:34]
Valeriy Kravchuk
I was able to repeat a crash with the test case provided on recent 6.0.7-alpha-debug. openxs@suse:/home2/openxs/dbs/6.0> bin/mysql -uroot test < /home/openxs/bug37936.test X 0 X 0000-00-00 X 0000-00-00 X 2004-10-27 X 1 16 X 1 8 12 19 ERROR 2013 (HY000) at line 158: Lost connection to MySQL server during query openxs@suse:/home2/openxs/dbs/6.0> 080703 16:57:45 mysqld_safe Number of processes running now: 0 080703 16:57:45 mysqld_safe mysqld restarted No meaningfull stack trace in the error log: thd: 0x9b13e58 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 = 0x47ebf430 thread_stack 0x30000 Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x9b6b318 = SELECT MIN( OUTR . `pk` ) AS X FROM C AS OUTR WHERE OUTR . `pk` IN ( SELECT INNR . `int_key` AS Y FROM B AS INNR WHERE INNR . `int_key` <> INNR . `int_key` AND OUTR . `date_nokey` < '2003-12-25' ) OR NOT ( OUTR . `date_key` < '2009-10-8' OR NOT OUTR . `varchar_nokey` <= 'd' ) GROUP BY OUTR . `pk` ORDER BY OUTR . `int_nokey` , OUTR . `pk` LIMIT 2 thd->thread_id=2 thd->killed=NOT_KILLED 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. 080703 16:57:45 mysqld_safe Number of processes running now: 0 080703 16:57:45 mysqld_safe mysqld restarted 080703 16:57:45 InnoDB: Started; log sequence number 0 46409 080703 16:57:46 [Note] Event Scheduler: Loaded 0 events 080703 16:57:46 [Note] /home2/openxs/dbs/6.0/libexec/mysqld: ready for connections. Version: '6.0.7-alpha-debug' socket: '/tmp/mysql.sock' port: 3306 Source distribution
[19 Jul 2008 13:39]
Valeriy Kravchuk
Recent 5.1.28 debug binaries are also affected.
[19 Jul 2008 13:41]
Valeriy Kravchuk
Recent 5.0 debug binaries are NOT affected, so this is a regression: openxs@suse:/home2/openxs/dbs/5.0> bin/mysql -uroot test < /home/openxs/bug37936.test X 0 X 0000-00-00 X 0000-00-00 X 2004-10-27 X 1 16 X 1 8 12 19 X NULL X 0 X 0000-00-00 X NULL X NULL X 5 X NULL X 0 0 4 X 0 X 1 4 8 9 12 17 19
[5 Nov 2008 14:55]
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/commits/57900 2690 Georgi Kodinov 2008-11-05 Bug #37936: ASSERT_COLUMN_MARKED_FOR_WRITE in Field_datetime::store , Field_varstring::store The code that temporary saved the bitmaps of the read set and the write set so that it can set it to all columns for debug purposes was not expecting that the table->read_set and table->write_set can be the same. And was always saving both in sequence. As a result the original value was never restored. Fixed by saving & restoring the original value only once if the two sets are the same.
[6 Nov 2008 13:57]
Ingo Strüwing
See comments by email.
[7 Nov 2008 10:11]
Georgi Kodinov
I'm not able to get the stack trace described here. All I'm getting is the stack trace from Bug #37937. Can you please try to get the same callstack with the latest 5.1 debug (I assume it's a debug version only) ?
[7 Nov 2008 10:47]
Georgi Kodinov
Bug #37937 marked as a duplicate of this bug
[7 Nov 2008 10:48]
Georgi Kodinov
Tried the original test case (using RQG) against a patched server : ======================================================= TEST RESULT TIME (ms) ------------------------------------------------------- Servers started, exiting Autoreleasing /tmp/mysql-test-ports:200 # 12:47:15 Starting # 12:47:15 gentest.pl \ # 12:47:15 --gendata= \ # 12:47:15 --threads=1 \ # 12:47:15 --queries=1000 \ # 12:47:15 --duration=3600 \ # 12:47:15 --dsn1=dbi:mysql:host=127.0.0.1:port=19306:user=root:database=test \ # 12:47:15 --grammar=bug37936.yy # 12:47:15 Starting # 12:47:15 # gendata-old.pl \ # 12:47:15 # --dsn=dbi:mysql:host=127.0.0.1:port=19306:user=root:database=test # 12:47:15 Creating table A, size 0 rows, engine . # 12:47:15 Creating table B, size 2 rows, engine . # 12:47:15 Creating table C, size 20 rows, engine . # 12:47:15 Creating table D, size 100 rows, engine . # 12:47:15 Creating table E, size 1000 rows, engine . # 12:47:16 Creating table AA, size 0 rows, engine . # 12:47:16 Creating table BB, size 2 rows, engine . # 12:47:16 Creating table CC, size 20 rows, engine . # 12:47:16 Creating table DD, size 100 rows, engine . # 12:47:16 Creating table AAA, size 0 rows, engine . # 12:47:16 Creating table BBB, size 1 rows, engine . # 12:47:16 Creating table CCC, size 20 rows, engine . # 12:47:16 Reporters: ErrorLog, Backtrace # 12:47:16 Validators: FalconErrors, ErrorMessageCorruption # 12:47:16 Starting 1 processes, 1000 queries each, duration 3600 seconds. # 12:47:18 Started periodic reporting process... # 12:47:20 Child process completed successfully. # 12:47:25 Killing periodic reporting process with pid 10690... # 12:47:30 Test completed successfully.
[7 Nov 2008 11:07]
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/commits/58165 2690 Georgi Kodinov 2008-11-07 Bug #37936: ASSERT_COLUMN_MARKED_FOR_WRITE in Field_datetime::store , Field_varstring::store The code that temporary saved the bitmaps of the read set and the write set so that it can set it to all columns for debug purposes was not expecting that the table->read_set and table->write_set can be the same. And was always saving both in sequence. As a result the original value was never restored. Fixed by saving & restoring the original value only once if the two sets are the same (in a special set of functions).
[8 Dec 2008 19:32]
Michael Widenius
Another way to define the new functions that does the same thing but
may be a bit easier to understand is:
static inline void dbug_tmp_use_all_columns(TABLE *table,
my_bitmap_map **save,
MY_BITMAP *read_set,
MY_BITMAP *write_set)
{
#ifndef DBUG_OFF
save[0]= read_set->bitmap;
save[1]= write_set->bitmap;
(void) tmp_use_all_columns(table, read_set);
(void) tmp_use_all_columns(table, write_set);
#endif
}
static inline void dbug_tmp_restore_column_maps(MY_BITMAP *read_set,
MY_BITMAP *write_set,
my_bitmap_map **old)
{
#ifndef DBUG_OFF
tmp_restore_column_map(read_set, old[0]);
tmp_restore_column_map(write_set, old[1]);
#endif
Feel free to use the above logic or just push the given code
[9 Dec 2008 17:46]
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/commits/61116 2690 Georgi Kodinov 2008-12-09 Bug #37936: ASSERT_COLUMN_MARKED_FOR_WRITE in Field_datetime::store , Field_varstring::store The code that temporary saved the bitmaps of the read set and the write set so that it can set it to all columns for debug purposes was not expecting that the table->read_set and table->write_set can be the same. And was always saving both in sequence. As a result the original value was never restored. Fixed by saving & restoring the original value only once if the two sets are the same (in a special set of functions).
[15 Jan 2009 6:35]
Bugs System
Pushed into 5.1.31 (revid:joro@sun.com-20090115053147-tx1oapthnzgvs1ro) (version source revid:azundris@mysql.com-20081230114838-cn52tu180wcrvh0h) (merge vers: 5.1.31) (pib:6)
[19 Jan 2009 11:25]
Bugs System
Pushed into 5.1.31-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090119095303-uwwvxiibtr38djii) (version source revid:tomas.ulin@sun.com-20090115073240-1wanl85vlvw2she1) (merge vers: 5.1.31-ndb-6.2.17) (pib:6)
[19 Jan 2009 13:03]
Bugs System
Pushed into 5.1.31-ndb-6.3.21 (revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (version source revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (merge vers: 5.1.31-ndb-6.3.21) (pib:6)
[19 Jan 2009 16:09]
Bugs System
Pushed into 5.1.31-ndb-6.4.1 (revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (version source revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (merge vers: 5.1.31-ndb-6.4.1) (pib:6)
[20 Jan 2009 18:56]
Bugs System
Pushed into 6.0.10-alpha (revid:joro@sun.com-20090119171328-2hemf2ndc1dxl0et) (version source revid:azundris@mysql.com-20081230114916-c290n83z25wkt6e4) (merge vers: 6.0.9-alpha) (pib:6)
[29 Jan 2009 19:57]
Paul DuBois
Noted in 5.1.31, 6.0.10 changelogs. An error in a debugging check caused crashes in debug servers.
Description: When executing a query containing date expressions, mysqld crashed as follows: #9 0x081f72dd in Field_datetime::store (this=0xa035828, from=0xa080f50 "2000-6-25", len=9, cs=0x877fc40) at field.cc:5831 #10 0x08171166 in Item::save_str_value_in_field (this=0xa080f60, field=0xe4d, result=0xa080f6c) at item.cc:371 #11 0x0817119c in Item_string::save_in_field (this=0xa080f60, field=0xa035828, no_conversions=true) at item.cc:4896 #12 0x0816c308 in Item::save_in_field_no_warnings (this=0xa080f60, field=0xa035828, no_conversions=<value optimized out>) at item.cc:972 #13 0x082ebda1 in get_mm_leaf (param=0xa891f338, conf_func=0xa080fe0, field=0xa035828, key_part=0xa08ac10, type=Item_func::LE_FUNC, value=0xa080f60) at opt_range.cc:5679 #14 0x082ec39d in get_mm_parts (param=0xa891f338, cond_func=0xa080fe0, field=0xa035828, type=Item_func::LE_FUNC, value=0xa080f60, cmp_type=INT_RESULT) at opt_range.cc:5488 #15 0x082f8b7c in get_func_mm_tree (param=0xa891f338, cond_func=0xa080fe0, field=0xa035828, value=0xa080f60, cmp_type=INT_RESULT, inv=false) at opt_range.cc:5167 #16 0x082f8d18 in get_full_func_mm_tree (param=0xa891f338, cond_func=0xa080fe0, field_item=0xa080eb8, value=0xa080f60, inv=<value optimized out>) at opt_range.cc:5266 #17 0x082f9513 in get_mm_tree (param=0xa891f338, cond=0xa080fe0) at opt_range.cc:5456 #18 0x082f8e2f in get_mm_tree (param=0xa891f338, cond=<value optimized out>) at opt_range.cc:5308 #19 0x082f9c58 in SQL_SELECT::test_quick_select (this=0xa081f70, thd=0xa025f40, keys_to_use={map = 16}, prev_tables=0, limit=4294967295, force_quick_range=false, ordered_output=false) at opt_range.cc:2311 #20 0x0828693f in make_join_statistics (join=0xa071db8, tables=0x0, conds=0xa081bb8, keyuse_array=0xa073094) at sql_select.cc:3758 #21 0x08287eb5 in JOIN::optimize (this=0x0) at sql_select.cc:1549 #22 0x0828e1a8 in mysql_select (thd=0xa025f40, rref_pointer_array=0xa027424, tables=0xa04b3e8, wild_num=0, fields=@0xa0273b4, conds=0xa0810d0, og_num=1, order=0x0, group=0xa0814b0, having=0x0, proc_param=0x0, select_options=2147764736, result=0xa081548, unit=0xa027090, select_lex=0xa027320) at sql_select.cc:2987 #23 0x082910dc in handle_select (thd=0xa025f40, lex=0xa027034, result=0xa081548, setup_tables_done_option=0) at sql_select.cc:302 #24 0x082201e2 in execute_sqlcom_select (thd=0xa025f40, all_tables=0xa04b3e8) at sql_parse.cc:4847 #25 0x08220f61 in mysql_execute_command (thd=0xa025f40) at sql_parse.cc:2015 #26 0x0822a02e in mysql_parse (thd=0xa025f40, inBuf=0xa04ae08 "SELECT COUNT(DISTINCT OUTR . `varchar_nokey` ) AS X FROM B AS OUTR2 LEFT JOIN C AS OUTR ON ( OUTR2 . `varchar_nokey` = OUTR . `varchar_key` ) WHERE OUTR . `varchar_key` IN ( SELECT INNR . `datetime_"..., length=451, found_semicolon=0xa8923314) at sql_parse.cc:5811 #27 0x0822a921 in dispatch_command (command=COM_QUERY, thd=0xa025f40, packet=0xa027959 "SELECT COUNT(DISTINCT OUTR . `varchar_nokey` ) AS X FROM B AS OUTR2 LEFT JOIN C AS OUTR ON ( OUTR2 . `varchar_nokey` = OUTR . `varchar_key` ) WHERE OUTR . `varchar_key` IN ( SELECT INNR . `datetime_"..., packet_length=453) at sql_parse.cc:1051 #28 0x0822ba49 in do_command (thd=0xa025f40) at sql_parse.cc:724 #29 0x0821bef0 in handle_one_connection (arg=0xa025f40) at sql_connect.cc:1153 #30 0x0057d32f in start_thread () from /lib/libpthread.so.0 #31 0x0049a27e in clone () from /lib/libc.so.6 The assertion that is being hit is ASSERT_COLUMN_MARKED_FOR_WRITE, at the entry of Field_datetime::store. The assertion is: (!table || (!table->write_set || bitmap_is_set(table->write_set, field_index)) (gdb) print table $1 = (st_table *) 0xa035140 (gdb) print table->write_set $2 = (MY_BITMAP *) 0xa0351e0 (gdb) print field_index $3 = 7 (gdb) print * table->write_set $4 = {bitmap = 0xa0313b0, n_bits = 11, last_word_mask = 4294965248, last_word_ptr = 0xa0359cc, mutex = 0x0} The query in question is: SELECT COUNT(DISTINCT OUTR . `varchar_nokey` ) AS X FROM B AS OUTR2 LEFT JOIN C AS OUTR ON ( OUTR2 . `varchar_nokey` = OUTR . `varchar_key` ) WHERE OUTR . `varchar_key` IN ( SELECT INNR . `datetime_key` AS Y FROM BB AS INNR2 LEFT JOIN AA AS INNR ON ( INNR2 . `int_nokey` = INNR . `pk` ) WHERE INNR . `varchar_key` < 'w' HAVING X = '16:36:21' ) AND OUTR . `datetime_key` <= '2000-6-25' AND OUTR . `varchar_nokey` >= 'hkq' GROUP BY OUTR . `int_nokey` How to repeat: A simplifed test case will be uploaded shortly.