[MDEV-12114] install_db shows corruption for rest encryption and innodb_checksum_algorithm=strict_none Created: 2017-02-23  Updated: 2020-01-08  Resolved: 2017-06-02

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1.22
Fix Version/s: 10.1.25

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

Attachments: File error.log     HTML File out    
Issue Links:
Problem/Incident
is caused by MDEV-12113 install_db shows corruption for rest ... Closed
Relates
relates to MDEV-21441 Assertion: index->id == btr_page_get_... Closed
Sprint: 10.1.24

 Description   

When trying to install database with rest encryption and innodb_checksum_algorithm=strict_none following errors are shown:

2017-02-23 12:16:40 139675033013184 [Warning] InnoDB: New log files created, LSN=45883
2017-02-23 12:16:40 139675033013184 [Note] InnoDB: Doublewrite buffer not found: creating new
2017-02-23 12:16:40 139675033013184 [Note] InnoDB: Doublewrite buffer created
2017-02-23 12:16:40 139675033013184 [ERROR] InnoDB:  Page 2 in space N/A (0) maybe corrupted. Post encryption checksum 3735928559 stored [3735928559:3735928559] key_version 1
2017-02-23 12:16:40 139675033013184 [ERROR] InnoDB:  Page 2 in space ./ibdata1 (0) maybe corrupted. Post encryption checksum 3735928559 stored [3735928559:3735928559] key_version 1
2017-02-23 12:16:40 7f08a0ba0bc0  InnoDB: Assertion failure in thread 139675033013184 in file fsp0fsp.cc line 1765
InnoDB: Failing assertion: n != ULINT_UNDEFINED
...
mysys/stacktrace.c:268(my_print_stacktrace)[0x5629310fdf86]
sql/signal_handler.cc:168(handle_fatal_signal)[0x5629311003d4]
srv/srv0start.cc:2837(innobase_start_or_create_for_mysql())[0x5629310e810a]
handler/ha_innodb.cc:4439(innobase_init(void*))[0x56293102633d]
sql/handler.cc:513(ha_initialize_handlerton(st_plugin_int*))[0x562930defc75]
sql/sql_plugin.cc:1408(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x562930c943ab]
sql/sql_plugin.cc:1678(plugin_init(int*, char**, int))[0x562930c952c2]
sql/mysqld.cc:5148(init_server_components())[0x562930bffbad]
sql/mysqld.cc:5739(mysqld_main(int, char**))[0x562930c04aa2]

Other values for innodb_checksum_algorithm are handled properly. As well no problem happens for strict_none without rest encryption.



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

Command line to repeat:

/usr/local/mysql/scripts/mysql_install_db --no-defaults --innodb-data-file-path="ibdata1:3M;ibdata2:10M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --innodb-file-per-table=0 --innodb-checksum-algorithm=strict_none

Full output :

