[MDEV-26757] Compression-related tests fail with MSAN errors in buf_page_is_corrupted Created: 2021-10-04  Updated: 2023-03-03

Status: Open
Project: MariaDB Server
Component/s: Compiling, Tests
Affects Version/s: 10.5, 10.6, 10.7
Fix Version/s: 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDBF-276 Apply changes to the MSAN builder Closed
relates to MDEV-12933 sort out the compression library chaos Closed

 Description   

preview-10.7-MDEV-12933-provider-plugins 67a8fca9b

 
mariabackup.compression_providers_loaded 'bzip2' w5 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2021-10-04 11:29:00
 
line
 
==154911==WARNING: MemorySanitizer: use-of-uninitialized-value
 
SUMMARY: MemorySanitizer: use-of-uninitialized-value /home/jenkins/workspace/sandbox-elenst/MSAN_build_test/src/storage/innobase/buf/buf0buf.cc:618:7 in buf_page_is_corrupted(bool, unsigned char const*, unsigned int)
 
^ Found warnings in /home/jenkins/workspace/sandbox-elenst/MSAN_build_test/src/mysql-test/var/5/log/mysqld.1.err
 
ok

All combinations of loaded/unloaded tests fail this way:

mariabackup.compression_providers_loaded 'bzip2'
mariabackup.compression_providers_loaded 'lz4'
mariabackup.compression_providers_loaded 'lzma'
mariabackup.compression_providers_loaded 'snappy'
mariabackup.compression_providers_loaded 'lzo'
mariabackup.compression_providers_unloaded 'bzip2'
mariabackup.compression_providers_unloaded 'lz4'
mariabackup.compression_providers_unloaded 'lzma'
mariabackup.compression_providers_unloaded 'snappy'
mariabackup.compression_providers_unloaded 'lzo'

 Comments   
Comment by Elena Stepanova [ 2021-10-04 ]

It also happens in the plugins.compression test, but the error is not detected as it occurs upon the intermediate server restart.

preview-10.7-MDEV-12933-provider-plugins 67a8fca9

 
Version: '10.7.0-MariaDB-debug-log'  socket: '/home/elenst/src/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
 
2021-10-04 17:09:11 0 [Note] /home/elenst/src/sql/mariadbd (initiated by: root[root] @ localhost []): Normal shutdown
 
2021-10-04 17:09:11 0 [Note] InnoDB: FTS optimize thread exiting.
 
2021-10-04 17:09:11 0 [Note] InnoDB: Starting shutdown...
 
2021-10-04 17:09:11 0 [Note] InnoDB: Dumping buffer pool(s) to /home/elenst/src/mysql-test/var/mysqld.1/data/ib_buffer_pool
 
2021-10-04 17:09:11 0 [Note] InnoDB: Restricted to 126 pages due to innodb_buf_pool_dump_pct=25
 
2021-10-04 17:09:11 0 [Note] InnoDB: Buffer pool(s) dump completed at 211004 17:09:11
 
