[MDEV-27048] UBSAN: runtime error: shift exponent 32 is too large for 32-bit type 'unsigned int' Created: 2021-11-15  Updated: 2023-11-23  Resolved: 2021-11-19

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.7.1, 10.7, 10.8
Fix Version/s: 10.8.0, 10.7.2

Type: Bug Priority: Blocker
Reporter: Roel Van de Paar Assignee: Aleksey Midenkov
Resolution: Fixed Votes: 0
Labels: affects-tests, corruption, init, memory_exhaustion, regression

Issue Links:
Duplicate
is duplicated by MDEV-27084 ddl_log_write_execute_entry: zero sto... Closed

 Description    

export UBSAN_OPTIONS=print_stacktrace=1
 
rm -Rf /test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-dbg/data
 
/test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-dbg/scripts/mariadb-install-db --no-defaults --force --auth-root-authentication-method=normal --basedir=/test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-dbg --datadir=/test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-dbg/data

Leads to:

10.8.0 5566cbadb03856aba9c236b131f544490cd2bee4 (Optimized)

 
/test/10.8_opt_san/sql/ddl_log.cc:2548:3: runtime error: shift exponent 32 is too large for 32-bit type 'unsigned int'
 
    #0 0x55c3771098f8 in ddl_log_write_execute_entry(unsigned int, unsigned int, st_ddl_log_memory_entry**) /test/10.8_opt_san/sql/ddl_log.cc:2548
 
    #1 0x55c377110862 in ddl_log_write_execute_entry(unsigned int, st_ddl_log_memory_entry**) /test/10.8_opt_san/sql/ddl_log.h:271
 
    #2 0x55c377110862 in ddl_log_write /test/10.8_opt_san/sql/ddl_log.cc:3044
 
    #3 0x55c377118669 in ddl_log_create_table(THD*, st_ddl_log_state*, handlerton*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, bool) /test/10.8_opt_san/sql/ddl_log.cc:3328
 
    #4 0x55c37701e621 in create_table_impl(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, DDL_options_st, HA_CREATE_INFO*, Alter_info*, int, bool*, st_key**, unsigned int*, st_mysql_const_unsigned_lex_string*) /test/10.8_opt_san/sql/sql_table.cc:4539
 
    #5 0x55c377022451 in mysql_create_table_no_lock(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, Alter_info*, bool*, int, TABLE_LIST*) /test/10.8_opt_san/sql/sql_table.cc:4666
 
    #6 0x55c3770238b5 in mysql_create_table(THD*, TABLE_LIST*, Table_specification_st*, Alter_info*) /test/10.8_opt_san/sql/sql_table.cc:4778
 
    #7 0x55c377045dea in Sql_cmd_create_table_like::execute(THD*) /test/10.8_opt_san/sql/sql_table.cc:11909
 
    #8 0x55c376aa2826 in mysql_execute_command(THD*, bool) /test/10.8_opt_san/sql/sql_parse.cc:5989
 
    #9 0x55c376a28e28 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.8_opt_san/sql/sql_parse.cc:8028
 
    #10 0x55c376a7740e in bootstrap(st_mysql_file*) /test/10.8_opt_san/sql/sql_parse.cc:1081
 
    #11 0x55c376269cb3 in mysqld_main(int, char**) /test/10.8_opt_san/sql/mysqld.cc:5782
 
    #12 0x14f7b3ddd0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
    #13 0x55c37611252d in _start (/test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-opt/bin/mariadbd+0x7d4952d)

