[MDEV-21673] Calling stored procedure twice in the same session causes MariaDB to crash Created: 2020-02-05  Updated: 2020-08-25  Resolved: 2020-04-06

Status: Closed
Project: MariaDB Server
Component/s: Stored routines
Affects Version/s: 10.3.16, 10.3.18, 10.3.22, 10.3, 10.4
Fix Version/s: 10.3.23, 10.4.13, 10.5.3

Type: Bug Priority: Critical
Reporter: Rob Schwyzer Assignee: Igor Babaev
Resolution: Fixed Votes: 1
Labels: None
Environment:

Reproduced in CentOS 7 and official MariaDB 10.3 Docker container



 Description   

When running the specified stored procedure twice in the same mysql CLI session, MariaDB crashes without providing an error to the error log (the session simply sees ERROR 2013 (HY000): Lost connection to MySQL server during query).

To reproduce-

  1. Setup a Linux environment with MariaDB 10.3 installed/running
  2. Ensure at least the following is configured in my.cnf (or similar)-
    1. [server]
      lower_case_table_names=1

  3. Create a new database called test (assuming one of the same name doesn't exist on your system already)
  4. Import the contents of 35872.sql (attached to this issue) into your new, test database
  5. On the mysql CLI...
    1. USE test ;
      CALL YAR_FUNC(str_to_date('2019-07-01', '%Y-%m-%d'),str_to_date('2019-10-01', '%Y-%m-%d'),0,'TEST_ANY_80_2','--MA--','Branch/Subsidiary','Locomotive Branch','GB_A_MOP_GENERAL_XTTY') ;
      CALL YAR_FUNC(str_to_date('2019-07-01', '%Y-%m-%d'),str_to_date('2019-10-01', '%Y-%m-%d'),0,'TEST_ANY_80_2','--MA--','Branch/Subsidiary','Locomotive Branch','GB_A_MOP_GENERAL_XTTY') ;

    2. Note that you can make other queries between the two CALL YAR_FUNC commands and the outcome will remain the same
  6. You should immediately experience a loss of connectivity, and if you check MariaDB's error log you should see evidence of a shutdown/restart

Backtrace-

#0  0x00007fb72f7157ab in __GI___clock_gettime (clock_id=clock_id@entry=0, tp=tp@entry=0x7fb7151e43b0) at ../sysdeps/unix/clock_gettime.c:115
#1  0x000055fdd6d0c113 in my_hrtime () at /usr/src/debug/MariaDB-10.3.22/src_0/mysys/my_getsystime.c:94
#2  0x000055fdd67b31e4 in handle_fatal_signal (sig=11) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/signal_handler.cc:124
#3  <signal handler called>
#4  __memcpy_ssse3 () at ../sysdeps/x86_64/multiarch/memcpy-ssse3.S:2835
#5  0x000055fdd6655728 in memcpy (__len=4294967292, __src=0x55fdda190a95, __dest=<optimized out>) at /usr/include/bits/string3.h:51
#6  String::append (this=this@entry=0x7fb7151e4f00,
    s=0x55fdda190a95 " \n\tAND th.nodeid = p_BranchSubsidary \n\tAND FIND_IN_SET(th.child_nodeid, p_Node)\n),\nDISTINCT_BACKTESTCONFIG AS (\n\tSELECT DISTINCT\n\t   backtest_confignum, var_datasetnum\n\tFROM backtest_config\n\tWHERE bac"..., size=4294967292) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/sql_string.cc:555
#7  0x000055fdd654c045 in copy_up_to (bytes=<optimized out>, this=<synthetic pointer>) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/item.h:554
#8  append (p=0x55fdda1d1268, this=<synthetic pointer>) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/item.h:564
#9  subst_spvars (instr=0x55fdda190448, query_str=0x55fdda190480, thd=0x55fdda0c75e8) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/sp_head.cc:1083
#10 sp_instr_stmt::execute (this=0x55fdda190448, thd=0x55fdda0c75e8, nextp=0x7fb7151e5230) at /usr/src/debug/MariaDB-10.3.22/src_0/sql/sp_head.cc:3503



 Comments   
Comment by Rob Schwyzer [ 2020-02-05 ]

Todos, time permitting

  1. Check if this behavior persists in MariaDB 10.4
  2. Narrow down the minimum reproduction case (it seems like only part of the stored procedure is at-fault, so a simpler procedure or query may be able to reproduce this issue)
