[MDEV-8864] Server crash #2 in Item_field::print on ANALYZE FORMAT=JSON - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.1(EOL)
Fix Version/s: 10.1.8
Component/s: Optimizer
Labels:
- analyze-stmt
- explain_json

Description

Note: Stack trace is different from ~~MDEV-7267~~, and the tentative patch for ~~MDEV-7267~~ does not fix it, so I'm filing it separately.

CREATE TABLE t1 (f1 INT) ENGINE=MyISAM;

INSERT INTO t1 VALUES (1),(2);

CREATE TABLE t2 (f2 INT) ENGINE=MyISAM;

INSERT INTO t2 VALUES (2),(3);

CREATE TABLE t3 (f3 INT) ENGINE=MyISAM;

INSERT INTO t3 VALUES (3),(4);

ANALYZE FORMAT=JSON

SELECT GROUP_CONCAT(f3) AS gc, ( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 ) sq

FROM t2, t3

WHERE f3 IN ( 1, 2 )

GROUP BY sq ORDER BY gc;

Stack trace from 10.1 + tentative patch for MDEV-7267
#3 <signal handler called>
#4 0x00007f19f4435d5e in Item_field::print (this=0x7f19e85a0050, str=0x7f19f3c70af0, query_type=QT_EXPLAIN) at /10.1-mdev7267/sql/item.cc:6624
#5 0x00007f19f44371b9 in Item_ref::print (this=0x7f19e867cd30, str=0x7f19f3c70af0, query_type=QT_EXPLAIN) at /10.1-mdev7267/sql/item.cc:7141
#6 0x00007f19f44371b9 in Item_ref::print (this=0x7f19e867cad8, str=0x7f19f3c70af0, query_type=QT_EXPLAIN) at /10.1-mdev7267/sql/item.cc:7141
#7 0x00007f19f4476632 in Item_func::print_op (this=0x7f19e867a2f0, str=0x7f19f3c70af0, query_type=QT_EXPLAIN) at /10.1-mdev7267/sql/item_func.cc:486
#8 0x00007f19f445a7b3 in Item_bool_rowready_func2::print (this=0x7f19e867a2f0, str=0x7f19f3c70af0, query_type=QT_EXPLAIN) at /10.1-mdev7267/sql/item_cmpfunc.h:389
#9 0x00007f19f4345545 in write_item (writer=0x7f19f3c70fb0, item=0x7f19e867a2f0) at /10.1-mdev7267/sql/sql_explain.cc:1351
#10 0x00007f19f434652e in Explain_table_access::print_explain_json (this=0x7f19e84e7bb0, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true, fs_tracker=0x0, first_table_sort_used=false) at /10.1-mdev7267/sql/sql_explain.cc:1680
#11 0x00007f19f434432b in Explain_basic_join::print_explain_json_interns (this=0x7f19e84e7560, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true, first_table_sort=0x0, first_table_sort_used=false) at /10.1-mdev7267/sql/sql_explain.cc:1002
#12 0x00007f19f4344193 in Explain_select::print_explain_json (this=0x7f19e84e7560, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true) at /10.1-mdev7267/sql/sql_explain.cc:961
#13 0x00007f19f434349b in Explain_node::print_explain_json_for_children (this=0x7f19e859e208, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true) at /10.1-mdev7267/sql/sql_explain.cc:662
#14 0x00007f19f4344394 in Explain_basic_join::print_explain_json_interns (this=0x7f19e859e208, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true, first_table_sort=0x0, first_table_sort_used=false) at /10.1-mdev7267/sql/sql_explain.cc:1010
#15 0x00007f19f4344193 in Explain_select::print_explain_json (this=0x7f19e859e208, query=0x7f19e84e73f0, writer=0x7f19f3c70fb0, is_analyze=true) at /10.1-mdev7267/sql/sql_explain.cc:961
#16 0x00007f19f4341bc6 in Explain_query::print_explain_json (this=0x7f19e84e73f0, output=0x7f19e85a03a8, is_analyze=true) at /10.1-mdev7267/sql/sql_explain.cc:223
#17 0x00007f19f4341921 in Explain_query::send_explain (this=0x7f19e84e73f0, thd=0x7f19ea573070) at /10.1-mdev7267/sql/sql_explain.cc:166
#18 0x00007f19f41e2f19 in execute_sqlcom_select (thd=0x7f19ea573070, all_tables=0x7f19e867a628) at /10.1-mdev7267/sql/sql_parse.cc:5861
#19 0x00007f19f41d8fab in mysql_execute_command (thd=0x7f19ea573070) at /10.1-mdev7267/sql/sql_parse.cc:2962
#20 0x00007f19f41e63e2 in mysql_parse (thd=0x7f19ea573070, rawbuf=0x7f19e8678088 "ANALYZE FORMAT=JSON \nSELECT GROUP_CONCAT(f3) AS gc, ( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 ) sq\nFROM t2, t3\nWHERE f3 IN ( 1, 2 ) \nGROUP BY sq ORDER BY gc", length=157, parser_state=0x7f19f3c721a0) at /10.1-mdev7267/sql/sql_parse.cc:7227
#21 0x00007f19f41d514a in dispatch_command (command=COM_QUERY, thd=0x7f19ea573070, packet=0x7f19ec135071 "", packet_length=157) at /10.1-mdev7267/sql/sql_parse.cc:1488
#22 0x00007f19f41d3e70 in do_command (thd=0x7f19ea573070) at /10.1-mdev7267/sql/sql_parse.cc:1110
#23 0x00007f19f4308fa5 in do_handle_one_connection (thd_arg=0x7f19ea573070) at /10.1-mdev7267/sql/sql_connect.cc:1350
#24 0x00007f19f4308cf6 in handle_one_connection (arg=0x7f19ea573070) at /10.1-mdev7267/sql/sql_connect.cc:1262
#25 0x00007f19f48d4837 in pfs_spawn_thread (arg=0x7f19f0c23d70) at /10.1-mdev7267/storage/perfschema/pfs.cc:1860
#26 0x00007f19f38adb50 in start_thread (arg=<optimized out>) at pthread_create.c:304
#27 0x00007f19f173995d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Attachments

