AddressSanitizer: use-after-poison 10.2/storage/innobase/lock/lock0lock.cc:6557 in lock_trx_handle_wait_low

ASAN failure hit during RQG testing

origin/10.2 6462af1c2e2cddf3a96818dc7884e187d8ba7f24 2020-05-22T15:00:29+04:00

[rr 40852 190304]==40852==ERROR: AddressSanitizer: use-after-poison on address 0x7f643b8b5fd0 at pc 0x555cc6a9db2b bp 0x7f640470ef30 sp 0x7f640470ef20

[rr 40852 190309]READ of size 1 at 0x7f643b8b5fd0 thread T36

2020-05-22 12:15:40 140067540461312 [Warning] Aborted connection 101 to db: 'test' user: 'root' host: 'localhost' (CLOSE_CONNECTION)

    #0 0x555cc6a9db2a in lock_trx_handle_wait_low /home/mleich/10.2/storage/innobase/lock/lock0lock.cc:6557

    #1 0x555cc6a9dcf8 in lock_trx_handle_wait(trx_t*) /home/mleich/10.2/storage/innobase/lock/lock0lock.cc:6581

    #2 0x555cc6941a80 in innobase_kill_query /home/mleich/10.2/storage/innobase/handler/ha_innodb.cc:5207

    #3 0x555cc63fd162 in kill_handlerton /home/mleich/10.2/sql/handler.cc:843

    #4 0x555cc5de357a in plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) /home/mleich/10.2/sql/sql_plugin.cc:2402

    #5 0x555cc63fd24e in ha_kill_query(THD*, thd_kill_levels) /home/mleich/10.2/sql/handler.cc:850

    #6 0x555cc5cd9afd in THD::awake(killed_state) /home/mleich/10.2/sql/sql_class.cc:1728

    #7 0x555cc5dc4c39 in kill_one_thread(THD*, long long, killed_state, killed_type) /home/mleich/10.2/sql/sql_parse.cc:8896

    #8 0x555cc5dc5801 in sql_kill /home/mleich/10.2/sql/sql_parse.cc:9002

    #9 0x555cc5dabb89 in mysql_execute_command(THD*) /home/mleich/10.2/sql/sql_parse.cc:5219

    #10 0x555cc5dbd350 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/mleich/10.2/sql/sql_parse.cc:7740

    #11 0x555cc5d9405a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/mleich/10.2/sql/sql_parse.cc:1831

    #12 0x555cc5d90a81 in do_command(THD*) /home/mleich/10.2/sql/sql_parse.cc:1385

    #13 0x555cc613549f in do_handle_one_connection(CONNECT*) /home/mleich/10.2/sql/sql_connect.cc:1336

    #14 0x555cc6134d5c in handle_one_connection /home/mleich/10.2/sql/sql_connect.cc:1241

    #15 0x7f644810f6da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)

    #16 0x7f64474f988e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x12188e)

0x7f643b8b5fd0 is located 26576 bytes inside of 4194304-byte region [0x7f643b8af800,0x7f643bcaf800)

allocated by thread T0 here:

    #0 0x7f6449707d28 in __interceptor_calloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xded28)

    #1 0x555cc6e1a3ec in Pool<trx_t, TrxFactory, TrxPoolLock>::Pool(unsigned long) /home/mleich/10.2/storage/innobase/include/ut0pool.h:65

    #2 0x555cc6e16abb in PoolManager<Pool<trx_t, TrxFactory, TrxPoolLock>, TrxPoolManagerLock>::add_pool(unsigned long) /home/mleich/10.2/storage/innobase/include/ut0pool.h:320

    #3 0x555cc6e161fc in PoolManager<Pool<trx_t, TrxFactory, TrxPoolLock>, TrxPoolManagerLock>::create() /home/mleich/10.2/storage/innobase/include/ut0pool.h:348

    #4 0x555cc6e1421a in PoolManager<Pool<trx_t, TrxFactory, TrxPoolLock>, TrxPoolManagerLock>::PoolManager(unsigned long) /home/mleich/10.2/storage/innobase/include/ut0pool.h:232

    #5 0x555cc6dfe649 in trx_pool_init() /home/mleich/10.2/storage/innobase/trx/trx0trx.cc:327

    #6 0x555cc6d3f13c in srv_boot() /home/mleich/10.2/storage/innobase/srv/srv0srv.cc:1172

    #7 0x555cc6d5787c in innobase_start_or_create_for_mysql() /home/mleich/10.2/storage/innobase/srv/srv0start.cc:1692

    #8 0x555cc693dcdf in innobase_init /home/mleich/10.2/storage/innobase/handler/ha_innodb.cc:4306

    #9 0x555cc63fb60d in ha_initialize_handlerton(st_plugin_int*) /home/mleich/10.2/sql/handler.cc:555

    #10 0x555cc5ddb1ee in plugin_initialize /home/mleich/10.2/sql/sql_plugin.cc:1417

    #11 0x555cc5ddcf17 in plugin_init(int*, char**, int) /home/mleich/10.2/sql/sql_plugin.cc:1698

    #12 0x555cc5b3bf12 in init_server_components /home/mleich/10.2/sql/mysqld.cc:5340

    #13 0x555cc5b3e19e in mysqld_main(int, char**) /home/mleich/10.2/sql/mysqld.cc:5938

    #14 0x555cc5b26289 in main /home/mleich/10.2/sql/main.cc:25

    #15 0x7f64473f9b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

