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

MSAN use-of-uninitialized-value in test maria.maria-recovery2

    XMLWordPrintable

    Details

      Description

      The test {{maria.maria-recovery2} fails as follows:

      10.5 d8ea11a33fba12331c98c04ff44c815a662faccb

      CURRENT_TEST: maria.maria-recovery2
      mysqltest: At line 70: query 'delete from t1 where b="b"' failed: 2013: Lost connection to MySQL server during query
      

      In the server error log, we have the following:

      10.5 d8ea11a33fba12331c98c04ff44c815a662faccb

      Version: '10.5.4-MariaDB-debug-log'  socket: '/dev/shm/10.5-msan/mysql-test/var/tmp/1/mysqld.1.sock'  port: 16000  Source distribution
      lex_end: enter: lex: 0x72b00002df68
      Query_arena::free_items: info: free item: 0x72b0000311a8
      Item::cleanup: enter: this: 0x72b0000311a8
      dispatch_command: info: query ready
      net_send_ok: info: affected_rows: 0  id: 0  status: 2  warning_count: 0
      vio_is_blocking: exit: 0
      alloc_root: exit: ptr: 0x72b000031eb8
      SQL_SELECT::test_quick_select: enter: keys_to_use: 18446744073709551615  prev_tables: 0  const_tables: 0
      SQL_SELECT::test_quick_select: info: records: 3
      SQL_SELECT::test_quick_select: info: ==404750==WARNING: MemorySanitizer: use-of-uninitialized-value
          #0 0x5633313f8b71 in my_gcvt /mariadb/10.5m/strings/dtoa.c:294:19
          #1 0x563331409cd3 in process_dbl_arg /mariadb/10.5m/strings/my_vsnprintf.c:304:10
          #2 0x563331409cd3 in my_vsnprintf_ex /mariadb/10.5m/strings/my_vsnprintf.c:694:11
          #3 0x5633312e41e7 in DbugVfprintf /mariadb/10.5m/dbug/dbug.c:1332:10
          #4 0x5633312e41e7 in _db_doprnt_ /mariadb/10.5m/dbug/dbug.c:1316:3
          #5 0x56332f3f185d in SQL_SELECT::test_quick_select(THD*, Bitmap<64u>, unsigned long long, unsigned long long, bool, bool, bool, bool) /mariadb/10.5m/sql/opt_range.cc:2691:3
          #6 0x56332f53a5fe in SQL_SELECT::check_quick(THD*, bool, unsigned long long) /mariadb/10.5m/sql/opt_range.h:1654:12
          #7 0x56332f53a5fe in mysql_delete(THD*, TABLE_LIST*, Item*, SQL_I_List<st_order>*, unsigned long long, unsigned long long, select_result*) /mariadb/10.5m/sql/sql_delete.cc:500:26
          #8 0x56332e0ec30e in mysql_execute_command(THD*) /mariadb/10.5m/sql/sql_parse.cc:4787:11
          #9 0x56332e0c22f5 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /mariadb/10.5m/sql/sql_parse.cc:7991:18
          #10 0x56332e0b2c79 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /mariadb/10.5m/sql/sql_parse.cc:1874:7
          #11 0x56332e0c41ba in do_command(THD*) /mariadb/10.5m/sql/sql_parse.cc:1355:17
          #12 0x56332e6e02be in do_handle_one_connection(CONNECT*, bool) /mariadb/10.5m/sql/sql_connect.cc:1411:11
          #13 0x56332e6dfaa4 in handle_one_connection /mariadb/10.5m/sql/sql_connect.cc:1313:5
          #14 0x56332fb8a2c7 in pfs_spawn_thread /mariadb/10.5m/storage/perfschema/pfs.cc:2201:3
          #15 0x7f1e693e8f26 in start_thread nptl/pthread_create.c:479:8
          #16 0x7f1e68ec731e in clone misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
       
        Uninitialized value was created by an allocation of 'stat_tables' in the stack frame of function '_Z26read_statistics_for_tablesP3THDP10TABLE_LIST'
          #0 0x56332e3fd9c0 in read_statistics_for_tables(THD*, TABLE_LIST*) /mariadb/10.5m/sql/sql_statistics.cc:3292
       
      SUMMARY: MemorySanitizer: use-of-uninitialized-value /mariadb/10.5m/strings/dtoa.c:294:19 in my_gcvt
      Exiting
      

      I can see two problems here.

      1. Apparently something is inadvertently enabling all possible DBUG output.
      2. While we are outputting the data, we seem to notice that the Aria storage engine failed to provide some statistics.
        Here is a snippet of SQL_SELECT::test_quick_select():

          if (head->force_index || force_quick_range)
            scan_time= read_time= DBL_MAX;
          else
          {
            scan_time= rows2double(records) / TIME_FOR_COMPARE;
            /*
              The 2 is there to prefer range scans to full table scans.
              This is mainly to make the test suite happy as many tests has
              very few rows. In real life tables has more than a few rows and the
              +2 has no practical effect.
            */
            read_time= (double) head->file->scan_time() + scan_time + 2;
            if (limit < records && read_time < (double) records + scan_time + 1 )
            {
              read_time= (double) records + scan_time + 1; // Force to use index
              notnull_cond= NULL;
            }
          }
         
          possible_keys.clear_all();
         
          DBUG_PRINT("info",("Time to scan table: %g", read_time));
        

        Apparently, the read_time is uninitialized because head->file->scan_time() was uninitialized. records cannot be uninitialized, because we compared it earlier in this function, without MemorySanitizer complaining.

      Please update affectedVersion and fixVersion as you see fit. I only tested this on 10.5.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              monty Michael Widenius
              Reporter:
              marko Marko Mäkelä
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: