ASAN: use-after-poison in Gap_time_tracker::log_time

main.log_slow_innodb                     w14 [ fail ]

        Test ended at 2025-09-22 06:55:26

CURRENT_TEST: main.log_slow_innodb

mysqltest: At line 58: query 'SELECT 1' failed: <Unknown> (2013): Lost connection to server during query

The result from queries just before the failure was:

< snip >

[log_grep.inc] found expected match count: 3

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Query_time: \d+\.\d+  Lock_time: \d+\.\d+  Rows_sent: \d+  Rows_examined: \d+$ expected_matches: 3

[log_grep.inc] found expected match count: 3

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Rows_affected: \d+  Bytes_sent: \d+$ expected_matches: 3

[log_grep.inc] found expected match count: 3

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Full_scan: (Yes|No)  Full_join: (Yes|No)  Tmp_table: (Yes|No)  Tmp_table_on_disk: (Yes|No)$

[log_grep.inc] lines:   1

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Filesort: (Yes|No)  Filesort_on_disk: (Yes|No)  Merge_passes: \d+\ Priority_queue: (Yes|No)$

[log_grep.inc] lines:   0

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Filesort: (Yes|No)  Filesort_on_disk: (Yes|No)  Merge_passes: \d+\ Priority_queue: (Yes|No)$

[log_grep.inc] lines:   0

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Tmp_tables: \d+  Tmp_disk_tables: \d+$

[log_grep.inc] lines:   0

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Pages_accessed: \d+  Pages_read: \d+  Pages_prefetched: \d+  Pages_updated: \d+  Old_rows_read: \d+$ expected_matches: 2

[log_grep.inc] found expected match count: 2

[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Pages_read_time: \d+\.\d+  Engine_time: \d+\.\d+$ expected_matches: 2

[log_grep.inc] found expected match count: 2

SET SESSION log_slow_verbosity='innodb,query_plan';

[slow_log_start.inc] log_slow_innodb-verbosity_2

SELECT 1;

More results from queries before failure can be found in /dev/shm/normal/14/log/log_slow_innodb.log

Server [mysqld.1 - pid: 259736, winpid: 259736, exit: 256] failed during test run

Server log from this test:

----------SERVER LOG START-----------

=================================================================

==259739==ERROR: AddressSanitizer: use-after-poison on address 0x7dcfd5efa038 at pc 0x55ba235bd2ea bp 0x7affb2264250 sp 0x7affb2264248

READ of size 8 at 0x7dcfd5efa038 thread T15

    #0 0x55ba235bd2e9 in Gap_time_tracker::log_time(unsigned long long, unsigned long long) /home/buildbot/src/sql/sql_analyze_stmt.h:147:12

    #1 0x55ba235bd2e9 in process_gap_time_tracker(THD*, unsigned long long) /home/buildbot/src/sql/sql_analyze_stmt.cc:117:36

    #2 0x55ba23598e61 in Exec_time_tracker::start_tracking(THD*) /home/buildbot/src/sql/sql_analyze_stmt.h:102:5

    #3 0x55ba23598e61 in Explain_query::Explain_query(THD*, st_mem_root*) /home/buildbot/src/sql/sql_explain.cc:51:29

    #4 0x55ba235b96a0 in create_explain_query(LEX*, st_mem_root*) /home/buildbot/src/sql/sql_explain.cc:2767:32

    #5 0x55ba2304ef76 in JOIN::prepare(TABLE_LIST*, Item*, unsigned int, st_order*, bool, st_order*, Item*, st_order*, st_select_lex*, st_select_lex_unit*) /home/buildbot/src/sql/sql_select.cc:1437:7

    #6 0x55ba230448c0 in mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /home/buildbot/src/sql/sql_select.cc:5218:21

    #7 0x55ba23043653 in handle_select(THD*, LEX*, select_result*, unsigned long long) /home/buildbot/src/sql/sql_select.cc:600:10

    #8 0x55ba22f444dc in execute_sqlcom_select(THD*, TABLE_LIST*) /home/buildbot/src/sql/sql_parse.cc:6427:12

    #9 0x55ba22f25af5 in mysql_execute_command(THD*, bool) /home/buildbot/src/sql/sql_parse.cc:4008:12

    #10 0x55ba22f091d5 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /home/buildbot/src/sql/sql_parse.cc:8180:18

    #11 0x55ba22f001ca in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /home/buildbot/src/sql/sql_parse.cc:1906:7

    #12 0x55ba22f0b765 in do_command(THD*, bool) /home/buildbot/src/sql/sql_parse.cc:1419:17

    #13 0x55ba234fd8dc in do_handle_one_connection(CONNECT*, bool) /home/buildbot/src/sql/sql_connect.cc:1475:11

    #14 0x55ba234fd119 in handle_one_connection /home/buildbot/src/sql/sql_connect.cc:1387:5

    #15 0x55ba246635bc in pfs_spawn_thread /home/buildbot/src/storage/perfschema/pfs.cc:2201:3

    #16 0x55ba229ac086 in asan_thread_start(void*) asan_interceptors.cpp.o

    #17 0x7effd0fb01f4  (/lib/x86_64-linux-gnu/libc.so.6+0x891f4) (BuildId: 79005c16293efa45b441fed45f4f29b138557e9e)

    #18 0x7effd102faff in clone (/lib/x86_64-linux-gnu/libc.so.6+0x108aff) (BuildId: 79005c16293efa45b441fed45f4f29b138557e9e)

0x7dcfd5efa038 is located 7224 bytes inside of 32760-byte region [0x7dcfd5ef8400,0x7dcfd5f003f8)

allocated by thread T15 here:

    #0 0x55ba229ae704 in malloc (/home/buildbot/bld/sql/mariadbd+0x1dd5704) (BuildId: 04e51ea346864e85564787eabec4169bae30e338)

    #1 0x55ba251cf778 in my_malloc /home/buildbot/src/mysys/my_malloc.c:92:29

    #2 0x55ba251ae6e9 in reset_root_defaults /home/buildbot/src/mysys/my_alloc.c:247:30

    #3 0x55ba22d26ce0 in THD::init_for_queries() /home/buildbot/src/sql/sql_class.cc:1473:3

    #4 0x55ba234fc1b3 in prepare_new_connection_state(THD*) /home/buildbot/src/sql/sql_connect.cc:1314:8

    #5 0x55ba234fe26e in thd_prepare_connection(THD*) /home/buildbot/src/sql/sql_connect.cc:1408:3

    #6 0x55ba234fd8bc in do_handle_one_connection(CONNECT*, bool) /home/buildbot/src/sql/sql_connect.cc:1465:9

    #7 0x55ba234fd119 in handle_one_connection /home/buildbot/src/sql/sql_connect.cc:1387:5

    #8 0x55ba246635bc in pfs_spawn_thread /home/buildbot/src/storage/perfschema/pfs.cc:2201:3

    #9 0x55ba229ac086 in asan_thread_start(void*) asan_interceptors.cpp.o

Thread T15 created by T0 here:

    #0 0x55ba22992931 in pthread_create (/home/buildbot/bld/sql/mariadbd+0x1db9931) (BuildId: 04e51ea346864e85564787eabec4169bae30e338)

    #1 0x55ba2466391c in my_thread_create(unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /home/buildbot/src/storage/perfschema/my_thread.h:52:10

    #2 0x55ba2466391c in pfs_spawn_thread_v1 /home/buildbot/src/storage/perfschema/pfs.cc:2252:15

    #3 0x55ba22a076a2 in inline_mysql_thread_create(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /home/buildbot/src/include/mysql/psi/mysql_thread.h:1139:11

    #4 0x55ba22a076a2 in create_thread_to_handle_connection(CONNECT*) /home/buildbot/src/sql/mysqld.cc:6139:19

    #5 0x55ba22a08cb8 in handle_connections_sockets() /home/buildbot/src/sql/mysqld.cc:6383:9

    #6 0x55ba22a06e22 in run_main_loop() /home/buildbot/src/sql/mysqld.cc:5639:3

    #7 0x55ba229fc2d7 in mysqld_main(int, char**) /home/buildbot/src/sql/mysqld.cc:6040:3

    #8 0x7effd0f4e249  (/lib/x86_64-linux-gnu/libc.so.6+0x27249) (BuildId: 79005c16293efa45b441fed45f4f29b138557e9e)

SUMMARY: AddressSanitizer: use-after-poison /home/buildbot/src/sql/sql_analyze_stmt.h:147:12 in Gap_time_tracker::log_time(unsigned long long, unsigned long long)

Shadow bytes around the buggy address:

  0x7dcfd5ef9d80: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5ef9e00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5ef9e80: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5ef9f00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5ef9f80: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

=>0x7dcfd5efa000: f7 f7 f7 f7 f7 f7 f7[f7]f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5efa080: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5efa100: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5efa180: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5efa200: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x7dcfd5efa280: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

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

==259739==ABORTING

250922  6:55:23 [ERROR] /home/buildbot/bld/sql/mariadbd got signal 6 ;

Sorry, we probably made a mistake, and this is a bug.

Your assistance in bug reporting will enable us to fix this for the next release.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs about how to report

a bug on https://jira.mariadb.org/.

Please include the information from the server start above, to the end of the

information below.

Server version: 10.11.15-MariaDB-asan-log source revision: 573d3ad1c61a14f72483e756da38be5b105169d3

The information page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mariadbd/

contains instructions to obtain a better version of the backtrace below.

Following these instructions will help MariaDB developers provide a fix quicker.

Attempting backtrace. Include this in the bug report.

(note: Retrieving this information may fail)

Thread pointer: 0x7dafd03d3218

stack_bottom = 0x7affb2266000 thread_stack 0xb00000

/home/buildbot/bld/sql/mariadbd(___interceptor_backtrace+0x46)[0x55ba22954486]

mysys/stacktrace.c:215(my_print_stacktrace)[0x55ba251dd815]

sql/signal_handler.cc:0(handle_fatal_signal)[0x55ba23b2f018]

/lib/x86_64-linux-gnu/libc.so.6(+0x3c050)[0x7effd0f63050]

/lib/x86_64-linux-gnu/libc.so.6(+0x8aeec)[0x7effd0fb1eec]

/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x12)[0x7effd0f62fb2]

