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

ASAN use-after-poison in Query_log_event::Query_log_event/THD::binlog_query

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Cannot Reproduce
    • None
    • N/A
    • Replication
    • None

    Description

      to reproduce - edit 1my.test l.15 --copy_file ... with path to the attached binlog and then run
      ./mtr 1_my.test -mysqld=default-storage-engine=innodb --mysqld=innodb --mysqld=sequence --mysqld=-partition

      preview-10.8-MDEV-11675-rpl-lag-free-alter 87c2019bb2f7ac4adb1b53

      =================================================================
      ==381279==ERROR: AddressSanitizer: use-after-poison on address 0x629000334de0 at pc 0x5605c95dfc41 bp 0x7fa90e7fc110 sp 0x7fa90e7fc100
      READ of size 4 at 0x629000334de0 thread T19
          #0 0x5605c95dfc40 in Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int) /10.8/sql/log_event_server.cc:1552
          #1 0x5605c883f7d5 in THD::binlog_query(THD::enum_binlog_query_type, char const*, unsigned long, bool, bool, bool, int) /10.8/sql/sql_class.cc:7626
          #2 0x5605c8c095c2 in write_bin_log(THD*, bool, char const*, unsigned long, bool) /10.8/sql/sql_table.cc:1009
          #3 0x5605c95e0a9b in Query_log_event::handle_split_alter_query_log_event(rpl_group_info*, bool&) /10.8/sql/log_event_server.cc:1701
          #4 0x5605c95e4264 in Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int) /10.8/sql/log_event_server.cc:2117
          #5 0x5605c95e04c8 in Query_log_event::do_apply_event(rpl_group_info*) /10.8/sql/log_event_server.cc:1612
          #6 0x5605c86de5b6 in Log_event::apply_event(rpl_group_info*) /10.8/sql/log_event.h:1518
          #7 0x5605c86bf953 in apply_event_and_update_pos_apply /10.8/sql/slave.cc:3881
          #8 0x5605c86c056b in apply_event_and_update_pos(Log_event*, THD*, rpl_group_info*) /10.8/sql/slave.cc:4047
          #9 0x5605c86c2275 in exec_relay_log_event /10.8/sql/slave.cc:4417
          #10 0x5605c86c9e47 in handle_slave_sql /10.8/sql/slave.cc:5594
          #11 0x5605c9aa1176 in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
          #12 0x7fa91ddc6608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
          #13 0x7fa91d999292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
       
      0x629000334de0 is located 3040 bytes inside of 16516-byte region [0x629000334200,0x629000338284)
      allocated by thread T19 here:
          #0 0x7fa91e2c1bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
          #1 0x5605ca6ff287 in sf_malloc /10.8/mysys/safemalloc.c:126
          #2 0x5605ca6cc4ad in my_malloc /10.8/mysys/my_malloc.c:90
          #3 0x5605ca6a7149 in root_alloc /10.8/mysys/my_alloc.c:66
          #4 0x5605ca6a807a in reset_root_defaults /10.8/mysys/my_alloc.c:243
          #5 0x5605c881307e in THD::init_for_queries() /10.8/sql/sql_class.cc:1393
          #6 0x5605c86c83cc in handle_slave_sql /10.8/sql/slave.cc:5348
          #7 0x5605c9aa1176 in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
          #8 0x7fa91ddc6608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
       
      Thread T19 created by T16 here:
          #0 0x7fa91e1ee805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
          #1 0x5605c9a9c12c in my_thread_create /10.8/storage/perfschema/my_thread.h:48
          #2 0x5605c9aa1569 in pfs_spawn_thread_v1 /10.8/storage/perfschema/pfs.cc:2252
          #3 0x5605c86a5de2 in inline_mysql_thread_create /10.8/include/mysql/psi/mysql_thread.h:1139
          #4 0x5605c86ae117 in start_slave_thread(unsigned int, void* (*)(void*), st_mysql_mutex*, st_mysql_mutex*, st_mysql_cond*, unsigned int volatile*, unsigned long volatile*, Master_info*) /10.8/sql/slave.cc:1150
          #5 0x5605c86aec5d in start_slave_threads(THD*, bool, bool, Master_info*, char const*, char const*, int) /10.8/sql/slave.cc:1276
          #6 0x5605c8a392a9 in start_slave(THD*, Master_info*, bool) /10.8/sql/sql_repl.cc:3274
          #7 0x5605c895facc in mysql_execute_command(THD*, bool) /10.8/sql/sql_parse.cc:4245
          #8 0x5605c897a986 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.8/sql/sql_parse.cc:8028
          #9 0x5605c8950a83 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.8/sql/sql_parse.cc:1894
          #10 0x5605c894d7a7 in do_command(THD*, bool) /10.8/sql/sql_parse.cc:1402
          #11 0x5605c8df157c in do_handle_one_connection(CONNECT*, bool) /10.8/sql/sql_connect.cc:1418
          #12 0x5605c8df0e08 in handle_one_connection /10.8/sql/sql_connect.cc:1312
          #13 0x5605c9aa1176 in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
          #14 0x7fa91ddc6608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
       
      Thread T16 created by T0 here:
          #0 0x7fa91e1ee805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
          #1 0x5605c9a9c12c in my_thread_create /10.8/storage/perfschema/my_thread.h:48
          #2 0x5605c9aa1569 in pfs_spawn_thread_v1 /10.8/storage/perfschema/pfs.cc:2252
          #3 0x5605c8595b68 in inline_mysql_thread_create /10.8/include/mysql/psi/mysql_thread.h:1139
          #4 0x5605c85ad852 in create_thread_to_handle_connection(CONNECT*) /10.8/sql/mysqld.cc:5969
          #5 0x5605c85adece in create_new_thread(CONNECT*) /10.8/sql/mysqld.cc:6028
          #6 0x5605c85ae23b in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.8/sql/mysqld.cc:6090
          #7 0x5605c85aec10 in handle_connections_sockets() /10.8/sql/mysqld.cc:6214
          #8 0x5605c85ad05f in mysqld_main(int, char**) /10.8/sql/mysqld.cc:5864
          #9 0x5605c8594e8c in main /10.8/sql/main.cc:34
          #10 0x7fa91d89e0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
       
      SUMMARY: AddressSanitizer: use-after-poison /10.8/sql/log_event_server.cc:1552 in Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int)
      Shadow bytes around the buggy address:
        0x0c528005e960: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e970: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e980: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e990: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e9a0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
      =>0x0c528005e9b0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]f7 f7 f7
        0x0c528005e9c0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e9d0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e9e0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005e9f0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c528005ea00: 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
        Shadow gap:              cc
      ==381279==ABORTING
      220111 16:04:16 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.8.0-MariaDB-debug-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=4
      max_threads=153
      thread_count=7
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63896 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x62b0001ff288
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7fa90e7fcf00 thread_stack 0x100000
      ??:0(__interceptor_tcgetattr)[0x7fa91e220d30]
      mysys/stacktrace.c:212(my_print_stacktrace)[0x5605ca6ddf6a]
      sql/signal_handler.cc:226(handle_fatal_signal)[0x5605c920750f]
      sigaction.c:0(__restore_rt)[0x7fa91ddd23c0]
      ??:0(gsignal)[0x7fa91d8bd18b]
      ??:0(abort)[0x7fa91d89c859]
      ??:0(__sanitizer_set_report_fd)[0x7fa91e2df6a2]
      ??:0(__sanitizer_get_module_and_offset_for_pc)[0x7fa91e2ea24c]
      ??:0(__sanitizer_ptr_cmp)[0x7fa91e2cb8ec]
      ??:0(__asan_on_error)[0x7fa91e2cb363]
      ??:0(__asan_report_load4)[0x7fa91e2cc08b]
      sql/log_event_server.cc:1552(Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int))[0x5605c95dfc41]
      sql/sql_class.cc:7626(THD::binlog_query(THD::enum_binlog_query_type, char const*, unsigned long, bool, bool, bool, int))[0x5605c883f7d6]
      sql/sql_table.cc:1009(write_bin_log(THD*, bool, char const*, unsigned long, bool))[0x5605c8c095c3]
      sql/log_event_server.cc:1701(Query_log_event::handle_split_alter_query_log_event(rpl_group_info*, bool&))[0x5605c95e0a9c]
      sql/log_event_server.cc:2117(Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int))[0x5605c95e4265]
      sql/log_event_server.cc:1613(Query_log_event::do_apply_event(rpl_group_info*))[0x5605c95e04c9]
      sql/log_event.h:1518(Log_event::apply_event(rpl_group_info*))[0x5605c86de5b7]
      sql/slave.cc:3881(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x5605c86bf954]
      sql/slave.cc:4047(apply_event_and_update_pos(Log_event*, THD*, rpl_group_info*))[0x5605c86c056c]
      sql/slave.cc:4417(exec_relay_log_event(THD*, Relay_log_info*, rpl_group_info*))[0x5605c86c2276]
      sql/slave.cc:5594(handle_slave_sql)[0x5605c86c9e48]
      perfschema/pfs.cc:2203(pfs_spawn_thread)[0x5605c9aa1177]
      nptl/pthread_create.c:478(start_thread)[0x7fa91ddc6609]
      ??:0(clone)[0x7fa91d999293]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x6140003fc0d3): ALTER /* QNO 2535 CON_ID 19 */ IGNORE TABLE alt_t1 /*!100301 WAIT 7 */ DROP COLUMN IF EXISTS tscol3, ALGORITHM=COPY, FORCE, LOCK=SHARED, ALGORITHM=COPY
      

      Attachments

        1. dd.7z
          4.26 MB
          Alice Sherepa

        Activity

          People

            alice Alice Sherepa
            alice Alice Sherepa
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.