Comment by Alice Sherepa [ 2020-02-06 ]

Reproduced as described on 10.3-10.4
on debug version assertion `bytes >= from' failed in Copy_query_with_rewrite::copy_up_to

10.3 fafb35ee517f309d9e50

#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x00007f9ec1c41535 in __GI_abort () at abort.c:79
#6  0x00007f9ec1c4140f in __assert_fail_base (fmt=0x7f9ec1da3ee0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x562e506ee478 "bytes >= from", file=0x562e506ee486 "/10.3/sql/item.h", line=553, function=<optimized out>) at assert.c:92
#7  0x00007f9ec1c4f102 in __GI___assert_fail (assertion=0x562e506ee478 "bytes >= from", file=0x562e506ee486 "/10.3/sql/item.h", line=553, function=0x562e506efe60 <Copy_query_with_rewrite::copy_up_to(unsigned long)::__PRETTY_FUNCTION__> "bool Copy_query_with_rewrite::copy_up_to(size_t)") at assert.c:101
#8  0x0000562e4f9a7024 in Copy_query_with_rewrite::copy_up_to (this=0x7f9ebc12bd80, bytes=213) at /10.3/sql/item.h:553
#9  0x0000562e4f9a70e4 in Copy_query_with_rewrite::append (this=0x7f9ebc12bd80, p=0x7f9e641bddb8) at /10.3/sql/item.h:564
#10 0x0000562e4f999e3d in subst_spvars (thd=0x7f9e64000d50, instr=0x7f9e6405a1d8, query_str=0x7f9e6405a210) at /10.3/sql/sp_head.cc:1083
#11 0x0000562e4f9a0b66 in sp_instr_stmt::execute (this=0x7f9e6405a1d8, thd=0x7f9e64000d50, nextp=0x7f9ebc12c194) at /10.3/sql/sp_head.cc:3503
#12 0x0000562e4f99a926 in sp_head::execute (this=0x7f9e64168078, thd=0x7f9e64000d50, merge_da_on_success=true) at /10.3/sql/sp_head.cc:1371
#13 0x0000562e4f99d3da in sp_head::execute_procedure (this=0x7f9e64168078, thd=0x7f9e64000d50, args=0x7f9e640059d0) at /10.3/sql/sp_head.cc:2311
#14 0x0000562e4fa7b064 in do_execute_sp (thd=0x7f9e64000d50, sp=0x7f9e64168078) at /10.3/sql/sql_parse.cc:2992
#15 0x0000562e4fa7bcde in Sql_cmd_call::execute (this=0x7f9e64012ce0, thd=0x7f9e64000d50) at /10.3/sql/sql_parse.cc:3232
#16 0x0000562e4fa85ab3 in mysql_execute_command (thd=0x7f9e64000d50) at /10.3/sql/sql_parse.cc:6031
#17 0x0000562e4fa8b1cc in mysql_parse (thd=0x7f9e64000d50, rawbuf=0x7f9e64012a78 "CALL SP_RPT_MONTHLY_BACKTEST_VAR_ACTION(str_to_date('2019-07-01', '%Y-%m-%d'),str_to_date('2019-10-01', '%Y-%m-%d'),0,'TEST_ANY_80_2','--MA--','Branch/Subsidiary','Locomotive Branch','GB_A_MOP_GENERAL"..., length=207, parser_state=0x7f9ebc12d5c0, is_com_multi=false, is_next_command=false) at /10.3/sql/sql_parse.cc:7818
#18 0x0000562e4fa77e39 in dispatch_command (command=COM_QUERY, thd=0x7f9e64000d50, packet=0x7f9e64008ed1 "CALL SP_RPT_MONTHLY_BACKTEST_VAR_ACTION(str_to_date('2019-07-01', '%Y-%m-%d'),str_to_date('2019-10-01', '%Y-%m-%d'),0,'TEST_ANY_80_2','--MA--','Branch/Subsidiary','Locomotive Branch','GB_A_MOP_GENERAL"..., packet_length=208, is_com_multi=false, is_next_command=false) at /10.3/sql/sql_parse.cc:1855
#19 0x0000562e4fa7678c in do_command (thd=0x7f9e64000d50) at /10.3/sql/sql_parse.cc:1401
#20 0x0000562e4fbec73d in do_handle_one_connection (connect=0x562e528001b0) at /10.3/sql/sql_connect.cc:1403
#21 0x0000562e4fbec49f in handle_one_connection (arg=0x562e528001b0) at /10.3/sql/sql_connect.cc:1308
#22 0x0000562e5058131d in pfs_spawn_thread (arg=0x562e5278c340) at /10.3/storage/perfschema/pfs.cc:1869
#23 0x00007f9ec236cfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#24 0x00007f9ec1d184cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Rob Schwyzer [ 2020-02-27 ]

I am unable to reproduce this in the following enviornment now, so maybe 10.4.12 helped with this?

cat /etc/redhat-release ; mysql -V
CentOS Linux release 7.7.1908 (Core)
mysql  Ver 15.1 Distrib 10.4.12-MariaDB, for Linux (x86_64) using readline 5.1

UPDATE-

I also verified with the official MariaDB Docker image for 10.4. Here is the docker-compose file I used-

# Use root/example as user/password credentials
version: '3.7'
 
services:
 
  db:
    image: mariadb:10.4
    restart: always
    environment:
      MYSQL_ROOT_PASSWORD: k!2la30A
    ports:
        - 3306:3306
    volumes:
      - ".\\my.cnf.d:/etc/mysql/conf.d"

I used docker cp to copy the file into /root/, then I used docker exec -it containerid bash to get a shell which I used to create the test database, import the .sql file into that database, and to then run the commands (in mysql CLI) from the original description of this issue. I encountered no crashes.

Comment by Rob Schwyzer [ 2020-03-02 ]

I have also verified 10.4.11 and 10.4.10 work without issue (via MariaDB Docker).

I plan to test 10.4.9 and lower as well (requires a different setup which I am working on now).

Comment by Rob Schwyzer [ 2020-03-02 ]

I should have gone about this from the other direction from the start as 10.4.1 works as well (I also tested 10.4.8 - 10.4.6 and verified those all work as well).

Buuuut... 10.4.0 fails-

db_1  | Thread pointer: 0x557313f20ee8
db_1  | Attempting backtrace. You can use the following information to find out
db_1  | where mysqld died. If you see no messages after this, something went
db_1  | terribly wrong...
db_1  | stack_bottom = 0x7f1d8010edd8 thread_stack 0x49000
db_1  | mysqld(my_print_stacktrace+0x2e)[0x557310052d6e]
db_1  | mysqld(handle_fatal_signal+0x5a5)[0x55730faed445]
db_1  | /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f1d87a45890]
db_1  | /lib/x86_64-linux-gnu/libc.so.6(+0x16c7e0)[0x7f1d870877e0]
db_1  | mysqld(_ZN6String6appendEPKcm+0xc2)[0x55730f988502]
db_1  | mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x42d)[0x55730f8870cd]
db_1  | mysqld(_ZN7sp_head7executeEP3THDb+0x83c)[0x55730f8829ac]
db_1  | mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x93e)[0x55730f883d9e]
db_1  | mysqld(+0x59c959)[0x55730f904959]
db_1  | mysqld(_ZN12Sql_cmd_call7executeEP3THD+0x166)[0x55730f906796]
db_1  | mysqld(_Z21mysql_execute_commandP3THD+0x1246)[0x55730f90c6c6]
db_1  | mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x245)[0x55730f913d85]
db_1  | mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1ca7)[0x55730f916757]
db_1  | mysqld(_Z10do_commandP3THD+0x178)[0x55730f917558]
db_1  | mysqld(_Z24do_handle_one_connectionP7CONNECT+0x212)[0x55730f9e6cd2]
db_1  | mysqld(handle_one_connection+0x3d)[0x55730f9e6ead]
db_1  | /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f1d87a3a6db]
db_1  | /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f1d8703c88f]
db_1  |
db_1  | Trying to get some variables.
db_1  | Some pointers may be invalid and cause the dump to abort.
db_1  | Query (0x5573140947d0): WITH TREE_NODE_TBL AS (  SELECT DISTINCT    child_nodenum AS nodenum   FROM tree_hierarchy th   JOIN tree t ON th.treenum = t.treenum  WHERE     t.treeid = 'GB_A_MOP_GENERAL_XTTY'   AND t.status = 'A'  AND th.day = p_ChartEndDate   AND th.nodeid = p_BranchSubsidary   AND FIND_IN_SET(th.child_nodeid, p_Node) ), DISTINCT_BACKTESTCONFIG AS (  SELECT DISTINCT     backtest_confignum, var_datasetnum  FROM backtest_config  WHERE backtest_configid = p_BacktestID ), DISTINCT_VAR_nodenum AS ( SELECT DISTINCT   nodenum FROM var  WHERE FIND_IN_SET(nodeid, p_Node) AND   (        ( p_Level LIKE 'Global Plaque Links%' AND nodenum IN ( SELECT nodenum FROM TREE_NODE_TBL ) )   OR    ( p_Level not like 'Global Plaque Links%' )     ) AND var_datasetnum in ( select distinct var_datasetnum FROM DISTINCT_BACKTESTCONFIG ) ), RANK_SQL AS ( select    DAY,    nodenum,    dense_rank() over (partition by nodenum order by day desc) rn FROM    backtest WHERE    day <= p_ChartEndDate AND result <> 'NPR' AND backtest_confignum in ( SELECT backtest_confignum FROM DISTINCT_BACKTESTCONFIG ) AND nodenum in ( SELECT nodenum FROM DISTINCT_VAR_nodenum )  ), RANK_BT_PERIOD AS ( SELECT DISTINCT day, nodenum FROM  RANK_SQL WHERE rn <= p_BacktestingPeriod ), MIN_START_DAY AS ( SELECT   MIN(DAY) as startday,   nodenum FROM RANK_BT_PERIOD GROUP BY nodenum ), BACKTEST_ACTION AS ( SELECT distinct    pl.nodenum,    pl.day,    pl.BACKTESTPL,    ((SUM(pl.BACKTESTPL) OVER (partition by pl.nodenum ORDER BY PL.DAY, PL.BACKTESTPL)) - (pl.DOWNSIDE_VAR)) CUMAPLSUBVAR,    pl.DOWNSIDE_VAR,    pl.UPSIDE_VAR,    SUM(pl.BACKTESTPL) OVER  ( partition by pl.nodenum ORDER BY pl.DAY, pl.BACKTESTPL ) as CUMACTUAL_PL,   ( pl.BACKTESTPL - pl.DOWNSIDE_VAR ) AS PLMINUSVAR,    pl.PL_TYPE,    A.startday FROM  backtest pl  JOIN backtest_config bc ON bc.backtest_confignum = pl.backtest_confignum  JOIN var V ON pl.day = v.day AND v.var_datasetnum = bc.var_datasetnum AND v.nodenum = pl.nodenum  JOIN var_dataset vd ON vd.var_datasetnum = v.var_datasetnum  LEFT OUTER JOIN MIN_START_DAY A ON pl.nodenum = A.nodenum WHERE    pl.DAY BETWEEN ( CASE WHEN p_BacktestingPeriod = 0 THEN p_ChartStartDate ELSE A.startday END ) AND p_ChartEndDate AND vd.treenum = ( SELECT treenum FROM tree WHERE treeid = p_Tree AND status = 'A' ) AND FIND_IN_SET(v.nodeid, p_Node) AND   (        ( p_Level LIKE 'Global Product Line%' AND v.nodenum IN ( SELECT nodenum FROM TREE_NODE_TBL ) )   OR    ( p_Level not like 'Global Product Line%' )     ) AND bc.backtest_configid = p_BacktestID AND v.status = 'S' AND v.version = 0 AND pl.result <> 'NPR' AND pl.status in ( 'A','U', 'L' ) AND vd.status = 'A' AND bc.status = 'A' ORDER BY pl.nodenum, pl.day ) SELECT * FROM BACKTEST_ACTION
db_1  | Connection ID (thread ID): 10
db_1  | Status: NOT_KILLED
db_1  |
db_1  | Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on

Comment by Rob Schwyzer [ 2020-03-02 ]

There is a DISTINCT windowing function in the test procedure, so I checked into whether MDEV-17676 could be related. It conveys it was fixed in 10.3.12 though and our test case in this issue fails against 10.3.12 (freshly verified). So this is something different.

Comment by Rob Schwyzer [ 2020-03-02 ]

Checked MDEV-15253 by configuring the following in [server] for the latest 10.3-

[server]
lower_case_table_names=1
use_stat_tables=preferably
optimizer_use_condition_selectivity=4

Still problematic-

Server version: 10.3.22-MariaDB-1:10.3.22+maria~bionic
key_buffer_size=134217728
read_buffer_size=2097152
max_used_connections=1
max_threads=102
thread_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 760034 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x556ed7cc0138
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 = 0x7f1f8c83fdd8 thread_stack 0x49000
mysqld(my_print_stacktrace+0x2e)[0x556ed523a2ee]
mysqld(handle_fatal_signal+0x515)[0x556ed4cd2005]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f1f950d0890]
/lib/x86_64-linux-gnu/libc.so.6(+0x16c7e0)[0x7f1f947127e0]
mysqld(_ZN6String6appendEPKcm+0xc2)[0x556ed4b6df82]
mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x42d)[0x556ed4a6b9ad]
mysqld(_ZN7sp_head7executeEP3THDb+0x82c)[0x556ed4a672dc]
mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x92b)[0x556ed4a686db]
mysqld(+0x581325)[0x556ed4ae9325]
mysqld(_ZN12Sql_cmd_call7executeEP3THD+0x166)[0x556ed4aeb196]
mysqld(_Z21mysql_execute_commandP3THD+0x33f0)[0x556ed4af3650]
mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x20a)[0x556ed4af854a]
mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1c57)[0x556ed4afaec7]
mysqld(_Z10do_commandP3THD+0x178)[0x556ed4afbc88]
mysqld(_Z24do_handle_one_connectionP7CONNECT+0x33e)[0x556ed4bce99e]
mysqld(handle_one_connection+0x3d)[0x556ed4bcea6d]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f1f950c56db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f1f946c788f]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x556ed7e5bef0): WITH TREE_NODE_TBL AS (  SELECT DISTINCT    child_nodenum AS nodenum   FROM tree_hierarchy th   JOIN tree t ON th.treenum = t.treenum  WHERE     t.treeid = 'GB_A_MOP_GENERAL_XTTY'   AND t.status = 'A'  AND th.day = p_ChartEndDate   AND th.nodeid = p_BranchSubsidary   AND FIND_IN_SET(th.child_nodeid, p_Node) ), DISTINCT_BACKTESTCONFIG AS (  SELECT DISTINCT     backtest_confignum, var_datasetnum  FROM backtest_config  WHERE backtest_configid = p_BacktestID ), DISTINCT_VAR_nodenum AS ( SELECT DISTINCT   nodenum FROM var  WHERE FIND_IN_SET(nodeid, p_Node) AND   (        ( p_Level LIKE 'Global Plaque Links%' AND nodenum IN ( SELECT nodenum FROM TREE_NODE_TBL ) )   OR    ( p_Level not like 'Global Plaque Links%' )     ) AND var_datasetnum in ( select distinct var_datasetnum FROM DISTINCT_BACKTESTCONFIG ) ), RANK_SQL AS ( select    DAY,    nodenum,    dense_rank() over (partition by nodenum order by day desc) rn FROM    backtest WHERE    day <= p_ChartEndDate AND result <> 'NPR' AND backtest_confignum in ( SELECT backtest_confignum FROM DISTINCT_BACKTESTCONFIG ) AND nodenum in ( SELECT nodenum FROM DISTINCT_VAR_nodenum )  ), RANK_BT_PERIOD AS ( SELECT DISTINCT day, nodenum FROM  RANK_SQL WHERE rn <= p_BacktestingPeriod ), MIN_START_DAY AS ( SELECT   MIN(DAY) as startday,   nodenum FROM RANK_BT_PERIOD GROUP BY nodenum ), BACKTEST_ACTION AS ( SELECT distinct    pl.nodenum,    pl.day,    pl.BACKTESTPL,    ((SUM(pl.BACKTESTPL) OVER (partition by pl.nodenum ORDER BY PL.DAY, PL.BACKTESTPL)) - (pl.DOWNSIDE_VAR)) CUMAPLSUBVAR,    pl.DOWNSIDE_VAR,    pl.UPSIDE_VAR,    SUM(pl.BACKTESTPL) OVER  ( partition by pl.nodenum ORDER BY pl.DAY, pl.BACKTESTPL ) as CUMACTUAL_PL,   ( pl.BACKTESTPL - pl.DOWNSIDE_VAR ) AS PLMINUSVAR,    pl.PL_TYPE,    A.startday FROM  backtest pl  JOIN backtest_config bc ON bc.backtest_confignum = pl.backtest_confignum  JOIN var V ON pl.day = v.day AND v.var_datasetnum = bc.var_datasetnum AND v.nodenum = pl.nodenum  JOIN var_dataset vd ON vd.var_datasetnum = v.var_datasetnum  LEFT OUTER JOIN MIN_START_DAY A ON pl.nodenum = A.nodenum WHERE    pl.DAY BETWEEN ( CASE WHEN p_BacktestingPeriod = 0 THEN p_ChartStartDate ELSE A.startday END ) AND p_ChartEndDate AND vd.treenum = ( SELECT treenum FROM tree WHERE treeid = p_Tree AND status = 'A' ) AND FIND_IN_SET(v.nodeid, p_Node) AND   (        ( p_Level LIKE 'Global Product Line%' AND v.nodenum IN ( SELECT nodenum FROM TREE_NODE_TBL ) )   OR    ( p_Level not like 'Global Product Line%' )     ) AND bc.backtest_configid = p_BacktestID AND v.status = 'S' AND v.version = 0 AND pl.result <> 'NPR' AND pl.status in ( 'A','U', 'L' ) AND vd.status = 'A' AND bc.status = 'A' ORDER BY pl.nodenum, pl.day ) SELECT * FROM BACKTEST_ACTION
Connection ID (thread ID): 8
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on

Worth noting preferably_for_queries for use_stat_tables was added in 10.4.1 and cannot be tested in earlier versions, but that doesn't seem likely to be the culprit.

I have not yet found the specific change from 10.4.0 to 10.4.1 which rectified this issue, but as 10.4.0 fails and 10.4.1 does not, there must be something in the 10.4.1 commit which can help us.

Comment by Chris Calender (Inactive) [ 2020-03-12 ]

Fwiw, I see this stack trace on Windows using 10.3.22 (it's slightly different, so may give some additional insight):

Version: '10.3.22-MariaDB-debug'  socket: ''  port: 3408  Source distribution
Assertion failed: bytes >= from, file C:\area51\mariadb-10.3.22\sql\item.h, line 553
200312  0:14:43 [ERROR] mysqld got exception 0x80000003 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.3.22-MariaDB-debug
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=1
max_threads=65537
thread_count=7
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 136225 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x144baffbd38
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...
mysqld.exe!my_sigabrt_handler()[my_thr_init.c:485]
mysqld.exe!raise()[signal.cpp:547]
mysqld.exe!abort()[abort.cpp:71]
mysqld.exe!common_assert_to_stderr<wchar_t>()[assert.cpp:186]
mysqld.exe!_wassert()[assert.cpp:443]
mysqld.exe!Copy_query_with_rewrite::copy_up_to()[item.h:553]
mysqld.exe!Copy_query_with_rewrite::append()[item.h:564]
mysqld.exe!subst_spvars()[sp_head.cc:1083]
mysqld.exe!sp_instr_stmt::execute()[sp_head.cc:3502]
mysqld.exe!sp_head::execute()[sp_head.cc:1371]
mysqld.exe!sp_head::execute_procedure()[sp_head.cc:2311]
mysqld.exe!do_execute_sp()[sql_parse.cc:2992]
mysqld.exe!Sql_cmd_call::execute()[sql_parse.cc:3232]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6031]
mysqld.exe!mysql_parse()[sql_parse.cc:7818]
mysqld.exe!dispatch_command()[sql_parse.cc:1858]
mysqld.exe!do_command()[sql_parse.cc:1401]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:359]
mysqld.exe!tp_callback()[threadpool_common.cc:186]
mysqld.exe!tp_callback()[threadpool_win.cc:376]
mysqld.exe!work_callback()[threadpool_win.cc:450]
ntdll.dll!TpReleaseWait()
ntdll.dll!RtlInitializeResource()
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
...

Comment by Chris Calender (Inactive) [ 2020-03-15 ]

Reduced Test Case:

CREATE or REPLACE TABLE `t1` (
`id2` smallint(6) NOT NULL
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t2` (
`id2` smallint(3) unsigned DEFAULT NULL,
`id3` date DEFAULT NULL,
`id4` varchar(50) COLLATE utf8_bin DEFAULT NULL,
`id5` int(8) unsigned DEFAULT NULL
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t3` (
`id1` int(11) DEFAULT NULL,
`id3` date DEFAULT NULL
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t4` (
`id1` int(11) NOT NULL,
`id3` date NOT NULL 
) ENGINE=InnoDB;
 
DELIMITER //
CREATE OR REPLACE PROCEDURE SP1()
BEGIN
DECLARE p_date date;
DECLARE p_var2 varchar(100);
SET p_date='2019-10-01';
SET p_var2='AAA';
WITH XXXXXXX AS
(
	SELECT DISTINCT id5 AS id1 
	FROM t2
	JOIN t1 ON t2.id2 = t1.id2
	WHERE t2.id3 = p_date 
	AND t2.id4 = p_var2 
),
COL2 AS (
	SELECT DISTINCT id1
	FROM t3 
	WHERE id1 IN ( SELECT id1 FROM XXXXXXX )
),
COL3 AS (
	SELECT distinct t4.id1 
	FROM t4
	JOIN t3 ON t4.id3 = t3.id3
	WHERE t3.id1 IN ( SELECT id1 FROM XXXXXXX )
) SELECT * FROM COL3;
END//

Then to crash the server, simply invoke the stored procedure twice:

CALL SP1();
CALL SP1();

Output of console session:

MariaDB [area51]> CALL SP1();
Empty set (0.027 sec)
 
Query OK, 0 rows affected (0.028 sec)
 
MariaDB [area51]> CALL SP1();
ERROR 2013 (HY000): Lost connection to MySQL server during query
MariaDB [area51]>

Stack trace from error log (Windows debug 10.4.0):

200315 18:40:13 [ERROR] mysqld got exception 0xc0000005 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.4.0-MariaDB
key_buffer_size=11534336
read_buffer_size=65536
max_used_connections=1
max_threads=65537
thread_count=7
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 13589 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0xd818ec8
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...
VCRUNTIME140.dll!memmove()
mysqld.exe!String::append()[sql_string.cc:555]
mysqld.exe!subst_spvars()[sp_head.cc:1039]
mysqld.exe!sp_instr_stmt::execute()[sp_head.cc:3461]
mysqld.exe!sp_head::execute()[sp_head.cc:1327]
mysqld.exe!sp_head::execute_procedure()[sp_head.cc:2267]
mysqld.exe!do_execute_sp()[sql_parse.cc:2952]
mysqld.exe!Sql_cmd_call::execute()[sql_parse.cc:3194]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6299]
mysqld.exe!mysql_parse()[sql_parse.cc:8096]
mysqld.exe!dispatch_command()[sql_parse.cc:1853]
mysqld.exe!do_command()[sql_parse.cc:1395]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:358]
mysqld.exe!tp_callback()[threadpool_common.cc:186]
ntdll.dll!TpPostWork()
ntdll.dll!TpDisassociateCallback()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0xfeaec80): WITH TREE_N1 AS
(
	SELECT DISTINCT id5 AS id1 
	FROM t2
	JOIN t1 ON t2.id2 = t1.id2
	WHERE t2.id3 = p_date 
	AND t2.id4 = p_var2 
),
COL2 AS (
	SELECT DISTINCT id1
	FROM t3 
	WHERE id1 IN ( SELECT id1 FROM TREE_N1 )
),
COL3 AS (
	SELECT distinct t4.id1 
	FROM t4
	JOIN t3 ON t4.id3 = t3.id3
	WHERE t3.id1 IN ( SELECT id1 FROM TREE_N1 )
 
) SELECT * FROM COL3
Connection ID (thread ID): 11
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on
 
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.