==13411==WARNING: MemorySanitizer: use-of-uninitialized-value
 
    #0 0x563e779298a9 in buf_page_is_corrupted(bool, unsigned char const*, unsigned int) /home/elenst/src/storage/innobase/buf/buf0buf.cc:618:7
 
    #1 0x563e779b9499 in buf_page_encrypt(fil_space_t*, buf_page_t*, unsigned char*, unsigned long*) /home/elenst/src/storage/innobase/buf/buf0flu.cc:736:7
 
    #2 0x563e779a4346 in buf_flush_page(buf_page_t*, bool, fil_space_t*) /home/elenst/src/storage/innobase/buf/buf0flu.cc:883:15
 
    #3 0x563e7799d6b7 in buf_do_flush_list_batch(unsigned long, unsigned long) /home/elenst/src/storage/innobase/buf/buf0flu.cc:1443:14
 
    #4 0x563e7799d6b7 in buf_flush_list(unsigned long, unsigned long) /home/elenst/src/storage/innobase/buf/buf0flu.cc:1518:26
 
    #5 0x563e779b4c6d in buf_flush_buffer_pool() /home/elenst/src/storage/innobase/buf/buf0flu.cc:2406:5
 
    #6 0x563e771a480e in logs_empty_and_mark_files_at_shutdown() /home/elenst/src/storage/innobase/log/log0log.cc:1113:3
 
    #7 0x563e776908be in innodb_shutdown() /home/elenst/src/storage/innobase/srv/srv0start.cc:1972:3
 
    #8 0x563e76f6275a in innobase_end(handlerton*, ha_panic_function) /home/elenst/src/storage/innobase/handler/ha_innodb.cc:4238:3
 
    #9 0x563e760063fb in ha_finalize_handlerton(st_plugin_int*) /home/elenst/src/sql/handler.cc:596:5
 
    #10 0x563e753cc8d4 in plugin_deinitialize(st_plugin_int*, bool) /home/elenst/src/sql/sql_plugin.cc:1268:19
 
    #11 0x563e753c29ec in reap_plugins() /home/elenst/src/sql/sql_plugin.cc:1333:5
 
    #12 0x563e753cdcfc in plugin_shutdown() /home/elenst/src/sql/sql_plugin.cc:2041:7
 
    #13 0x563e74d7e2df in clean_up(bool) /home/elenst/src/sql/mysqld.cc:1941:3
 
    #14 0x563e74d9405c in mysqld_main(int, char**) /home/elenst/src/sql/mysqld.cc:5875:3
 
    #15 0x563e74d79c93 in main /home/elenst/src/sql/main.cc:34:10
 
    #16 0x7fad8a46c0b2 in __libc_start_main /build/glibc-eX1tMB/glibc-2.31/csu/../csu/libc-start.c:308:16
 
    #17 0x563e74cfd23d in _start (/home/elenst/src/sql/mariadbd+0x6ff23d)
 
 
 
  Uninitialized value was created by a heap allocation
 
    #0 0x563e74d033c5 in posix_memalign (/home/elenst/src/sql/mariadbd+0x7053c5)
 
    #1 0x563e779b8ad7 in aligned_malloc(unsigned long, unsigned long) /home/elenst/src/storage/innobase/include/buf0buf.h:442:7
 
    #2 0x563e779b8ad7 in buf_tmp_reserve_compression_buf(buf_tmp_buffer_t*) /home/elenst/src/storage/innobase/buf/buf0flu.cc:580:38
 
    #3 0x563e779b8ad7 in buf_page_encrypt(fil_space_t*, buf_page_t*, unsigned char*, unsigned long*) /home/elenst/src/storage/innobase/buf/buf0flu.cc:701:5
 
 
 
SUMMARY: MemorySanitizer: use-of-uninitialized-value /home/elenst/src/storage/innobase/buf/buf0buf.cc:618:7 in buf_page_is_corrupted(bool, unsigned char const*, unsigned int)
 
Exiting
 
$ /home/elenst/src/sql/mariadbd --defaults-group-suffix=.1 --defaults-file=/home/elenst/src/mysql-test/var/my.cnf --log-output=file --innodb --plugin-load-add=provider_snappy.so --loose-provider-snappy --disable-provider-snappy --core-file --loose-debug-sync-timeout=300
 
2021-10-04 17:09:12 0 [Note] /home/elenst/src/sql/mariadbd (server 10.7.0-MariaDB-debug-log) starting as process 13432 ...

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

I think that there are 2 alternatives:

  1. Compile each compression library with MSAN instrumentation. Bonus: no code changes should be needed.
  2. In the wrapper layer that MDEV-12933 introduces, add __msan_unpoison() calls. If this is implemented, then there still is a possibility that you could get bogus MemorySanitizer errors reported for the uninstrumented compression library code, if they invoke anything that would be intercepted by the instrumented libc.so.
Comment by Elena Stepanova [ 2021-10-11 ]

I've removed the connection to 10.7 preview activities, because apparently it's not specific to the providers in 10.7. Here is a similar stack trace from 10.6 main:

10.6 d8b8258a

 
innodb.innodb-page_compression_lz4 'innodb' w5 [ fail ]
 
        Test ended at 2021-10-11 09:49:46
 
 
 
CURRENT_TEST: innodb.innodb-page_compression_lz4
 
mysqltest: At line 64: query 'insert into innodb_page_compressed1 select * from innodb_normal' failed: <Unknown> (2013): Lost connection to server during query
 
 
 
The result from queries just before the failure was:
 
< snip >
 
) ENGINE=InnoDB DEFAULT CHARSET=latin1 `page_compressed`=1 `page_compression_level`=9
 
create procedure innodb_insert_proc (repeat_count int)
 
begin
 
declare current_num int;
 
set current_num = 0;
 
while current_num < repeat_count do
 
insert into innodb_normal values(current_num,'testing..');
 
set current_num = current_num + 1;
 
end while;
 
end//
 
commit;
 
