[MDEV-11547] encryption tests fail massively in buildbot with valgrind Created: 2016-12-12  Updated: 2017-01-11  Resolved: 2017-01-11

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Tests
Affects Version/s: 10.1
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jani Tolonen
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-7069 Fix buildbot failures in main server ... Stalled

 Description   

http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/9632/steps/test/logs/stdio

encryption.innodb_encryption 'xtradb'    w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2016-12-11 07:41:19
line
==25332== Use of uninitialised value of size 8
==25332==    at 0x5B80ECA: AES_encrypt (in /usr/lib64/libcrypto.so.0.9.8)
==25332==    by 0x5BCC208: ??? (in /usr/lib64/libcrypto.so.0.9.8)
==25332==    by 0x5BCA46F: EVP_EncryptUpdate (in /usr/lib64/libcrypto.so.0.9.8)
==25332==    by 0x11B029D: MyCTX::update(unsigned char const*, unsigned int, unsigned char*, unsigned int*) (my_crypt.cc:59)
==25332==    by 0x11AFED9: my_aes_crypt_update (my_crypt.cc:244)
==25332==    by 0x11B0210: my_aes_crypt (my_crypt.cc:263)
==25332==    by 0xDCF6A0: init_crypt_key(crypt_info_t*) (log0crypt.cc:276)
==25332==    by 0xDCF795: add_crypt_info(crypt_info_t*, bool) (log0crypt.cc:324)
==25332==    by 0xDCFBA4: log_crypt_set_ver_and_key(unsigned long) (log0crypt.cc:392)
==25332==    by 0xDCAA1E: recv_recovery_from_checkpoint_start(unsigned long) (log0recv.cc:4367)
==25332==    by 0xEEA0CE: innobase_start_or_create_for_mysql() (srv0start.cc:2224)
==25332==    by 0xD361DA: innobase_init(void*) (ha_innodb.cc:4573)

encryption.innodb_encryption_is 'cbc,xtradb' w4 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2016-12-11 08:18:26
line
==2232== Thread 9:
==2232== Syscall param pwrite64(buf) points to uninitialised byte(s)
==2232==    at 0x4E3F3C8: ??? (in /lib64/libpthread-2.9.so)
==2232==    by 0xDE4BE9: SyncFileIO::execute(IORequest const&) (os0file.cc:2199)
==2232==    by 0xDE4CA5: os_file_io(IORequest const&, int, void*, unsigned long, unsigned long, dberr_t*) (os0file.cc:5617)
==2232==    by 0xDE59B1: os_file_pwrite(IORequest&, int, unsigned char const*, unsigned long, unsigned long, dberr_t*) (os0file.cc:5716)
==2232==    by 0xDE5AFF: os_file_write_page(IORequest&, char const*, int, unsigned char const*, unsigned long, unsigned long) (os0file.cc:5746)
==2232==    by 0xDE5F37: os_file_write_func(IORequest&, char const*, int, void const*, unsigned long, unsigned long) (os0file.cc:6291)
==2232==    by 0xDE6565: os_aio_func(IORequest&, unsigned long, char const*, int, void*, unsigned long, unsigned long, bool, fil_node_t*, void*, unsigned long*) (os0file.cc:7549)
==2232==    by 0x1048F09: pfs_os_aio_func(IORequest&, unsigned long, char const*, int, void*, unsigned long, unsigned long, bool, fil_node_t*, void*, unsigned long*, char const*, unsigned long) (os0file.ic:259)
==2232==    by 0x105444E: fil_io(IORequest const&, bool, page_id_t const&, page_size_t const&, unsigned long, unsigned long, void*, void*, unsigned long*) (fil0fil.cc:5749)
==2232==    by 0xDB7ECC: log_group_write_buf(log_group_t*, unsigned char*, unsigned long, unsigned long, unsigned long, unsigned long) (log0log.cc:1137)
==2232==    by 0xDB85FB: log_write_up_to(unsigned long, bool) (log0log.cc:1396)
==2232==    by 0xFDA4E0: buf_flush_write_block_low(buf_page_t*, buf_flush_t, bool) (buf0flu.cc:1046)
==2232==  Address 0x19e85420 is 992 bytes inside a block of size 2,097,664 alloc'd
==2232==    at 0x4C25553: calloc (vg_replace_malloc.c:711)
==2232==    by 0xDB956E: log_init() (log0log.cc:823)
==2232==    by 0xEE8EDC: innobase_start_or_create_for_mysql() (srv0start.cc:1837)
==2232==    by 0xD361DA: innobase_init(void*) (ha_innodb.cc:4573)
==2232==    by 0x9BDBD5: ha_initialize_handlerton(st_plugin_int*) (handler.cc:512)
==2232==    by 0x741957: plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) (sql_plugin.cc:1415)
==2232==    by 0x745FD6: plugin_init(int*, char**, int) (sql_plugin.cc:1689)
==2232==    by 0x64AEBE: init_server_components() (mysqld.cc:5293)
==2232==    by 0x64D102: mysqld_main(int, char**) (mysqld.cc:5884)
==2232==    by 0x63B9D6: main (main.cc:25)

and more



 Comments   
Comment by Sergei Golubchik [ 2016-12-12 ]

It's either valgrind or, more likely, OpenSSL bug (work has a five year old 0.9.8t). "Use of uninitialised value" in AES_encrypt happens because IV is considered uninitialized. To see that one can use MEM_CHECK_DEFINED macro:

sql/log.cc

3515
          if (my_random_bytes(crypto.nonce, sizeof(crypto.nonce)))
3516
            goto err;
3517
          MEM_CHECK_DEFINED(crypto.nonce, sizeof(crypto.nonce));

On this valgrind will print a warning that crypto.nonce is uninitialized.

There are (at least) two ways to fix it. Upgrade OpenSSL (one isn't supposed to use 0.9.8 anyway) or use VALGRIND_MAKE_MEM_DEFINED macro here.

Comment by Sergei Golubchik [ 2016-12-12 ]

jani, could you, please, see if it's possible to upgrade OpenSSL on work to 1.0.2-something?

Comment by Jani Tolonen [ 2017-01-11 ]

work.askmonty.org upgraded to opensuse 13.1. (upgrade to 13.2. failed) and openssl and it's components were separately upgraded to version 1.0.2j. Previous opensuse installation 11.1. was had too old kernel to be able to do any upgrades on it.

Generated at Thu Feb 08 07:50:48 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.