[MDEV-12606] Crash when enabling encryption on Slave Created: 2017-04-27  Updated: 2017-05-03  Resolved: 2017-05-03

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.5
Fix Version/s: 10.2.6

Type: Bug Priority: Major
Reporter: Andrii Nikitin (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Cannot Reproduce Votes: 0
Labels: 10.2-ga, crash, encryption


 Description   

I've got this crash, working on reproduction steps

2017-04-27 17:11:35 140015867094784 [Note] /home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld: Shutdown complete
 
 
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Uses event mutexes
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Using Linux native AIO
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Number of pools: 1
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Using SSE2 crc32 instructions
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Initializing buffer pool, total size = 4G, instances = 8, chunk size = 128M
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Completed initialization of buffer pool
 
2017-04-27 17:11:53 139996821378816 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: Highest supported file format is Barracuda.
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: S: (0x0B0F05010D06080B01070A060003030A0E050B02050C07050C09090D0F0F060B02080201050607070506080704010E07000F0B0B0D0B05000D000200060801070B03050D0E0C0D0D010102020B09060C050B090205080C0D0707070D060B0E0900020D00040C0D0F0D090706020B0B0C0805080F0D0B060D02040F020A050600070B090A0F0E050002050D050E0107000D000605040E01010302080A040E0B040F030E0C0D03090B080C090F00070F0B020803010C0B0C06050903050D050B000C0B0F0E060B09060E0B0B0D0F0A060A0B090C00070A0B08090809050F0F0E020B080200040E010A090B0E0E030B0E09030A050102090C03030102000800000A030D08020D090F000A030A0B0C0A0605010F000707080406070504090E010C010B0F0A00040301020B050B0500060904000409060C0E08030A0E08080301020707090206050C08090B09060F07080A000D09010E010F0F04070A0107030706070809080C090D00070E0F09000B08040609060D0403090B0F0E070A030C080700030A030D0C02030E0202020F01060A06080A090304000B0805060E0B090F060B0D0304060B0B0A0E0305010C0B0C02010F010E04070E02050B0B0207050A01010B0B0809050B03070F05010E0C060C09020B030102090F0804070C060A0D030C080B040603000508080507010D0C0107010F010B040406070
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: c: (0x010F000A0000000000020E000C000400020E000E000F0400020F0002000F0F0F0F0200020F0006000400020F0008000F0F0F0F0200020F000C000400020F000E000F040002000002000F0F0F0F02000200000600040002000008000F0F0F0F02000200000C0004000200000E000F0200010A0E0A00040002030002000F0F0F0F02000203000600040002030008000F0F0F0F02000203000C0004000203000E000400020C0002000F0F0F0F0100000104000A0100000104000A040000000A01090800020C000200000000000400020C000E000A050C0304000203000A000F0200020D0000000400010B0C0E000F0F0F0F010000020E000A010000020E000A040000000A01080F0400010B0C0A000F0F0F0F010000020E000E010000020E000E040000000A01070F0400010B0C06000F0F0F0F010000020D000B010000020D000B040000000A01060F04000D0002000F0F0F0F02000D00060004000D0008000F0F0F0F02000D000C0004000D000E000400010B0C02000F0F0F0F010000020D000F010000020D000F040000000A01050800010B0C0200000000000400010B0C0E000A050C0304000D000A000F000303020C0D0D0501050107090503070D090402010F0C080202010004000200020900040F04080B06050A0B060409080803050F020D02020D030D0A0C09080F0500020A080706000B04040E040
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: S: (0x0B0F05010D06080B01070A060003030A0E050B02050C07050C09090D0F0F060B02080201050607070506080704010E07000F0B0B0D0B05000D000200060801070B03050D0E0C0D0D010102020B09060C050B090205080C0D0707070D060B0E0900020D00040C0D0F0D090706020B0B0C0805080F0D0B060D02040F020A050600070B090A0F0E050002050D050E0107000D000605040E01010302080A040E0B040F030E0C0D03090B080C090F00070F0B020803010C0B0C06050903050D050B000C0B0F0E060B09060E0B0B0D0F0A060A0B090C00070A0B08090809050F0F0E020B080200040E010A090B0E0E030B0E09030A050102090C03030102000800000A030D08020D090F000A030A0B0C0A0605010F000707080406070504090E010C010B0F0A00040301020B050B0500060904000409060C0E08030A0E08080301020707090206050C08090B09060F07080A000D09010E010F0F04070A0107030706070809080C090D00070E0F09000B08040609060D0403090B0F0E070A030C080700030A030D0C02030E0202020F01060A06080A090304000B0805060E0B090F060B0D0304060B0B0A0E0305010C0B0C02010F010E04070E02050B0B0207050A01010B0B0809050B03070F05010E0C060C09020B030102090F0804070C060A0D030C080B040603000508080507010D0C0107010F010B040406070
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: c: (0x010F000A0000000000020E000C000400020E000E000F0400020F0002000F0F0F0F0200020F0006000400020F0008000F0F0F0F0200020F000C000400020F000E000F040002000002000F0F0F0F02000200000600040002000008000F0F0F0F02000200000C0004000200000E000F0200010A0E0A00040002030002000F0F0F0F02000203000600040002030008000F0F0F0F02000203000C0004000203000E000400020C0002000F0F0F0F0100000104000A0100000104000A040000000A01090800020C000200000000000400020C000E000A050C0304000203000A000F0200020D0000000400010B0C0E000F0F0F0F010000020E000A010000020E000A040000000A01080F0400010B0C0A000F0F0F0F010000020E000E010000020E000E040000000A01070F0400010B0C06000F0F0F0F010000020D000B010000020D000B040000000A01060F04000D0002000F0F0F0F02000D00060004000D0008000F0F0F0F02000D000C0004000D000E000400010B0C02000F0F0F0F010000020D000F010000020D000F040000000A01050800010B0C0200000000000400010B0C0E000A050C0304000D000A000F000303020C0D0D0501050107090503070D090402010F0C080202010004000200020900040F04080B06050A0B060409080803050F020D02020D030D0A0C09080F0500020A080706000B04040E040
 
2017-04-27 17:11:53 140001983624704 [ERROR] InnoDB: The page [page id: space=0, page number=6] in file innodb_system cannot be decrypted.
 
2017-04-27 17:11:53 140001983624704 [Note] InnoDB: However key management plugin or used key_version 1 is not found or used encryption algorithm or method does not match.
 
2017-04-27 17:11:53 0x7f54c0807600  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/storage/innobase/buf/buf0buf.cc line 6088
 
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.7/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
170427 17:11:53 [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.2.5-MariaDB
 
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 = 467200 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 0x49000
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(my_print_stacktrace+0x2e)[0xdd68de]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(handle_fatal_signal+0x444)[0x7d2454]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11630)[0x7f54c03f8630]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x9f)[0x7f54bf17e7ef]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f54bf1803ea]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb626d3]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xbb2578]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xbd5c02]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xbd6fa9]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xbb6c59]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb44276]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb44be9]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb55d52]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb4a77b]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0xb196b8]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0x9dbce6]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x5e)[0x7d7bfe]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0x5fb46a]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(_Z11plugin_initPiPPci+0xbc0)[0x5fddc0]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld[0x549fcd]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(_Z11mysqld_mainiPPc+0xa08)[0x54b358]
 
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7f54bf1693f1]
 
