[MDEV-12634] Uninitialised ROW_MERGE_RESERVE_SIZE bytes written to temporary file Created: 2017-04-29  Updated: 2017-09-28  Resolved: 2017-09-14

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1.7, 10.2.0, 10.3.0
Fix Version/s: 10.1.27, 10.2.9

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Problem/Incident
is caused by MDEV-8708 InnoDB temp file encryption Closed
Relates
relates to MDEV-13826 CREATE FULLTEXT INDEX on encrypted ta... Closed
relates to MDEV-13827 Add encryption tests for FULLTEXT INDEX Closed
Sprint: 10.1.24

 Description   

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

innodb.innodb_bug53290 'innodb_plugin'   w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2017-04-27 12:29:08
line
==31315== Thread 22:
==31315== Uninitialised byte(s) found during client check request
==31315==    at 0xC0F7216: row_merge_write_eof(unsigned char*, unsigned char*, int, unsigned long*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:1360)
==31315==    by 0xC0F9CE2: row_merge_blocks(row_merge_dup_t const*, merge_file_t const*, unsigned char*, unsigned long*, unsigned long*, merge_file_t*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2328)
==31315==    by 0xC0FA449: row_merge(trx_t*, row_merge_dup_t const*, merge_file_t*, unsigned char*, int*, unsigned long*, unsigned long*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2484)
==31315==    by 0xC0FAB01: row_merge_sort(trx_t*, row_merge_dup_t const*, merge_file_t*, unsigned char*, int*, bool, float, float, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2649)
==31315==    by 0xC0FE2F5: row_merge_build_indexes(trx_t*, dict_table_t*, dict_table_t*, bool, dict_index_t**, unsigned long const*, unsigned long, TABLE*, dtuple_t const*, unsigned long const*, unsigned long, ib_sequence_t&) (row0merge.cc:4230)
==31315==    by 0xC018846: ha_innodb::inplace_alter_table(TABLE*, Alter_inplace_info*) (handler0alter.cc:4249)
==31315==    by 0x6E90C6: handler::ha_inplace_alter_table(TABLE*, Alter_inplace_info*) (handler.h:3704)
==31315==    by 0x6E1256: mysql_inplace_alter_table(THD*, TABLE_LIST*, TABLE*, TABLE*, Alter_inplace_info*, enum_alter_inplace_result, MDL_request*, Alter_table_ctx*) (sql_table.cc:7133)
==31315==    by 0x6E5ACF: mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) (sql_table.cc:8945)
==31315==    by 0x75AFCD: Sql_cmd_alter_table::execute(THD*) (sql_alter.cc:325)
==31315==    by 0x6266AF: mysql_execute_command(THD*) (sql_parse.cc:5695)
==31315==    by 0x62A952: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7343)
==31315==  Address 0x18736000 is in a rw- anonymous segment



 Comments   
Comment by Elena Stepanova [ 2017-08-10 ]

Reproducible locally (Jessie 8.8 64-bit, valgrind-3.12.0.SVN, gcc (Debian 4.9.2-10) 4.9.2) on the current 10.1 tree:

10.1 535910ae5f20e36405631030e9c0eb22fe40a7c4

innodb.innodb_bug53290 'innodb_plugin'   [ fail ]  Found warnings/errors in server log file!
        Test ended at 2017-08-10 13:49:48
