ASAN errors in Exec_time_tracker::get_cycles with innodb slow log verbosity

CREATE TABLE t (a INT, b INT);

INSERT INTO t VALUES (1,2);

SET SESSION log_slow_verbosity= 'innodb';

--delimiter $

BEGIN NOT ATOMIC DECLARE r ROW TYPE OF t DEFAULT (SELECT * FROM t); SELECT r.a; END $

--delimiter ;

# Cleanup

DROP TABLE t;

==122112==ERROR: AddressSanitizer: use-after-poison on address 0x625000183f48 at pc 0x55aacc0612a7 bp 0x7f775a84e730 sp 0x7f775a84e728

READ of size 8 at 0x625000183f48 thread T5

    #0 0x55aacc0612a6 in Exec_time_tracker::get_cycles() const (/mnt8t/bld/10.6-asan/bin/mariadbd+0x19432a6)

    #1 0x55aacc02f22d in close_thread_table(THD*, TABLE**) /data/src/10.6/sql/sql_base.cc:992

    #2 0x55aacc02ea80 in close_thread_tables(THD*) /data/src/10.6/sql/sql_base.cc:955

    #3 0x55aacbf83797 in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /data/src/10.6/sql/sp_head.cc:3519

    #4 0x55aacbf8528c in sp_instr_set::execute(THD*, unsigned int*) /data/src/10.6/sql/sp_head.cc:3796

    #5 0x55aacbf75a59 in sp_head::execute(THD*, bool) /data/src/10.6/sql/sp_head.cc:1435

    #6 0x55aacbf7bf77 in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.6/sql/sp_head.cc:2449

    #7 0x55aacc1d1d71 in do_execute_sp /data/src/10.6/sql/sql_parse.cc:3036

    #8 0x55aacc1e62fa in mysql_execute_command(THD*, bool) /data/src/10.6/sql/sql_parse.cc:5749

    #9 0x55aacc1f5454 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.6/sql/sql_parse.cc:8053

    #10 0x55aacc1cb115 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/src/10.6/sql/sql_parse.cc:1896

    #11 0x55aacc1c7e49 in do_command(THD*, bool) /data/src/10.6/sql/sql_parse.cc:1409

    #12 0x55aacc637cbb in do_handle_one_connection(CONNECT*, bool) /data/src/10.6/sql/sql_connect.cc:1416

    #13 0x55aacc63767c in handle_one_connection /data/src/10.6/sql/sql_connect.cc:1318

    #14 0x55aacd2931e7 in pfs_spawn_thread /data/src/10.6/storage/perfschema/pfs.cc:2201

    #15 0x7f77620a7fd3 in start_thread nptl/pthread_create.c:442

    #16 0x7f77621285bb in clone3 ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

0x625000183f48 is located 1608 bytes inside of 8176-byte region [0x625000183900,0x6250001858f0)

