[MDEV-25335] Assertion `!is_arena_for_set_stmt()' failed upon PS with SET STATEMENT within executable comment Created: 2021-04-04  Updated: 2023-07-28  Resolved: 2023-07-28

Status: Closed
Project: MariaDB Server
Component/s: Parser, Prepared Statements
Affects Version/s: 10.2
Fix Version/s: N/A

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: not-10.3, not-10.4, not-10.5, not-10.6


 Description   

The issue appears to be 10.2-only and debug-only, so I don't expect it to be fixed, but it has to be filed.

Execute from MTR with --ps-protocol. 

/*!100102 SET STATEMENT LOCK_WAIT_TIMEOUT= 1 FOR */ SELECT 1;
 
select 2;

The second select doesn't affect the outcome, but it seems to help to get a coredump, otherwise the server tends to die in the middle of writing a crash report in the error log, without a coredump.

10.2 fb9d1519

 
mysqld: /data/src/10.2/sql/sql_lex.h:2926: void LEX::free_set_stmt_mem_root(): Assertion `!is_arena_for_set_stmt()' failed.
 
210404  2:55:09 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f9cb1b57f36 in __GI___assert_fail (assertion=0x5595de1218bb "!is_arena_for_set_stmt()", file=0x5595de121865 "/data/src/10.2/sql/sql_lex.h", line=2926, function=0x5595de121898 "void LEX::free_set_stmt_mem_root()") at assert.c:101
 
#8  0x00005595dd61bab2 in LEX::free_set_stmt_mem_root (this=0x7f9c9407d868) at /data/src/10.2/sql/sql_lex.h:2926
 
#9  0x00005595dd61bca8 in LEX::~LEX (this=0x7f9c9407d868, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:2939
 
#10 0x00005595dd61dec0 in st_lex_local::~st_lex_local (this=0x7f9c9407d868, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:3387
 
#11 0x00005595dd61dee0 in st_lex_local::~st_lex_local (this=0x7f9c9407d868, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:3387
 
#12 0x00005595dd6ef23f in Prepared_statement::~Prepared_statement (this=0x7f9c940068b0, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_prepare.cc:4082
 
#13 0x00005595dd6ef2b4 in Prepared_statement::~Prepared_statement (this=0x7f9c940068b0, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_prepare.cc:4086
 
#14 0x00005595dd681545 in delete_statement_as_hash_key (key=0x7f9c940068b0) at /data/src/10.2/sql/sql_class.cc:3642
 
#15 0x00005595de079a34 in my_hash_delete (hash=0x7f9c94002838, record=0x7f9c940068b0 "\350\\s\336\225U") at /data/src/10.2/mysys/hash.c:632
 
#16 0x00005595dd681883 in Statement_map::erase (this=0x7f9c94002838, statement=0x7f9c940068b0) at /data/src/10.2/sql/sql_class.cc:3757
 
#17 0x00005595dd6f2197 in Prepared_statement::deallocate (this=0x7f9c940068b0) at /data/src/10.2/sql/sql_prepare.cc:5202
 
#18 0x00005595dd6ee382 in mysqld_stmt_close (thd=0x7f9c94000d90, packet=0x7f9c94008b51 "\001") at /data/src/10.2/sql/sql_prepare.cc:3720
 
#19 0x00005595dd6c1354 in dispatch_command (command=COM_STMT_CLOSE, thd=0x7f9c94000d90, packet=0x7f9c94008b51 "\001", packet_length=4, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1790
 
#20 0x00005595dd6c015f in do_command (thd=0x7f9c94000d90) at /data/src/10.2/sql/sql_parse.cc:1381
 
#21 0x00005595dd81ac94 in do_handle_one_connection (connect=0x5595e011f120) at /data/src/10.2/sql/sql_connect.cc:1336
 
#22 0x00005595dd81a9f9 in handle_one_connection (arg=0x5595e011f120) at /data/src/10.2/sql/sql_connect.cc:1241
 
#23 0x00005595de044f16 in pfs_spawn_thread (arg=0x5595e0102800) at /data/src/10.2/storage/perfschema/pfs.cc:1869
 
#24 0x00007f9cb2069609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#25 0x00007f9cb1c43293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

No obvious immediate problem on non-debug builds.
Not reproducible on 10.3+, including very old 10.3.6.



 Comments   
Comment by Elena Stepanova [ 2021-05-27 ]

Another variation. No executable comment, Perl connector instead.
Also affects 10.2 only.

--perl
 
  use DBI;
 
  my $dbh= DBI->connect("dbi:mysql:user=root:host=127.0.0.1:port=$ENV{MASTER_MYPORT}:database=test;mysql_server_prepare=1");
 
  $dbh->do("SET STATEMENT binlog_format=statement FOR CREATE OR REPLACE TABLE t (a INT)");
 
EOF
 
 
 
--source include/restart_mysqld.inc
 
DROP TABLE t;