jan@jan-laptop-asus:~/jpl$ /usr/local/mysql/scripts/mysql_install_db --no-defaults --innodb-data-file-path="ibdata1:3M;ibdata2:10M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --innodb-file-per-table=0 --innodb-checksum-algorithm=strict_none 
Installing MariaDB/MySQL system tables in './data' ...
2017-05-18 11:50:15 139750420227584 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 3358 ...
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 11:50:15 139750420227584 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 11:50:15 139750420227584 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Using Linux native AIO
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Setting file ./ibdata1 size to 3 MB
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Data file ./ibdata2 did not exist: new to be created
2017-05-18 11:50:15 139750420227584 [Note] InnoDB: Setting file ./ibdata2 size to 10 MB
2017-05-18 11:50:16 139750420227584 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
2017-05-18 11:50:16 139750420227584 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
2017-05-18 11:50:16 139750420227584 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile101 key_id 0 encryption 0.
2017-05-18 11:50:16 139750420227584 [Note] InnoDB: Created tablespace for space 4294967281 name arch_log_space key_id 0 encryption 0.
2017-05-18 11:50:16 139750420227584 [ERROR] InnoDB:  Page 1 in space N/A (0) maybe corrupted. Post encryption checksum 3735928559 stored [3735928559:3735928559] key_version 1
2017-05-18 11:50:16 7f1a2e27a600  InnoDB: Assertion failure in thread 139750420227584 in file fil0crypt.cc line 647
InnoDB: Failing assertion: fil_space_verify_crypt_checksum(dst_frame, zip_size, __null, offset)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
170518 11:50:16 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.1.24-MariaDB-debug
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467207 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x48400
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x38)[0x55850331b158]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x394)[0x558502cba007]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x110c0)[0x7f1a2df0b0c0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcf)[0x7f1a2b4a7fcf]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f1a2b4a93fa]
/usr/local/mysql/bin/mysqld(+0xccc2f7)[0x55850327c2f7]
mysys/stacktrace.c:267(my_print_stacktrace)[0x55850327c421]
sql/signal_handler.cc:168(handle_fatal_signal)[0x5585031fe6f0]
buf/buf0flu.cc:951(buf_flush_write_block_low(buf_page_t*, buf_flush_t, bool))[0x55850320a12c]
buf/buf0flu.cc:1129(buf_flush_page(buf_pool_t*, buf_page_t*, buf_flush_t, bool))[0x55850320a70f]
buf/buf0flu.cc:1340(buf_flush_try_neighbors(unsigned long, unsigned long, buf_flush_t, unsigned long, unsigned long))[0x55850320aceb]
buf/buf0flu.cc:1428(buf_flush_page_and_try_neighbors(buf_page_t*, buf_flush_t, unsigned long, unsigned long*))[0x55850320afeb]
buf/buf0flu.cc:1758(buf_do_flush_list_batch(buf_pool_t*, unsigned long, unsigned long))[0x55850320baf6]
buf/buf0flu.cc:1833(buf_flush_batch(buf_pool_t*, buf_flush_t, unsigned long, unsigned long, bool, flush_counters_t*))[0x55850320be55]
buf/buf0flu.cc:2116(buf_flush_list(unsigned long, unsigned long, unsigned long*))[0x55850320c5b1]
srv/srv0start.cc:2465(innobase_start_or_create_for_mysql())[0x5585031661c1]
handler/ha_innodb.cc:4454(innobase_init(void*))[0x558502ff53b3]
sql/handler.cc:513(ha_initialize_handlerton(st_plugin_int*))[0x558502cbc049]
sql/sql_plugin.cc:1400(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x558502a99803]
sql/sql_plugin.cc:1677(plugin_init(int*, char**, int))[0x558502a9a400]
sql/mysqld.cc:5143(init_server_components())[0x5585029b931b]
sql/mysqld.cc:5732(mysqld_main(int, char**))[0x5585029ba39b]
sql/main.cc:26(main)[0x5585029afa60]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7f1a2b4952b1]
/usr/local/mysql/bin/mysqld(_start+0x2a)[0x5585029af93a]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Aborted

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

https://github.com/MariaDB/server/commit/f98333eda2a95d96eec2b31dc6a7575d6a13c7af

Manual testing:

jan@jan-laptop-asus:~/jpl$ /usr/local/mysql/scripts/mysql_install_db --no-defaults --innodb-data-file-path="ibdata1:3M;ibdata2:10M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --innodb-file-per-table=0 --innodb-checksum-algorithm=strict_none
Installing MariaDB/MySQL system tables in './data' ...
2017-05-18 14:28:36 139979512808960 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18558 ...
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:28:37 139979512808960 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:37 139979512808960 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Setting file ./ibdata1 size to 3 MB
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Data file ./ibdata2 did not exist: new to be created
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Setting file ./ibdata2 size to 10 MB
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile101 key_id 0 encryption 0.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Created tablespace for space 4294967281 name arch_log_space key_id 0 encryption 0.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-05-18 14:28:37 139979512808960 [Warning] InnoDB: New log files created, LSN=45883
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Doublewrite buffer not found: creating new
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Doublewrite buffer created
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:28:37 139979512808960 [Warning] InnoDB: Creating foreign key constraint system tables.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Foreign key constraint system tables created
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Creating tablespace and datafile system tables.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB: Tablespace and datafile system tables created.
2017-05-18 14:28:37 139979512808960 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 0
2017-05-18 14:28:37 139978768119552 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK
Filling help tables...
2017-05-18 14:28:40 139702222960128 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18622 ...
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:28:40 139702222960128 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:40 139702222960128 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile0 key_id 0 encryption 0.
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Created tablespace for space 4294967281 name arch_log_space key_id 0 encryption 0.
2017-05-18 14:28:40 139702222960128 [Note] InnoDB: Highest supported file format is Barracuda.
2017-05-18 14:28:41 139702222960128 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:28:41 139702222960128 [Note] InnoDB: Waiting for purge to start
2017-05-18 14:28:41 139702222960128 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 1612482
2017-05-18 14:28:41 139701465904896 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK
Creating OpenGIS required SP-s...
2017-05-18 14:28:44 139719321855488 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18678 ...
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:28:44 139719321855488 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:44 139719321855488 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile0 key_id 0 encryption 0.
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Created tablespace for space 4294967281 name arch_log_space key_id 0 encryption 0.
2017-05-18 14:28:44 139719321855488 [Note] InnoDB: Highest supported file format is Barracuda.
2017-05-18 14:28:46 139719321855488 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:28:46 139719321855488 [Note] InnoDB: Waiting for purge to start
2017-05-18 14:28:46 139719321855488 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 1612492
2017-05-18 14:28:46 139718566082304 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK
 
To start mysqld at boot time you have to copy
support-files/mysql.server to the right place for your system
 
PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB root USER !
To do so, start the server, then issue the following commands:
 
'/usr/local/mysql/bin/mysqladmin' -u root password 'new-password'
'/usr/local/mysql/bin/mysqladmin' -u root -h jan-laptop-asus password 'new-password'
 
Alternatively you can run:
'/usr/local/mysql/bin/mysql_secure_installation'
 
which will also give you the option of removing the test
databases and anonymous user created by default.  This is
strongly recommended for production servers.
 
See the MariaDB Knowledgebase at http://mariadb.com/kb or the
MySQL manual for more instructions.
 
You can start the MariaDB daemon with:
cd '/usr/local/mysql' ; /usr/local/mysql/bin/mysqld_safe --datadir='./data'
 
You can test the MariaDB daemon with mysql-test-run.pl
cd '/usr/local/mysql/mysql-test' ; perl mysql-test-run.pl
 
Please report any problems at http://mariadb.org/jira
 
The latest information about MariaDB is available at http://mariadb.org/.
You can find additional information about the MySQL part at:
http://dev.mysql.com
Consider joining MariaDB's strong and vibrant community:
https://mariadb.org/get-involved/
 
jan@jan-laptop-asus:~/jpl$ rm -rf data
jan@jan-laptop-asus:~/jpl$ /usr/local/mysql/scripts/mysql_install_db --no-defaults --innodb-data-file-path="ibdata1:3M;ibdata2:10M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --innodb-file-per-table=0 --innodb-checksum-algorithm=strict_none --ignore-builtin-innodb --plugin-load-add=ha_innodb
Installing MariaDB/MySQL system tables in './data' ...
2017-05-18 14:28:59 140041713952256 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18866 ...
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:28:59 140041713952256 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:59 140041713952256 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Setting file ./ibdata1 size to 3 MB
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Data file ./ibdata2 did not exist: new to be created
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Setting file ./ibdata2 size to 10 MB
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile101 key_id 0 encryption 0.
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-05-18 14:28:59 140041713952256 [Warning] InnoDB: New log files created, LSN=45883
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Doublewrite buffer not found: creating new
2017-05-18 14:28:59 140041713952256 [Note] InnoDB: Doublewrite buffer created
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:29:00 140041713952256 [Warning] InnoDB: Creating foreign key constraint system tables.
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: Foreign key constraint system tables created
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: Creating tablespace and datafile system tables.
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: Tablespace and datafile system tables created.
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: Waiting for purge to start
2017-05-18 14:29:00 140041713952256 [Note] InnoDB: 5.6.35 started; log sequence number 0
2017-05-18 14:29:00 140040982230784 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK
Filling help tables...
2017-05-18 14:29:02 140323780761088 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18920 ...
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:29:02 140323780761088 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:29:02 140323780761088 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile0 key_id 0 encryption 0.
2017-05-18 14:29:02 140323780761088 [Note] InnoDB: Highest supported file format is Barracuda.
2017-05-18 14:29:03 140323780761088 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:29:03 140323780761088 [Note] InnoDB: Waiting for purge to start
2017-05-18 14:29:03 140323780761088 [Note] InnoDB: 5.6.35 started; log sequence number 1612482
2017-05-18 14:29:03 140323040786176 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK
Creating OpenGIS required SP-s...
2017-05-18 14:29:05 140488685151744 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 18975 ...
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-05-18 14:29:05 140488685151744 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-18 14:29:05 140488685151744 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: The InnoDB memory heap is disabled
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Using Linux native AIO
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Using SSE crc32 instructions
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Completed initialization of buffer pool
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile0 key_id 0 encryption 0.
2017-05-18 14:29:05 140488685151744 [Note] InnoDB: Highest supported file format is Barracuda.
2017-05-18 14:29:06 140488685151744 [Note] InnoDB: 128 rollback segment(s) are active.
2017-05-18 14:29:06 140488685151744 [Note] InnoDB: Waiting for purge to start
2017-05-18 14:29:06 140488685151744 [Note] InnoDB: 5.6.35 started; log sequence number 1612492
2017-05-18 14:29:06 140487944042240 [Note] InnoDB: Dumping buffer pool(s) not yet started
OK