I think it is worth noting that when I reduce the length of "XXXXXXX" by even 1 character, say "XXXXXX", it does not crash for me using this abbreviated test case. However, if I shorten the name in the original test case, that does not fix the problem and it still crashes.

Comment by Chris Calender (Inactive) [ 2020-03-18 ]

Further simplified test case:

CREATE or REPLACE TABLE `t1` (
`id1` int(1),
`id2` varchar(5)
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t2` (
`id1` int(1)
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t3` (
`id1` int(1)
) ENGINE=InnoDB;
 
DELIMITER //
CREATE OR REPLACE PROCEDURE SP1()
BEGIN
DECLARE p_var1 int(1);
DECLARE p_var2 varchar(5);
SET p_var1=1;
SET p_var2='WPAFB';
WITH XXXXXXXXXXXX AS
(
    SELECT id1 AS id1 FROM t1
    WHERE id1 = p_var1 
    AND id2 = p_var2 
),
COL2 AS (
    SELECT id1 FROM t2 
    WHERE id1 IN ( SELECT id1 FROM XXXXXXXXXXXX )
),
COL3 AS (
    SELECT id1 FROM t3
    WHERE id1 IN ( SELECT id1 FROM XXXXXXXXXXXX )
) SELECT * FROM COL3;
END//

CALL SP1();
CALL SP1();

Comment by Chris Calender (Inactive) [ 2020-03-19 ]

I tried to reduce it further, but then the crash would not reproduce. As I shortened the test case, I had to increase the length of the first "WITH" 'table' (i.e., XXXXXXXXXXXX). For some reason, I think it requires the double SELECTs from the first WITH 'table' from WITH 'tables' 2 & 3. Just a hunch... However, the variables had to be used, set, and part of the queries... I could not just compare id1 to an INT nor id2 to a string... Also, as I've mentioned, the length of the first WITH 'table' needs to be a certain length. If this test case does not work for you initially in 10.3.22 or 10.4.0, then try increasing the length of that first... Weird but worked for me today on a different machine...

Comment by Oleksandr Byelkin [ 2020-04-01 ]

hmmm no traces about tests on earlier version....

Comment by Oleksandr Byelkin [ 2020-04-01 ]

test suite in terms of our test suite language

 
--source include/have_innodb.inc
 
CREATE or REPLACE TABLE `t1` (
`id1` int(1),
`id2` varchar(5)
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t2` (
`id1` int(1)
) ENGINE=InnoDB;
 
CREATE or REPLACE TABLE `t3` (
`id1` int(1)
) ENGINE=InnoDB;
 
DELIMITER //;
CREATE OR REPLACE PROCEDURE SP1()
BEGIN
DECLARE p_var1 int(1);
DECLARE p_var2 varchar(5);
SET p_var1=1;
SET p_var2='WPAFB';
WITH XXXXXXXXXXXX AS
(
    SELECT id1 AS id1 FROM t1
    WHERE id1 = p_var1 
    AND id2 = p_var2 
),
COL2 AS (
    SELECT id1 FROM t2 
    WHERE id1 IN ( SELECT id1 FROM XXXXXXXXXXXX )
),
COL3 AS (
    SELECT id1 FROM t3
    WHERE id1 IN ( SELECT id1 FROM XXXXXXXXXXXX )
) SELECT * FROM COL3;
END//
DELIMITER ;//
 
CALL SP1();
CALL SP1();

Comment by Oleksandr Byelkin [ 2020-04-01 ]

can not be reproduced on 10.2

Comment by Oleksandr Byelkin [ 2020-04-01 ]

It important to have 2 CTE inside other one, type of subquery, position in the query, and table type are not important, so here is even more simple test suite:

CREATE or REPLACE TABLE `t1` (
`id1` int(1),
`id2` varchar(5)
);
 
CREATE or REPLACE TABLE `t2` (
`id1` int(1)
);
 
 
DELIMITER //;
CREATE OR REPLACE PROCEDURE SP1()
BEGIN
  DECLARE p_var1 int(1);
  DECLARE p_var2 varchar(5);
  SET p_var1=1;
  SET p_var2='WPAFB';
  WITH XXXXXXXXXXXX AS
  (
    SELECT id1 AS id1 FROM t1
    WHERE id1 = p_var1 
    AND id2 = p_var2 
  ),
  COL3 AS (
    SELECT (SELECT id1 FROM XXXXXXXXXXXX LIMIT 1) = 1 or
      (SELECT id1 FROM XXXXXXXXXXXX LIMIT 1) = 2 FROM t2
  ) SELECT  FROM COL3;
END//
DELIMITER ;//
 
CALL SP1();
CALL SP1();

Comment by Oleksandr Byelkin [ 2020-04-04 ]

Ok to push

Comment by Igor Babaev [ 2020-04-06 ]

A fix for this bug was pushed into 10.3

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