/home/a/mariadb-environs/m1-10.2.5/../_depot/m-tar/10.2.5/bin/mysqld(__gxx_personality_v0+0x3d1)[0x5406d9]
 
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.



 Comments   
Comment by Andrii Nikitin (Inactive) [ 2017-04-27 ]

I recreated slave and was able to enable encryption when replication was down. Then reset slave again and got identical crash while starting Server with encryption enabled (when Slave was starting as well):

2017-04-27 18:15:18 140621122352640 [Note] InnoDB: S: (0x09090B020604040701080D0002010F0E09010E0F0606070707020D0C010A0D0A01070702030403060703030201040D0C03070902030E060001030C0B060D0E0D0409040E0A0C0401050E0E070A070D0803080C07010D0C0C03070E00070C0C0B0004000008030D070D0E010A0B01010C0703040701020702070E0F0000060E02090C040B05050D040C0208010806010000080D0C050E02090E090704000104080B0408090B0D0B07060C0801040A05010C020C0E0508090C0F0E07090C0A07080C0A030B080007030806000204030C070B090E050D010F0D00040E010E0E030E00050207040A020702020D040E04060F090E020400040A090E050F08060C0C0B0A0F020C0F0E040000010601030F0207090C070E0C060904000B0B0B06020406010905030F040401000803010C0E090D03020F0A09040B06010A0D07040C0D060A0200030403090502070E08050B02080F070901050203000C08000303030F080A010E0A010B080E06010E0B04000C0002080B0101040905030101050809090B0E000A0E0B0B00000E0E09050B01000D0A0F070E0D060E000E01090D0C0A050E0304090E02070B060D080C070F0C0A060907020708050E0B0E080B0D0505080404030A080904070904000D0F0D05090C02090E000A020E0905090E010A0009060002060E0402080F0609000A020805010505020B020B0B040
 
2017-04-27 18:15:18 140621122352640 [Note] InnoDB: c: (0x0000000000000001090E06050E040F02090F050E0609020F0E0D050E040E090204000F08000000000C0B0D07020504030907070103000F0C03030C0200030A0C000A0E070E05010007000B040C060B020A0E0B0C04060708000101070301030D070807040C020A0C0F0E01090C0C090001040C02080C0D0C0303060509020808030E0A0C0507050303070C0101050F0209080D0B080D090A08070403000304060A0F05010B0C0F01050F090B000C030603020E060609090105090C05040C040C0B06050B0D070A0C0F050500080404020802020704080D0A0C0C010B05050B020F010F0507030404080A03050F0A030206060C03000D020203000A0B0E080C0D000B0B090E080E08000A09010B04060C070B0B0907000E000E08060F000F00000E01070C0F070B010C09000807030105050409060B050F000D0901090C010E08090901090B070F020C050C0E0C0B08060402090C0004030F040C0F0508040C0A060B020F000F0D0B0E06040A08060A01020400010A0D0107090F0E0A04040E0B04090006020104050603080D0D08070D030C080C030A02090A0A0D00060807020A09050A0D030A00000D0D0A07090A0B0E08090D08040C030B0A060506030B0F06090D0C01040D0B000F06090E06040D0C0408030B000D05090C0B0B08000802050E030A0F090C0A0F0307070B070A0A04040D08070B070E0
 
2017-04-27 18:15:18 140621122352640 [Note] InnoDB: S: (0x09090B020604040701080D0002010F0E09010E0F0606070707020D0C010A0D0A01070702030403060703030201040D0C03070902030E060001030C0B060D0E0D0409040E0A0C0401050E0E070A070D0803080C07010D0C0C03070E00070C0C0B0004000008030D070D0E010A0B01010C0703040701020702070E0F0000060E02090C040B05050D040C0208010806010000080D0C050E02090E090704000104080B0408090B0D0B07060C0801040A05010C020C0E0508090C0F0E07090C0A07080C0A030B080007030806000204030C070B090E050D010F0D00040E010E0E030E00050207040A020702020D040E04060F090E020400040A090E050F08060C0C0B0A0F020C0F0E040000010601030F0207090C070E0C060904000B0B0B06020406010905030F040401000803010C0E090D03020F0A09040B06010A0D07040C0D060A0200030403090502070E08050B02080F070901050203000C08000303030F080A010E0A010B080E06010E0B04000C0002080B0101040905030101050809090B0E000A0E0B0B00000E0E09050B01000D0A0F070E0D060E000E01090D0C0A050E0304090E02070B060D080C070F0C0A060907020708050E0B0E080B0D0505080404030A080904070904000D0F0D05090C02090E000A020E0905090E010A0009060002060E0402080F0609000A020805010505020B020B0B040
 
2017-04-27 18:15:18 140621122352640 [Note] InnoDB: c: (0x0000000000000001090E06050E040F02090F050E0609020F0E0D050E040E090204000F08000000000C0B0D07020504030907070103000F0C03030C0200030A0C000A0E070E05010007000B040C060B020A0E0B0C04060708000101070301030D070807040C020A0C0F0E01090C0C090001040C02080C0D0C0303060509020808030E0A0C0507050303070C0101050F0209080D0B080D090A08070403000304060A0F05010B0C0F01050F090B000C030603020E060609090105090C05040C040C0B06050B0D070A0C0F050500080404020802020704080D0A0C0C010B05050B020F010F0507030404080A03050F0A030206060C03000D020203000A0B0E080C0D000B0B090E080E08000A09010B04060C070B0B0907000E000E08060F000F00000E01070C0F070B010C09000807030105050409060B050F000D0901090C010E08090901090B070F020C050C0E0C0B08060402090C0004030F040C0F0508040C0A060B020F000F0D0B0E06040A08060A01020400010A0D0107090F0E0A04040E0B04090006020104050603080D0D08070D030C080C030A02090A0A0D00060807020A09050A0D030A00000D0D0A07090A0B0E08090D08040C030B0A060506030B0F06090D0C01040D0B000F06090E06040D0C0408030B000D05090C0B0B08000802050E030A0F090C0A0F0307070B070A0A04040D08070B070E0
 
2017-04-27 18:15:18 140621122352640 [ERROR] InnoDB: The page [page id: space=0, page number=3] in file innodb_system cannot be decrypted.

Comment by Andrii Nikitin (Inactive) [ 2017-04-28 ]

While I am trying to repeat this case - I can reliably bring down whole machine with steps below in 10.2.5, 10.2.4 and 10.2 branch :

cp suite/encryption/t/innodb_encryption.opt suite/encryption/t/innodb_encryption_load.opt
 
 
 
echo '--exec $MYSQL < /home/a/sakila-schema.sql' > suite/encryption/t/innodb_encryption_load.test 
echo '--exec $MYSQL < /home/a/sakila-data.sql' >> suite/encryption/t/innodb_encryption_load.test 
 
 
./mysql-test-run.pl innodb_encryption_load --mysqld=--plugin-load-add=file_key_management.so --mysqld=--innodb --mysqld=--file-key-management-filename=$(pwd)/var/std_data/keys.txt

Let's assume this problem has the same cause as original problem in replication.
The same test doesn't give any problems in 10.1.22 as well as in current 10.1 branch

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

Can't repeat the last instructions. I think you have bootstrapped your database using innodb-encrypt-tables=ON and some key file and then started your slave with different key file.

Comment by Elena Stepanova [ 2017-05-02 ]

The last case is unrelated to slave and encryption, it's a FK/locking issue. I've created a separate bug report MDEV-12669 with a simple test case.
In scope of MDEV-12606 I suggest to focus on the initial problem.

Comment by Andrii Nikitin (Inactive) [ 2017-05-03 ]

Cannot reproduce in current 10.2 tree, closing for now

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