line
==18674== Thread 22:
==18674== Uninitialised byte(s) found during client check request
==18674==    at 0xC700ACA: row_merge_write_eof(unsigned char*, unsigned char*, int, unsigned long*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:1360)
==18674==    by 0xC7034AD: row_merge_blocks(row_merge_dup_t const*, merge_file_t const*, unsigned char*, unsigned long*, unsigned long*, merge_file_t*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2328)
==18674==    by 0xC703BD4: row_merge(trx_t*, row_merge_dup_t const*, merge_file_t*, unsigned char*, int*, unsigned long*, unsigned long*, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2484)
==18674==    by 0xC70427B: row_merge_sort(trx_t*, row_merge_dup_t const*, merge_file_t*, unsigned char*, int*, bool, float, float, fil_space_crypt_t*, unsigned char*, unsigned long) (row0merge.cc:2649)
==18674==    by 0xC707A36: row_merge_build_indexes(trx_t*, dict_table_t*, dict_table_t*, bool, dict_index_t**, unsigned long const*, unsigned long, TABLE*, dtuple_t const*, unsigned long const*, unsigned long, ib_sequence_t&) (row0merge.cc:4243)
==18674==    by 0xC621B30: ha_innodb::inplace_alter_table(TABLE*, Alter_inplace_info*) (handler0alter.cc:4260)
==18674==    by 0x6A896A: handler::ha_inplace_alter_table(TABLE*, Alter_inplace_info*) (handler.h:3718)
==18674==    by 0x6A0AA1: mysql_inplace_alter_table(THD*, TABLE_LIST*, TABLE*, TABLE*, Alter_inplace_info*, enum_alter_inplace_result, MDL_request*, Alter_table_ctx*) (sql_table.cc:7159)
==18674==    by 0x6A535A: mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) (sql_table.cc:8973)
==18674==    by 0x719F7E: Sql_cmd_alter_table::execute(THD*) (sql_alter.cc:325)
==18674==    by 0x5E5357: mysql_execute_command(THD*) (sql_parse.cc:5699)
==18674==    by 0x5E9608: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7344)
==18674==    by 0x5D8565: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1484)
==18674==    by 0x5D7302: do_command(THD*) (sql_parse.cc:1106)
==18674==    by 0x714C78: do_handle_one_connection(THD*) (sql_connect.cc:1349)
==18674==    by 0x7149DC: handle_one_connection (sql_connect.cc:1261)

Comment by Marko Mäkelä [ 2017-08-10 ]

This is due to the ROW_MERGE_RESERVE_SIZE (4) bytes at the start of the first block of the merge sort file.
As far as I can tell, these bytes would be always uninitialized if encryption is not enabled.

This bug was introduced in MariaDB 10.1.7 by MDEV-8708: InnoDB temp file encryption

I do not understand why we need to allocate and write these bytes to the file even when using encryption.
The temporary files are only useful to the current thread that is executing the ALTER TABLE…ALGORITHM=INPLACE. That thread can remember any necessary encryption parameters in memory.

Running vgdb instead of or inside manual-gdb confirms this:

(gdb) target remote |vgdb
(gdb) c
Thread 3 received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 10630]
0x0000000000c89e67 in row_merge_write_eof (block=0x1d046000 "", 
    b=0x1d106005 "", fd=49, foffs=0x412ac88, crypt_data=0x0, crypt_block=0x0, 
    space=4) at /mariadb/10.2/storage/innobase/row/row0merge.cc:1556
(gdb) p sizeof block[0]
$1 = 1
(gdb) p b - &block[0]
$2 = 786437
(gdb) monitor get_vbits 0x1d046000 786437
ffffffff 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00

The only uninitialized bytes are the first 4 bytes of the buffer.

Comment by Marko Mäkelä [ 2017-08-10 ]

When fixing this (by removing the ROW_MERGE_RESERVE_SIZE), please also ensure that row_log_apply() and row_log_table_apply() are using encryption on the temporary files.

Comment by Jan Lindström (Inactive) [ 2017-09-08 ]

https://github.com/MariaDB/server/commit/6550bae39d848e0359df44ea5a85cf0d574dd5c3

Comment by Jan Lindström (Inactive) [ 2017-09-08 ]

Fix is quite big as we need to pass key_version to several functions and there really is not any suitable structure where it could be stored. Note that you can't use min_key_version or key_found in crypt_data structure as they could change during alter table (background key rotation could change them).

Comment by Marko Mäkelä [ 2017-09-08 ]

I would like to have some simpler data structures.
Many of the functions already have more than enough parameters.

Comment by Marko Mäkelä [ 2017-09-08 ]