set autocommit=0;
 
call innodb_insert_proc(5000);
 
commit;
 
set autocommit=1;
 
select count(*) from innodb_normal;
 
count(*)
 
5000
 
insert into innodb_compressed select * from innodb_normal;
 
insert into innodb_page_compressed1 select * from innodb_normal;
 
 
 
More results from queries before failure can be found in /dev/shm/mtr/5/log/innodb-page_compression_lz4.log
 
 
 
 
 
Server [mysqld.1 - pid: 268838, winpid: 268838, exit: 19712] failed during test run
 
Server log from this test:


----------SERVER LOG START-----------
 
==268839==WARNING: MemorySanitizer: use-of-uninitialized-value
 
    #0 0x555860ffb43a in buf_page_is_corrupted(bool, unsigned char const*, unsigned long) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0buf.cc:621:7
 
    #1 0x55586108c073 in buf_page_encrypt(fil_space_t*, buf_page_t*, unsigned char*, unsigned long*) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:742:7
 
    #2 0x555861076b1e in buf_flush_page(buf_page_t*, bool, fil_space_t*) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:889:15
 
    #3 0x55586106ff07 in buf_do_flush_list_batch(unsigned long, unsigned long) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:1449:14
 
    #4 0x55586106ff07 in buf_flush_list(unsigned long, unsigned long) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:1524:26
 
    #5 0x55586108299d in buf_flush_page_cleaner() /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:2331:30
 
    #6 0x555861093218 in decltype(std::__1::forward<void (*)()>(fp)()) std::__1::__invoke<void (*)()>(void (*&&)()) /usr/lib/llvm-11/bin/../include/c++/v1/type_traits:3899:1
 
    #7 0x555861093218 in void std::__1::__thread_execute<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, void (*)()>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, void (*)()>&, std::__1::__tuple_indices<>) /usr/lib/llvm-11/bin/../include/c++/v1/thread:280:5
 
    #8 0x555861093218 in void* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, void (*)()> >(void*) /usr/lib/llvm-11/bin/../include/c++/v1/thread:291:5
 
    #9 0x7f49d0aca608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477:8
 
    #10 0x7f49d0691292 in clone /build/glibc-eX1tMB/glibc-2.31/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
 
 
  Uninitialized value was created by a heap allocation
 
    #0 0x55585e3d6c55 in posix_memalign (/home/jenkins/workspace/sandbox-elenst/MSAN/src/sql/mariadbd+0x706c55)
 
    #1 0x55586108b6a6 in aligned_malloc(unsigned long, unsigned long) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/include/buf0buf.h:445:7
 
    #2 0x55586108b6a6 in buf_tmp_reserve_compression_buf(buf_tmp_buffer_t*) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:586:38
 
    #3 0x55586108b6a6 in buf_page_encrypt(fil_space_t*, buf_page_t*, unsigned char*, unsigned long*) /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0flu.cc:707:5
 
 
 
SUMMARY: MemorySanitizer: use-of-uninitialized-value /home/jenkins/workspace/sandbox-elenst/MSAN/src/storage/innobase/buf/buf0buf.cc:621:7 in buf_page_is_corrupted(bool, unsigned char const*, unsigned long)
 
Exiting
 
----------SERVER LOG END-------------

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

Here is how I built liblz4.so with MemorySanitizer instrumentation:

apt source liblz4-1
 
cd lz4-1*/
 
CC=clang-13 CXX=clang++-13 \
 
CPPFLAGS='-Wdate-time -fsanitize=memory -DLZ4F_PUBLISH_STATIC_FUNCTIONS' \
 
CFLAGS='-Wdate-time -fsanitize=memory -DLZ4F_PUBLISH_STATIC_FUNCTIONS -g -O2' \
 
CXXFLAGS='-Wdate-time -fsanitize=memory -DLZ4F_PUBLISH_STATIC_FUNCTIONS -g -O2' \
 
make -j$(nproc)

I moved the generated lib/lz4.so* to my directory that contains MemorySanitizer-instrumented libraries (which is pointed to by LD_LIBRARY_PATH when I run the instrumented code). Furthermore, I removed -DWITH_INNODB_LZ4=OFF from my usual MemorySanitizer configuration script (see MDEV-20377). With this, the test innodb.innodb-page_compression_lz4 passed.

I think that compiling instrumented versions of other compression libraries should be similar: use the same version of clang, add -fsanitize=memory to the compiler flags, and make sure that no uninstrumented assembler code is being used.

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