Issue Links

relates to

MDEV-7267 Server crashes in Item_field::print on ANALYZE FORMAT=JSON

Closed

Activity

Ascending order - Click to sort in descending order

Sergei Petrunia added a comment - 2015-10-04 13:53

It crashes when trying to print the WHERE clause for the subquery

( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 )

"t2.f2" is printed sucessfully. We crash when printing "f3". "f3" refers to "t3.f3" from the parent query.

Upper query does a GROUP BY over the subquery value. I guess this means that the subquery is only evaluated in the pre-group-by context.

Sergei Petrunia added a comment - 2015-10-04 13:53 It crashes when trying to print the WHERE clause for the subquery ( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 ) "t2.f2" is printed sucessfully. We crash when printing "f3". "f3" refers to "t3.f3" from the parent query. Upper query does a GROUP BY over the subquery value. I guess this means that the subquery is only evaluated in the pre-group-by context.

Sergei Petrunia added a comment - 2015-10-04 13:55

Changed the query's WHERE to be f3 IN ( 3,4 ) so that the upper query produces some rows.

Then, looking at the subquery WHERE while subquery is executed:

(gdb) p dbug_print_item(join_tab[1].select_cond)

  $161 = 0x555556cebec0 "(t2.f2 = t3.f3)"

(gdb) p ((Item*)(join_tab[1].select_cond))->args[0]

  $163 = (Item_field *) 0x7fff50009488

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]

  $164 = (Item_outer_ref *) 0x7fff5000be80

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]

  $166 = (Item_direct_ref *) 0x7fff5000c0d8

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]

  $167 = (Item_field *) 0x7fff50009580

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field

  $168 = (Field_long *) 0x7fff50020f48

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field->field_name

  $169 = 0x7fff5001de19 "f3"

(gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field->table->alias.Ptr

  $171 = 0x7fff5001dcb0 "t3"

Sergei Petrunia added a comment - 2015-10-04 13:55 Changed the query's WHERE to be f3 IN ( 3,4 ) so that the upper query produces some rows. Then, looking at the subquery WHERE while subquery is executed: (gdb) p dbug_print_item(join_tab[1].select_cond) $161 = 0x555556cebec0 "(t2.f2 = t3.f3)" (gdb) p ((Item*)(join_tab[1].select_cond))->args[0] $163 = (Item_field *) 0x7fff50009488 (gdb) p ((Item*)(join_tab[1].select_cond))->args[1] $164 = (Item_outer_ref *) 0x7fff5000be80 (gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0] $166 = (Item_direct_ref *) 0x7fff5000c0d8 (gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0] $167 = (Item_field *) 0x7fff50009580 (gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field $168 = (Field_long *) 0x7fff50020f48 (gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field->field_name $169 = 0x7fff5001de19 "f3" (gdb) p ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]->field->table->alias.Ptr $171 = 0x7fff5001dcb0 "t3"

Sergei Petrunia added a comment - 2015-10-04 15:26

That is, when subquery executes, we have:

Item_outer_ref(Item_direct_ref(Item_field(t3.f3)))

Watching this expression

(gdb) set $a2=& ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0]

(gdb) p *$a2

  $211 = (Item_field *) 0x7fff50009580

(gdb) watch *$a2

...

  Hardware watchpoint 10: *$a2

  Old value = (Item_field *) 0x7fff50009580

  New value = (Item_field *) 0x7fff5002d308

we see that it changes here:

  #0  __memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1997

  #1  0x0000555555ab52c4 in JOIN::set_items_ref_array (this=0x7fff5000ad48, ptr=0x7fff5000b2f0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.h:1431

  #2  0x0000555555a77926 in JOIN::exec_inner (this=0x7fff5000ad48) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:2706

  #3  0x0000555555a7660f in JOIN::exec (this=0x7fff5000ad48) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:2409

  #4  0x0000555555a79cf1 in mysql_select (thd=0x55555ac73a30, rref_pointer_array=0x55555ac77d98, tables=0x7fff500099a8, wild_num=0, fields=..., conds=0x7fff5000a830, og_num=2, order=0x7fff5000abb8, group=0x7fff5000aa70, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fff5000ad28, unit=0x55555ac77430, select_lex=0x55555ac77b20) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:3346

  #5  0x0000555555a6fc57 in handle_select (thd=0x55555ac73a30, lex=0x55555ac77368, result=0x7fff5000ad28, setup_tables_done_option=0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:371

  #6  0x0000555555a40496 in execute_sqlcom_select (thd=0x55555ac73a30, all_tables=0x7fff500099a8) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:5849

  #7  0x0000555555a365b4 in mysql_execute_command (thd=0x55555ac73a30) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:2962

  #8  0x0000555555a439ed in mysql_parse (thd=0x55555ac73a30, rawbuf=0x7fff50007418 "ANALYZE FORMAT=JSON  SELECT GROUP_CONCAT(f3) AS gc, ( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 ) sq FROM t2, t3 WHERE f3 IN ( 3,4 )  GROUP BY sq ORDER BY gc", length=156, parser_state=0x7fff6bffe100) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:7227

The change is from an Item_field("t3.f3") to Item_field(<temporary table>).