Thread T36 created by T0 here:

    #0 0x7f6449660d2f in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.4+0x37d2f)

    #1 0x555cc77bffae in spawn_thread_noop /home/mleich/10.2/mysys/psi_noop.c:187

    #2 0x555cc5b27940 in inline_mysql_thread_create /home/mleich/10.2/include/mysql/psi/mysql_thread.h:1246

    #3 0x555cc5b3f7bf in create_thread_to_handle_connection(CONNECT*) /home/mleich/10.2/sql/mysqld.cc:6517

    #4 0x555cc5b3ff90 in create_new_thread /home/mleich/10.2/sql/mysqld.cc:6585

    #5 0x555cc5b41269 in handle_connections_sockets() /home/mleich/10.2/sql/mysqld.cc:6860

    #6 0x555cc5b3eb6b in mysqld_main(int, char**) /home/mleich/10.2/sql/mysqld.cc:6134

    #7 0x555cc5b26289 in main /home/mleich/10.2/sql/main.cc:25

    #8 0x7f64473f9b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

[rr 40852 197549]SUMMARY: AddressSanitizer: use-after-poison /home/mleich/10.2/storage/innobase/lock/lock0lock.cc:6557 in lock_trx_handle_wait_low

[rr 40852 197981]Shadow bytes around the buggy address:

  0x0fed0770eba0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0fed0770ebb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0fed0770ebc0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

  0x0fed0770ebd0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f7

  0x0fed0770ebe0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f7 f7

=>0x0fed0770ebf0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]f7 f7 f7 f7 f7

  0x0fed0770ec00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0fed0770ec10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0fed0770ec20: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0fed0770ec30: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7

  0x0fed0770ec40: 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

[rr 40852 197993]==40852==ABORTING

...

Query (0x62b0000fc228): KILL SOFT QUERY @kill_id

Connection ID (thread ID): 96

Status: NOT_KILLED

RQG:

git clone https://github.com/mleich1/rqg --branch experimental RQG_mleich

origin/experimental b2e97d7d0757fc515591526dcd0c1f3aedd9e0a9 2020-05-19T19:46:01+02:00

perl rqg.pl \                    

--mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \

--gendata=conf/mariadb/table_stress.zz \

--gendata_sql=conf/mariadb/table_stress.sql \

--engine=Innodb \

--reporters=Deadlock1,ErrorLog,Backtrace \

--mysqld=--connect_timeout=60 \

--mysqld=--net_read_timeout=30 \

--mysqld=--net_write_timeout=60 \

--mysqld=--loose-idle_readonly_transaction_timeout=0 \

--mysqld=--loose-idle_transaction_timeout=0 \

--mysqld=--loose-idle_write_transaction_timeout=0 \

--mysqld=--interactive_timeout=28800 \

--mysqld=--lock_wait_timeout=86400 \

--mysqld=--innodb-lock-wait-timeout=50 \

--mysqld=--loose-table_lock_wait_timeout=50 \

--mysqld=--wait_timeout=28800 \

--mysqld=--slave_net_timeout=60 \

--mysqld=--loose-max-statement-time=30 \

--mysqld=--loose-debug_assert_on_not_freed_memory=0 \

--mysqld=--log-output=none \

--duration=300 \

--seed=random \

--grammar=conf/mariadb/table_stress_innodb_nocopy.yy \

--threads=9 \

--mysqld=--innodb_stats_persistent=OFF \

--mysqld=--innodb_adaptive_hash_index=OFF \

--mysqld=--innodb_page_size=32K \

--mysqld=--innodb-buffer-pool-size=256M \

--no_mask \

--workdir=...

...