allocated by thread T5 here:

    #0 0x7f7762cb89cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69

    #1 0x55aacde93692 in my_malloc /data/src/10.6/mysys/my_malloc.c:91

    #2 0x55aacde6fffc in alloc_root /data/src/10.6/mysys/my_alloc.c:249

    #3 0x55aacbeda8f9 in Sql_alloc::operator new(unsigned long, st_mem_root*) /data/src/10.6/sql/sql_alloc.h:37

    #4 0x55aacbedaafb in base_list::push_back(void*, st_mem_root*) /data/src/10.6/sql/sql_list.h:195

    #5 0x55aacc38fea6 in List<JOIN_TAB_RANGE>::push_back(JOIN_TAB_RANGE*, st_mem_root*) (/mnt8t/bld/10.6-asan/bin/mariadbd+0x1c71ea6)

    #6 0x55aacc2e0a97 in JOIN::get_best_combination() /data/src/10.6/sql/sql_select.cc:11232

    #7 0x55aacc29bc0a in JOIN::optimize_stage2() /data/src/10.6/sql/sql_select.cc:2576

    #8 0x55aacc29b6e6 in JOIN::optimize_inner() /data/src/10.6/sql/sql_select.cc:2555

    #9 0x55aacc2943c8 in JOIN::optimize() /data/src/10.6/sql/sql_select.cc:1868

    #10 0x55aaccc94e37 in subselect_single_select_engine::exec() /data/src/10.6/sql/item_subselect.cc:4011

    #11 0x55aaccc71529 in Item_subselect::exec() /data/src/10.6/sql/item_subselect.cc:811

    #12 0x55aaccc76a4c in Item_singlerow_subselect::bring_value() /data/src/10.6/sql/item_subselect.cc:1413

    #13 0x55aacc9bb7d7 in Field_row::sp_prepare_and_store_item(THD*, Item**) /data/src/10.6/sql/field.cc:2683

    #14 0x55aacbf6def8 in THD::sp_eval_expr(Field*, Item**) /data/src/10.6/sql/sp_head.cc:432

    #15 0x55aacbfaa59e in sp_rcontext::set_variable(THD*, unsigned int, Item**) /data/src/10.6/sql/sp_rcontext.cc:639

    #16 0x55aacbf85462 in sp_instr_set::exec_core(THD*, unsigned int*) /data/src/10.6/sql/sp_head.cc:3809

    #17 0x55aacbf83647 in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /data/src/10.6/sql/sp_head.cc:3501

    #18 0x55aacbf8528c in sp_instr_set::execute(THD*, unsigned int*) /data/src/10.6/sql/sp_head.cc:3796

    #19 0x55aacbf75a59 in sp_head::execute(THD*, bool) /data/src/10.6/sql/sp_head.cc:1435

    #20 0x55aacbf7bf77 in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.6/sql/sp_head.cc:2449

    #21 0x55aacc1d1d71 in do_execute_sp /data/src/10.6/sql/sql_parse.cc:3036

    #22 0x55aacc1e62fa in mysql_execute_command(THD*, bool) /data/src/10.6/sql/sql_parse.cc:5749

    #23 0x55aacc1f5454 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.6/sql/sql_parse.cc:8053

    #24 0x55aacc1cb115 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/src/10.6/sql/sql_parse.cc:1896

    #25 0x55aacc1c7e49 in do_command(THD*, bool) /data/src/10.6/sql/sql_parse.cc:1409

    #26 0x55aacc637cbb in do_handle_one_connection(CONNECT*, bool) /data/src/10.6/sql/sql_connect.cc:1416

    #27 0x55aacc63767c in handle_one_connection /data/src/10.6/sql/sql_connect.cc:1318

    #28 0x55aacd2931e7 in pfs_spawn_thread /data/src/10.6/storage/perfschema/pfs.cc:2201

    #29 0x7f77620a7fd3 in start_thread nptl/pthread_create.c:442

Thread T5 created by T0 here:

    #0 0x7f7762c49726 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:207

    #1 0x55aacd28ef22 in my_thread_create /data/src/10.6/storage/perfschema/my_thread.h:52

    #2 0x55aacd2935d6 in pfs_spawn_thread_v1 /data/src/10.6/storage/perfschema/pfs.cc:2252

    #3 0x55aacbeb789b in inline_mysql_thread_create /data/src/10.6/include/mysql/psi/mysql_thread.h:1139

    #4 0x55aacbeceae4 in create_thread_to_handle_connection(CONNECT*) /data/src/10.6/sql/mysqld.cc:5991

    #5 0x55aacbecf0f5 in create_new_thread(CONNECT*) /data/src/10.6/sql/mysqld.cc:6050

    #6 0x55aacbecf3e0 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.6/sql/mysqld.cc:6112

    #7 0x55aacbecfd70 in handle_connections_sockets() /data/src/10.6/sql/mysqld.cc:6236

    #8 0x55aacbece361 in mysqld_main(int, char**) /data/src/10.6/sql/mysqld.cc:5886

    #9 0x55aacbeb69a8 in main /data/src/10.6/sql/main.cc:34

    #10 0x7f7762046189 in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58

SUMMARY: AddressSanitizer: use-after-poison (/mnt8t/bld/10.6-asan/bin/mariadbd+0x19432a6) in Exec_time_tracker::get_cycles() const

Shadow bytes around the buggy address:

  0x0c4a80028790: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0c4a800287a0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0c4a800287b0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0c4a800287c0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0c4a800287d0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

=>0x0c4a800287e0: f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]f7 f7 f7 f7 f7 f7

  0x0c4a800287f0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 00 00 00 00 00 00

  0x0c4a80028800: 00 00 f7 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0c4a80028810: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0c4a80028820: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0c4a80028830: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

Shadow byte legend (one shadow byte represents 8 application bytes):

  Addressable:           00

  Partially addressable: 01 02 03 04 05 06 07 

  Heap left redzone:       fa

  Freed heap region:       fd

  Stack left redzone:      f1

  Stack mid redzone:       f2

  Stack right redzone:     f3

  Stack after return:      f5

  Stack use after scope:   f8

  Global redzone:          f9

  Global init order:       f6

  Poisoned by user:        f7

  Container overflow:      fc

  Array cookie:            ac

  Intra object redzone:    bb

  ASan internal:           fe

  Left alloca redzone:     ca

  Right alloca redzone:    cb

commit 6bf8483cac34651f331bc2dece91580b003cf3a4

Merge: 72928e640e6 65405308a13

Author: Oleksandr Byelkin

Date:   Tue Aug 1 15:08:52 2023 +0200

    Merge branch '10.5' into 10.6