[MDEV-8591] Database page corruption on disk or a failed space, Assertion failure in file buf0buf.cc line 2856 on querying a table using wrong default encryption key Created: 2015-08-09  Updated: 2015-09-10  Resolved: 2015-09-07

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

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

Issue Links:
Duplicate
is duplicated by MDEV-8588 Assertion failure in file ha_innodb.c... Closed
Relates

 Description   
  • start server with valid key file and default encryption key id 1;
  • create a table, insert some data;
  • restart server with a different key file (different value for encryption key 1);
  • read the table
    =>

InnoDB: Database page corruption on disk or a failed
InnoDB: space 4 file test/t1 read of page 3.
InnoDB: You may have to recover from a backup.
2015-08-09 19:56:14 7efe086b8700 InnoDB: Page dump in ascii and hex (16384 bytes):
...
InnoDB: End of page dump
2015-08-09 19:56:17 7efe086b8700 InnoDB: uncompressed page, stored checksum in field1 2405105318, calculated checksums for field1: crc32 4172384744, innodb 2132655181, none 3735928559,
 stored checksum in field2 3749994095, calculated checksums for field2: crc32 4172384744, innodb 3749994095, none 3735928559, page LSN 0 1633250, low 4 bytes of LSN at page end 1633250, page number (if stored to page already) 3, space id (if created with >= MySQL-4.1.1 and stored already) 4
InnoDB: page type 1170145280 meaning PAGE TYPE CORRUPTED
InnoDB: Page may be an index page where index id is 4322600208618841523
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 3.
InnoDB: You may have to recover from a backup.
InnoDB: It is also possible that your operating
InnoDB: system has corrupted its own file cache
InnoDB: and rebooting your computer removes the
InnoDB: error.
InnoDB: If the corrupt page is an index page
InnoDB: you can also try to fix the corruption
InnoDB: by dumping, dropping, and reimporting
InnoDB: the corrupt table. You can use CHECK
InnoDB: TABLE to scan your table for corruption.
InnoDB: See also http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
InnoDB: Error: Unable to read tablespace 4 page no 3 into the buffer pool after 100 attempts
InnoDB: The most probable cause of this error may be that the table has been corrupted.
InnoDB: You can try to fix this problem by using innodb_force_recovery.
InnoDB: Please see reference manual for more details.
InnoDB: Aborting...
2015-08-09 19:56:17 7efe086b8700  InnoDB: Assertion failure in thread 139629528057600 in file buf0buf.cc line 2856
InnoDB: We intentionally generate a memory trap.

Stack trace from 10.1 46ad86f6a35aff59ecb68a23dba228e5796e935a

