Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1(EOL), 10.2(EOL)
-
Windows
-
5.5.59, 10.3.6-1
Description
https://internal.askmonty.org/buildbot/builders/win32-debug/builds/3945/steps/test/logs/stdio
innodb.doublewrite 'innodb_plugin' w2 [ fail ]
|
Test ended at 2017-05-20 15:15:56
|
|
|
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 220: query 'set global innodb_fil_make_page_dirty_debug = @space_id' failed: 2013: Lost connection to MySQL server during query
|
|
|
The result from queries just before the failure was:
|
< snip >
|
f1 f2
|
1 ############
|
2 ++++++++++++
|
3 ////////////
|
4 ------------
|
5 ............
|
# Test End
|
# ---------------------------------------------------------------
|
# Test Begin: Test if recovery works if 2nd page of user
|
# tablespace is corrupted.
|
select space from information_schema.innodb_sys_tables
|
where name = 'test/t1' into @space_id;
|
# Ensure that dirty pages of table t1 is flushed.
|
flush tables t1 for export;
|
unlock tables;
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Make the 2nd page dirty for table t1
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = @space_id;
|
|
|
More results from queries before failure can be found in D:\win32-debug\build\mysql-test\var\2\log\doublewrite.log
|
|
|
|
|
Server [mysqld.1 - pid: 5132, winpid: 5132, exit: 768] failed during test run
|
Server log from this test:
|
----------SERVER LOG START-----------
|
----------SERVER LOG END-------------
|
Attachments
Issue Links
- is duplicated by
-
-
- Closed
-
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
MDEV-11125 Introduce a reduced doublewrite mode, handling error detection only
-
- Closed
-
-
-
- Closed
-
(5 relates to)
Activity
Is it possible to get fully resolved stack traces (with function names and arguments for each thread) or a core dump?
10.1.26:
[External Code]
|
[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
> ha_innodb.dll!os_cond_wait_timed(_RTL_CONDITION_VARIABLE * cond, os_fast_mutex_t * fast_mutex, unsigned long time_in_ms) Line 156 C++
|
ha_innodb.dll!os_event_wait_time_low(os_event * event, unsigned long time_in_usec, __int64 reset_sig_count) Line 698 C++
|
ha_innodb.dll!recv_writer_thread(void * arg) Line 353 C++
|
[External Code]
|
[External Code]
|
[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
> mysqld.exe!pthread_cond_timedwait(pthread_cond_t * cond, _RTL_CRITICAL_SECTION * mutex, const timespec * abstime) Line 298 C
|
mysqld.exe!inline_mysql_cond_timedwait(st_mysql_cond * that, st_mysql_mutex * mutex, const timespec * abstime, const char * src_file, unsigned int src_line) Line 1191 C
|
mysqld.exe!timer_handler(void * arg) Line 293 C
|
mysqld.exe!pfs_spawn_thread(void * arg) Line 1860 C++
|
mysqld.exe!pthread_start(void * p) Line 60 C
|
mysqld.exe!invoke_thread_procedure(unsigned int(__stdcall*)(void *) procedure, void * const context) Line 92 C++
|
mysqld.exe!thread_start<unsigned int (__stdcall*)(void *)>(void * const parameter) Line 115 C++
|
[External Code]
|
[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
> ha_innodb.dll!os_aio_windows_handle(unsigned long segment, unsigned long pos, fil_node_t * * message1, void * * message2, unsigned long * type) Line 5041 C++
|
ha_innodb.dll!fil_aio_wait(unsigned long segment) Line 6162 C++
|
ha_innodb.dll!io_handler_thread(void * arg) Line 556 C++
|
[External Code]
|
ha_innodb.dll!issue_debug_notification(const wchar_t * const message) Line 125 C++
|
ha_innodb.dll!__acrt_report_runtime_error(const wchar_t * message) Line 142 C++
|
ha_innodb.dll!abort() Line 51 C++
|
> ha_innodb.dll!buf_block_align_instance(buf_pool_t * buf_pool, const unsigned char * ptr) Line 2864 C++
|
ha_innodb.dll!buf_block_align(const unsigned char * ptr) Line 2894 C++
|
ha_innodb.dll!mtr_memo_contains_page(mtr_t * mtr, const unsigned char * ptr, unsigned long type) Line 420 C++
|
ha_innodb.dll!ibuf_bitmap_page_get_bits_low(const unsigned char * page, unsigned long page_no, unsigned long zip_size, unsigned long latch_type, mtr_t * mtr, unsigned long bit) Line 740 C++
|
ha_innodb.dll!ibuf_merge_or_delete_for_page(buf_block_t * block, unsigned long space_id, unsigned long page_no, unsigned long zip_size, unsigned long update_ibuf_bitmap) Line 4638 C++
|
ha_innodb.dll!buf_page_io_complete(buf_page_t * bpage, bool evict) Line 4941 C++
|
ha_innodb.dll!buf_read_page_low(dberr_t * err, bool sync, unsigned long mode, unsigned long space, unsigned long zip_size, unsigned long unzip, __int64 tablespace_version, unsigned long offset) Line 228 C++
|
ha_innodb.dll!buf_read_page(unsigned long space_id, unsigned long zip_size, unsigned long offset) Line 449 C++
|
ha_innodb.dll!buf_page_get_gen(unsigned long space, unsigned long zip_size, unsigned long offset, unsigned long rw_latch, buf_block_t * guess, unsigned long mode, const char * file, unsigned long line, mtr_t * mtr, dberr_t * err) Line 3186 C++
|
ha_innodb.dll!btr_cur_search_to_nth_level(dict_index_t * index, unsigned long level, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_cur_t * cursor, unsigned long has_search_latch, const char * file, unsigned long line, mtr_t * mtr) Line 612 C++
|
ha_innodb.dll!btr_pcur_open_low(dict_index_t * index, unsigned long level, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_pcur_t * cursor, const char * file, unsigned long line, mtr_t * mtr) Line 439 C++
|
ha_innodb.dll!btr_pcur_open_on_user_rec_func(dict_index_t * index, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_pcur_t * cursor, const char * file, unsigned long line, mtr_t * mtr) Line 589 C++
|
ha_innodb.dll!dict_load_indexes(dict_table_t * table, mem_block_info_t * heap, dict_err_ignore_t ignore_err) Line 1837 C++
|
ha_innodb.dll!dict_load_sys_table(dict_table_t * table) Line 2765 C++
|
ha_innodb.dll!dict_boot() Line 479 C++
|
ha_innodb.dll!innobase_start_or_create_for_mysql() Line 2548 C++
|
ha_innodb.dll!innobase_init(void * p) Line 3970 C++
|
mysqld.exe!ha_initialize_handlerton(st_plugin_int * plugin) Line 513 C++
|
mysqld.exe!plugin_initialize(st_mem_root * tmp_root, st_plugin_int * plugin, int * argc, char * * argv, bool options_only) Line 1406 C++
|
mysqld.exe!plugin_init(int * argc, char * * argv, int flags) Line 1683 C++
|
mysqld.exe!init_server_components() Line 5148 C++
|
mysqld.exe!win_main(int argc, char * * argv) Line 5737 C++
|
mysqld.exe!mysql_service(void * p) Line 5981 C++
|
mysqld.exe!mysqld_main(int argc, char * * argv) Line 6175 C++
|
mysqld.exe!main(int argc, char * * argv) Line 25 C++
|
|
|
[External Code]
|
[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
|
|
|
Locals:
|
|
- block 0x08a90898 {page={space=0 offset=1 buf_fix_count=1 ...} frame=0x08b10000 "" unzip_LRU={prev=0x00000000 <NULL> ...} ...} buf_block_t *
|
+ page {space=0 offset=1 buf_fix_count=1 ...} buf_page_t
|
+ frame 0x08b10000 "" unsigned char *
|
+ unzip_LRU {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<buf_block_t>
|
in_unzip_LRU_list 0 unsigned long
|
+ mutex {event=0x081c2950 {handle=0xcdcdcdcd os_mutex={mutex={DebugInfo=0xffffffff {Type=??? CreatorBackTraceIndex=...} ...} ...} ...} ...} ib_mutex_t
|
+ lock {lock_word=0 waiters=0 recursive=1 ...} rw_lock_t
|
lock_hash_val 2325 unsigned int
|
check_index_page_at_flush 0 unsigned long
|
modify_clock 0 unsigned __int64
|
n_hash_helps 0 unsigned long
|
n_fields 1 unsigned long
|
n_bytes 0 unsigned long
|
left_side 1 unsigned long
|
n_pointers 0 unsigned long
|
curr_n_fields 0 unsigned int
|
curr_n_bytes 0 unsigned int
|
curr_left_side 0 unsigned int
|
+ index 0x00000000 <NULL> dict_index_t *
|
+ debug_latch {lock_word=1048575 waiters=0 recursive=0 ...} rw_lock_t
|
- block->page {space=0 offset=1 buf_fix_count=1 ...} buf_page_t
|
space 0 unsigned int
|
offset 1 unsigned int
|
buf_fix_count 1 unsigned int
|
io_fix 0 unsigned int
|
state 5 unsigned int
|
flush_type 0 unsigned int
|
buf_pool_index 0 unsigned int
|
+ zip {data=0x00000000 <NULL> m_start=0 m_external=false ...} page_zip_des_t
|
write_size 0 unsigned long
|
encrypted false bool
|
real_size 0 unsigned long
|
+ slot 0x00000000 <NULL> buf_tmp_buffer_t *
|
+ hash 0x00000000 <NULL> buf_page_t *
|
in_page_hash 1 unsigned long
|
in_zip_hash 0 unsigned long
|
+ list {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<buf_page_t>
|
in_flush_list 1 unsigned long
|
in_free_list 0 unsigned long
|
newest_modification 3282542 unsigned __int64
|
oldest_modification 3282536 unsigned __int64
|
+ LRU {prev=0x00000000 <NULL> next=0x08a906e0 {space=0 offset=11 buf_fix_count=0 ...} } ut_list_node<buf_page_t>
|
in_LRU_list 1 unsigned long
|
old 0 unsigned int
|
freed_page_clock 0 unsigned int
|
access_time 3416551707 unsigned int
|
file_page_was_freed 0 unsigned long
|
block->page.offset 1 unsigned int
|
block->page.space 0 unsigned int
|
- ptr 0x08b10000 "" const unsigned char *
|
0 '\0' const unsigned char
|
0x08B10000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 32 16 6b 00 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 .....................2.k........................
|
0x08B10030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10090 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B100C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B100F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10120 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10150 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10180 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B101B0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B101E0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10210 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10240 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10270 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B102A0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B102D0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10300 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10330 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10360 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10390 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B103C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B103F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10420 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10450 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10480 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B104B0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B104E0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10510 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10540 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10570 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B105A0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B105D0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10600 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10630 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10660 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10690 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B106C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B106F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10720 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10750 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10780 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B107B0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B107E0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10810 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10840 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10870 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B108A0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B108D0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10900 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10930 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10960 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B10990 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
0x08B109C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
Error log
2017-08-10 13:15:27 1840 [Note] InnoDB: Rollback of trx with id 95492 completed
|
2017-08-10 13:15:27 1840 [Note] InnoDB: Rollback of non-prepared transactions completed
|
2017-08-10 13:15:27 7496 [Note] InnoDB: 5.6.36 started; log sequence number 3280849
|
2017-08-10 13:15:28 2936 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2017-08-10 13:15:28 7496 [Note] Plugin 'partition' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'SEQUENCE' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_CMP' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'XTRADB_RSEG' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'FEEDBACK' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2017-08-10 13:15:28 7496 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
2017-08-10 13:15:28 7496 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-pam-debug'
|
2017-08-10 13:15:28 7496 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
2017-08-10 13:15:28 7496 [Note] Server socket created on IP: '::'.
|
2017-08-10 13:15:28 7496 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: ready for connections.
|
Version: '10.1.26-MariaDB-debug' socket: '' port: 16000 Source distribution
|
2017-08-10 13:15:28 1712 [Note] InnoDB: Saving InnoDB page number: 0
|
2017-08-10 13:15:28 1712 [Note] InnoDB: Dirtying page:0 of space:0
|
2017-08-10 13:15:29 1992 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe (mysqld 10.1.26-MariaDB-debug) starting as process 2596 ...
|
2017-08-10 13:15:29 1992 [Note] InnoDB: innodb-page-size has been changed from the default value 16384 to 32768.
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2017-08-10 13:15:29 1992 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:29 1992 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:29 1992 [Note] InnoDB: The InnoDB memory heap is disabled
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
|
2017-08-10 13:15:29 1992 [Note] InnoDB: _mm_lfence() and _mm_sfence() are used for memory barrier
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Using generic crc32 instructions
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Initializing buffer pool, size = 24.0M
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Completed initialization of buffer pool
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Restoring page 0 of tablespace 0
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Writing 32768 bytes into file: ibdata1
|
InnoDB: Error: Current page size 32768 != page size on page 16384
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3280891
|
2017-08-10 13:15:29 1992 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
|
2017-08-10 13:15:30 1992 [Note] InnoDB: Starting final batch to recover 2 pages from redo log
|
2017-08-10 13:15:31 12048 [Note] InnoDB: Starting in background the rollback of recovered transactions
|
2017-08-10 13:15:31 1992 [Note] InnoDB: 128 rollback segment(s) are active.
|
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
|
InnoDB: in total 1 row operations to undo
|
InnoDB: Trx id counter is 96512
|
2017-08-10 13:15:31 2f10 InnoDB: Rolling back trx with id 96004, 1 rows to undo
|
2017-08-10 13:15:31 1992 [Note] InnoDB: Waiting for purge to start
|
2017-08-10 13:15:31 12048 [Note] InnoDB: Rollback of trx with id 96004 completed
|
2017-08-10 13:15:31 12048 [Note] InnoDB: Rollback of non-prepared transactions completed
|
2017-08-10 13:15:31 1992 [Note] InnoDB: 5.6.36 started; log sequence number 3281424
|
2017-08-10 13:15:32 10284 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2017-08-10 13:15:32 1992 [Note] Plugin 'partition' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'SEQUENCE' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_CMP' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'XTRADB_RSEG' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'FEEDBACK' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2017-08-10 13:15:32 1992 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
2017-08-10 13:15:32 1992 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-pam-debug'
|
2017-08-10 13:15:32 1992 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
2017-08-10 13:15:32 1992 [Note] Server socket created on IP: '::'.
|
2017-08-10 13:15:32 1992 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: ready for connections.
|
Version: '10.1.26-MariaDB-debug' socket: '' port: 16000 Source distribution
|
2017-08-10 13:15:32 11252 [Note] InnoDB: Saving InnoDB page number: 0
|
2017-08-10 13:15:32 11252 [Note] InnoDB: Dirtying page:0 of space:0
|
2017-08-10 13:15:33 604 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe (mysqld 10.1.26-MariaDB-debug) starting as process 5220 ...
|
2017-08-10 13:15:33 604 [Note] InnoDB: innodb-page-size has been changed from the default value 16384 to 32768.
|
2017-08-10 13:15:33 604 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2017-08-10 13:15:33 604 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:33 604 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:33 604 [Note] InnoDB: The InnoDB memory heap is disabled
|
2017-08-10 13:15:33 604 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
|
2017-08-10 13:15:33 604 [Note] InnoDB: _mm_lfence() and _mm_sfence() are used for memory barrier
|
2017-08-10 13:15:33 604 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2017-08-10 13:15:33 604 [Note] InnoDB: Using generic crc32 instructions
|
2017-08-10 13:15:33 604 [Note] InnoDB: Initializing buffer pool, size = 24.0M
|
2017-08-10 13:15:33 604 [Note] InnoDB: Completed initialization of buffer pool
|
2017-08-10 13:15:33 604 [Note] InnoDB: Restoring page 0 of tablespace 0
|
2017-08-10 13:15:33 604 [Note] InnoDB: Writing 32768 bytes into file: ibdata1
|
InnoDB: Error: Current page size 32768 != page size on page 16384
|
2017-08-10 13:15:33 604 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-08-10 13:15:33 604 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3281977
|
2017-08-10 13:15:33 604 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
|
2017-08-10 13:15:34 604 [Note] InnoDB: Starting final batch to recover 1 pages from redo log
|
2017-08-10 13:15:35 12616 [Note] InnoDB: Starting in background the rollback of recovered transactions
|
2017-08-10 13:15:35 604 [Note] InnoDB: 128 rollback segment(s) are active.
|
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
|
InnoDB: in total 1 row operations to undo
|
InnoDB: Trx id counter is 97024
|
2017-08-10 13:15:35 3148 InnoDB: Rolling back trx with id 96516, 1 rows to undo
|
2017-08-10 13:15:35 604 [Note] InnoDB: Waiting for purge to start
|
2017-08-10 13:15:35 12616 [Note] InnoDB: Rollback of trx with id 96516 completed
|
2017-08-10 13:15:35 12616 [Note] InnoDB: Rollback of non-prepared transactions completed
|
2017-08-10 13:15:35 604 [Note] InnoDB: 5.6.36 started; log sequence number 3281983
|
2017-08-10 13:15:36 13248 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2017-08-10 13:15:36 604 [Note] Plugin 'partition' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'SEQUENCE' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_CMP' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'XTRADB_RSEG' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'FEEDBACK' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2017-08-10 13:15:36 604 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
2017-08-10 13:15:36 604 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-pam-debug'
|
2017-08-10 13:15:36 604 [Warning] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
2017-08-10 13:15:36 604 [Note] Server socket created on IP: '::'.
|
2017-08-10 13:15:36 604 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe: ready for connections.
|
Version: '10.1.26-MariaDB-debug' socket: '' port: 16000 Source distribution
|
2017-08-10 13:15:36 11984 [Note] InnoDB: Saving InnoDB page number: 1
|
2017-08-10 13:15:37 11984 [Note] InnoDB: Dirtying page:1 of space:0
|
2017-08-10 13:15:37 5912 [Note] I:/mysql/10.1/bld/sql//Debug/mysqld.exe (mysqld 10.1.26-MariaDB-debug) starting as process 5068 ...
|
2017-08-10 13:15:37 5912 [Note] InnoDB: innodb-page-size has been changed from the default value 16384 to 32768.
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2017-08-10 13:15:37 5912 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:37 5912 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
|
2017-08-10 13:15:37 5912 [Note] InnoDB: The InnoDB memory heap is disabled
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
|
2017-08-10 13:15:37 5912 [Note] InnoDB: _mm_lfence() and _mm_sfence() are used for memory barrier
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Using generic crc32 instructions
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Initializing buffer pool, size = 24.0M
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Completed initialization of buffer pool
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3282025
|
2017-08-10 13:15:37 5912 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
|
2017-08-10 13:15:38 5912 [ERROR] InnoDB: Corruption: Block space_id 0 != page space_id 0 or Block offset 1 != page offset 0
|
170810 13:15:45 [ERROR] mysqld got exception 0x80000003 ;
|
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.26-MariaDB-debug
|
key_buffer_size=1048576
|
read_buffer_size=131072
|
max_used_connections=0
|
max_threads=1001
|
thread_count=0
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 387368 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...
|
ha_innodb.dll!issue_debug_notification()[report_runtime_error.cpp:125]
|
ha_innodb.dll!__acrt_report_runtime_error()[report_runtime_error.cpp:142]
|
ha_innodb.dll!abort()[abort.cpp:51]
|
ha_innodb.dll!buf_block_align_instance()[buf0buf.cc:2864]
|
ha_innodb.dll!buf_block_align()[buf0buf.cc:2894]
|
ha_innodb.dll!mtr_memo_contains_page()[mtr0mtr.cc:420]
|
ha_innodb.dll!ibuf_bitmap_page_get_bits_low()[ibuf0ibuf.cc:740]
|
ha_innodb.dll!ibuf_merge_or_delete_for_page()[ibuf0ibuf.cc:4638]
|
ha_innodb.dll!buf_page_io_complete()[buf0buf.cc:4941]
|
ha_innodb.dll!buf_read_page_low()[buf0rea.cc:228]
|
ha_innodb.dll!buf_read_page()[buf0rea.cc:449]
|
ha_innodb.dll!buf_page_get_gen()[buf0buf.cc:3186]
|
ha_innodb.dll!btr_cur_search_to_nth_level()[btr0cur.cc:612]
|
ha_innodb.dll!btr_pcur_open_low()[btr0pcur.ic:439]
|
ha_innodb.dll!btr_pcur_open_on_user_rec_func()[btr0pcur.cc:589]
|
ha_innodb.dll!dict_load_indexes()[dict0load.cc:1837]
|
ha_innodb.dll!dict_load_sys_table()[dict0load.cc:2765]
|
ha_innodb.dll!dict_boot()[dict0boot.cc:479]
|
ha_innodb.dll!innobase_start_or_create_for_mysql()[srv0start.cc:2548]
|
ha_innodb.dll!innobase_init()[ha_innodb.cc:3970]
|
mysqld.exe!ha_initialize_handlerton()[handler.cc:513]
|
mysqld.exe!plugin_initialize()[sql_plugin.cc:1406]
|
mysqld.exe!plugin_init()[sql_plugin.cc:1683]
|
mysqld.exe!init_server_components()[mysqld.cc:5148]
|
mysqld.exe!win_main()[mysqld.cc:5737]
|
mysqld.exe!mysql_service()[mysqld.cc:5981]
|
mysqld.exe!mysqld_main()[mysqld.cc:6175]
|
mysqld.exe!main()[main.cc:25]
|
mysqld.exe!invoke_main()[exe_common.inl:64]
|
mysqld.exe!__scrt_common_main_seh()[exe_common.inl:259]
|
mysqld.exe!__scrt_common_main()[exe_common.inl:302]
|
mysqld.exe!mainCRTStartup()[exe_main.cpp:17]
|
KERNEL32.DLL!BaseThreadInitThunk()
|
ntdll.dll!RtlGetAppContainerNamedObjectPath()
|
ntdll.dll!RtlGetAppContainerNamedObjectPath()
|
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.
|
Writing a core file
|
Minidump written to I:\mysql\10.1\bld\mysql-test\var\mysqld.1\data\mysqld.dmp
|
----------SERVER LOG END-------------
|
mysqltest failed but provided no output
|
The result from queries just before the failure was:
|
< snip >
|
2 ++++++++++++
|
3 ////////////
|
4 ------------
|
5 ............
|
# Test End
|
# ---------------------------------------------------------------
|
# Test Begin: Test if recovery works if 2nd page of
|
# system tablespace is full of zeroes.
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Ensure that all dirty pages in the system are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Make the second page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
# Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Make the 2nd page (page_no=1) of the system tablespace
|
# all zeroes.
|
|
|
|
|
- saving 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-32k,innodb_plugin/' to 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-32k,innodb_plugin/'
|
- found 'mysqld.dmp' (0/5)
|
|
|
Trying 'cdb' to get a backtrace
|
Cannot find cdb. Please Install Debugging tools for Windows
|
from http://www.microsoft.com/whdc/devtools/debugging/install64bit.mspx (native x64 version)
|
|
|
Only 1 of 10 completed.
|
--------------------------------------------------------------------------
|
The servers were restarted 0 times
|
Spent 800.812 of 2432 seconds executing testcases
|
|
|
Failure: Failed 1/19 tests, 94.74% were successful.
|
|
|
Failing test(s): innodb.doublewrite
|
|
|
The log files in var/log may give you some hint of what went wrong.
|
|
|
If you want to report this error, please read first the documentation
|
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
|
|
|
mysql-test-run: *** ERROR: there were failing test cases
|
|
|
I:\mysql\10.1\bld\mysql-test>
|
How to repeat. Use win32 and --repeat=100, in my machine it does repeat after ~20runs.
>Debug.listcallstack /showvalues /allthreads
|
Callstack for Thread 1 (Thread Id: 360 (0x168)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 ha_innodb.dll!issue_debug_notification(const wchar_t * const message=0x0ff11c80)
|
2 ha_innodb.dll!__acrt_report_runtime_error(const wchar_t * message=0x0ff11c80)
|
3 ha_innodb.dll!abort()
|
4 ha_innodb.dll!buf_block_align_instance(buf_pool_t * buf_pool=0x083c3ee8, const unsigned char * ptr=0x08cdc000)
|
5 ha_innodb.dll!buf_block_align(const unsigned char * ptr=0x08cdc000)
|
6 ha_innodb.dll!mtr_memo_contains_page(mtr_t * mtr=0x00ef9ac4, const unsigned char * ptr=0x08cdc000, unsigned long type=0x00000002)
|
*7 ha_innodb.dll!ibuf_bitmap_page_get_bits_low(const unsigned char * page=0x08cdc000, unsigned long page_no=0x0000000b, unsigned long zip_size=0x00000000, unsigned long latch_type=0x00000002, mtr_t * mtr=0x00ef9ac4, unsigned long bit=0x00000002)
|
8 ha_innodb.dll!ibuf_merge_or_delete_for_page(buf_block_t * block=0x08c906e0, unsigned long space_id=0x00000000, unsigned long page_no=0x0000000b, unsigned long zip_size=0x00000000, unsigned long update_ibuf_bitmap=0x00000001)
|
9 ha_innodb.dll!buf_page_io_complete(buf_page_t * bpage=0x08c906e0, bool evict=false)
|
10 ha_innodb.dll!buf_read_page_low(dberr_t * err=0x00efa0b0, bool sync=true, unsigned long mode=0x00000084, unsigned long space=0x00000000, unsigned long zip_size=0x00000000, unsigned long unzip=0x00000000, __int64 tablespace_version=0x0000000000000001, unsigned long offset=0x0000000b)
|
11 ha_innodb.dll!buf_read_page(unsigned long space_id=0x00000000, unsigned long zip_size=0x00000000, unsigned long offset=0x0000000b)
|
12 ha_innodb.dll!buf_page_get_gen(unsigned long space=0x00000000, unsigned long zip_size=0x00000000, unsigned long offset=0x0000000b, unsigned long rw_latch=0x00000003, buf_block_t * guess=0x00000000, unsigned long mode=0x0000000a, const char * file=0x0f92c00c, unsigned long line=0x0000072e, mtr_t * mtr=0x00efa59c, dberr_t * err=0x00efa45c)
|
13 ha_innodb.dll!btr_cur_search_to_nth_level(dict_index_t * index=0x08499118, unsigned long level=0x00000000, const dtuple_t * tuple=0x08499818, unsigned long mode=0x00000002, unsigned long latch_mode=0x00000001, btr_cur_t * cursor=0x00efaa2c, unsigned long has_search_latch=0x00000000, const char * file=0x0f92c00c, unsigned long line=0x0000072e, mtr_t * mtr=0x00efa59c)
|
14 ha_innodb.dll!btr_pcur_open_low(dict_index_t * index=0x08499118, unsigned long level=0x00000000, const dtuple_t * tuple=0x08499818, unsigned long mode=0x00000002, unsigned long latch_mode=0x00000001, btr_pcur_t * cursor=0x00efaa2c, const char * file=0x0f92c00c, unsigned long line=0x0000072e, mtr_t * mtr=0x00efa59c)
|
15 ha_innodb.dll!btr_pcur_open_on_user_rec_func(dict_index_t * index=0x08499118, const dtuple_t * tuple=0x08499818, unsigned long mode=0x00000002, unsigned long latch_mode=0x00000001, btr_pcur_t * cursor=0x00efaa2c, const char * file=0x0f92c00c, unsigned long line=0x0000072e, mtr_t * mtr=0x00efa59c)
|
16 ha_innodb.dll!dict_load_indexes(dict_table_t * table=0x08483ea8, mem_block_info_t * heap=0x084997d8, dict_err_ignore_t ignore_err=DICT_ERR_IGNORE_NONE)
|
17 ha_innodb.dll!dict_load_sys_table(dict_table_t * table=0x08483ea8)
|
18 ha_innodb.dll!dict_boot()
|
19 ha_innodb.dll!innobase_start_or_create_for_mysql()
|
20 ha_innodb.dll!innobase_init(void * p=0x082fe768)
|
21 mysqld.exe!ha_initialize_handlerton(st_plugin_int * plugin=0x000b8610)
|
22 mysqld.exe!plugin_initialize(st_mem_root * tmp_root=0x00eff140, st_plugin_int * plugin=0x000b8610, int * argc=0x02da42b8, char * * argv=0x000ec1e0, bool options_only=false)
|
23 mysqld.exe!plugin_init(int * argc=0x02da42b8, char * * argv=0x000ec1e0, int flags=0x00000002)
|
24 mysqld.exe!init_server_components()
|
25 mysqld.exe!win_main(int argc=0x00000093, char * * argv=0x000ec1e0)
|
26 mysqld.exe!mysql_service(void * p=0x00000000)
|
27 mysqld.exe!mysqld_main(int argc=0x00000016, char * * argv=0x000d8938)
|
28 mysqld.exe!main(int argc=0x00000016, char * * argv=0x000d8938)
|
29 [External Code]
|
30 [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
|
|
|
Callstack for Thread 2 (Thread Id: 11292 (0x2c1c)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 mysqld.exe!pthread_cond_timedwait(pthread_cond_t * cond=0x035ff2a0, _RTL_CRITICAL_SECTION * mutex=0x035ff284, const timespec * abstime=0x08b9f864)
|
4 mysqld.exe!inline_mysql_cond_timedwait(st_mysql_cond * that=0x035ff2a0, st_mysql_mutex * mutex=0x035ff284, const timespec * abstime=0x08b9f864, const char * src_file=0x02bdd9e8, unsigned int src_line=0x00000124)
|
5 mysqld.exe!timer_handler(void * arg=0x00000000)
|
6 mysqld.exe!pfs_spawn_thread(void * arg=0x000c2f68)
|
7 mysqld.exe!pthread_start(void * p=0x000d1970)
|
8 mysqld.exe!invoke_thread_procedure(unsigned int(__stdcall*)(void *) procedure=0x01d096b0, void * const context=0x000d1970)
|
9 mysqld.exe!thread_start<unsigned int (__stdcall*)(void *)>(void * const parameter=0x08257780)
|
10 [External Code]
|
|
|
Callstack for Thread 3 (Thread Id: 6900 (0x1af4)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000000, unsigned long pos=0x00000000, fil_node_t * * message1=0x096df7e4, void * * message2=0x096df7d8, unsigned long * type=0x096df7cc)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000000)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5d0)
|
6 [External Code]
|
|
|
Callstack for Thread 4 (Thread Id: 6836 (0x1ab4)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000000, unsigned long pos=0x00000000, fil_node_t * * message1=0x097df8b4, void * * message2=0x097df8a8, unsigned long * type=0x097df89c)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000001)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5d4)
|
6 [External Code]
|
|
|
Callstack for Thread 5 (Thread Id: 2720 (0xaa0)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000000, unsigned long pos=0x00000000, fil_node_t * * message1=0x098dfbec, void * * message2=0x098dfbe0, unsigned long * type=0x098dfbd4)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000002)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5d8)
|
6 [External Code]
|
|
|
Callstack for Thread 6 (Thread Id: 8388 (0x20c4)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000001, unsigned long pos=0x00000000, fil_node_t * * message1=0x099dfd40, void * * message2=0x099dfd34, unsigned long * type=0x099dfd28)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000003)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5dc)
|
6 [External Code]
|
|
|
Callstack for Thread 7 (Thread Id: 12948 (0x3294)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000000, unsigned long pos=0x00000000, fil_node_t * * message1=0x09adf908, void * * message2=0x09adf8fc, unsigned long * type=0x09adf8f0)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000004)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5e0)
|
6 [External Code]
|
|
|
Callstack for Thread 8 (Thread Id: 13064 (0x3308)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_aio_windows_handle(unsigned long segment=0x00000001, unsigned long pos=0x00000000, fil_node_t * * message1=0x09bdfe94, void * * message2=0x09bdfe88, unsigned long * type=0x09bdfe7c)
|
4 ha_innodb.dll!fil_aio_wait(unsigned long segment=0x00000005)
|
5 ha_innodb.dll!io_handler_thread(void * arg=0x0ff7a5e4)
|
6 [External Code]
|
|
|
Callstack for Thread 9 (Thread Id: 6544 (0x1990)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
3 ha_innodb.dll!os_cond_wait_timed(_RTL_CONDITION_VARIABLE * cond=0x0840b3d0, os_fast_mutex_t * fast_mutex=0x0840b3a4, unsigned long time_in_ms=0x00000064)
|
4 ha_innodb.dll!os_event_wait_time_low(os_event * event=0x0840b3a0, unsigned long time_in_usec=0x000186a0, __int64 reset_sig_count=0x0000000000000001)
|
5 ha_innodb.dll!recv_writer_thread(void * arg=0x00000000)
|
6 [External Code]
|
|
|
Callstack for Thread 10 (Thread Id: 6160 (0x1810)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
|
|
Callstack for Thread 11 (Thread Id: 12564 (0x3114)):
|
Index Function
|
--------------------------------------------------------------------------------
|
1 [External Code]
|
2 [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll]
|
|
Locals from ibuf:
latch_type 0x00000002 unsigned long
|
- mtr 0x00ef9ac4 {state=0x00002fc7 memo={heap=0x00000000 <NULL> used=0x00000008 data=0x00ef9ad0 "\x2" ...} ...} mtr_t *
|
state 0x00002fc7 unsigned long
|
+ memo {heap=0x00000000 <NULL> used=0x00000008 data=0x00ef9ad0 "\x2" ...} dyn_block_t
|
+ log {heap=0x00000000 <NULL> used=0x00000000 data=0x00ef9cf4 "ÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌÌ... ...} dyn_block_t
|
inside_ibuf 0x00000001 unsigned int
|
modifications 0x00000000 unsigned int
|
made_dirty 0x00000000 unsigned int
|
n_log_recs 0x00000000 unsigned long
|
n_freed_pages 0x00000000 unsigned long
|
log_mode 0x00000015 unsigned long
|
start_lsn 0xcccccccccccccccc unsigned __int64
|
end_lsn 0xcccccccccccccccc unsigned __int64
|
magic_n 0x0000d517 unsigned long
|
+ trx 0x00000000 <NULL> trx_t *
|
- page 0x08cdc000 "" const unsigned char *
|
0x00 '\0' const unsigned char
|
zip_size 0x00000000 unsigned long
|
This is different way to crash:
ha_innodb.dll!issue_debug_notification(const wchar_t * const message) Line 125 C++
|
ha_innodb.dll!__acrt_report_runtime_error(const wchar_t * message) Line 142 C++
|
ha_innodb.dll!abort() Line 51 C++
|
ha_innodb.dll!ib_logf(ib_log_level_t level, const char * format, ...) Line 20631 C++
|
> ha_innodb.dll!buf_page_io_complete(buf_page_t * bpage, bool evict) Line 4913 C++
|
ha_innodb.dll!buf_read_page_low(dberr_t * err, bool sync, unsigned long mode, unsigned long space, unsigned long zip_size, unsigned long unzip, __int64 tablespace_version, unsigned long offset) Line 228 C++
|
ha_innodb.dll!buf_read_page(unsigned long space_id, unsigned long zip_size, unsigned long offset) Line 449 C++
|
ha_innodb.dll!buf_page_get_gen(unsigned long space, unsigned long zip_size, unsigned long offset, unsigned long rw_latch, buf_block_t * guess, unsigned long mode, const char * file, unsigned long line, mtr_t * mtr, dberr_t * err) Line 3186 C++
|
ha_innodb.dll!ibuf_bitmap_get_map_page_func(unsigned long space, unsigned long page_no, unsigned long zip_size, const char * file, unsigned long line, mtr_t * mtr) Line 870 C++
|
ha_innodb.dll!ibuf_merge_or_delete_for_page(buf_block_t * block, unsigned long space_id, unsigned long page_no, unsigned long zip_size, unsigned long update_ibuf_bitmap) Line 4633 C++
|
ha_innodb.dll!buf_page_io_complete(buf_page_t * bpage, bool evict) Line 4941 C++
|
ha_innodb.dll!buf_read_page_low(dberr_t * err, bool sync, unsigned long mode, unsigned long space, unsigned long zip_size, unsigned long unzip, __int64 tablespace_version, unsigned long offset) Line 228 C++
|
ha_innodb.dll!buf_read_page(unsigned long space_id, unsigned long zip_size, unsigned long offset) Line 449 C++
|
ha_innodb.dll!buf_page_get_gen(unsigned long space, unsigned long zip_size, unsigned long offset, unsigned long rw_latch, buf_block_t * guess, unsigned long mode, const char * file, unsigned long line, mtr_t * mtr, dberr_t * err) Line 3186 C++
|
ha_innodb.dll!btr_cur_search_to_nth_level(dict_index_t * index, unsigned long level, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_cur_t * cursor, unsigned long has_search_latch, const char * file, unsigned long line, mtr_t * mtr) Line 612 C++
|
ha_innodb.dll!btr_pcur_open_low(dict_index_t * index, unsigned long level, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_pcur_t * cursor, const char * file, unsigned long line, mtr_t * mtr) Line 439 C++
|
ha_innodb.dll!btr_pcur_open_on_user_rec_func(dict_index_t * index, const dtuple_t * tuple, unsigned long mode, unsigned long latch_mode, btr_pcur_t * cursor, const char * file, unsigned long line, mtr_t * mtr) Line 589 C++
|
ha_innodb.dll!dict_load_indexes(dict_table_t * table, mem_block_info_t * heap, dict_err_ignore_t ignore_err) Line 1837 C++
|
ha_innodb.dll!dict_load_sys_table(dict_table_t * table) Line 2765 C++
|
ha_innodb.dll!dict_boot() Line 479 C++
|
ha_innodb.dll!innobase_start_or_create_for_mysql() Line 2548 C++
|
ha_innodb.dll!innobase_init(void * p) Line 3970 C++
|
mysqld.exe!ha_initialize_handlerton(st_plugin_int * plugin) Line 513 C++
|
mysqld.exe!plugin_initialize(st_mem_root * tmp_root, st_plugin_int * plugin, int * argc, char * * argv, bool options_only) Line 1406 C++
|
mysqld.exe!plugin_init(int * argc, char * * argv, int flags) Line 1683 C++
|
mysqld.exe!init_server_components() Line 5148 C++
|
mysqld.exe!win_main(int argc, char * * argv) Line 5737 C++
|
mysqld.exe!mysql_service(void * p) Line 5981 C++
|
mysqld.exe!mysqld_main(int argc, char * * argv) Line 6175 C++
|
mysqld.exe!main(int argc, char * * argv) Line 25 C++
|
[External Code]
|
[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
|
Locals
- bpage 0x08d40898 {space=0x00000000 offset=0x00000001 buf_fix_count=0x00000000 ...} buf_page_t *
|
space 0x00000000 unsigned int
|
offset 0x00000001 unsigned int
|
buf_fix_count 0x00000000 unsigned int
|
io_fix 0x00000001 unsigned int
|
state 0x00000005 unsigned int
|
flush_type 0x00000000 unsigned int
|
buf_pool_index 0x00000000 unsigned int
|
+ zip {data=0x00000000 <NULL> m_start=0x00000000 m_external=false ...} page_zip_des_t
|
write_size 0x00000000 unsigned long
|
encrypted false bool
|
real_size 0x00000000 unsigned long
|
+ slot 0x00000000 <NULL> buf_tmp_buffer_t *
|
+ hash 0x00000000 <NULL> buf_page_t *
|
in_page_hash 0x00000001 unsigned long
|
in_zip_hash 0x00000000 unsigned long
|
+ list {prev=0x00000000 <NULL> next=0x08d40a50 {space=0x00000000 offset=0x00000000 buf_fix_count=0x00000000 ...} } ut_list_node<buf_page_t>
|
in_flush_list 0x00000000 unsigned long
|
in_free_list 0x00000000 unsigned long
|
newest_modification 0x0000000000000000 unsigned __int64
|
oldest_modification 0x0000000000000000 unsigned __int64
|
+ LRU {prev=0x00000000 <NULL> next=0x08d406e0 {space=0x00000000 offset=0x0000000b buf_fix_count=0x00000000 ...} } ut_list_node<buf_page_t>
|
in_LRU_list 0x00000001 unsigned long
|
old 0x00000000 unsigned int
|
freed_page_clock 0x00000000 unsigned int
|
access_time 0x00000000 unsigned int
|
file_page_was_freed 0x00000000 unsigned long
|
+ buf_pool 0x084a3fa0 {mutex={event=0x08433da8 {handle=0xcdcdcdcd os_mutex={mutex={DebugInfo=0xffffffff {Type=??? ...} ...} ...} ...} ...} ...} buf_pool_t *
|
err DB_PAGE_CORRUPTED (0x00000044) dberr_t
|
evict false bool
|
+ frame 0x08dc0000 "" unsigned char *
|
io_type BUF_IO_READ (0x00000001) buf_io_fix
|
key_version 0x00000000 unsigned int
|
read_page_no 0x00000000 unsigned long
|
read_space_id 0x00000000 unsigned long
|
- space 0x085fb880 {name=0x083ae020 ".\\ibdata1" id=0x00000000 tablespace_version=0x0000000000000001 ...} fil_space_t *
|
+ name 0x083ae020 ".\\ibdata1" char *
|
id 0x00000000 unsigned long
|
tablespace_version 0x0000000000000001 __int64
|
stop_ios 0x00000000 unsigned long
|
stop_new_ops false bool
|
purpose 0x000001f5 unsigned long
|
+ chain {count=0x00000001 start=0x085fbbe0 {space=0x085fb880 {name=0x083ae020 ".\\ibdata1" id=0x00000000 tablespace_version=...} ...} ...} ut_list_base<fil_node_t>
|
size 0x00000980 unsigned long
|
recv_size 0x00000000 unsigned long
|
flags 0x00000180 unsigned long
|
n_reserved_extents 0x00000000 unsigned long
|
n_pending_flushes 0x00000000 unsigned long
|
n_pending_ops 0x00000003 unsigned long
|
n_pending_ios 0x00000002 unsigned long
|
hash 0x00000000 void *
|
name_hash 0x00000000 void *
|
+ latch {lock_word=0x00100000 waiters=0x00000000 recursive=0x00000000 ...} rw_lock_t
|
+ unflushed_spaces {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<fil_space_t>
|
is_in_unflushed_spaces true bool
|
printed_compression_failure false bool
|
+ crypt_data 0x085fb728 {min_key_version=0x00000000 page0_offset=0x000050bc encryption=FIL_ENCRYPTION_DEFAULT (0x00000000) ...} fil_space_crypt_t *
|
file_block_size 0x00000200 unsigned long
|
+ space_list {prev=0x00000000 <NULL> next=0x085fbca8 {name=0x083ae420 ".\\ib_logfile0" id=0xfffffff0 tablespace_version=...} } ut_list_node<fil_space_t>
|
+ rotation_list {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<fil_space_t>
|
is_in_rotation_list false bool
|
magic_n 0x00015d80 unsigned long
|
uncompressed 0x00000001 const unsigned long
|
Locals from case 1.
- block 0x091a0898 {page={space=0x00000000 offset=0x00000001 buf_fix_count=0x00000001 ...} frame=0x09220000 "" ...} buf_block_t *
|
- page {space=0x00000000 offset=0x00000001 buf_fix_count=0x00000001 ...} buf_page_t
|
space 0x00000000 unsigned int
|
offset 0x00000001 unsigned int
|
buf_fix_count 0x00000001 unsigned int
|
io_fix 0x00000000 unsigned int
|
state 0x00000005 unsigned int
|
flush_type 0x00000000 unsigned int
|
buf_pool_index 0x00000000 unsigned int
|
+ zip {data=0x00000000 <NULL> m_start=0x00000000 m_external=false ...} page_zip_des_t
|
write_size 0x00000000 unsigned long
|
encrypted false bool
|
real_size 0x00000000 unsigned long
|
+ slot 0x00000000 <NULL> buf_tmp_buffer_t *
|
+ hash 0x00000000 <NULL> buf_page_t *
|
in_page_hash 0x00000001 unsigned long
|
in_zip_hash 0x00000000 unsigned long
|
+ list {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<buf_page_t>
|
in_flush_list 0x00000001 unsigned long
|
in_free_list 0x00000000 unsigned long
|
newest_modification 0x00000000003167fb unsigned __int64
|
oldest_modification 0x00000000003167f5 unsigned __int64
|
+ LRU {prev=0x00000000 <NULL> next=0x091a06e0 {space=0x00000000 offset=0x0000000b buf_fix_count=0x00000000 ...} } ut_list_node<buf_page_t>
|
in_LRU_list 0x00000001 unsigned long
|
old 0x00000000 unsigned int
|
freed_page_clock 0x00000000 unsigned int
|
access_time 0xcc208128 unsigned int
|
file_page_was_freed 0x00000000 unsigned long
|
+ frame 0x09220000 "" unsigned char *
|
+ unzip_LRU {prev=0x00000000 <NULL> next=0x00000000 <NULL> } ut_list_node<buf_block_t>
|
in_unzip_LRU_list 0x00000000 unsigned long
|
+ mutex {event=0x088c4848 {handle=0xcdcdcdcd os_mutex={mutex={DebugInfo=0xffffffff {Type=??? CreatorBackTraceIndex=...} ...} ...} ...} ...} ib_mutex_t
|
+ lock {lock_word=0x00000000 waiters=0x00000000 recursive=0x00000001 ...} rw_lock_t
|
lock_hash_val 0x00000915 unsigned int
|
check_index_page_at_flush 0x00000000 unsigned long
|
modify_clock 0x0000000000000000 unsigned __int64
|
n_hash_helps 0x00000000 unsigned long
|
n_fields 0x00000001 unsigned long
|
n_bytes 0x00000000 unsigned long
|
left_side 0x00000001 unsigned long
|
n_pointers 0x00000000 unsigned long
|
curr_n_fields 0x00000000 unsigned int
|
curr_n_bytes 0x00000000 unsigned int
|
curr_left_side 0x00000000 unsigned int
|
+ index 0x00000000 <NULL> dict_index_t *
|
+ debug_latch {lock_word=0x000fffff waiters=0x00000000 recursive=0x00000000 ...} rw_lock_t
|
+ buf_pool 0x088c3fa0 {mutex={event=0x08854208 {handle=0xcdcdcdcd os_mutex={mutex={DebugInfo=0xffffffff {Type=??? ...} ...} ...} ...} ...} ...} buf_pool_t *
|
+ chunk 0x087ce420 {mem_size=0x01858000 size=0x00000300 mem=0x091a0000 ...} buf_chunk_t *
|
i 0x00000000 unsigned long
|
offs 0x00000005 unsigned long
|
offset 0x00000000 unsigned long
|
+ ptr 0x09220000 "" const unsigned char *
|
space 0x00000000 unsigned long
|
ptr content:
0x09220000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 31 67 f8 00 05 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 .....................1gø........................
|
0x09220030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................................................
|
Error case 3:
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
|
innodb.doublewrite '32k,innodb_plugin' [ pass ] 45666
|
innodb.doublewrite '32k,innodb_plugin' [ fail ]
|
Test ended at 2017-08-10 15:55:21
|
|
|
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 325: query 'select f1, f2 from t1' failed: 1286: Unknown storage engine 'InnoDB'
|
|
|
The result from queries just before the failure was:
|
< snip >
|
# Test End
|
# ---------------------------------------------------------------
|
# Test Begin: Test if recovery works if first page of
|
# system tablespace is corrupted.
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Ensure that all dirty pages in the system are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Make the first page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 0;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
# Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Corrupt the first page (page_no=0) of the system tablespace.
|
check table t1;
|
Table Op Msg_type Msg_text
|
test.t1 check Error Unknown storage engine 'InnoDB'
|
test.t1 check error Corrupt
|
select f1, f2 from t1;
|
|
|
More results from queries before failure can be found in I:\mysql\10.1\bld\mysql-test\var\log\doublewrite.log
|
|
|
- saving 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-32k,innodb_plugin/' to 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-32k,innodb_plugin/'
|
|
|
Only 1 of 10 completed.
|
--------------------------------------------------------------------------
|
The servers were restarted 0 times
|
Spent 45.666 of 102 seconds executing testcases
|
|
|
Failure: Failed 1/2 tests, 50.00% were successful.
|
|
|
Failing test(s): innodb.doublewrite
|
|
|
The log files in var/log may give you some hint of what went wrong.
|
|
|
If you want to report this error, please read first the documentation
|
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
|
|
|
mysql-test-run: *** ERROR: there were failing test cases
|
Thanks! The buf_block_t matches the ptr; we have block->frame == ptr, and block->state = BUF_BLOCK_FILE_PAGE.
The only mystery is why the second page of the system tablespace (page 0:1) is not a valid change buffer bitmap page.
A possible explanation is that the test was run with innodb_page_size=32k or innodb_page_size=64k, and we got this kicking in:
--source include/kill_mysqld.inc
|
|
|
--echo # Make the first page (page_no=0) of the system tablespace
|
--echo # all zeroes.
|
perl;
|
use IO::Handle;
|
my $fname= "$ENV{'MYSQLD_DATADIR'}ibdata1";
|
open(FILE, "+<", $fname) or die;
|
FILE->autoflush(1);
|
binmode FILE;
|
print FILE chr(0) x ($ENV{'INNODB_PAGE_SIZE'});
|
close FILE;
|
EOF
|
|
|
--source include/start_mysqld.inc
|
Which page size was used when the test failed? Which portion of the test was executing right before the failure? (Look in the subdirectories of mysql-test/var for the test client output.)
My current hypothesis is that somehow, when seeing that the first half of page 0 is filled with zeroes, InnoDB determined the page size to be 16k, and perhaps also loaded a part of the larger page 0 frame to the buffer pool as page 1.
All my failures with innodb.doublewrite,32k,innodb_plugin
Case 1 and 3 seen also with 16k page size. Case 3 with 8k page size, there is some race condition.
Observation it is not always the same place in test:
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Ensure that all dirty pages in the system are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Make the second page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
# Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Make the 2nd page (page_no=1) of the system tablespace
|
# all zeroes.
|
|
|
|
|
- saving 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-8k,innodb_plugin/' to 'I:/mysql/10.1/bld/mysql-test/var/log/innodb.doublewrite-8k,innodb_plugin/'
|
- found 'mysqld.dmp' (0/5)
|
|
|
Trying 'cdb' to get a backtrace
|
Cannot find cdb. Please Install Debugging tools for Windows
|
from http://www.microsoft.com/whdc/devtools/debugging/install64bit.mspx (native x64 version)
|
|
|
Only 1 of 2 completed.
|
--------------------------------------------------------------------------
|
The servers were restarted 0 times
|
Spent 83.045 of 1110 seconds executing testcases
|
|
|
Failure: Failed 1/3 tests, 66.67% were successful.
|
|
|
Failing test(s): innodb.doublewrite
|
|
|
The log files in var/log may give you some hint of what went wrong.
|
|
|
If you want to report this error, please read first the documentation
|
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
|
|
|
mysql-test-run: *** ERROR: there were failing test cases
|
|
|
I:\mysql\10.1\bld\mysql-test>mysql-test-run.pl doublewrite,4k --repeat=100
|
Logging: I:/mysql/10.1/mysql-test/mysql-test-run.pl doublewrite,4k --repeat=100
|
VS config: Debug
|
vardir: I:/mysql/10.1/bld/mysql-test/var
|
Checking leftover processes...
|
Removing old var directory...
|
Creating var directory 'I:/mysql/10.1/bld/mysql-test/var'...
|
Checking supported features...
|
MariaDB Version 10.1.26-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
|
innodb.doublewrite '4k,innodb_plugin' [ fail ]
|
Test ended at 2017-08-10 18:36:08
|
|
|
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 325: query 'select f1, f2 from t1' failed: 1286: Unknown storage engine 'InnoDB'
|
|
|
The result from queries just before the failure was:
|
< snip >
|
# Test End
|
# ---------------------------------------------------------------
|
# Test Begin: Test if recovery works if first page of
|
# system tablespace is corrupted.
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Ensure that all dirty pages in the system are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Make the first page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 0;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
# Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Corrupt the first page (page_no=0) of the system tablespace.
|
check table t1;
|
Table Op Msg_type Msg_text
|
test.t1 check Error Unknown storage engine 'InnoDB'
|
test.t1 check error Corrupt
|
select f1, f2 from t1;
|
I can repeat on Linux (do not use --vardir=/dev/shm) but unfortunately can't get good stack:
innodb.doublewrite '16k,innodb_plugin' w2 [ fail ] Found warnings/errors in server log file!
|
Test ended at 2017-08-10 21:28:46
|
line
|
170810 21:28:43 [ERROR] mysqld got signal 11 ;
|
Attempting backtrace. You can use the following information to find out
|
^ Found warnings in /home/jan/mysql/10.1/mysql-test/var/2/log/mysqld.1.err
|
ok
|
|
|
- saving '/home/jan/mysql/10.1/mysql-test/var/2/log/innodb.doublewrite-16k,innodb_plugin/' to '/home/jan/mysql/10.1/mysql-test/var/log/innodb.doublewrite-16k,innodb_plugin/'
|
- found 'core' (0/5)
|
|
|
Trying 'dbx' to get a backtrace
|
|
|
Trying 'gdb' to get a backtrace from coredump /home/jan/mysql/10.1/mysql-test/var/log/innodb.doublewrite-16k,innodb_plugin/mysqld.1/data/core
|
Core generated by '/home/jan/mysql/10.1/sql/mysqld'
|
Output from gdb follows. The first stack trace is from the failing thread.
|
The following stack traces are from all threads (so the failing one is
|
duplicated).
|
--------------------------
|
[New LWP 31637]
|
[New LWP 31613]
|
[New LWP 31635]
|
[New LWP 31634]
|
[New LWP 31636]
|
[New LWP 31638]
|
[New LWP 31674]
|
[New LWP 31639]
|
[Thread debugging using libthread_db enabled]
|
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
|
Core was generated by `/home/jan/mysql/10.1/sql/mysqld --defaults-group-suffix=.1 --defaults-file=/hom'.
|
Program terminated with signal SIGSEGV, Segmentation fault.
|
#0 0x00007fab33bb4c7b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1
|
[Current thread is 1 (Thread 0x7fab27bfc700 (LWP 31637))]
|
#0 0x00007fab33bb4c7b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1
|
#1 0x00007fab33bb6618 in _Unwind_Backtrace () from /lib/x86_64-linux-gnu/libgcc_s.so.1
|
#2 0x00007fab338fcc6f in __GI___backtrace (array=<optimized out>, size=<optimized out>) at ../sysdeps/x86_64/backtrace.c:110
|
#3 0x000055aa0767c746 in my_print_stacktrace (stack_bottom=0x0, thread_stack=295936) at /home/jan/mysql/10.1/mysys/stacktrace.c:267
|
#4 0x000055aa07018b6f in handle_fatal_signal (sig=11) at /home/jan/mysql/10.1/sql/signal_handler.cc:166
|
#5 <signal handler called>
|
#6 0x00007fab2c38307e in ?? ()
|
#7 0x00007fab2c4f3138 in ?? ()
|
#8 0x0000000000000100 in ?? ()
|
#9 0x0000000000000001 in ?? ()
|
#10 0x00007fab2dfff060 in ?? ()
|
#11 0x0000000100000007 in ?? ()
|
#12 0x00007fab3240e730 in ?? ()
|
#13 0x00007fab2e3f1000 in ?? ()
|
#14 0x00007fab366bf000 in ?? ()
|
#15 0x0000000000000100 in ?? ()
|
#16 0x0000000000000200 in ?? ()
|
#17 0x00007fab27bfbc50 in ?? ()
|
#18 0x00007fab2c386451 in ?? ()
|
#19 0x0000000000000000 in ?? ()
|
jplindst, your comment about SIGSEGV on Linux seems to be a known problem: server crash on shutdown after aborted InnoDB startup. At the end of the test, we have such a scenario that hit SIGSEGV for both me and elenst when running 10.1 with
./mtr --valgrind innodb.doublewrite,16k,innodb_plugin
|
--echo #
|
--echo # MDEV-12600 crash during install_db with innodb_page_size=32K
|
--echo # and ibdata1=3M
|
--echo #
|
let bugdir= $MYSQLTEST_VARDIR/tmp/doublewrite;
|
--mkdir $bugdir
|
|
|
let $check_no_innodb=SELECT * FROM INFORMATION_SCHEMA.ENGINES
|
WHERE engine = 'innodb'
|
AND support IN ('YES', 'DEFAULT', 'ENABLED');
|
|
|
--let $ibp=--innodb-log-group-home-dir=$bugdir --innodb-data-home-dir=$bugdir
|
--let $ibd=$ibp --innodb-undo-tablespaces=0 --innodb-log-files-in-group=2
|
--let $ibp=$ibp --innodb-data-file-path=ibdata1:1M;ibdata2:1M:autoextend
|
|
|
--let $restart_parameters= $ibp
|
--source include/restart_mysqld.inc
|
eval $check_no_innodb;
|
--let SEARCH_PATTERN= \[ERROR\] InnoDB: Cannot create doublewrite buffer
|
--source include/search_pattern_in_file.inc
|
--let $restart_parameters=
|
--source include/restart_mysqld.inc
|
In MariaDB 10.2, I have made numerous fixes to allow the server to shut down cleanly after aborted InnoDB startup. One of the first fixes was January 31, 2017. Such large refactoring is not possible in a GA release.
It seems that we never got this kind of a failure on buildbot.
The problems that were observed on Windows are more alarming, because they seem to hint that the contents of the buffer pool is corrupted, or alternatively that the block->lock is not correctly protecting the block->frame contents during I/O.
For the record, with Valgrind, the crash at shutdown after aborted InnoDB startup looks like this:
2017-08-11 14:43:44 67431040 [Warning] InnoDB: New log files created, LSN=45890
|
2017-08-11 14:43:44 67431040 [ERROR] InnoDB: Cannot create doublewrite buffer: the first file in innodb_data_file_path must be at least 3M.
|
2017-08-11 14:43:44 67431040 [ERROR] InnoDB: Database creation was aborted at /mariadb/10.1/storage/innobase/srv/srv0start.cc [2821] with error Generic error. You may need to delete the ibdata1 file before trying to start up again.
|
2017-08-11 14:43:44 67431040 [ERROR] Plugin 'InnoDB' init function returned error.
|
2017-08-11 14:43:44 67431040 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
|
2017-08-11 14:43:44 67431040 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
…
|
2017-08-11 14:43:44 67431040 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
2017-08-11 14:43:44 67431040 [Warning] /mariadb/10.1/bld/sql/mysqld: unknown option '--loose-pam-debug'
|
2017-08-11 14:43:44 67431040 [Warning] /mariadb/10.1/bld/sql/mysqld: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
2017-08-11 14:43:44 67431040 [Note] Server socket created on IP: '127.0.0.1'.
|
2017-08-11 14:43:45 67431040 [Note] /mariadb/10.1/bld/sql/mysqld: ready for connections.
|
Version: '10.1.26-MariaDB-debug' socket: '/mariadb/10.1/bld/mysql-test/var/tmp/mysqld.1.sock' port: 16000 Source distribution
|
2017-08-11 14:43:46 68348672 [Note] /mariadb/10.1/bld/sql/mysqld: Normal shutdown
|
|
|
2017-08-11 14:43:46 68348672 [Note] Event Scheduler: Purging the queue. 0 events
|
==12404== Thread 5:
|
==12404== Jump to the invalid address stated on the next line
|
==12404== at 0xBC494A7: ???
|
==12404== by 0xBC49855: ???
|
==12404== by 0xBB5A80A: ???
|
==12404== by 0xBD2E339: ???
|
==12404== by 0x4E3F493: start_thread (pthread_create.c:333)
|
==12404== by 0x66AAABE: clone (clone.S:97)
|
==12404== Address 0xbc494a7 is not stack'd, malloc'd or (recently) free'd
|
==12404==
|
170811 14:43:46 [ERROR] mysqld got signal 11 ;
|
Shorter version where page corruption was repeatable Win32Debug
I looked at some of the attached dumps. To my surprise, I did not find any sign of a doublewrite buffer copy of page 0:1 (which is mentioned in some of the buffer pool crashes) in the attachments.
In case2_8k.zip, the doublewrite buffer page numbers are 128‥255, corresponding to the file offset 0x100000‥0x1fffff. In the ibdata1 file, all bytes from 0x100000 to 0x2ffffff are zero. So, the doublewrite buffer was apparently not enabled at all (why? was this the original, unmodified test?). In this test, the failure occurs because the intentionally corrupted page 0:1 cannot be restored (unsurprisingly).
innodb.doublewrite '4k,innodb_plugin' failed on windows http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/4896/steps/test/logs/stdio
innodb.doublewrite '4k,innodb_plugin' w2 [ fail ]
|
Test ended at 2017-08-17 14:19:48
|
|
|
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 247: query 'select f1, f2 from t1' failed: 1932: Table 'test.t1' doesn't exist in engine
|
|
|
The result from queries just before the failure was:
|
< snip >
|
# tablespace is corrupted.
|
select space from information_schema.innodb_sys_tables
|
where name = 'test/t1' into @space_id;
|
# Ensure that dirty pages of table t1 is flushed.
|
flush tables t1 for export;
|
unlock tables;
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Make the 2nd page dirty for table t1
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = @space_id;
|
# Ensure that the dirty pages of table t1 are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Corrupt the 2nd page (page_no=1) of the user tablespace.
|
check table t1;
|
Table Op Msg_type Msg_text
|
test.t1 check Error Table 'test.t1' doesn't exist in engine
|
test.t1 check status Operation failed
|
select f1, f2 from t1;
|
2017-08-17 14:19:24 2452 [ERROR] InnoDB: innodb-page-size mismatch in tablespace .\test\t1.ibd (table test/t1)
|
InnoDB: Error: Current page size 4096 != page size on page 16384
|
2017-08-17 14:19:31 376 [ERROR] InnoDB: innodb-page-size mismatch in tablespace .\test\t1.ibd (table test/t1)
|
InnoDB: Error: Current page size 4096 != page size on page 16384
|
2017-08-17 14:19:45 2024 [ERROR] InnoDB: Database page corruption on disk or a failed file read of tablespace test/t1 page [page id: space=4, page number=1]. You may have to recover from a backup.
|
2017-08-17 14:19:47 5996 [ERROR] InnoDB: Table "test"."t1" is corrupted. Please drop the table and recreate.len 4096; hex
|
2017-08-17 14:19:47 5996 [Warning] InnoDB: Cannot open table test/t1 from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
|
2017-08-17 14:19:47 5996 [ERROR] InnoDB: Table "test"."t1" is corrupted. Please drop the table and recreate.
|
alice, please file separate issues for different problems and try to analyze the logs more carefully.
This MDEV-12905 originally reported a crash during SQL statement execution:
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 220: query 'set global innodb_fil_make_page_dirty_debug = @space_id' failed: 2013: Lost connection to MySQL server during query
|
It appears that the log files for this run are no longer available. I would have wanted to check what is in the corresponding mysqld.1.err file.
The original issue may have been repeated by jplindst who reported later in this issue that the buffer pool contains a corrupted copy of page 0:1, detected in this stack trace:
ha_innodb.dll!abort() Line 51 C++
|
> ha_innodb.dll!buf_block_align_instance(buf_pool_t * buf_pool, const unsigned char * ptr) Line 2864 C++
|
ha_innodb.dll!buf_block_align(const unsigned char * ptr) Line 2894 C++
|
ha_innodb.dll!mtr_memo_contains_page(mtr_t * mtr, const unsigned char * ptr, unsigned long type) Line 420 C++
|
ha_innodb.dll!ibuf_bitmap_page_get_bits_low(const unsigned char * page, unsigned long page_no, unsigned long zip_size, unsigned long latch_type, mtr_t * mtr, unsigned long bit) Line 740 C++
|
ha_innodb.dll!ibuf_merge_or_delete_for_page(buf_block_t * block, unsigned long space_id, unsigned long page_no, unsigned long zip_size, unsigned long update_ibuf_bitmap) Line 4638 C++
|
This MDEV-12905 ticket was also convoluted with reports of a known problem that the server may crash on shutdown after failed InnoDB startup. I fixed the issue in 10.2, but I think that it would require too big changes to 10.1 or earlier.
Let me now extract the relevant data from the logs:
innodb.doublewrite '4k,innodb_plugin' w2 [ fail ]
|
Test ended at 2017-08-17 14:19:48
|
|
|
CURRENT_TEST: innodb.doublewrite
|
mysqltest: At line 247: query 'select f1, f2 from t1' failed: 1932: Table 'test.t1' doesn't exist in engine
|
We have to look for this timestamp 2017-08-17 14:19:48 (give or take a few seconds) in the mysqld.1.err file that corresponds to worker 2. The timestamps 14:19:24 and 14:19:31 are definitely from other runs and not relevant, because they were generated by deliberate fault injection. You also did not dig up the reason why the server did not start up.
The cause for these repeated page dumps could be MDEV-11799.
The server error log suggests that the startup took too long because of the repeated page dumps (InnoDB was still starting up, spitting page dumps), and the server was killed at 14:19:48.
The server restarted only 4 seconds earlier, after forced kill in no_checkpoint-end.inc:
2017-08-17 14:19:42 4012 [Note] InnoDB: Dirtying page:1 of space:4
|
2017-08-17 14:19:44 4500 [Note] D:/winx64-debug/build/sql//Debug/mysqld.exe (mysqld 10.1.27-MariaDB-debug) starting as process 2396 ...
|
The above log snippet corresponds to these lines in doublewrite.test:
--echo # Make the 2nd page dirty for table t1
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = @space_id;
|
|
|
--echo # Ensure that the dirty pages of table t1 are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
|
|
--source include/no_checkpoint_end.inc
|
|
|
--echo # Corrupt the 2nd page (page_no=1) of the user tablespace.
|
perl;
|
use IO::Handle;
|
my $fname= "$ENV{'MYSQLD_DATADIR'}test/t1.ibd";
|
open(FILE, "+<", $fname) or die;
|
FILE->autoflush(1);
|
binmode FILE;
|
seek(FILE, $ENV{'INNODB_PAGE_SIZE'}, SEEK_SET);
|
print FILE chr(0) x ($ENV{'INNODB_PAGE_SIZE'}/2);
|
close FILE;
|
EOF
|
|
|
--source include/start_mysqld.inc
|
To add insult to injury, the CURRENT_TEST line immediately before the next startup is preceded by a page dump (a long sequence of zeroes). The next startup is this one, probably for the retry attempt:
2017-08-17 14:20:02 2500 [Note] D:/winx64-debug/build/sql//Debug/mysqld.exe (mysqld 10.1.27-Maria2017-08-17 14:20:02 2500 [Note] D:/winx64-debug/build/sql//Debug/mysqld.exe (mysqld 10.1.27-MariaDB-debug) starting as process 4912 ...
|
2017-08-17 14:20:02 2500 [Note] InnoDB: innodb-page-size has been changed from the default value 16384 to 4096.
|
So, we have two questions to ask:
- Why did the SELECT time out so quickly (in only 4 seconds) and decide that the server did not start up?
- What was the contents of the doublewrite buffer? Can this be an occurrence of
MDEV-11799(Buildbot does not preserve the ibdata1 file, so we will never know.)
Latest crash on Windows on var.zip test log:
# ---------------------------------------------------------------
|
# Test Begin: Test if recovery works if 2nd page of
|
# system tablespace is full of zeroes.
|
begin;
|
insert into t1 values (6, repeat('%', 400));
|
# Ensure that all dirty pages in the system are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Make the second page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
# Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Make the 2nd page (page_no=1) of the system tablespace
|
# all zeroes.
|
# Start 7
|
#
|
I can confirm that the log/mysqld.1.err in var.zip
corresponds to the restart after this fault injection:
--echo # Make the second page dirty for system tablespace
|
set global innodb_saved_page_number_debug = 1;
|
set global innodb_fil_make_page_dirty_debug = 0;
|
|
|
--echo # Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
|
|
--source include/kill_mysqld.inc
|
|
|
--echo # Make the 2nd page (page_no=1) of the system tablespace
|
--echo # all zeroes.
|
I can also confirm that the ibdata1_start7 page 1 (bytes 0x1000 to 0x1fff) are all zero.
Then, I proceeded to start up the server with this file:
./mtr --mem --manual-gdb innodb.doublewrite,innodb_plugin
|
cd /path/to/restored
|
unzip var.zip
|
ln -s backup/ib_logfile0_start7 ib_logfile0
|
ln -s backup/ib_logfile1_start7 ib_logfile1
|
ln -s backup/ibdata1_start7 ibdata1
|
cd -
|
# [interrupt]
|
# [copy and adapt the arguments from the generated file]
|
gdb ../sql/mysqld
|
run --defaults-group-suffix=.1 --defaults-file=/mariadb/10.1/build/mysql-test/var/my.cnf --debug=d,ib_log --log-output=file --gdb --ignore-builtin-innodb --plugin-load-add=ha_innodb.so --innodb-page-size=4K --gdb --innodb-log-group-home-dir=/path/to/restored --innodb-data-home-dir=/path/to/restored
|
Yes, this will point datadir to the instance created by mtr bootstrap. And yes, the t1.ibd is missing. What matters for InnoDB should be the system tablespace and the redo log files.
As expected, no redo log was applied (the redo log was clean). After startup and clean shutdown, the system tablespace page 1 was not recovered from the doublewrite buffer (the file still contained zeroes in that page).
The doublewrite buffer is located at pages 256 to 511:
00005f40: 0032 1fff bd5f 0000 0100 0000 0200 1fff .2..._..........
|
The doublewrite buffer does not contain a copy of that page. It only contains these 3 pages:
unzip -p var.zip backup/ibdata1_start7|od -Ax -t x1 -j 0x100000 -N 0x100000|grep -B 2 '020\>'
|
100000 07 99 92 8b 00 00 03 2c 00 00 00 00 00 00 00 00
|
100010 00 00 00 00 00 0b 2b 34 00 02 00 00 00 00 00 00
|
100020 00 00 00 00 00 00 00 01 01 10 01 1c ff ff ff ff
|
--
|
101000 af 00 06 27 00 00 00 03 ff ff ff ff ff ff ff ff
|
101010 00 00 00 00 00 0b 2d 03 45 bf 00 00 00 00 00 00
|
101020 00 00 00 00 00 04 00 02 02 f9 80 09 01 33 00 24
|
--
|
102000 8e 53 5a c2 00 00 03 2c 00 00 00 00 00 00 00 00
|
102010 00 00 00 00 00 0b 2b 04 00 02 00 00 00 00 00 00
|
102020 00 00 00 00 00 00 00 01 01 10 01 10 ff ff ff ff
|
These are pages 0:0x32c, 4:3 (the clustered index root page of t1_start7.ibd), and 0:0x32c again.
There is no copy of page 0:1, even though the test wanted to write that.
Side note: page 0:0x32c is an undo log page, apparently for updating a record that contains the string gtid_slave_pos:
unzip -p var.zip backup/ibdata1_start7|od -Ax -t x1 -j 0x32c000 -N 0x1000
|
32c000 07 99 92 8b 00 00 03 2c 00 00 00 00 00 00 00 00
|
32c010 00 00 00 00 00 0b 2b 34 00 02 00 00 00 00 00 00
|
32c020 00 00 00 00 00 00 00 01 01 10 01 1c ff ff ff ff
|
32c030 00 00 ff ff ff ff 00 00 00 01 00 56 00 00 00 00
|
32c040 00 00 03 28 09 32 00 00 00 01 00 00 03 2c 00 2c
|
32c050 00 00 03 2c 00 2c 00 00 00 00 00 00 13 04 00 00
|
32c060 00 00 00 00 00 00 00 01 01 10 00 00 00 00 00 00
|
32c070 00 00 00 11 00 00 00 00 00 00 00 00 00 00 00 00
|
32c080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
32c110 01 1c 0b 00 12 04 80 00 00 06 01 10 67 74 69 64
|
32c120 5f 73 6c 61 76 65 5f 70 6f 73 01 10 01 41 0b 01
|
So, the assertion failure is catching a genuine bug: the page 0:1 that our test intentionally corrupted was loaded in corrupted form to the buffer pool.
Actually, it is revealing 2 bugs:
- innodb_fil_make_page_dirty_debug somehow skipped the write to the doublewrite buffer
- we loaded an all-zero page into the buffer pool; maybe in
MDEV-13542we should return an error to the buf_page_get_gen() caller for trying to read all-zero pages
jplindst, I am reassigning this to you, because you can repeat this in your environment.
For me, the doublewrite buffer does contain a copy of the page 0:1 at that point of the test:
diff --git a/mysql-test/suite/innodb/t/doublewrite.test b/mysql-test/suite/innodb/t/doublewrite.test
|
index aba3d6ecff5..8fb7a339f6a 100644
|
--- a/mysql-test/suite/innodb/t/doublewrite.test
|
+++ b/mysql-test/suite/innodb/t/doublewrite.test
|
@@ -380,6 +380,7 @@ set global innodb_fil_make_page_dirty_debug = 0;
|
--echo # Ensure that the dirty page of system tablespace is also flushed.
|
set global innodb_buf_flush_list_now = 1;
|
|
+--copy_file $MYSQLD_DATADIR/ibdata1 $MYSQLD_DATADIR/ibdata1_start7
|
--source include/kill_mysqld.inc
|
|
--echo # Make the 2nd page (page_no=1) of the system tablespace |
./mtr --mem innodb.doublewrite,4k,innodb_plugin
|
od -Ax -t x1 var/mysqld.1/data/ibdata1_start7 -j 0x100000 -N 0x100000|grep -B 2 '020\>'
|
100000 f2 e6 bb 7a 00 00 00 01 00 00 00 00 00 00 00 00
|
100010 00 00 00 00 00 0b 2f 38 00 05 00 00 00 00 00 00
|
100020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
--
|
101000 ae f6 82 52 00 00 00 03 ff ff ff ff ff ff ff ff
|
101010 00 00 00 00 00 0b 2f 32 45 bf 00 00 00 00 00 00
|
101020 00 00 00 00 00 04 00 02 02 f9 80 09 01 33 00 24
|
--
|
102000 48 76 9e cd 00 00 03 2c 00 00 00 00 00 00 00 00
|
102010 00 00 00 00 00 0b 2d 33 00 02 00 00 00 00 00 00
|
102020 00 00 00 00 00 00 00 01 01 10 01 10 ff ff ff ff
|
See, pages 0:1, 4:3, and 0:0x32c are there. And yes, 0:0x32c is an undo log page that looks equivalent to the ibdata1_start7 in var.zip.
Note: the stack trace with the assertion failure is the path how we currently detect the corrupted (all-zero) first change buffer bitmap page of the system tablespace (page 0:1). The change buffer bitmap would be consulted for determining if there are any unmerged changes to pages in the range 2‥innodb_page_size-1. Any read of the pages in the range 0‥innodb_page_size-1 will require page 0:1 to be loaded and consulted. Because the InnoDB internal data dictionary tables are stored in this page range, this corruption of the change buffer bitmap page should be noticed on every server InnoDB startup, when the 4 hard-coded InnoDB dictionary tables are being loaded in dict_boot().
(I cannot currently explain why it did not fail for me when I tried to start up InnoDB on the ibdata1_start7 file.)
One more failure on 32-bit Windows:
innodb.doublewrite '64k,innodb_plugin' w4 [ fail ]
|
Test ended at 2017-09-25 09:06:38
|
|
|
CURRENT_TEST: innodb.doublewrite
|
|
|
|
|
Server [mysqld.1 - pid: 1212, winpid: 1212, exit: 768] failed during test run
|
…
|
# Ensure that dirty pages of table t1 are flushed.
|
set global innodb_buf_flush_list_now = 1;
|
# Kill the server
|
# Corrupt the first page (page_no=0) of the user tablespace.
|
|
|
|
|
|
|
- saving 'D:/win32-debug/build/mysql-test/var/4/log/innodb.doublewrite-64k,innodb_plugin/' to 'D:/win32-debug/build/mysql-test/var/log/innodb.doublewrite-64k,innodb_plugin/'
|
|
|
Retrying test innodb.doublewrite, attempt(2/3)...
|
|
|
***Warnings generated in error logs during shutdown after running tests: innodb.doublewrite
|
|
|
2017-09-25 9:06:31 5108 [ERROR] InnoDB: innodb-page-size mismatch in tablespace .\test\t1.ibd (table test/t1)
|
InnoDB: Error: Current page size 65536 != page size on page 16384
|
2017-09-25 9:06:37 6752 [ERROR] InnoDB: innodb-page-size mismatch in tablespace .\test\t1.ibd (table test/t1)
|
2017-09-25 9:06:37 6752 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 4
|
I believe that I have repeated the same problem once on 10.2, using
cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DWITH_ASAN=1
|
with the following symptoms:
CURRENT_TEST: innodb.log_file_name
|
mysqltest: At line 135: query 'SELECT * FROM t3' failed: 2013: Lost connection to MySQL server during query
|
This SELECT should be the very first SQL access to table t3 after the server was originally killed. Before the kill, there were only INSERT and COMMIT, so there should be nothing to roll back or (in 10.2, before MDEV-12288 which is in 10.3) to purge:
--source include/no_checkpoint_start.inc
|
CREATE TABLE t3(a INT PRIMARY KEY) ENGINE=InnoDB; |
|
|
BEGIN; |
INSERT INTO t3 VALUES (33101),(347); |
INSERT INTO t1 VALUES (42),(9),(101); |
RENAME TABLE t1 TO t2; |
UPDATE t2 SET a=347 where a=42; |
COMMIT; |
|
|
--let CLEANUP_IF_CHECKPOINT=DROP TABLE t2,t3;
|
--source include/no_checkpoint_end.inc |
The last statement would kill the server. After this, the test does move t3.ibd around, and it is expecting the InnoDB startup to fail due to various consistencies that should prevent a redo log apply (WL#7142) and cause InnoDB to refuse startup.
The crashing SELECT is after the very first expected-to-be-successful recovery attempt:
# Restore t2.ibd
|
--remove_file $MYSQLD_DATADIR/test/t2.ibd
|
--move_file $MYSQLD_DATADIR/test/t.ibd $MYSQLD_DATADIR/test/t2.ibd
|
|
|
--source include/start_mysqld.inc
|
|
|
SELECT * FROM t2; |
SELECT * FROM t3; |
The crash occurs, because the file t3.ibd is uninitialized, except for the first page that contains some valid information:
od -Ax -t x1 bld/mysql-test/var/log/innodb.log_file_name-innodb/mysqld.1/data/test/t3.ibd
|
000000 d7 ca d3 0a 00 00 00 00 00 00 00 00 00 00 00 00
|
000010 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
000020 00 00 00 00 00 b3 00 00 00 b3 00 00 00 00 00 00
|
000030 00 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00
|
000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
003ff0 00 00 00 00 00 00 00 00 d7 ca d3 0a 00 00 00 00
|
004000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
*
|
018000
|
The doublewrite buffer is located at pages 64 to 128 (I would expect 64 to 192):
od -t x1 -Ax -N 16 -j 0x17f40 bld/mysql-test/var/log/innodb.log_file_name-innodb/mysqld.1/data/ibdata1
|
017f40 0a b2 1f ff bd 5f 00 00 00 40 00 00 00 80 1f ff
|
017f50
|
Looking at pages 64 to 192, I see no buffered changes for this tablespace (space_id=0xb3):
od -t x1 -Ax -N 0x200000 -j 0x100000 bld/mysql-test/var/log/innodb.log_file_name-innodb/mysqld.1/data/ibdata1 |grep -B 2 '[048c]020\>.*b3'
|
114000 f1 f2 81 12 00 00 00 0c ff ff ff ff ff ff ff ff
|
114010 00 00 00 00 05 b5 54 25 45 bf 00 00 00 00 00 00
|
114020 00 00 00 00 00 00 00 06 1b dc 00 b3 1b 3f 18 60
|
The false match is for the page 0:12. So, nothing was buffered for t3.ibd.
Here is the SYS_TABLES record for the table. (There were also a couple delete-marked entries; I suppose the name test.t3 was used in some preceding tests.)
000213d0: b200 0000 5000 0000 ae34 b030 2c24 201c ....P....4.0,$ .
|
000213e0: 140d 0700 01e8 1500 7474 6573 742f 7433 ........ttest/t3
|
000213f0: 0000 0000 1b83 d400 0001 8501 1000 0000 ................
|
00021400: 0000 0000 f380 0000 0100 0000 2100 0000 ............!...
|
00021410: 0000 0000 0000 0000 5000 0000 b300 0000 ........P.......
|
This decodes to (NAME,DB_TRX_ID,DB_ROLL_PTR,ID,N_COLS,TYPE,MIX_ID,MIX_LEN,CLUSTER_NAME,SPACE)
as follows: NAME='test/t3',ID=0xf3, N_COLS=1|(ROW_FORMAT!=REDUNDANT), TYPE=0x21, MIX_ID=0, MIX_LEN=0x50,CLUSTER_NAME=NULL,SPACE=0xb3.
For reference, the first byte of the record header is at 0x213d9, and it says that the last column is 4 bytes, ending at offset 0x34 from the record start. This indeed is the field SPACE=0xb3, which matches page 0 of t3.ibd.
I believe that I have proven that the same problem is repeatable on 10.2, with different symptoms. For some reason, before the test killed the server, there was nothing written to the doublewrite buffer for that tablespace 0xb3 (t3.ibd). This looks very very wrong.
For some reason, the problem is more easily repeatable on the 10.1 innodb_plugin on Windows, using the test innodb.doublewrite. Based on the above, I do not think that the problem is limited to that platform.
For the record, here is the relevant part of the error log for the above innodb.log_file_name failure:
CURRENT_TEST: innodb.log_file_name
|
2017-10-11 12:01:15 139847651086784 [Note] /mariadb/10.2/bld/sql/mysqld (mysqld 10.2.10-MariaDB-log) starting as process 30950 ...
|
…
|
2017-10-11 12:01:34 140067481366976 [Note] /mariadb/10.2/bld/sql/mysqld (mysqld 10.2.10-MariaDB-log) starting as process 32089 ...
|
…
|
Version: '10.2.10-MariaDB-log' socket: '/mariadb/10.2/bld/mysql-test/var/tmp/1/mysqld.1.sock' port: 16060 Source distribution
|
2017-10-11 12:01:35 140067061847808 [ERROR] InnoDB: Flag mismatch in page [page id: space=179, page number=3] index `PRIMARY` of table `test`.`t3`
|
2017-10-11 12:01:35 0x7f63e7775700 InnoDB: Assertion failure in file /mariadb/10.2/storage/innobase/btr/btr0btr.cc line 185
|
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.
|
171011 12:01:35 [ERROR] mysqld got signal 6 ;
|
The first startup message is the first (failed) recovery attempt after the test killed the server. There are several failed startup attempts initiated by the test. The last messages are from the last recovery attempt, which should have succeeded.
For the record, on the second recovery attempt we did get this message for the file t3.ibd, and apparently did not refuse startup as expected:
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: Cannot open datafile for read-only: './test/t3.ibd' OS error: 71
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2017-10-11 12:01:21 140400653447616 [ERROR] InnoDB: Could not find a valid tablespace file for `test/t3`. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
|
2017-10-11 12:01:21 140400653447616 [Warning] InnoDB: Ignoring tablespace for `test`.`t3` because it could not be opened.
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: 128 out of 128 rollback segments are active.
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2017-10-11 12:01:21 140400653447616 [Note] InnoDB: 5.7.19 started; log sequence number 95773105
|
This corresponds to the following test snippet:
--echo # Fault 2: Wrong space_id in a dirty file, and a missing file.
|
--move_file $MYSQLD_DATADIR/test/t3.ibd $MYSQLD_DATADIR/test/t1.ibd
|
|
|
--source include/start_mysqld.inc
|
eval $check_no_innodb;
|
|
|
let SEARCH_PATTERN= InnoDB: Ignoring data file '.*t1.ibd' with space ID.*; |
--source include/search_pattern_in_file.inc
|
|
|
let SEARCH_PATTERN= InnoDB: Tablespace \d+ was not found at.*t3.ibd.*; |
--source include/search_pattern_in_file.inc
|
|
|
--source include/shutdown_mysqld.inc |
In the log_file_name.log we indeed got the unexpected result that InnoDB did start up:
# Fault 2: Wrong space_id in a dirty file, and a missing file.
|
SELECT * FROM INFORMATION_SCHEMA.ENGINES
|
WHERE engine = 'innodb'
|
AND support IN ('YES', 'DEFAULT', 'ENABLED');
|
ENGINE SUPPORT COMMENT TRANSACTIONS XA SAVEPOINTS
|
InnoDB YES Supports transactions, row-level locking, foreign keys and encryption for tables YES YES YES
|
FOUND 1 /InnoDB: Ignoring data file '.*t1.ibd' with space ID.*/ in mysqld.1.err
|
FOUND 1 /InnoDB: Tablespace \d+ was not found at.*t3.ibd.*/ in mysqld.1.err
|
It is theoretically possible that the doublewrite entries for t3.ibd were cleared at this recovery attempt, which should have failed. We really should have refused to start up the server, because --innodb-force-recovery was not specified and we were unable to find a data file for which there were changes since the latest redo log checkpoint.
To track the Fault 2 mentioned above, I filed the following issue:
MDEV-14049 InnoDB fails to refuse startup when a file is not found in crash recovery
One last dump before I abandon the dataset. Here are the page headers for all doublewrite buffer entries that are not referring to the system tablespace (I separately verified that the maximum space ID was less than 0xff):
od -t x1 -Ax -N 0x200000 -j 0x100000 bld/mysql-test/var/log/innodb.log_file_name-innodb/mysqld.1/data/ibdata1 |grep -B 2 '[048c]020\> .. .. 00 00 00 0\?[^0]'
|
138000 15 ff db 5e 00 00 00 01 00 00 00 00 00 00 00 00
|
138010 00 00 00 00 05 b5 43 26 00 05 00 00 00 00 00 00
|
138020 00 00 00 00 00 b2 00 00 00 00 00 00 00 00 00 00
|
--
|
13c000 de 52 fa 4d 00 00 00 00 00 00 00 00 00 00 00 00
|
13c010 00 00 00 00 05 b5 50 27 00 08 00 00 00 00 00 00
|
13c020 00 00 00 00 00 b2 00 00 00 b2 00 00 00 00 00 00
|
--
|
144000 72 81 c7 fe 00 00 00 02 00 00 00 00 00 00 00 00
|
144010 00 00 00 00 05 b5 50 27 00 03 00 00 00 00 00 00
|
144020 00 00 00 00 00 b2 ff ff ff ff 00 00 ff ff ff ff
|
--
|
148000 07 3f 5a 7f 00 00 00 03 ff ff ff ff ff ff ff ff
|
148010 00 00 00 00 05 b5 61 e8 45 bf 00 00 00 00 00 00
|
148020 00 00 00 00 00 b2 00 02 00 d0 80 06 00 7d 00 16
|
--
|
170000 5f 47 ec 8e 00 00 00 3f 00 00 00 3e 00 00 00 80
|
170010 00 00 00 00 05 92 b9 a1 45 bf 00 00 00 00 00 00
|
170020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
178000 67 af 59 cc 00 00 00 59 00 00 00 58 00 00 00 5a
|
178010 00 00 00 00 05 91 d2 28 45 bf 00 00 00 00 00 00
|
178020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
17c000 d7 b7 48 fd 00 00 00 5a 00 00 00 59 00 00 00 5b
|
17c010 00 00 00 00 05 92 79 25 45 bf 00 00 00 00 00 00
|
17c020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
180000 67 31 15 c6 00 00 00 80 00 00 00 3f 00 00 00 81
|
180010 00 00 00 00 05 94 25 7d 45 bf 00 00 00 00 00 00
|
180020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
188000 44 91 d0 5b 00 00 00 5b 00 00 00 5a 00 00 00 5c
|
188010 00 00 00 00 05 93 20 82 45 bf 00 00 00 00 00 00
|
188020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
190000 68 f2 38 57 00 00 00 5c 00 00 00 5b 00 00 00 5d
|
190010 00 00 00 00 05 93 c7 7f 45 bf 00 00 00 00 00 00
|
190020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
194000 0e 8c ca c6 00 00 00 81 00 00 00 80 00 00 00 82
|
194010 00 00 00 00 05 95 91 bb 45 bf 00 00 00 00 00 00
|
194020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
198000 98 1e 93 94 00 00 00 5d 00 00 00 5c 00 00 00 5e
|
198010 00 00 00 00 05 94 6e d0 45 bf 00 00 00 00 00 00
|
198020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1a0000 0d 8e 02 82 00 00 00 5e 00 00 00 5d 00 00 00 5f
|
1a0010 00 00 00 00 05 95 15 d9 45 bf 00 00 00 00 00 00
|
1a0020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1a4000 a7 fa cb e3 00 00 00 82 00 00 00 81 00 00 00 83
|
1a4010 00 00 00 00 05 96 fd 97 45 bf 00 00 00 00 00 00
|
1a4020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
1a8000 2d 64 47 e4 00 00 00 5f 00 00 00 5e 00 00 00 60
|
1a8010 00 00 00 00 05 95 bd 8c 45 bf 00 00 00 00 00 00
|
1a8020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1b0000 4c 4b dd 6f 00 00 00 60 00 00 00 5f 00 00 00 61
|
1b0010 00 00 00 00 05 96 64 37 45 bf 00 00 00 00 00 00
|
1b0020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1b8000 f4 8e 1f 88 00 00 00 83 00 00 00 82 00 00 00 84
|
1b8010 00 00 00 00 05 98 6a e8 45 bf 00 00 00 00 00 00
|
1b8020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
1bc000 f6 b8 dd 29 00 00 00 61 00 00 00 60 00 00 00 62
|
1bc010 00 00 00 00 05 97 0b e6 45 bf 00 00 00 00 00 00
|
1bc020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1c0000 0a a2 2e ea 00 00 00 62 00 00 00 61 00 00 00 63
|
1c0010 00 00 00 00 05 97 b2 f3 45 bf 00 00 00 00 00 00
|
1c0020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1c8000 55 86 f7 a6 00 00 00 84 00 00 00 83 00 00 00 c0
|
1c8010 00 00 00 00 05 99 d7 26 45 bf 00 00 00 00 00 00
|
1c8020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
1cc000 92 53 2c 87 00 00 00 63 00 00 00 62 00 00 00 64
|
1cc010 00 00 00 00 05 98 59 9c 45 bf 00 00 00 00 00 00
|
1cc020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1d4000 1f 1a 6a 30 00 00 00 64 00 00 00 63 00 00 00 65
|
1d4010 00 00 00 00 05 99 02 54 45 bf 00 00 00 00 00 00
|
1d4020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1d8000 ff 1f 2e 11 00 00 00 65 00 00 00 64 00 00 00 66
|
1d8010 00 00 00 00 05 99 a8 f6 45 bf 00 00 00 00 00 00
|
1d8020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1dc000 4b e6 50 4c 00 00 00 c0 00 00 00 84 00 00 00 c1
|
1dc010 00 00 00 00 05 9b 42 fa 45 bf 00 00 00 00 00 00
|
1dc020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
1e4000 db 6e 99 79 00 00 00 66 00 00 00 65 00 00 00 67
|
1e4010 00 00 00 00 05 9a 50 9a 45 bf 00 00 00 00 00 00
|
1e4020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1e8000 2f 94 9e 9f 00 00 00 67 00 00 00 66 00 00 00 68
|
1e8010 00 00 00 00 05 9a f7 a3 45 bf 00 00 00 00 00 00
|
1e8020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1f0000 18 17 01 e6 00 00 00 c1 00 00 00 c0 00 00 00 c2
|
1f0010 00 00 00 00 05 9c ae ce 45 bf 00 00 00 00 00 00
|
1f0020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
1f4000 c7 53 33 93 00 00 00 68 00 00 00 67 00 00 00 69
|
1f4010 00 00 00 00 05 9b 9e ec 45 bf 00 00 00 00 00 00
|
1f4020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
1fc000 8a f2 be 75 00 00 00 69 00 00 00 68 00 00 00 6a
|
1fc010 00 00 00 00 05 9c 45 e9 45 bf 00 00 00 00 00 00
|
1fc020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
200000 f8 26 de 50 00 00 00 c2 00 00 00 c1 00 00 00 c3
|
200010 00 00 00 00 05 9e 1b 04 45 bf 00 00 00 00 00 00
|
200020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
204000 87 a8 df 66 00 00 00 6a 00 00 00 69 00 00 00 6b
|
204010 00 00 00 00 05 9c ed a0 45 bf 00 00 00 00 00 00
|
204020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
20c000 e9 03 be ee 00 00 00 6b 00 00 00 6a 00 00 00 6c
|
20c010 00 00 00 00 05 9d 94 4b 45 bf 00 00 00 00 00 00
|
20c020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
210000 10 5c da 2f 00 00 00 c3 00 00 00 c2 00 00 00 c4
|
210010 00 00 00 00 05 9f 86 d8 45 bf 00 00 00 00 00 00
|
210020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
218000 25 b1 90 e4 00 00 00 6c 00 00 00 6b 00 00 00 6d
|
218010 00 00 00 00 05 9e 3b e6 45 bf 00 00 00 00 00 00
|
218020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
21c000 83 6c 47 94 00 00 00 6d 00 00 00 6c 00 00 00 6e
|
21c010 00 00 00 00 05 9e e2 9d 45 bf 00 00 00 00 00 00
|
21c020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
224000 0e 82 e8 6e 00 00 00 c4 00 00 00 c3 00 00 00 c5
|
224010 00 00 00 00 05 a0 f3 16 45 bf 00 00 00 00 00 00
|
224020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
228000 9b a8 ab d8 00 00 00 6e 00 00 00 6d 00 00 00 6f
|
228010 00 00 00 00 05 9f 8a 48 45 bf 00 00 00 00 00 00
|
228020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
22c000 d1 c7 74 02 00 00 00 6f 00 00 00 6e 00 00 00 70
|
22c010 00 00 00 00 05 a0 31 45 45 bf 00 00 00 00 00 00
|
22c020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
234000 dd 74 c0 2a 00 00 00 c5 00 00 00 c4 00 00 00 c6
|
234010 00 00 00 00 05 a2 5f 4c 45 bf 00 00 00 00 00 00
|
234020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
238000 40 79 e6 8d 00 00 00 70 00 00 00 6f 00 00 00 71
|
238010 00 00 00 00 05 a0 d7 f3 45 bf 00 00 00 00 00 00
|
238020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
240000 d6 5e 80 cb 00 00 00 71 00 00 00 70 00 00 00 72
|
240010 00 00 00 00 05 a1 7f 97 45 bf 00 00 00 00 00 00
|
240020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
244000 44 6d 95 85 00 00 00 72 00 00 00 71 00 00 00 73
|
244010 00 00 00 00 05 a2 26 a4 45 bf 00 00 00 00 00 00
|
244020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
248000 af d8 c9 08 00 00 00 c6 00 00 00 c5 00 00 00 c7
|
248010 00 00 00 00 05 a3 cb 20 45 bf 00 00 00 00 00 00
|
248020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
250000 8c 67 c7 07 00 00 00 73 00 00 00 72 00 00 00 74
|
250010 00 00 00 00 05 a2 cd e9 45 bf 00 00 00 00 00 00
|
250020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
258000 b2 1e c2 e0 00 00 00 74 00 00 00 73 00 00 00 75
|
258010 00 00 00 00 05 a3 74 f6 45 bf 00 00 00 00 00 00
|
258020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
25c000 9a f5 a7 2d 00 00 00 c7 00 00 00 c6 00 00 00 c8
|
25c010 00 00 00 00 05 a5 36 f4 45 bf 00 00 00 00 00 00
|
25c020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
260000 7b 09 85 2c 00 00 00 75 00 00 00 74 00 00 00 76
|
260010 00 00 00 00 05 a4 1c 3f 45 bf 00 00 00 00 00 00
|
260020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
268000 79 9b ce 15 00 00 00 76 00 00 00 75 00 00 00 77
|
268010 00 00 00 00 05 a4 c3 48 45 bf 00 00 00 00 00 00
|
268020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
26c000 21 1a e5 5e 00 00 00 c8 00 00 00 c7 00 00 00 c9
|
26c010 00 00 00 00 05 a6 a3 2a 45 bf 00 00 00 00 00 00
|
26c020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
270000 40 03 52 a2 00 00 00 77 00 00 00 76 00 00 00 78
|
270010 00 00 00 00 05 a5 6a f3 45 bf 00 00 00 00 00 00
|
270020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
278000 ae 50 ee ea 00 00 00 78 00 00 00 77 00 00 00 79
|
278010 00 00 00 00 05 a6 11 8e 45 bf 00 00 00 00 00 00
|
278020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
27c000 57 d9 cd 5c 00 00 00 c9 00 00 00 c8 00 00 00 ca
|
27c010 00 00 00 00 05 a8 0f 68 45 bf 00 00 00 00 00 00
|
27c020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
284000 71 96 f8 aa 00 00 00 79 00 00 00 78 00 00 00 7a
|
284010 00 00 00 00 05 a6 b9 45 45 bf 00 00 00 00 00 00
|
284020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
288000 eb 99 ec f6 00 00 00 7a 00 00 00 79 00 00 00 7b
|
288010 00 00 00 00 05 a7 60 52 45 bf 00 00 00 00 00 00
|
288020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
290000 2a f9 2c e5 00 00 00 ca 00 00 00 c9 00 00 00 cb
|
290010 00 00 00 00 05 a9 7c 29 45 bf 00 00 00 00 00 00
|
290020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
294000 cb 30 78 3e 00 00 00 7b 00 00 00 7a 00 00 00 7c
|
294010 00 00 00 00 05 a8 07 02 45 bf 00 00 00 00 00 00
|
294020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
29c000 e4 71 3f 08 00 00 00 7c 00 00 00 7b 00 00 00 7d
|
29c010 00 00 00 00 05 a8 ae a4 45 bf 00 00 00 00 00 00
|
29c020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2a0000 96 c5 60 ef 00 00 00 7d 00 00 00 7c 00 00 00 7e
|
2a0010 00 00 00 00 05 a9 55 c1 45 bf 00 00 00 00 00 00
|
2a0020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2a4000 e8 e3 cc 67 00 00 00 cb 00 00 00 ca 00 00 00 cc
|
2a4010 00 00 00 00 05 aa ec 7e 45 bf 00 00 00 00 00 00
|
2a4020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
2ac000 f7 70 59 32 00 00 00 7e 00 00 00 7d 00 00 00 7f
|
2ac010 00 00 00 00 05 a9 fe 74 45 bf 00 00 00 00 00 00
|
2ac020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2b0000 22 08 75 ce 00 00 00 7f 00 00 00 7e 00 00 01 00
|
2b0010 00 00 00 00 05 aa a7 f3 45 bf 00 00 00 00 00 00
|
2b0020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2b8000 df a2 40 d9 00 00 00 cc 00 00 00 cb 00 00 00 cd
|
2b8010 00 00 00 00 05 ac 5d 98 45 bf 00 00 00 00 00 00
|
2b8020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
2bc000 91 8f 0a 77 00 00 01 00 00 00 00 7f 00 00 01 01
|
2bc010 00 00 00 00 05 ab 51 aa 45 bf 00 00 00 00 00 00
|
2bc020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2c4000 b6 52 02 bb 00 00 01 01 00 00 01 00 00 00 01 02
|
2c4010 00 00 00 00 05 ab fb 25 45 bf 00 00 00 00 00 00
|
2c4020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2c8000 3c df 71 03 00 00 00 cd 00 00 00 cc 00 00 00 ce
|
2c8010 00 00 00 00 05 ad cf 24 45 bf 00 00 00 00 00 00
|
2c8020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
2cc000 e3 c7 10 3d 00 00 01 02 00 00 01 01 00 00 01 03
|
2cc010 00 00 00 00 05 ac a5 4a 45 bf 00 00 00 00 00 00
|
2cc020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2d4000 39 dd 55 ea 00 00 01 03 00 00 01 02 00 00 01 04
|
2d4010 00 00 00 00 05 ad 4e 63 45 bf 00 00 00 00 00 00
|
2d4020 00 00 00 00 00 b0 00 96 3a c5 82 57 00 00 00 00
|
--
|
2d8000 e9 29 66 62 00 00 00 ce 00 00 00 cd 00 00 00 cf
|
2d8010 00 00 00 00 05 af 40 4e 45 bf 00 00 00 00 00 00
|
2d8020 00 00 00 00 00 b0 01 46 3d 68 85 16 00 00 00 00
|
--
|
2e0000 e9 ac 0d 0e 00 00 00 07 ff ff ff ff ff ff ff ff
|
2e0010 00 00 00 00 05 4c d8 c5 45 bf 00 00 00 00 00 00
|
2e0020 00 00 00 00 00 a2 00 02 00 ab 80 06 00 00 00 00
|
--
|
2e4000 c1 0e 67 a6 00 00 00 04 ff ff ff ff ff ff ff ff
|
2e4010 00 00 00 00 05 4c b7 98 45 bf 00 00 00 00 00 00
|
2e4020 00 00 00 00 00 a2 00 02 00 97 80 05 00 00 00 00
|
--
|
2e8000 12 66 dd 54 00 00 00 11 ff ff ff ff ff ff ff ff
|
2e8010 00 00 00 00 05 4b 9c 63 45 bf 00 00 00 00 00 00
|
2e8020 00 00 00 00 00 9e 00 02 00 f3 80 03 00 00 00 00
|
--
|
2ec000 1d 3e e7 19 00 00 00 0a ff ff ff ff ff ff ff ff
|
2ec010 00 00 00 00 05 4b 9c 63 45 bf 00 00 00 00 00 00
|
2ec020 00 00 00 00 00 9e 00 02 00 e9 80 03 00 00 00 00
|
--
|
2f0000 3c fd 30 24 00 00 00 0b ff ff ff ff ff ff ff ff
|
2f0010 00 00 00 00 05 4b 9c 63 45 bf 00 00 00 00 00 00
|
2f0020 00 00 00 00 00 9e 00 02 00 e9 80 03 00 00 00 00
|
There are some entries referring to tablespace 0xb2 (t2.ibd) and many to some earlier tablespaces (such as 0x9e, 0xa2, 0xb0) which were probably created and dropped by earlier tests.
This leads me to believe that in the unexpectedly-not-refused startup attempt "Fault 2", the doublewrite buffer was not emptied, and we indeed did not have doublewrite entries for t3.ibd before the kill. So, the doublewrite buffer bug should affect MariaDB 10.2 as well.
Test report from 10.1 and Windows 32-bit: The difference between successful test run and failed one is that in innodb_plugin when page 1 from tablespace 0 is dirtied it uses buffered doublewrite write for that dirtied page. When test fails that buffered write does not happen i.e. server is killed before the buffered doublewrite page is written.
MDEV-15325 shows how to repeat this deterministically on GNU/Linux.
I wonder if we still encounter this. With an rr replay trace of the killed server and the failed recovery this should be trivial to analyze.
Starting with 10.5 the code is very different, mostly due to MDEV-23855, which streamlined the page flushing and made the doublewrite buffer use asynchronous writes.
In 10.1 (which finally reached its end of life in 2020), the test innodb.doublewrite would also fail due to other reasons (memory corruption after InnoDB failed to start up). The memory leaks and corruption on failed InnoDB startup were only fixed in the 10.2 series.
The last occurrences of innodb.doublewrite test failures that I observed for other than 10.1 branches were:
| branch | revision | platform | timestamp |
|---|---|---|---|
| 10.2 | aed2050e40cb332d54e8d40eb7242309 | win32-debug | 2018-01-01 15:27:00 |
| 10.3 | 956b296248acbe35aa87f056ccf99dbb | kvm-fulltest2 | 2018-06-19 12:01:31 |
All 10.4 failures (there were very few of them in total) that I checked were actually due to MDEV-20159. Also the most recent failures for 10.2 and 10.3 appear to be for something else.
It seems that MDEV-15325 must have fixed this in March 2018. Also MDEV-12699 and related improvements reduced the need for the doublewrite buffer, but that was fixed in April 2019, much later.
Another fail case:
innodb.doublewrite '16k,innodb_plugin' w5 [ fail ] Found warnings/errors in server log file!Test ended at 2017-07-20 10:27:29line170720 10:27:26 [ERROR] mysqld got signal 11 ;Attempting backtrace. You can use the following information to find out^ Found warnings in /dev/shm/5/log/mysqld.1.errok- saving '/dev/shm/5/log/innodb.doublewrite-16k,innodb_plugin/' to '/dev/shm/log/innodb.doublewrite-16k,innodb_plugin/'- found 'core' (0/5)Trying 'dbx' to get a backtraceTrying 'gdb' to get a backtrace from coredump /dev/shm/log/innodb.doublewrite-16k,innodb_plugin/mysqld.1/data/coreCore generated by '/home/jan/mysql/10.1-tmp/sql/mysqld'Output from gdb follows. The first stack trace is from the failing thread.The following stack traces are from all threads (so the failing one isduplicated).--------------------------[New LWP 4838][New LWP 4835][New LWP 4834][New LWP 4836][New LWP 4837][New LWP 4839][New LWP 4804][New LWP 4877][Thread debugging using libthread_db enabled]Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".Core was generated by `/home/jan/mysql/10.1-tmp/sql/mysqld --defaults-group-suffix=.1 --defaults-file='.Program terminated with signal SIGSEGV, Segmentation fault.#0 0x00007fac6946bc7b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1[Current thread is 1 (Thread 0x7fac5cffb700 (LWP 4838))]#0 0x00007fac6946bc7b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1#1 0x00007fac6946d618 in _Unwind_Backtrace () from /lib/x86_64-linux-gnu/libgcc_s.so.1#2 0x00007fac691b3c6f in __GI___backtrace (array=<optimized out>, size=<optimized out>) at ../sysdeps/x86_64/backtrace.c:110#3 0x00005627a70f13e4 in my_print_stacktrace (stack_bottom=0x0, thread_stack=295936) at /home/jan/mysql/10.1-tmp/mysys/stacktrace.c:267#4 0x00005627a6a8e835 in handle_fatal_signal (sig=11) at /home/jan/mysql/10.1-tmp/sql/signal_handler.cc:166#5 <signal handler called>#6 0x00007fac62380f54 in ?? ()#7 0x00007fac624f1838 in ?? ()#8 0x0000000000000100 in ?? ()#9 0x0000000000000000 in ?? ()Thread 8 (Thread 0x7fac6be2bb00 (LWP 4877)):#0 0x00007fac6946b2a5 in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1#1 0x00007fac6946bdef in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1#2 0x00007fac6946d02b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1#3 0x00007fac6946d364 in _Unwind_ForcedUnwind () from /lib/x86_64-linux-gnu/libgcc_s.so.1#4 0x00007fac6bb53d60 in __GI___pthread_unwind (buf=<optimized out>) at unwind.c:121#5 0x00007fac6bb4c585 in __do_cancel () at pthreadP.h:283#6 __pthread_exit (value=<optimized out>) at pthread_exit.c:28#7 0x00005627a678664c in unireg_end () at /home/jan/mysql/10.1-tmp/sql/mysqld.cc:2007#8 0x00005627a6786540 in kill_server (sig_ptr=0x0) at /home/jan/mysql/10.1-tmp/sql/mysqld.cc:1929#9 0x00005627a6786568 in kill_server_thread (arg=0x7fac6bebf050) at /home/jan/mysql/10.1-tmp/sql/mysqld.cc:1952#10 0x00005627a6db36a1 in pfs_spawn_thread (arg=0x7fac5a4290f0) at /home/jan/mysql/10.1-tmp/storage/perfschema/pfs.cc:1860#11 0x00007fac6bb4b494 in start_thread (arg=0x7fac6be2bb00) at pthread_create.c:333#12 0x00007fac691a6aff in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97Thread 7 (Thread 0x7fac6bec4600 (LWP 4804)):#0 0x00007fac691a2597 in madvise () at ../sysdeps/unix/syscall-template.S:84#1 0x00007fac6a814c6e in ?? () from /usr/lib/x86_64-linux-gnu/libjemalloc.so.1#2 0x00007fac6a80f8b5 in ?? () from /usr/lib/x86_64-linux-gnu/libjemalloc.so.1#3 0x00007fac6a8113cd in ?? () from /usr/lib/x86_64-linux-gnu/libjemalloc.so.1#4 0x00005627a6d89489 in pfs_free (ptr=0x7fac63c06000) at /home/jan/mysql/10.1-tmp/storage/perfschema/pfs_global.cc:103#5 0x00005627a6d89b2a in cleanup_host () at /home/jan/mysql/10.1-tmp/storage/perfschema/pfs_host.cc:121#6 0x00005627a6d92dcd in cleanup_performance_schema () at /home/jan/mysql/10.1-tmp/storage/perfschema/pfs_server.cc:181#7 0x00005627a6d92e06 in shutdown_performance_schema () at /home/jan/mysql/10.1-tmp/storage/perfschema/pfs_server.cc:194#8 0x00005627a678692d in mysqld_exit (exit_code=0) at /home/jan/mysql/10.1-tmp/sql/mysqld.cc:2076#9 0x00005627a678e137 in mysqld_main (argc=148, argv=0x7fac67c960c0) at /home/jan/mysql/10.1-tmp/sql/mysqld.cc:5960#10 0x00005627a6783160 in main (argc=24, argv=0x7ffeb00ef7c8) at /home/jan/mysql/10.1-tmp/sql/main.cc:25Thread 6 (Thread 0x7fac5c7fa700 (LWP 4839)):#0 0x00007fac6aec76ca in ?? () from /lib/x86_64-linux-gnu/libaio.so.1#1 0x00007fac62380f54 in ?? ()#2 0x00007fac624f1838 in ?? ()#3 0x0000000000000100 in ?? ()#4 0x0000000000000001 in ?? ()#5 0x00007fac637ff150 in ?? ()#6 0x0000000100000007 in ?? ()#7 0x0000000067c0e850 in ?? ()#8 0x00007fac61113000 in ?? ()#9 0x00007fac6bf62000 in ?? ()#10 0x0000000000000100 in ?? ()#11 0x0000000000000200 in ?? ()#12 0x00007fac5c7f9c50 in ?? ()#13 0x00007fac62384327 in ?? ()#14 0x0000000000000000 in ?? ()Thread 5 (Thread 0x7fac5d7fc700 (LWP 4837)):#0 0x00007fac6aec76ca in ?? () from /lib/x86_64-linux-gnu/libaio.so.1#1 0x00007fac62380f54 in ?? ()#2 0x00007fac624f1838 in ?? ()#3 0x0000000000000100 in ?? ()#4 0x0000000000000001 in ?? ()#5 0x00007fac637ff060 in ?? ()#6 0x0000000100000007 in ?? ()#7 0x0000000067c0e730 in ?? ()#8 0x00007fac63bdd000 in ?? ()#9 0x00007fac6bf76000 in ?? ()#10 0x0000000000000100 in ?? ()#11 0x0000000000000200 in ?? ()#12 0x00007fac5d7fbc50 in ?? ()#13 0x00007fac62384327 in ?? ()#14 0x0000000000000000 in ?? ()Thread 4 (Thread 0x7fac5dffd700 (LWP 4836)):#0 0x00007fac6aec76ca in ?? () from /lib/x86_64-linux-gnu/libaio.so.1#1 0x00007fac62380f54 in ?? ()#2 0x00007fac624f1838 in ?? ()#3 0x0000000000000100 in ?? ()#4 0x0000000000000000 in ?? ()Thread 3 (Thread 0x7fac5efff700 (LWP 4834)):#0 0x00007fac6aec76ca in ?? () from /lib/x86_64-linux-gnu/libaio.so.1#1 0x00007fac62380f54 in ?? ()#2 0x00007fac624f1838 in ?? ()#3 0x0000000000000100 in ?? ()#4 0x0000000000000000 in ?? ()Thread 2 (Thread 0x7fac5e7fe700 (LWP 4835)):#0 0x00007fac6aec76ca in ?? () from /lib/x86_64-linux-gnu/libaio.so.1#1 0x00007fac62380f54 in ?? ()#2 0x00007fac624f1838 in ?? ()#3 0x0000000000000100 in ?? ()#4 0x0000000000000000 in ?? ()Thread 1 (Thread 0x7fac5cffb700 (LWP 4838)):#0 0x00007fac6946bc7b in ?? () from /lib/x86_64-linux-gnu/libgcc_s.so.1#1 0x00007fac6946d618 in _Unwind_Backtrace () from /lib/x86_64-linux-gnu/libgcc_s.so.1#2 0x00007fac691b3c6f in __GI___backtrace (array=<optimized out>, size=<optimized out>) at ../sysdeps/x86_64/backtrace.c:110#3 0x00005627a70f13e4 in my_print_stacktrace (stack_bottom=0x0, thread_stack=295936) at /home/jan/mysql/10.1-tmp/mysys/stacktrace.c:267#4 0x00005627a6a8e835 in handle_fatal_signal (sig=11) at /home/jan/mysql/10.1-tmp/sql/signal_handler.cc:166#5 <signal handler called>#6 0x00007fac62380f54 in ?? ()#7 0x00007fac624f1838 in ?? ()#8 0x0000000000000100 in ?? ()#9 0x0000000000000000 in ?? ()