10.2 17106c98 debug

 
mysqld: /data/src/10.2/sql/sql_lex.h:2947: void LEX::free_set_stmt_mem_root(): Assertion `!is_arena_for_set_stmt()' failed.
 
210528  1:09:12 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f6bbf068f36 in __GI___assert_fail (assertion=0x5605b7faa93b "!is_arena_for_set_stmt()", file=0x5605b7faa8e5 "/data/src/10.2/sql/sql_lex.h", line=2947, function=0x5605b7faa918 "void LEX::free_set_stmt_mem_root()") at assert.c:101
 
#8  0x00005605b74a1bb0 in LEX::free_set_stmt_mem_root (this=0x7f6b9c018938) at /data/src/10.2/sql/sql_lex.h:2947
 
#9  0x00005605b74a1da6 in LEX::~LEX (this=0x7f6b9c018938, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:2960
 
#10 0x00005605b74a3fbe in st_lex_local::~st_lex_local (this=0x7f6b9c018938, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:3432
 
#11 0x00005605b74a3fde in st_lex_local::~st_lex_local (this=0x7f6b9c018938, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_lex.h:3432
 
#12 0x00005605b7575479 in Prepared_statement::~Prepared_statement (this=0x7f6b9c018500, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_prepare.cc:4079
 
#13 0x00005605b75754ee in Prepared_statement::~Prepared_statement (this=0x7f6b9c018500, __in_chrg=<optimized out>) at /data/src/10.2/sql/sql_prepare.cc:4083
 
#14 0x00005605b7507657 in delete_statement_as_hash_key (key=0x7f6b9c018500) at /data/src/10.2/sql/sql_class.cc:3696
 
#15 0x00005605b7f01900 in my_hash_free_elements (hash=0x7f6b9c002838) at /data/src/10.2/mysys/hash.c:134
 
#16 0x00005605b7f01a26 in my_hash_reset (hash=0x7f6b9c002838) at /data/src/10.2/mysys/hash.c:177
 
#17 0x00005605b7507ad6 in Statement_map::reset (this=0x7f6b9c002838) at /data/src/10.2/sql/sql_class.cc:3830
 
#18 0x00005605b7500787 in THD::cleanup (this=0x7f6b9c000d90) at /data/src/10.2/sql/sql_class.cc:1419
 
#19 0x00005605b7452bf4 in unlink_thd (thd=0x7f6b9c000d90) at /data/src/10.2/sql/mysqld.cc:2963
 
#20 0x00005605b74530a3 in one_thread_per_connection_end (thd=0x7f6b9c000d90, put_in_cache=true) at /data/src/10.2/sql/mysqld.cc:3108
 
#21 0x00005605b76a1b1a in do_handle_one_connection (connect=0x5605ba007bb0) at /data/src/10.2/sql/sql_connect.cc:1355
 
#22 0x00005605b76a1796 in handle_one_connection (arg=0x5605ba007bb0) at /data/src/10.2/sql/sql_connect.cc:1241
 
#23 0x00005605b7ecdd30 in pfs_spawn_thread (arg=0x5605ba049930) at /data/src/10.2/storage/perfschema/pfs.cc:1869
 
#24 0x00007f6bbf578609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#25 0x00007f6bbf154293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.2 17106c98 non-debug ASAN

 
Warning: Memory not freed: 16
 
 
 
=================================================================
 
==3112267==ERROR: LeakSanitizer: detected memory leaks
 
 
 
Direct leak of 16 byte(s) in 1 object(s) allocated from:
 
    #0 0x7f3141a08bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x55b7e887c156 in my_malloc /data/src/10.2/mysys/my_malloc.c:101
 
    #2 0x55b7e7396ed3 in String::real_alloc(unsigned long) /data/src/10.2/sql/sql_string.cc:45
 
    #3 0x55b7e73977ca in String::alloc(unsigned long) /data/src/10.2/sql/sql_string.h:361
 
    #4 0x55b7e73977ca in String::copy(char const*, unsigned long, charset_info_st const*) /data/src/10.2/sql/sql_string.cc:188
 
    #5 0x55b7e71ad803 in Item_string::Item_string(THD*, charset_info_st const*, char const*, unsigned int) /data/src/10.2/sql/item.h:3525
 
    #6 0x55b7e71ad803 in run_set_statement_if_requested(THD*, LEX*) /data/src/10.2/sql/sql_parse.cc:3094
 
    #7 0x55b7e71c4713 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3397
 
    #8 0x55b7e721fc48 in Prepared_statement::execute(String*, bool) /data/src/10.2/sql/sql_prepare.cc:5052
 
    #9 0x55b7e72205b3 in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /data/src/10.2/sql/sql_prepare.cc:4481
 
    #10 0x55b7e7224964 in mysql_stmt_execute_common /data/src/10.2/sql/sql_prepare.cc:3465
 
    #11 0x55b7e7224c0e in mysqld_stmt_execute(THD*, char*, unsigned int) /data/src/10.2/sql/sql_prepare.cc:3255
 
    #12 0x55b7e71e5dee in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1770
 
    #13 0x55b7e71eccb5 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1381
 
    #14 0x55b7e74edc86 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
 
    #15 0x55b7e74ee3ce in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #16 0x55b7e87c37f8 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
 
    #17 0x7f314138e608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
 
 
SUMMARY: AddressSanitizer: 16 byte(s) leaked in 1 allocation(s).

Comment by Elena Stepanova [ 2023-07-28 ]

10.2 is EOL.

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