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

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

Details

    Description

      --source include/have_log_bin.inc
       
      --connect (con1,localhost,root,,)
      CREATE TEMPORARY TABLE tmp (a INT);
      --send
        CREATE TABLE non_existing_db.t SELECT SLEEP(2) AS b;
      --disconnect con1
      --connection default
      

      10.4 c5beac68

      ==27246==ERROR: AddressSanitizer: use-after-poison on address 0x62b0000a8bf8 at pc 0x55c23b0c854f bp 0x7f3973995e40 sp 0x7f3973995e38
      READ of size 4 at 0x62b0000a8bf8 thread T29
          #0 0x55c23b0c854e in Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int) /data/src/10.4/sql/log_event.cc:4433
          #1 0x55c23ac226fc in THD::log_events_and_free_tmp_shares() /data/src/10.4/sql/temporary_tables.cc:1382
          #2 0x55c23ac1dd1a in THD::close_temporary_tables() /data/src/10.4/sql/temporary_tables.cc:523
          #3 0x55c23a5a7193 in THD::cleanup() /data/src/10.4/sql/sql_class.cc:1525
          #4 0x55c23a40e9f7 in unlink_thd(THD*) /data/src/10.4/sql/mysqld.cc:2627
          #5 0x55c23a40f371 in one_thread_per_connection_end(THD*, bool) /data/src/10.4/sql/mysqld.cc:2776
          #6 0x55c23aa125eb in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1418
          #7 0x55c23aa11eb9 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1306
          #8 0x7f399721c4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
          #9 0x7f3995764d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
       
      0x62b0000a8bf8 is located 2552 bytes inside of 24716-byte region [0x62b0000a8200,0x62b0000ae28c)
      allocated by thread T29 here:
          #0 0x7f39974f3d28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
          #1 0x55c23bed84aa in sf_malloc /data/src/10.4/mysys/safemalloc.c:118
          #2 0x55c23beaa74b in my_malloc /data/src/10.4/mysys/my_malloc.c:101
          #3 0x55c23be8a48e in reset_root_defaults /data/src/10.4/mysys/my_alloc.c:151
          #4 0x55c23a5a6417 in THD::init_for_queries() /data/src/10.4/sql/sql_class.cc:1385
          #5 0x55c23aa11876 in prepare_new_connection_state(THD*) /data/src/10.4/sql/sql_connect.cc:1237
          #6 0x55c23aa11eff in thd_prepare_connection(THD*) /data/src/10.4/sql/sql_connect.cc:1321
          #7 0x55c23aa124af in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1391
          #8 0x55c23aa11eb9 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1306
          #9 0x7f399721c4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
       
      Thread T29 created by T0 here:
          #0 0x7f3997462f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
          #1 0x55c23bf03ab2 in spawn_thread_noop /data/src/10.4/mysys/psi_noop.c:187
          #2 0x55c23a4051b8 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
          #3 0x55c23a41930d in create_thread_to_handle_connection(CONNECT*) /data/src/10.4/sql/mysqld.cc:6238
          #4 0x55c23a419a04 in create_new_thread(CONNECT*) /data/src/10.4/sql/mysqld.cc:6308
          #5 0x55c23a419d8f in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.4/sql/mysqld.cc:6406
          #6 0x55c23a41a9f0 in handle_connections_sockets() /data/src/10.4/sql/mysqld.cc:6564
          #7 0x55c23a418b51 in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5896
          #8 0x55c23a40309f in main /data/src/10.4/sql/main.cc:25
          #9 0x7f399569c2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
       
      SUMMARY: AddressSanitizer: use-after-poison /data/src/10.4/sql/log_event.cc:4433 in Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int)
      Shadow bytes around the buggy address:
        0x0c568000d120: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d130: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d140: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d150: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d160: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
      =>0x0c568000d170: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]
        0x0c568000d180: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d190: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d1a0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d1b0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
        0x0c568000d1c0: 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
        Heap right redzone:      fb
        Freed heap region:       fd
        Stack left redzone:      f1
        Stack mid redzone:       f2
        Stack right redzone:     f3
        Stack partial redzone:   f4
        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
      ==27246==ABORTING
      ----------SERVER LOG END-------------
      

      Not reproducible on 10.3.

      Attachments

        Activity

          Elkin Andrei Elkin added a comment -

          Thanks for a good piece of analysis, Sujatha! The patch is okay, just make sure we
          don't push 2 secs extra waiting for the mtr test to run ... times as many as it's going to be launched in the future .

          Elkin Andrei Elkin added a comment - Thanks for a good piece of analysis, Sujatha! The patch is okay, just make sure we don't push 2 secs extra waiting for the mtr test to run ... times as many as it's going to be launched in the future .

          "rpl_drop_temp_table_invaid_lex.test" fails ocassionally on build bot with following symptoms.
          It needs to be fixed.

          http://buildbot.askmonty.org/buildbot/builders/bld-p9-rhel7/builds/4201/steps/mtr/logs/stdio

          rpl.rpl_drop_temp_table_invaid_lex 'mix' w30 [ pass ]   3361
           
          MTR's internal check of the test case 'rpl.rpl_drop_temp_table_invaid_lex' failed.
          This means that the test case does not preserve the state that existed
          before the test case was executed.  Most likely the test case did not
          do a proper clean-up. It could also be caused by the previous test run
          by this thread, if the server wasn't restarted.
          This is the diff of the states of the servers before and after the
          test case was executed:
          mysqltest: Logging to '/opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.log'.
          mysqltest: Results saved in '/opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.result'.
          mysqltest: Connecting to server localhost:16561 (socket /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/tmp/30/mysqld.2.sock) as 'root', connection 'default', attempt 0 ...
          mysqltest: ... Connected.
          mysqltest: Start processing test commands from './include/check-testcase.test' ...
          mysqltest: ... Done processing test commands.
          --- /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.result	2020-06-11 15:23:27.656444761 +0300
          +++ /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.reject	2020-06-11 15:23:33.476210985 +0300
          @@ -1032,7 +1032,7 @@
           DropGeometryColumn	def	mysql	DropGeometryColumn	PROCEDURE		NULL	NULL	NULL	NULL	NULL	NULL	NULL	NULL	SQL	begin
             set @qwe= concat('ALTER TABLE ', t_schema, '.', t_name, ' DROP ', geometry_column); PREPARE ls from @qwe; execute ls; deallocate prepare ls; end	NULL	NULL	SQL	NO	CONTAINS SQL	NULL	INVOKER	2020-06-11 15:15:22	2020-06-11 15:15:22			mariadb.sys@localhost	latin1	latin1_swedish_ci	latin1_swedish_ci
           Variable_name	Value
          -Slave_open_temp_tables	0
          +Slave_open_temp_tables	1
           Table	Checksum
           mysql.columns_priv	0
           mysql.db	204716352
          

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - - edited "rpl_drop_temp_table_invaid_lex.test" fails ocassionally on build bot with following symptoms. It needs to be fixed. http://buildbot.askmonty.org/buildbot/builders/bld-p9-rhel7/builds/4201/steps/mtr/logs/stdio rpl.rpl_drop_temp_table_invaid_lex 'mix' w30 [ pass ] 3361   MTR's internal check of the test case 'rpl.rpl_drop_temp_table_invaid_lex' failed. This means that the test case does not preserve the state that existed before the test case was executed. Most likely the test case did not do a proper clean-up. It could also be caused by the previous test run by this thread, if the server wasn't restarted. This is the diff of the states of the servers before and after the test case was executed: mysqltest: Logging to '/opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.log'. mysqltest: Results saved in '/opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.result'. mysqltest: Connecting to server localhost:16561 (socket /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/tmp/30/mysqld.2.sock) as 'root', connection 'default', attempt 0 ... mysqltest: ... Connected. mysqltest: Start processing test commands from './include/check-testcase.test' ... mysqltest: ... Done processing test commands. --- /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.result 2020-06-11 15:23:27.656444761 +0300 +++ /opt/buildbot-slave/bld-p9-rhel7/build/mysql-test/var/30/tmp/check-mysqld_2.reject 2020-06-11 15:23:33.476210985 +0300 @@ -1032,7 +1032,7 @@ DropGeometryColumn def mysql DropGeometryColumn PROCEDURE NULL NULL NULL NULL NULL NULL NULL NULL SQL begin set @qwe= concat('ALTER TABLE ', t_schema, '.', t_name, ' DROP ', geometry_column); PREPARE ls from @qwe; execute ls; deallocate prepare ls; end NULL NULL SQL NO CONTAINS SQL NULL INVOKER 2020-06-11 15:15:22 2020-06-11 15:15:22 mariadb.sys@localhost latin1 latin1_swedish_ci latin1_swedish_ci Variable_name Value -Slave_open_temp_tables 0 +Slave_open_temp_tables 1 Table Checksum mysql.columns_priv 0 mysql.db 204716352

          Hello Elkin

          • "rpl_drop_temp_table_invaid_lex.test" test fails sporadically in build bot, 'check-testcase' fails.
          • Test name also needs to be changed from s/rpl_drop_temp_table_invaid_lex.test/rpl_drop_temp_table_invalid_lex.test

          I have implemented the changes. Please find the following patch.

          Patch: https://github.com/MariaDB/server/commit/9b8dd9690a9a3bcf5f1f6e7929860751e732091b

          Thank you.

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Hello Elkin "rpl_drop_temp_table_invaid_lex.test" test fails sporadically in build bot, 'check-testcase' fails. Test name also needs to be changed from s/rpl_drop_temp_table_invaid_lex.test/rpl_drop_temp_table_invalid_lex.test I have implemented the changes. Please find the following patch. Patch: https://github.com/MariaDB/server/commit/9b8dd9690a9a3bcf5f1f6e7929860751e732091b Thank you.

          Hello alice

          Can you please review the changes to "rpl_drop_temp_table_invalid_lex.test".

          1. "rpl_drop_temp_table_invaid_lex.test" test fails sporadically in build bot, 'check-testcase' fails.
          2. Test name also needs to be changed from s/rpl_drop_temp_table_invaid_lex.test/rpl_drop_temp_table_invalid_lex.test

          Patch: https://github.com/MariaDB/server/commit/fa2505dbcccf5b6316a52e36596270d9fcb1f9c1

          Thank you.

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Hello alice Can you please review the changes to "rpl_drop_temp_table_invalid_lex.test". "rpl_drop_temp_table_invaid_lex.test" test fails sporadically in build bot, 'check-testcase' fails. Test name also needs to be changed from s/rpl_drop_temp_table_invaid_lex.test/rpl_drop_temp_table_invalid_lex.test Patch: https://github.com/MariaDB/server/commit/fa2505dbcccf5b6316a52e36596270d9fcb1f9c1 Thank you.

          Patch was reviewed and approved by alice. Test changes are pushed into 10.4.18.

          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Patch was reviewed and approved by alice . Test changes are pushed into 10.4.18.

          People

            sujatha.sivakumar Sujatha Sivakumar (Inactive)
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            4 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.