[MDEV-7267] Server crashes in Item_field::print on ANALYZE FORMAT=JSON Created: 2014-12-04  Updated: 2015-10-06  Resolved: 2015-10-06

Status: Closed
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 10.1
Fix Version/s: 10.1.8

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Petrunia
Resolution: Fixed Votes: 0
Labels: analyze-stmt, explain_json

Issue Links:
Relates
relates to MDEV-8864 Server crash #2 in Item_field::print ... Closed
relates to MDEV-6109 EXPLAIN JSON Closed
Sprint: 10.1.8-3, 10.1.8-4

 Description    

CREATE TABLE t1 (a INT);
 
INSERT INTO t1 VALUES (1),(2);
 
 
 
CREATE TABLE t2 (b INT);
 
INSERT INTO t2 VALUES (3),(4);
 
 
 
ANALYZE FORMAT=JSON SELECT STRAIGHT_JOIN * FROM t1, t2 WHERE b IN ( SELECT a FROM t1 );

Stack trace from e1913ba1

 
#3  <signal handler called>
 
#4  0x00007fd375bc4e8e in Item_field::print (this=0x7fd369c5c198, str=0x7fd37543ec50, query_type=QT_EXPLAIN) at 10.1/sql/item.cc:6689
 
#5  0x00007fd375c04b26 in Item_func::print_op (this=0x7fd369e8ba48, str=0x7fd37543ec50, query_type=QT_EXPLAIN) at 10.1/sql/item_func.cc:494
 
#6  0x00007fd375be93c3 in Item_bool_func2::print (this=0x7fd369e8ba48, str=0x7fd37543ec50, query_type=QT_EXPLAIN) at 10.1/sql/item_cmpfunc.h:390
 
#7  0x00007fd375ade71c in write_item (writer=0x7fd37543efd0, item=0x7fd369e8ba48) at 10.1/sql/sql_explain.cc:1065
 
#8  0x00007fd375adf281 in Explain_table_access::print_explain_json (this=0x7fd369e8c620, query=0x7fd369df5088, writer=0x7fd37543efd0, is_analyze=true) at 10.1/sql/sql_explain.cc:1268
 
#9  0x00007fd375add6a6 in Explain_basic_join::print_explain_json (this=0x7fd369e8c018, query=0x7fd369df5088, writer=0x7fd37543efd0, is_analyze=true) at 10.1/sql/sql_explain.cc:739
 
#10 0x00007fd375add5b2 in Explain_select::print_explain_json (this=0x7fd369e8c018, query=0x7fd369df5088, writer=0x7fd37543efd0, is_analyze=true) at 10.1/sql/sql_explain.cc:720
 
#11 0x00007fd375adbb28 in Explain_query::print_explain_json (this=0x7fd369df5088, output=0x7fd369e8c8d8, is_analyze=true) at 10.1/sql/sql_explain.cc:205
 
#12 0x00007fd375adb885 in Explain_query::send_explain (this=0x7fd369df5088, thd=0x7fd36df26070) at 10.1/sql/sql_explain.cc:149
 
#13 0x00007fd3759840fe in execute_sqlcom_select (thd=0x7fd36df26070, all_tables=0x7fd369de02f8) at 10.1/sql/sql_parse.cc:5767
 
#14 0x00007fd37597a643 in mysql_execute_command (thd=0x7fd36df26070) at 10.1/sql/sql_parse.cc:2892
 
#15 0x00007fd375987169 in mysql_parse (thd=0x7fd36df26070, rawbuf=0x7fd369de0088 "ANALYZE FORMAT=JSON SELECT STRAIGHT_JOIN * FROM t1, t2 WHERE b IN ( SELECT a FROM t1 )", length=86, parser_state=0x7fd3754401c0) at 10.1/sql/sql_parse.cc:7028
 
#16 0x00007fd375976a5e in dispatch_command (command=COM_QUERY, thd=0x7fd36df26070, packet=0x7fd36e3fa071 "", packet_length=86) at 10.1/sql/sql_parse.cc:1460
 
#17 0x00007fd37597587c in do_command (thd=0x7fd36df26070) at 10.1/sql/sql_parse.cc:1089
 
#18 0x00007fd375aa40b0 in do_handle_one_connection (thd_arg=0x7fd36df26070) at 10.1/sql/sql_connect.cc:1347
 
#19 0x00007fd375aa3df5 in handle_one_connection (arg=0x7fd36df26070) at 10.1/sql/sql_connect.cc:1258
 
#20 0x00007fd376040e22 in pfs_spawn_thread (arg=0x7fd3728249f0) at 10.1/storage/perfschema/pfs.cc:1860
 
#21 0x00007fd375076b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#22 0x00007fd37310d20d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112



 Comments   
Comment by Sergei Petrunia [ 2014-12-06 ]

The query uses SJ-Materialization.

The query plan is:

MariaDB [j5]> EXPLAIN FORMAT=JSON SELECT STRAIGHT_JOIN * FROM t1, t2 WHERE b IN ( SELECT a FROM t1 )\G
 
*************************** 1. row ***************************
 