10.8.0 5566cbadb03856aba9c236b131f544490cd2bee4 (Debug)

 
/test/10.8_dbg_san/sql/ddl_log.cc:2548:3: runtime error: shift exponent 32 is too large for 32-bit type 'unsigned int'
 
    #0 0x5562e831d31d in ddl_log_write_execute_entry(unsigned int, unsigned int, st_ddl_log_memory_entry**) /test/10.8_dbg_san/sql/ddl_log.cc:2548
 
    #1 0x5562e832179a in ddl_log_write_execute_entry(unsigned int, st_ddl_log_memory_entry**) /test/10.8_dbg_san/sql/ddl_log.h:271
 
    #2 0x5562e832179a in ddl_log_write /test/10.8_dbg_san/sql/ddl_log.cc:3044
 
    #3 0x5562e83262d4 in ddl_log_create_table(THD*, st_ddl_log_state*, handlerton*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, bool) /test/10.8_dbg_san/sql/ddl_log.cc:3328
 
    #4 0x5562e8222ea6 in create_table_impl(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, DDL_options_st, HA_CREATE_INFO*, Alter_info*, int, bool*, st_key**, unsigned int*, st_mysql_const_unsigned_lex_string*) /test/10.8_dbg_san/sql/sql_table.cc:4539
 
    #5 0x5562e8225ce8 in mysql_create_table_no_lock(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, Alter_info*, bool*, int, TABLE_LIST*) /test/10.8_dbg_san/sql/sql_table.cc:4666
 
    #6 0x5562e8227b7a in mysql_create_table(THD*, TABLE_LIST*, Table_specification_st*, Alter_info*) /test/10.8_dbg_san/sql/sql_table.cc:4778
 
    #7 0x5562e8233e25 in Sql_cmd_create_table_like::execute(THD*) /test/10.8_dbg_san/sql/sql_table.cc:11909
 
    #8 0x5562e7b66788 in mysql_execute_command(THD*, bool) /test/10.8_dbg_san/sql/sql_parse.cc:5989
 
    #9 0x5562e7aa19f6 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.8_dbg_san/sql/sql_parse.cc:8028
 
    #10 0x5562e7b06311 in bootstrap(st_mysql_file*) /test/10.8_dbg_san/sql/sql_parse.cc:1081
 
    #11 0x5562e713c8b0 in mysqld_main(int, char**) /test/10.8_dbg_san/sql/mysqld.cc:5782
 
    #12 0x5562e7107b7a in main /test/10.8_dbg_san/sql/main.cc:34
 
    #13 0x149f2cf210b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
    #14 0x5562e6fdb57d in _start (/test/UBASAN_MD151121-mariadb-10.8.0-linux-x86_64-dbg/bin/mariadbd+0x825157d)



 Comments   
Comment by Roel Van de Paar [ 2021-11-15 ] 

  /*
 
    We haven't synched the log entries yet, we sync them now before
 
    writing the execute entry.
 
  */
 
  (void) ddl_log_sync_no_lock();
 
  bzero(file_entry_buf, global_ddl_log.io_size);
 
 
 
  file_entry_buf[DDL_LOG_ENTRY_TYPE_POS]= (uchar)DDL_LOG_EXECUTE_CODE;
 
  int4store(file_entry_buf + DDL_LOG_NEXT_ENTRY_POS, first_entry);
 
  int8store(file_entry_buf + DDL_LOG_ID_POS, (cond_entry << DDL_LOG_RETRY_BITS));    <<<<<<<<<<< Line 2548 <<<<<<<<<<<

Comment by Marko Mäkelä [ 2021-11-15 ]

cond_entry is defined as uint, which should be 32 bits on every platform on our CI systems. Converting to a 64-bit type before the bit shifting should work.

The error was introduced in 10.7.1.

Comment by Roel Van de Paar [ 2021-11-17 ]

The issue is much more serious than originally thought. The issue can also be observed in mariadbd (not just mariadb-install-db)

CREATE TABLE t (a INT,b INT,c INT,x TEXT,y TEXT,z TEXT,id INT UNSIGNED AUTO_INCREMENT,i INT,KEY(id),UNIQUE KEY a (a,b,c));
 
ALTER TABLE t ADD CONSTRAINT test UNIQUE (id) USING HASH;

Will lead to the same issue, and a temporary table corruption. InnoDB ad MyISAM both produce the issue.