/lib/x86_64-linux-gnu/libc.so.6(abort+0xd3)[0x7effd0f4d472]

/home/buildbot/bld/sql/mariadbd(+0x1dfddcc)[0x55ba229d6dcc]

/home/buildbot/bld/sql/mariadbd(+0x1dfbc6e)[0x55ba229d4c6e]

/home/buildbot/bld/sql/mariadbd(+0x1ddb729)[0x55ba229b4729]

/home/buildbot/bld/sql/mariadbd(+0x1ddec57)[0x55ba229b7c57]

/home/buildbot/bld/sql/mariadbd(__asan_report_load8+0x36)[0x55ba229b8b56]

/home/buildbot/bld/sql/mariadbd(+0x29e42ea)[0x55ba235bd2ea]

sql/sql_explain.cc:52(Explain_query::Explain_query(THD*, st_mem_root*))[0x55ba23598e62]

sql/sql_explain.cc:2767(create_explain_query(LEX*, st_mem_root*))[0x55ba235b96a1]

sql/sql_select.cc:0(JOIN::prepare(TABLE_LIST*, Item*, unsigned int, st_order*, bool, st_order*, Item*, st_order*, st_select_lex*, st_select_lex_unit*))[0x55ba2304ef77]

sql/sql_select.cc:5218(mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x55ba230448c1]

sql/sql_select.cc:600(handle_select(THD*, LEX*, select_result*, unsigned long long))[0x55ba23043654]

sql/sql_parse.cc:0(execute_sqlcom_select(THD*, TABLE_LIST*))[0x55ba22f444dd]

sql/sql_parse.cc:0(mysql_execute_command(THD*, bool))[0x55ba22f25af6]

sql/sql_parse.cc:0(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55ba22f091d6]

sql/sql_parse.cc:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55ba22f001cb]

sql/sql_parse.cc:1421(do_command(THD*, bool))[0x55ba22f0b766]

sql/sql_connect.cc:1475(do_handle_one_connection(CONNECT*, bool))[0x55ba234fd8dd]

sql/sql_connect.cc:1391(handle_one_connection)[0x55ba234fd11a]

perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55ba246635bd]

asan_interceptors.cpp.o:0(asan_thread_start(void*))[0x55ba229ac087]

/lib/x86_64-linux-gnu/libc.so.6(+0x891f5)[0x7effd0fb01f5]

/lib/x86_64-linux-gnu/libc.so.6(__clone+0x40)[0x7effd102fb00]