EXPLAIN: {
 
  "query_block": {
 
    "select_id": 1,
 
    "table": {
 
      "table_name": "t1",
 
      "access_type": "ALL",
 
      "rows": 2,
 
      "filtered": 100
 
    },
 
    "block-nl-join": {
 
      "table": {
 
        "table_name": "<subquery2>",
 
        "access_type": "ALL",
 
        "possible_keys": ["distinct_key"],
 
        "rows": 2,
 
        "filtered": 100
 
      },
 
      "buffer_type": "flat",
 
      "join_type": "BNL",
 
      "materialized": {
 
        "unique": 1,
 
        "query_block": {
 
          "select_id": 2,
 
          "table": {
 
            "table_name": "t1",
 
            "access_type": "ALL",
 
            "rows": 2,
 
            "filtered": 100
 
          }
 
        }
 
      }
 
    },
 
    "block-nl-join": {
 
      "table": {
 
        "table_name": "t2",
 
        "access_type": "ALL",
 
        "rows": 2,
 
        "filtered": 100
 
      },
 
      "buffer_type": "incremental",
 
      "join_type": "BNL",
 
      "attached_condition": "(t2.b = `<subquery2>`.a)"
 
    }
 
  }
 
}

we crash when printing 

      "attached_condition": "(t2.b = `<subquery2>`.a)"

and we crash because we free the temp_table before we try to print ANALYZE output.

Comment by Sergei Petrunia [ 2014-12-06 ]

For most Items, it should be possible to call Item::print after execution structures (joins, temp.tables, etc) have been destroyed.

However, some items are exceptional. Like in this example where an Item_field refers to a field of a temporary table.

  • Solution #1:
    Just don't show conditions in ANALYZE (btw MySQL did something similar in.. was it EXPLAIN FORMAT=JSON FOR CONNECTION?)
  • Solution #2:
    Make the items allow Item::print (or at least Item::print (QT_EXPLAIN) after execution structures have been destroyed. We can modify the existing Item_field, or create a derived class that overrides ::print, and keeps enough data to be able to print. Materialization IN-equalities will use the derived class instead of Item_field.
Comment by Sergei Petrunia [ 2015-09-24 ]

The problematic Item_field object is created here:

  #0  Item_field::Item_field (this=0x7fff5000c510, thd=0x55555ac70a40, context_arg=0x7fff5000c4c0, f=0x7fff500230a8) at /home/psergey/dev-git/10.1-dbg3/sql/item.cc:2206
 
  #1  0x0000555555d160bf in subselect_hash_sj_engine::make_semi_join_conds (this=0x7fff5000bb58) at /home/psergey/dev-git/10.1-dbg3/sql/item_subselect.cc:4945
 
  #2  0x0000555555d15d20 in subselect_hash_sj_engine::init (this=0x7fff5000bb58, tmp_columns=0x7fff500084a0, subquery_id=2) at /home/psergey/dev-git/10.1-dbg3/sql/item_subselect.cc:4868
 
  #3  0x0000555555d126f4 in Item_in_subselect::setup_mat_engine (this=0x7fff50009510) at /home/psergey/dev-git/10.1-dbg3/sql/item_subselect.cc:3274
 
  #4  0x0000555555bbfade in JOIN::choose_subquery_plan (this=0x7fff5000a0d0, join_tables=1) at /home/psergey/dev-git/10.1-dbg3/sql/opt_subselect.cc:5631
 
  #5  0x0000555555a7b7de in make_join_statistics (join=0x7fff5000a0d0, tables_list=..., keyuse_array=0x7fff5000a3e8) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:4118
 
  #6  0x0000555555a7194a in JOIN::optimize_inner (this=0x7fff5000a0d0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:1358
 
  #7  0x0000555555a707a2 in JOIN::optimize (this=0x7fff5000a0d0) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:1021
 
  #8  0x0000555555d0a3dc in Item_in_subselect::optimize (this=0x7fff50009510, out_rows=0x7ffff42ffd78, cost=0x7ffff42ffd80) at /home/psergey/dev-git/10.1-dbg3/sql/item_subselect.cc:709
 
  #9  0x0000555555bbeeb6 in setup_jtbm_semi_joins (join=0x7fff50009820, join_list=0x55555ac74ca8, join_where=0x7fff50009c50) at /home/psergey/dev-git/10.1-dbg3/sql/opt_subselect.cc:5271
 
  #10 0x0000555555a70fa2 in JOIN::optimize_inner (this=0x7fff50009820) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:1194
 
  #11 0x0000555555a707a2 in JOIN::optimize (this=0x7fff50009820) at /home/psergey/dev-git/10.1-dbg3/sql/sql_select.cc:1021
 
  #12 0x0000555555a789e1 in mysql_select (thd=0x55555ac70a40, ...

Comment by Sergei Petrunia [ 2015-09-28 ]

A tentative patch: https://gist.github.com/spetrunia/cfb21f01ef3c462bdb64
elenst, I assume this bug was discovered by some RQG test load? May I request that you run the same load with the above patch and see if there are any other issues?

Comment by Elena Stepanova [ 2015-09-28 ]

psergey,
Yes, it was. Okay, I will.

FYI, during the last run, the same load was triggering 5 more known bugs, which are not 10.1-specific; so it's possible that the results will be cluttered with those, and we won't see ANALYZE/JSON-related issues.

Generated at Thu Feb 08 07:18:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.