10.8.0 5566cbadb03856aba9c236b131f544490cd2bee4 (Debug)

 
/test/10.8_dbg_san/sql/ddl_log.cc:2548:3: runtime error: shift exponent 32 is too large for 32-bit type 'unsigned int'
 
    #0 0x55ef9c67531d in ddl_log_write_execute_entry(unsigned int, unsigned int, st_ddl_log_memory_entry**) /test/10.8_dbg_san/sql/ddl_log.cc:2548
 
    #1 0x55ef9c67979a in ddl_log_write_execute_entry(unsigned int, st_ddl_log_memory_entry**) /test/10.8_dbg_san/sql/ddl_log.h:271
 
    #2 0x55ef9c67979a in ddl_log_write /test/10.8_dbg_san/sql/ddl_log.cc:3044
 
    #3 0x55ef9c67e2d4 in ddl_log_create_table(THD*, st_ddl_log_state*, handlerton*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, bool) /test/10.8_dbg_san/sql/ddl_log.cc:3328
 
    #4 0x55ef9c57aea6 in create_table_impl(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, st_mysql_const_lex_string const&, DDL_options_st, HA_CREATE_INFO*, Alter_info*, int, bool*, st_key**, unsigned int*, st_mysql_const_unsigned_lex_string*) /test/10.8_dbg_san/sql/sql_table.cc:4539
 
    #5 0x55ef9c57dce8 in mysql_create_table_no_lock(THD*, st_ddl_log_state*, st_ddl_log_state*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, Alter_info*, bool*, int, TABLE_LIST*) /test/10.8_dbg_san/sql/sql_table.cc:4666
 
    #6 0x55ef9c57fb7a in mysql_create_table(THD*, TABLE_LIST*, Table_specification_st*, Alter_info*) /test/10.8_dbg_san/sql/sql_table.cc:4778
 
    #7 0x55ef9c58be25 in Sql_cmd_create_table_like::execute(THD*) /test/10.8_dbg_san/sql/sql_table.cc:11909
 
    #8 0x55ef9bebe788 in mysql_execute_command(THD*, bool) /test/10.8_dbg_san/sql/sql_parse.cc:5989
 
    #9 0x55ef9bdf99f6 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.8_dbg_san/sql/sql_parse.cc:8028
 
    #10 0x55ef9be6efd8 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.8_dbg_san/sql/sql_parse.cc:1894
 
    #11 0x55ef9be85a3c in do_command(THD*, bool) /test/10.8_dbg_san/sql/sql_parse.cc:1402
 
    #12 0x55ef9c9404f5 in do_handle_one_connection(CONNECT*, bool) /test/10.8_dbg_san/sql/sql_connect.cc:1418
 
    #13 0x55ef9c94338f in handle_one_connection /test/10.8_dbg_san/sql/sql_connect.cc:1312
 
    #14 0x55ef9ee2f990 in pfs_spawn_thread /test/10.8_dbg_san/storage/perfschema/pfs.cc:2201
 
    #15 0x14d745abc608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
    #16 0x14d744d32292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
 
 
 
2021-11-18  9:36:02 4 [ERROR] mysqld: Incorrect information in file: './test/#sql-alter-c4dc9-4.frm'

Comment by Roel Van de Paar [ 2021-11-17 ]

This issue is observed in many trials, so there are likely many more avenues to produce the corruption and overflow.

Comment by Roel Van de Paar [ 2021-11-17 ]

Issue is also seen in different stacks. List of UniqueID's seen so far:

UBSAN|shift exponent X is too large for 32-bit type 'unsigned int'|sql/ddl_log.cc|ddl_log_write_execute_entry|ddl_log_write_execute_entry|ddl_log_write|ddl_log_create_table  (ref above)
 
UBSAN|shift exponent X is too large for 32-bit type 'unsigned int'|sql/ddl_log.cc|ddl_log_write_execute_entry|ddl_log_write_execute_entry|ddl_log_write|ddl_log_alter_table
 
UBSAN|shift exponent X is too large for 32-bit type 'unsigned int'|sql/ddl_log.cc|ddl_log_write_execute_entry|ddl_log_write_execute_entry|ddl_log_write|ddl_log_create_view
 
UBSAN|shift exponent X is too large for 32-bit type 'unsigned int'|sql/ddl_log.cc|ddl_log_write_execute_entry|ddl_log_write_execute_entry|ddl_log_write|ddl_log_drop_db  
UBSAN|shift exponent X is too large for 32-bit type 'unsigned int'|sql/ddl_log.cc|ddl_log_write_execute_entry|ddl_log_write_execute_entry|ddl_log_write|ddl_log_drop_init

As well as various table corruptions. I can reduce more testcases for any of these if of interest, but I expect the issue is clear thanks to marko's input?

Comment by Roel Van de Paar [ 2021-11-17 ]

I wonder why this was not picked up by MTR testing? marko is it due to the reason you stated above? marko & midenok, what can be done so we don't miss these? Thank you

Comment by Roel Van de Paar [ 2021-11-17 ]

I have a number of testcase reducers which seem to go OOM quickly. It may be that this change is causing memory exhaustion issues. Will retest after fix.

Comment by Aleksey Midenkov [ 2021-11-17 ]

Please review bb-10.7-midenok2

Comment by Roel Van de Paar [ 2021-11-18 ]

Will do another run with this branch now.

Comment by Roel Van de Paar [ 2021-11-18 ]

Issue looks fixed in bb-10.7-midenok2, none of the uniqueID's above are showing, and other issues are surfacing now that the runs are not being short-stopped by these blocking issues.

Comment by Oleksandr Byelkin [ 2021-11-19 ]

OK to push

Generated at Thu Feb 08 09:49:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.