Comment by Marko Mäkelä [ 2017-05-23 ]

The patch looks OK, provided that you add regression tests that exercise encryption with all innodb_checksum_algorithm variants, including none and strict_none.
Meaningful implementation of this on buildbot may depend on MDEV-12042.
Because of that, I am OK with manual testing, something like this:

for i in innodb crc32 none strict_innodb strict_crc32 strict_none
do
    ./mtr --mem --parallel=auto --mysqld=--innodb-checksum-algorithm=$i --suite=encryption
done

Comment by Jan Lindström (Inactive) [ 2017-05-30 ]

At least following will fail with none|strict_none:

  • encryption.innochecksum MDEV-11939
  • encryption.innodb-bad-key-change (can't detect corruption after decryption with wrong keys)
  • encryption.innodb-force-corrupt (forced corruption not detected after decryption)
  • encryption.innodb-bad-key-change4 (can't detect corruption after decryption with wrong keys)
Comment by Jan Lindström (Inactive) [ 2017-05-30 ]

innodb-compressed-blob test will be run with crc32 and none combinations.

Comment by Jan Lindström (Inactive) [ 2017-05-30 ]

Made additional changes that require review in:

https://github.com/MariaDB/server/commit/d4c8a8b420688b3f63944a2132a6965bb0b79d46

Comment by Jan Lindström (Inactive) [ 2017-05-30 ]

jan@jan-laptop-asus:~/mysql/10.1/mysql-test$ ./mtr --vardir=/dev/shm innodb-compressed-blob --valgrind
Logging: ./mtr  --vardir=/dev/shm innodb-compressed-blob --valgrind
Turning on valgrind for all executables
Running valgrind with options " --tool=memcheck --show-reachable=yes --leak-check=yes --num-callers=16 --quiet --suppressions=/home/jan/mysql/10.1/mysql-test/valgrind.supp "
vardir: /dev/shm
Checking leftover processes...
Removing old var directory...
couldn't chmod(0777, /dev/shm): Operation not permitted at /usr/share/perl/5.24/File/Find.pm line 511.
Couldn't remove directory '/dev/shm': Permission denied at /usr/share/perl/5.24/File/Find.pm line 511.
Creating var directory '/dev/shm'...
Checking supported features...
MariaDB Version 10.1.24-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
Sphinx 'indexer' binary not found, sphinx suite will be skipped
Collecting tests...
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
encryption.innodb-compressed-blob 'cbc,crc32,innodb_plugin' [ pass ]  75139
encryption.innodb-compressed-blob 'cbc,innodb_plugin,none' [ pass ]  77155
encryption.innodb-compressed-blob 'cbc,crc32,xtradb' [ pass ]  99573
encryption.innodb-compressed-blob 'cbc,none,xtradb' [ pass ]  108279
encryption.innodb-compressed-blob 'crc32,ctr,innodb_plugin' [ pass ]  102948
encryption.innodb-compressed-blob 'ctr,innodb_plugin,none' [ pass ]  102571
encryption.innodb-compressed-blob 'crc32,ctr,xtradb' [ pass ]  90882
encryption.innodb-compressed-blob 'ctr,none,xtradb' [ pass ]  88621
valgrind_report                          [ pass ]       
--------------------------------------------------------------------------
The servers were restarted 7 times
Spent 745.168 of 1024 seconds executing testcases
 
Completed: All 9 tests were successful.

Comment by Marko Mäkelä [ 2017-05-30 ]

Please address my additional review comments and also manually test an upgrade from innodb_checksum_algorithm=none: encrypted tables should be unreadable (invalid checksum)

Add mysql-test for the following:

  • restart after changing the setting innodb_checksum_algorithm=innodb to innodb_checksum_algorithm=strict_crc32: must get reports of checksum mismatch, for both encrypted and unencrypted tables, also for ROW_FORMAT=COMPRESSED
  • restart after changing the setting innodb_checksum_algorithm=crc32 to strict_innodb: No warnings for encrypted tables, also not for ROW_FORMAT=COMPRESSED (because encrypted tables will always use crc32)
Comment by Jan Lindström (Inactive) [ 2017-06-01 ]

As fil_crypt_verify_crypt_checksum still supports stored none checksum to allow upgrade from earlier versions it will not report any invalid checksum:

jan@jan-laptop-asus:~/mysql/10.1-bugs/scripts/mysql_install_db --no-defaults --innodb-data-file-path="ibdata1:3M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --innodb-checksum-algorithm=none
 
jan@jan-laptop-asus:~/mysql/10.1$ sql/mysqld --innodb-data-file-path="ibdata1:3M:autoextend" --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=/home/jan/mysql/10.1//mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --datadir=/home/jan/jpl/data
 
2017-06-01 13:23:27 140387115673088 [Note] sql/mysqld (mysqld 10.1.24-MariaDB-debug) starting as process 26428 ...
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.
 
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-01 13:23:27 140387115673088 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-06-01 13:23:27 140387115673088 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Using Linux native AIO
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Using SSE crc32 instructions
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Completed initialization of buffer pool
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 0 name ./ibdata1 key_id 1 encryption 0.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 4294967280 name ./ib_logfile0 key_id 0 encryption 0.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 4294967281 name arch_log_space key_id 0 encryption 0.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 3 name mysql/gtid_slave_pos key_id 0 encryption 0.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 2 name mysql/innodb_index_stats key_id 0 encryption 0.
2017-06-01 13:23:27 140387115673088 [Note] InnoDB: Created tablespace for space 1 name mysql/innodb_table_stats key_id 0 encryption 0.
2017-06-01 13:23:29 140387115673088 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-01 13:23:29 140387115673088 [Note] InnoDB: Waiting for purge to start
2017-06-01 13:23:29 140387115673088 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 1617148
2017-06-01 13:23:29 140386362193664 [Note] InnoDB: Dumping buffer pool(s) not yet started
2017-06-01 13:23:29 140387115673088 [Note] Plugin 'FEEDBACK' is disabled.
2017-06-01 13:23:29 140387115673088 [Note] Server socket created on IP: '::'.
2017-06-01 13:23:29 140387115673088 [Note] sql/mysqld: ready for connections.
Version: '10.1.24-MariaDB-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
2017-06-01 13:25:04 140387114973952 [Note] sql/mysqld: Normal shutdown
 
2017-06-01 13:25:04 140387114973952 [Note] Event Scheduler: Purging the queue. 0 events
2017-06-01 13:25:04 140386341213952 [Note] InnoDB: FTS optimize thread exiting.
2017-06-01 13:25:04 140387114973952 [Note] InnoDB: Starting shutdown...
2017-06-01 13:25:05 140387114973952 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-06-01 13:25:06 140387114973952 [Note] InnoDB: Shutdown completed; log sequence number 1617158
2017-06-01 13:25:06 140387114973952 [Note] sql/mysqld: Shutdown complete

Comment by Jan Lindström (Inactive) [ 2017-06-02 ]

MDEV-12114: install_db shows corruption for rest encryption and innodb_checksum_algorithm=strict_none

Problem was that checksum check resulted false positives that page is
both not encrypted and encryted when checksum_algorithm was
strict_none.

Encrypton checksum will use only crc32 regardless of setting.

buf_zip_decompress: If compression fails report a error message
containing the space name if available (not available during import).
And note if space could be encrypted.

buf_page_get_gen: Do not assert if decompression fails,
instead unfix the page and return NULL to upper layer.

fil_crypt_calculate_checksum: Use only crc32 method.

fil_space_verify_crypt_checksum: Here we need to check
crc32, innodb and none method for old datafiles.

fil_space_release_for_io: Allow null space.

encryption.innodb-compressed-blob is now run with crc32 and none
combinations.

Note that with none and strict_none method there is not really
a way to detect page corruptions and page corruptions after
decrypting the page with incorrect key.

New test innodb-checksum-algorithm to test different checksum
algorithms with encrypted, row compressed and page compressed
tables.

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