Sergei Petrunia added a comment - 2015-10-04 15:26 That is, when subquery executes, we have: Item_outer_ref(Item_direct_ref(Item_field(t3.f3))) Watching this expression (gdb) set $a2=& ((Item*)(join_tab[1].select_cond))->args[1]->ref[0]->ref[0] (gdb) p *$a2 $211 = (Item_field *) 0x7fff50009580 (gdb) watch *$a2 ... Hardware watchpoint 10: *$a2 Old value = (Item_field *) 0x7fff50009580 New value = (Item_field *) 0x7fff5002d308 we see that it changes here: #0 __memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1997 #1 0x0000555555ab52c4 in JOIN::set_items_ref_array (this=0x7fff5000ad48, ptr=0x7fff5000b2f0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.h:1431 #2 0x0000555555a77926 in JOIN::exec_inner (this=0x7fff5000ad48) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:2706 #3 0x0000555555a7660f in JOIN::exec (this=0x7fff5000ad48) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:2409 #4 0x0000555555a79cf1 in mysql_select (thd=0x55555ac73a30, rref_pointer_array=0x55555ac77d98, tables=0x7fff500099a8, wild_num=0, fields=..., conds=0x7fff5000a830, og_num=2, order=0x7fff5000abb8, group=0x7fff5000aa70, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fff5000ad28, unit=0x55555ac77430, select_lex=0x55555ac77b20) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:3346 #5 0x0000555555a6fc57 in handle_select (thd=0x55555ac73a30, lex=0x55555ac77368, result=0x7fff5000ad28, setup_tables_done_option=0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:371 #6 0x0000555555a40496 in execute_sqlcom_select (thd=0x55555ac73a30, all_tables=0x7fff500099a8) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:5849 #7 0x0000555555a365b4 in mysql_execute_command (thd=0x55555ac73a30) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:2962 #8 0x0000555555a439ed in mysql_parse (thd=0x55555ac73a30, rawbuf=0x7fff50007418 "ANALYZE FORMAT=JSON SELECT GROUP_CONCAT(f3) AS gc, ( SELECT MAX(f1) FROM t1, t2 WHERE f2 = f3 ) sq FROM t2, t3 WHERE f3 IN ( 3,4 ) GROUP BY sq ORDER BY gc", length=156, parser_state=0x7fff6bffe100) at /home/psergey/dev-git/10.1-dbg3/sql/sql_parse.cc:7227 The change is from an Item_field("t3.f3") to Item_field(<temporary table>).

Sergei Petrunia added a comment - 2015-10-04 19:37

So if we have functions like JOIN::set_items_ref_array that change what Item_ref items point to, how can one try to print item trees that have been implicitly modified by set_items_ref_array?

Attempt to save and print the item that Item_ref originally pointed to. We'll need to distinguish between "early" (pre-set_items_ref_array) and "late" (post-set_items_ref_array) expressions. Considering that each subquery has its own set_items_ref_array call (or even several?), this may get very complex.
Make Item_field objects that point to temporary tables printable after the table is gone. Hope that printing these Item_field objects instead of what Item_ref was originally pointing at is acceptable.

Sergei Petrunia added a comment - 2015-10-04 19:37 So if we have functions like JOIN::set_items_ref_array that change what Item_ref items point to, how can one try to print item trees that have been implicitly modified by set_items_ref_array ? Attempt to save and print the item that Item_ref originally pointed to. We'll need to distinguish between "early" (pre-set_items_ref_array) and "late" (post-set_items_ref_array) expressions. Considering that each subquery has its own set_items_ref_array call (or even several?), this may get very complex. Make Item_field objects that point to temporary tables printable after the table is gone. Hope that printing these Item_field objects instead of what Item_ref was originally pointing at is acceptable.

Sergei Petrunia added a comment - 2015-10-05 15:51

elenst, Could you make a test run with this patch (combined for ~~MDEV-8864~~ and ~~MDEV-7267~~) http://lists.askmonty.org/pipermail/commits/2015-October/008482.html ?

Do you still observe other failures?

Sergei Petrunia added a comment - 2015-10-05 15:51 elenst , Could you make a test run with this patch (combined for MDEV-8864 and MDEV-7267 ) http://lists.askmonty.org/pipermail/commits/2015-October/008482.html ? Do you still observe other failures?

Sergei Petrunia added a comment - 2015-10-05 18:56

Found this comment at the end of JOIN::exec_inner :

/*

    With EXPLAIN EXTENDED we have to restore original ref_array

    for a derived table which is always materialized.

    We also need to do this when we have temp table(s).

    Otherwise we would not be able to print the query correctly.

*/

Sergei Petrunia added a comment - 2015-10-05 18:56 Found this comment at the end of JOIN::exec_inner : /* With EXPLAIN EXTENDED we have to restore original ref_array for a derived table which is always materialized. We also need to do this when we have temp table(s). Otherwise we would not be able to print the query correctly. */

People

Assignee:: Sergei Petrunia

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 2015-09-29 00:16

Updated:: 2015-10-06 18:10

Resolved:: 2015-10-06 18:10

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server