#5  0x00007efe062e63e0 in *__GI_abort () at abort.c:92
#6  0x00007efdffa37750 in buf_page_get_gen (space=4, zip_size=0, offset=3, rw_latch=2, guess=0x0, mode=10, file=0x7efdffca59d0 "10.1/storage/innobase/btr/btr0btr.cc", line=736, mtr=0x7efe086b49c0) at 10.1/storage/innobase/buf/buf0buf.cc:2856
#7  0x00007efdff9f5cf0 in btr_block_get_func (space=4, zip_size=0, page_no=3, mode=2, file=0x7efdffca59d0 "10.1/storage/innobase/btr/btr0btr.cc", line=736, index=0x7efdfef24ff8, mtr=0x7efe086b49c0) at 10.1/storage/innobase/include/btr0btr.ic:60
#8  0x00007efdff9f6a9a in btr_root_block_get (index=0x7efdfef24ff8, mode=2, mtr=0x7efe086b49c0) at 10.1/storage/innobase/btr/btr0btr.cc:736
#9  0x00007efdff9f6bd4 in btr_root_get (index=0x7efdfef24ff8, mtr=0x7efe086b49c0) at 10.1/storage/innobase/btr/btr0btr.cc:763
#10 0x00007efdff9f79c1 in btr_get_size_and_reserved (index=0x7efdfef24ff8, flag=2, used=0x7efe086b4988, mtr=0x7efe086b49c0) at 10.1/storage/innobase/btr/btr0btr.cc:1256
#11 0x00007efdff9f78be in btr_get_size (index=0x7efdfef24ff8, flag=2, mtr=0x7efe086b49c0) at 10.1/storage/innobase/btr/btr0btr.cc:1220
#12 0x00007efdffa902f2 in dict_stats_update_transient_for_index (index=0x7efdfef24ff8) at 10.1/storage/innobase/dict/dict0stats.cc:889
#13 0x00007efdffa90527 in dict_stats_update_transient (table=0x7efdfd599df8) at 10.1/storage/innobase/dict/dict0stats.cc:965
#14 0x00007efdffa94e15 in dict_stats_update (table=0x7efdfd599df8, stats_upd_option=DICT_STATS_RECALC_TRANSIENT) at 10.1/storage/innobase/dict/dict0stats.cc:3387
#15 0x00007efdffaf90ca in dict_stats_init (table=0x7efdfd599df8) at 10.1/storage/innobase/include/dict0stats.ic:174
#16 0x00007efdffaff88e in ha_innodb::open (this=0x7efdfef4c088, name=0x7efdfef3af60 "./test/t1", mode=2, test_if_locked=18) at 10.1/storage/innobase/handler/ha_innodb.cc:5594
#17 0x00007efe08e8bf72 in handler::ha_open (this=0x7efdfef4c088, table_arg=0x7efdfef6da70, name=0x7efdfef3af60 "./test/t1", mode=2, test_if_locked=18) at 10.1/sql/handler.cc:2495
#18 0x00007efe08d4173b in open_table_from_share (thd=0x7efdfd69e070, share=0x7efdfef3aa88, alias=0x7efdfefb1260 "t1", db_stat=39, prgflag=44, ha_open_flags=18, outparam=0x7efdfef6da70, is_create_table=false) at 10.1/sql/table.cc:2920
#19 0x00007efe08bdbe37 in open_table (thd=0x7efdfd69e070, table_list=0x7efdfefb1268, ot_ctx=0x7efe086b5f90) at 10.1/sql/sql_base.cc:2550
#20 0x00007efe08bde66c in open_and_process_table (thd=0x7efdfd69e070, lex=0x7efdfd6a19a0, tables=0x7efdfefb1268, counter=0x7efe086b6034, flags=0, prelocking_strategy=0x7efe086b60a0, has_prelocking_list=false, ot_ctx=0x7efe086b5f90) at 10.1/sql/sql_base.cc:4016
#21 0x00007efe08bdf75b in open_tables (thd=0x7efdfd69e070, options=..., start=0x7efe086b6018, counter=0x7efe086b6034, flags=0, prelocking_strategy=0x7efe086b60a0) at 10.1/sql/sql_base.cc:4527
#22 0x00007efe08be0934 in open_and_lock_tables (thd=0x7efdfd69e070, options=..., tables=0x7efdfefb1268, derived=true, flags=0, prelocking_strategy=0x7efe086b60a0) at 10.1/sql/sql_base.cc:5185
#23 0x00007efe08bd4437 in open_and_lock_tables (thd=0x7efdfd69e070, tables=0x7efdfefb1268, derived=true, flags=0) at 10.1/sql/sql_base.h:530
#24 0x00007efe08c50016 in execute_sqlcom_select (thd=0x7efdfd69e070, all_tables=0x7efdfefb1268) at 10.1/sql/sql_parse.cc:5750
#25 0x00007efe08c4669f in mysql_execute_command (thd=0x7efdfd69e070) at 10.1/sql/sql_parse.cc:2947
#26 0x00007efe08c53a7d in mysql_parse (thd=0x7efdfd69e070, rawbuf=0x7efdfefb1088 "SELECT * FROM t1", length=16, parser_state=0x7efe086b71a0) at 10.1/sql/sql_parse.cc:7205
#27 0x00007efe08c42935 in dispatch_command (command=COM_QUERY, thd=0x7efdfd69e070, packet=0x7efdfd57b071 "SELECT * FROM t1", packet_length=16) at 10.1/sql/sql_parse.cc:1475
#28 0x00007efe08c4165b in do_command (thd=0x7efdfd69e070) at 10.1/sql/sql_parse.cc:1097
#29 0x00007efe08d8328d in do_handle_one_connection (thd_arg=0x7efdfd69e070) at 10.1/sql/sql_connect.cc:1350
#30 0x00007efe08d82fde in handle_one_connection (arg=0x7efdfd69e070) at 10.1/sql/sql_connect.cc:1262
#31 0x00007efe09304337 in pfs_spawn_thread (arg=0x7efdfef263f0) at 10.1/storage/perfschema/pfs.cc:1860
#32 0x00007efe082f7b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
#33 0x00007efe0638c95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Test case

-- source include/have_innodb.inc
 
--echo
--echo # Start server with keys.txt
-- let $restart_parameters=--file-key-management-filename=$MYSQL_TEST_DIR/std_data/keys.txt --plugin-load-add=file_key_management
-- source include/restart_mysqld.inc
 
CREATE TABLE t1 (c VARCHAR(8)) ENGINE=InnoDB ENCRYPTED=YES;
INSERT INTO t1 VALUES ('foobar');
 
--echo
--echo # Retart server with keys2.txt
-- let $restart_parameters=--file-key-management-filename=$MYSQL_TEST_DIR/std_data/keys2.txt --plugin-load-add=file_key_management
-- source include/restart_mysqld.inc
 
SELECT * FROM t1;
 
DROP TABLE t1;



 Comments   
Comment by Jan Lindström (Inactive) [ 2015-08-14 ]

Improved error message to be:

Version: '10.1.6-MariaDB-debug-log'  socket: '/dev/shm/tmp/mysqld.1.sock'  port: 16000  Source distribution
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Database page corruption on disk or a failed
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Space 4 file test/t1 read of page 3.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: You may have to recover from a backup.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Maybe corruption: Block space_id 4 in file test/t1 maybe corrupted.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Page based on contents maybe encrypted.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Reason could be that key_version 1 in page or in crypt_data 0x7f6c2efb1630 could not be found.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Reason could be also that key management plugin is not found orused encryption algorithm or method does not match.
2015-08-14 15:44:52 140102306318080 [ERROR] InnoDB: Based on page page compressed 0, compressed and encrypted 0.
2015-08-14 15:44:52 7f6c1c334700 InnoDB: Page dump in ascii and hex (16384 bytes):

After this change, this is duplicate of MDEV-8588.

Comment by Jan Lindström (Inactive) [ 2015-08-14 ]

commit a80753594a37538a35df7c02ae80da624578dec4
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Fri Aug 14 15:49:56 2015 +0300

MDEV-8591: Database page corruption on disk or a failed space, Assertion failure in file buf0buf.cc line 2856 on querying a table using wrong default encryption key

Improved error messaging to show based on original page before
encryption is page maybe encrypted or just corrupted.

Comment by Jan Lindström (Inactive) [ 2015-08-16 ]

Investigating if I could use similar approach as in MDEV-8588 i.e. mark tablespace not usable (assuming that tablespace is not system tablespace) and later then push additional warning.

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