My suggestion would be to introduce fil_space_t::key_version. When ALTER TABLE…ALGORITHM=INPLACE is in progress (creating indexes or rebuilding a table), I think that key rotation for the affected tablespace can be disabled.
Or we can introduce another field, say, fil_space_t::key_version_alter. This field would jump to key_version at the next ha_innobase::prepare_inplace_alter_table(). For the system tablespace, we would have to keep the old key_version_alter if there are other ALTER TABLE…ALGORITHM=INPLACE in progress. Something like fil_space_t::pending_alter could help with that. All fields can be protected by fil_space_t::latch (SX-latch or X-latch for writing, S-latch for reading).

Comment by Jan Lindström (Inactive) [ 2017-09-13 ]

Requesting a new review as implementation changed significantly:
https://github.com/MariaDB/server/commit/0364a93e7c09a92239a8e9c4e3b81344585ee95f

Comment by Marko Mäkelä [ 2017-09-13 ]

I think that the patch can be simplified further. We can simply make the encryption of the temporary files dependent on the innodb_encrypt_log parameter.

Comment by Jan Lindström (Inactive) [ 2017-09-14 ]

commit fa2701c6f7b028782cf231565f578b2fc0f10d51
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Thu Sep 14 09:23:20 2017 +0300

MDEV-12634: Uninitialised ROW_MERGE_RESERVE_SIZE bytes written to tem…
…porary file

Fixed by removing writing key version to start of every block that
was encrypted. Instead we will use single key version from log_sys
crypt info.

After this MDEV also blocks writen to row log are encrypted and blocks
read from row log aren decrypted if encryption is configured for the
table.

innodb_status_variables[], struct srv_stats_t
Added status variables for merge block and row log block
encryption and decryption amounts.

Removed ROW_MERGE_RESERVE_SIZE define.

row_merge_fts_doc_tokenize
Remove ROW_MERGE_RESERVE_SIZE

row_log_t
Add index, crypt_tail, crypt_head to be used in case of
encryption.

row_log_online_op, row_log_table_close_func
Before writing a block encrypt it if encryption is enabled

row_log_table_apply_ops, row_log_apply_ops
After reading a block decrypt it if encryption is enabled

row_log_allocate
Allocate temporary buffers crypt_head and crypt_tail
if needed.

row_log_free
Free temporary buffers crypt_head and crypt_tail if they
exist.

row_merge_encrypt_buf, row_merge_decrypt_buf
Removed.

row_merge_buf_create, row_merge_buf_write
Remove ROW_MERGE_RESERVE_SIZE

row_merge_build_indexes
Allocate temporary buffer used in decryption and encryption
if needed.

log_tmp_blocks_crypt, log_tmp_block_encrypt, log_temp_block_decrypt
New functions used in block encryption and decryption

log_tmp_is_encrypted
New function to check is encryption enabled.

Added test case innodb-rowlog to force creating a row log and
verify that operations are done using introduced status
variables.

Comment by Marko Mäkelä [ 2017-09-15 ]

Please push a merge of the 10.1 commit and 10.2 to a staging branch, for review. There are lots of conflicts.

Comment by Marko Mäkelä [ 2017-09-15 ]

I would revert this instrumentation from 10.1 and instead, introduce an innodb_encrypt_log.combinations file and use it in the tests innodb.innodb-table-online and innodb.innodb-index-online.

	DBUG_EXECUTE_IF(
		"ib_merge_wait_after_read",
		os_thread_sleep(20000000););  /* 20 sec */

Those two tests use proper DEBUG_SYNC synchronization and do not introduce such unreasonable (and inherently nondeterministic) delays.
This is now building on bb-10.1-marko.

Comment by Marko Mäkelä [ 2017-09-17 ]

I pushed the merge to 10.2 and an adjustment to innodb-table-online that makes it use the merge sort files.

Comment by Jan Lindström (Inactive) [ 2017-09-18 ]

greenman Can you update the documentation to mention that in 10.1.27, 10.2.9,10.3.2 temporary files created by merge sort and row log are encrypted if innodb-encrypt-log=TRUE regardless is table encrypted or not.

Comment by Ian Gilfillan [ 2017-09-18 ]

jplindst so this is regardless of the setting of encrypt_tmp_files, correct?

Comment by Jan Lindström (Inactive) [ 2017-09-18 ]

Correct, this effects only temporary files created and used by InnoDB internally.

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