Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-25524

AddressSanitizer: heap-use-after-free in fil0fil.cc:2074 in fil_space_t::rename(char const*, bool, bool)

    XMLWordPrintable

    Details

      Description

      Work flow:
      1. Start the server and generate some initial data
      2. Concurrent DDL/DML load
      3. During 2. is ongoing send SIGKILL to the DB server
      4. Restart attempt
      According to the server error log (during restart) we have no entries looking like
          [ERROR] InnoDB:   <whatever>
      It ends with
      ...
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 24686]2021-04-26  5:42:15 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-392f2b-45.ibd' with space ID 1227. Another data file called ./test/t3.ibd exists with the same space ID.
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 26173]2021-04-26  5:42:16 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 42 row operations to undo
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 26177]2021-04-26  5:42:16 0 [Note] InnoDB: Trx id counter is 6829
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 26181]2021-04-26  5:42:16 0 [Note] InnoDB: Starting final batch to recover 278 pages from redo log.
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27110]2021-04-26  5:42:16 0 [Note] InnoDB: Last binlog file './mysql-bin.000001', position 1012195
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27121]2021-04-26  5:42:16 0 [Note] InnoDB: 128 rollback segments are active.
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27508]2021-04-26  5:42:16 0 [Note] InnoDB: TRUNCATE rollback: 1227,./test/t3.ibd
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27520]2021-04-26  5:42:16 0 [Note] InnoDB: Deleting ./test/t3.ibd
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27526]=================================================================
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27533][rr 3840652 27537]==3840652==ERROR: AddressSanitizer: heap-use-after-free on address 0x612000003fa8 at pc 0x55ee3443aea2 bp 0x7ffd3a5f39b0 sp 0x7ffd3a5f39a0
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 27540][rr 3840652 27542]READ of size 8 at 0x612000003fa8 thread T0
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33030]    #0 0x55ee3443aea1 in fil_space_t::rename(char const*, bool, bool) /data/Server/10.6alpha/storage/innobase/fil/fil0fil.cc:2074
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33046]    #1 0x55ee343b1825 in dict_table_rename_in_cache(dict_table_t*, char const*, bool, bool) /data/Server/10.6alpha/storage/innobase/dict/dict0dict.cc:1655
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33056]    #2 0x55ee345461d4 in row_undo_ins_parse_undo_rec /data/Server/10.6alpha/storage/innobase/row/row0uins.cc:401
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33058]    #3 0x55ee34546cb7 in row_undo_ins(undo_node_t*, que_thr_t*) /data/Server/10.6alpha/storage/innobase/row/row0uins.cc:544
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33064]    #4 0x55ee3418222e in row_undo /data/Server/10.6alpha/storage/innobase/row/row0undo.cc:440
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33066]    #5 0x55ee34182710 in row_undo_step(que_thr_t*) /data/Server/10.6alpha/storage/innobase/row/row0undo.cc:496
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33072]    #6 0x55ee3401c5fe in que_thr_step /data/Server/10.6alpha/storage/innobase/que/que0que.cc:651
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33074]    #7 0x55ee3401c9c2 in que_run_threads_low /data/Server/10.6alpha/storage/innobase/que/que0que.cc:709
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33076]    #8 0x55ee3401cb64 in que_run_threads(que_thr_t*) /data/Server/10.6alpha/storage/innobase/que/que0que.cc:729
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33086]    #9 0x55ee3421db01 in trx_rollback_active /data/Server/10.6alpha/storage/innobase/trx/trx0roll.cc:604
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33088]    #10 0x55ee3421ecdb in trx_rollback_recovered(bool) /data/Server/10.6alpha/storage/innobase/trx/trx0roll.cc:756
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33096]    #11 0x55ee341cc311 in srv_start(bool) /data/Server/10.6alpha/storage/innobase/srv/srv0start.cc:1745
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33118]    #12 0x55ee33d645cf in innodb_init /data/Server/10.6alpha/storage/innobase/handler/ha_innodb.cc:3771
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33132]    #13 0x55ee3345645a in ha_initialize_handlerton(st_plugin_int*) /data/Server/10.6alpha/sql/handler.cc:647
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33144]    #14 0x55ee32d0b71a in plugin_initialize /data/Server/10.6alpha/sql/sql_plugin.cc:1459
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33146]    #15 0x55ee32d0d474 in plugin_init(int*, char**, int) /data/Server/10.6alpha/sql/sql_plugin.cc:1751
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33158]    #16 0x55ee32a209b4 in init_server_components /data/Server/10.6alpha/sql/mysqld.cc:5019
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33160]    #17 0x55ee32a22380 in mysqld_main(int, char**) /data/Server/10.6alpha/sql/mysqld.cc:5617
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33162]    #18 0x55ee32a1111c in main /data/Server/10.6alpha/sql/main.cc:25
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33164]    #19 0x7fb3f46250b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
      # 2021-04-26T05:43:28 [3742622] | [rr 3840652 33166]    #20 0x55ee32a1103d in _start (/data/Server_bin/10.6alpha_asan/bin/mariadbd+0x13c103d)
       
      SUMMARY: AddressSanitizer: heap-use-after-free /data/Server/10.6alpha/storage/innobase/fil/fil0fil.cc:2074 in fil_space_t::rename(char const*, bool, bool)    
       
      sdp:/data/Results/1619433372/TBR-1035/dev/shm/vardir/1619433372/83/1/rr
      _RR_TRACE_DIR="." rr replay --mark-stdio mysqld-0  # Fate of the server till SIGKILL
      _RR_TRACE_DIR="." rr replay --mark-stdio mysqld-1  # Fate of the server during restart
          
      /data/Results/1619433372/TBR-1035/dev/shm/vardir/1619433372/83/1/data_copy
               Copy of the data directory of the server after SIGKILL and before restart attempt
       
      10.6 1a647b700f6b72dc97211510a5d0c647d5d3d911 2021-04-23T10:07:08+03:00
       
      RQG
      -------
      git clone https://github.com/mleich1/rqg --branch experimental RQG
       
      perl rqg.pl \
      --grammar=conf/mariadb/table_stress_innodb.yy \
      --gendata=conf/mariadb/table_stress.zz \
      --gendata_sql=conf/mariadb/table_stress.sql \
      --reporters=CrashRecovery1 \
      --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
      --mysqld=--loose-idle_write_transaction_timeout=0 \
      --mysqld=--loose-idle_transaction_timeout=0 \
      --mysqld=--loose-idle_readonly_transaction_timeout=0 \
      --mysqld=--connect_timeout=60 \
      --mysqld=--interactive_timeout=28800 \
      --mysqld=--slave_net_timeout=60 \
      --mysqld=--net_read_timeout=30 \
      --mysqld=--net_write_timeout=60 \
      --mysqld=--loose-table_lock_wait_timeout=50 \
      --mysqld=--wait_timeout=28800 \
      --mysqld=--lock-wait-timeout=86400 \
      --mysqld=--innodb-lock-wait-timeout=50 \
      --no-mask \
      --queries=10000000 \
      --seed=random \
      --reporters=Backtrace \
      --reporters=ErrorLog \
      --reporters=Deadlock1 \
      --validators=None \
      --mysqld=--log_output=none \
      --mysqld=--log-bin \
      --mysqld=--log_bin_trust_function_creators=1 \
      --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
      --engine=InnoDB \
      --restart_timeout=240 \
      --mysqld=--plugin-load-add=file_key_management.so \
      --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
      --duration=300 \
      --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
      --mysqld=--loose-innodb-sync-debug \
      --mysqld=--innodb_stats_persistent=off \
      --mysqld=--innodb_adaptive_hash_index=on \
      --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
      --mysqld=--loose-max-statement-time=30 \
      --threads=9 \
      --mysqld=--innodb-use-native-aio=0 \
      --rr=Extended \
      --rr_options="--wait" \
      --mysqld=--innodb_page_size=8K \
      --mysqld=--innodb-buffer-pool-size=8M \
      --duration=300 \
      --no_mask \
      --workdir=<local settings> \
      --vardir=<local settings> \
      --mtr-build-thread=<local settings> \
      --basedir1=<local settings> \
      --script_debug=_nix_
      
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration