[MDEV-23512] Process mysqld.exe crashes in row_prebuilt_free -> ut_dbg_assertion_failed -> abort Created: 2020-08-19  Updated: 2023-04-14  Resolved: 2023-04-14

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.3.23
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Andrey Kazachkov Assignee: Marko Mäkelä
Resolution: Cannot Reproduce Votes: 0
Labels: corruption
Environment:

Windows 7 Version 7601 (Service Pack 1) MP (8 procs) x64


Attachments: PNG File a20e2e69-a02a-4109-a0c2-ecbdd8f35fa0.png     Zip Archive ini_and_err_files.zip     Zip Archive my.ini-20200820.zip     Zip Archive my_ini__fixed.zip    
Issue Links:
Relates
relates to MDEV-23434 Failing assertion: magic2 == ROW_PREB... Closed

 Description   

Process mysqld.exe 10.3.23 sporadically crashes while processig different queries.

.err and .ini files are attached

Example 1.
mysqld.exe!my_sigabrt_handler()[my_thr_init.c:485]
mysqld.exe!raise()[signal.cpp:516]
mysqld.exe!abort()[abort.cpp:71]
mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:60]
mysqld.exe!row_prebuilt_free()[row0mysql.cc:1029]
mysqld.exe!ha_innobase::close()[ha_innodb.cc:6520]
mysqld.exe!closefrm()[table.cc:3593]
mysqld.exe!intern_close_table()[table_cache.cc:223]
mysqld.exe!tc_add_table()[table_cache.cc:389]
mysqld.exe!open_table()[sql_base.cc:2005]
mysqld.exe!open_and_process_table()[sql_base.cc:3596]
mysqld.exe!open_tables()[sql_base.cc:4119]
mysqld.exe!open_and_lock_tables()[sql_base.cc:4996]
mysqld.exe!execute_sqlcom_select()[sql_parse.cc:6472]
mysqld.exe!mysql_execute_command()[sql_parse.cc:3772]
mysqld.exe!mysql_parse()[sql_parse.cc:8100]
mysqld.exe!dispatch_command()[sql_parse.cc:1856]
mysqld.exe!do_command()[sql_parse.cc:1395]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:358]
mysqld.exe!tp_callback()[threadpool_common.cc:186]
ntdll.dll!RtlDllShutdownInProgress()
ntdll.dll!DbgUiRemoteBreakin()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x2749f1e20): SELECT `appctrl_exefile`.`binCertId`, `exefile_certificates`.`wstrCertIssuer`, `exefile_certificates`.`binCertSerial`, `exefile_certificates`.`wstrCertSubject`, `exefile_certificates`.`binCertThumbprint`, `exefile_certificates`.`tmCertValidFrom`, `exefile_certificates`.`tmCertValidTo`, CASE WHEN `appctrl_exefile`.`isValidMd5` = 1 THEN `appctrl_exefile`.`md5` ELSE NULL END , `appctrl_exefile`.`binSHA256`, `appctrl_exefile`.`nFileHipsId`, `appctrl_exefile`.`nId`, `appctrl_exefile`.`wstrFileName`, `appctrl_exefile`.`wstrFileNonEmptyName`, `appctrl_exefile`.`nFileType`, `appctrl_exefile`.`nFileVersion`, `appctrl_exefile`.`wstrFileVersion`, `appctrl_exefile`.`tmFirstAppear`, `appctrl_exefile`.`tmCalcFirstStart`, `CategoryAliasTable`.`CategoryNameAlias`, `appctrl_exefile`.`wstrOrganizationName`, `appctrl_exefile`.`wstrProductName`, `appctrl_exefile`.`nProductVersion`, `appctrl_exefile`.`wstrProductVersion`, `appctrl_exefile`.`nCalcTrustedGroupNumber` FROM `_ttmp_srvview_chunk269` INNER JOIN `appctrl_exefile` ON `_ttmp_srvview_chunk269`.`srvview_keyid` = `appctrl_exefile`.`nId` AND `appctrl_exefile`.`nId` BETWEEN 4864 AND 4864 LEFT OUTER JOIN ( SELECT uuid AS 'uuid', CONVERT(name USING utf8) AS CategoryNameAlias FROM v_fc_kl_list
UNION SELECT 0x0000000000000000A3BDDED20FBE7F76 AS 'uuid', _utf8'Various categories' AS CategoryNameAlias
UNION SELECT 0xEAC00100000000000000000000000000 AS 'uuid', utf8'Uncategorized' AS CategoryNameAlias) AS CategoryAliasTable ON `appctrl_exefile`.`CalcKLCategoryUID` = CategoryAliasTable.uuid LEFT OUTER JOIN exefile_certificates ON appctrl_exefile.binCertId = exefile_certificates.binCertId ORDER BY `_ttmp_srvview_chunk269`.chunk_order ASC

Example 2.
mysqld.exe!my_sigabrt_handler()[my_thr_init.c:485]
mysqld.exe!raise()[signal.cpp:547]
mysqld.exe!abort()[abort.cpp:71]
mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:60]
mysqld.exe!row_prebuilt_free()[row0mysql.cc:1030]
mysqld.exe!ha_innobase::close()[ha_innodb.cc:6491]
mysqld.exe!closefrm()[table.cc:3639]
mysqld.exe!intern_close_table()[table_cache.cc:223]
mysqld.exe!tc_add_table()[table_cache.cc:389]
mysqld.exe!open_table()[sql_base.cc:2013]
mysqld.exe!open_and_process_table()[sql_base.cc:3675]
mysqld.exe!open_tables()[sql_base.cc:4144]
mysqld.exe!open_and_lock_tables()[sql_base.cc:5041]
mysqld.exe!mysql_execute_command()[sql_parse.cc:4535]
mysqld.exe!sp_instr_stmt::exec_core()[sp_head.cc:3611]
mysqld.exe!sp_lex_keeper::reset_lex_and_exec_core()[sp_head.cc:3341]
mysqld.exe!sp_instr_stmt::execute()[sp_head.cc:3515]
mysqld.exe!sp_head::execute()[sp_head.cc:1371]
mysqld.exe!sp_head::execute_procedure()[sp_head.cc:2311]
mysqld.exe!do_execute_sp()[sql_parse.cc:2991]
mysqld.exe!Sql_cmd_call::execute()[sql_parse.cc:3231]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6040]
mysqld.exe!sp_instr_stmt::exec_core()[sp_head.cc:3611]
mysqld.exe!sp_lex_keeper::reset_lex_and_exec_core()[sp_head.cc:3341]
mysqld.exe!sp_instr_stmt::execute()[sp_head.cc:3515]
mysqld.exe!sp_head::execute()[sp_head.cc:1371]
mysqld.exe!sp_head::execute_procedure()[sp_head.cc:2311]
mysqld.exe!do_execute_sp()[sql_parse.cc:2991]
mysqld.exe!Sql_cmd_call::execute()[sql_parse.cc:3231]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6040]
mysqld.exe!mysql_parse()[sql_parse.cc:7821]
mysqld.exe!dispatch_command()[sql_parse.cc:1858]
mysqld.exe!do_command()[sql_parse.cc:1401]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:358]
mysqld.exe!tp_callback()[threadpool_common.cc:185]
ntdll.dll!RtlDllShutdownInProgress()
ntdll.dll!DbgUiRemoteBreakin()
kernel32.dll!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x27ea0d2b0): INSERT INTO `hst_host_status` ( `nId` ) SELECT `Hosts`.`nId` FROM `Hosts` LEFT OUTER JOIN `hst_host_status` ON `hst_host_status`.`nId` = `Hosts`.`nId` WHERE `hst_host_status`.`nId` IS NULL

Example 3.
This dump file has a breakpoint exception stored in it.
The stored exception information can be accessed via .ecxr.
mysqld!my_sigabrt_handler+0x3:
00000001`403f2173 c3 ret
0:039> kb500

  1. RetAddr : Args to Child : Call Site
    00 00000001`404732a4 : 00000000`00000016 00000001`40472f4b 00000001`403f2170 00000001`406d3db8 : mysqld!my_sigabrt_handler+0x3 [D:\winx64-packages\build\src\mysys\my_thr_init.c @ 486]
    01 00000001`40471494 : 00000000`7ed5c401 00000000`00000000 00000000`00000000 00000000`00000406 : mysqld!raise+0x228 [minkernel\crts\ucrt\src\appcrt\misc\signal.cpp @ 547]
    02 00000001`4022775c : 00000001`406f72f0 00000001`40c30e28 00000001`406d3db8 00000000`0000018c : mysqld!abort+0x18 [minkernel\crts\ucrt\src\appcrt\startup\abort.cpp @ 71]
    03 00000001`4018783e : 00000002`4e8e2a28 00000000`00000000 00000002`6456e250 00000001`401530bc : mysqld!ut_dbg_assertion_failed+0xac [D:\winx64-packages\build\src\storage\innobase\ut\ut0dbg.cc @ 60]
    04 00000001`4014e597 : 00000002`3db64738 00000002`3aea0150 00000002`3e1a2a98 00000001`40160b3d : mysqld!row_prebuilt_free+0x22e [D:\winx64-packages\build\src\storage\innobase\row\row0mysql.cc @ 1030]
    05 00000001`3fe5bc2c : 00000002`3e1a2968 00000000`00000012 00000000`00000000 00000001`3ff533bc : mysqld!ha_innobase::close+0x17 [D:\winx64-packages\build\src\storage\innobase\handler\ha_innodb.cc @ 6491]
    06 00000001`4005b4f2 : 00000002`896614d8 00000000`7ed5c740 00000000`00000000 00000000`00000000 : mysqld!closefrm+0x2c [D:\winx64-packages\build\src\sql\table.cc @ 3639]
    07 00000001`4005bd65 : 00000000`01494dd8 00000000`00000000 00000002`896614d8 00000000`00000000 : mysqld!intern_close_table+0x22 [D:\winx64-packages\build\src\sql\table_cache.cc @ 223]
    08 00000001`4002b00c : 00000002`6db30528 00000000`00000000 00000000`7ed5c9e8 00000002`00000021 : mysqld!tc_add_table+0x295 [D:\winx64-packages\build\src\sql\table_cache.cc @ 389]
    09 00000001`4002a0ce : 00000002`67669e60 00000002`6db30528 00000002`6766c2c0 00000002`6766c2c0 : mysqld!open_table+0x79c [D:\winx64-packages\build\src\sql\sql_base.cc @ 2013]
    0a 00000001`4002b8ef : 00000000`00000001 00000002`6766c2c0 00000000`7ed5cb00 00000000`00000000 : mysqld!open_and_process_table+0x42e [D:\winx64-packages\build\src\sql\sql_base.cc @ 3675]
    0b 00000001`40029a73 : 00000000`00000002 00000002`6766b028 00000002`ffffff00 00000000`7ed5cad0 : mysqld!open_tables+0x33f [D:\winx64-packages\build\src\sql\sql_base.cc @ 4144]
    0c 00000001`3ffef4a2 : 00000001`00000004 00000001`3fdf0000 00000002`67674d48 00000001`3fdf0000 : mysqld!open_and_lock_tables+0x53 [D:\winx64-packages\build\src\sql\sql_base.cc @ 5041]
    0d (Inline Function) : -------`------- -------`------- -------`------- -------`------- : mysqld!open_and_lock_tables+0x29 [D:\winx64-packages\build\src\sql\sql_base.h @ 503]
    0e 00000001`400835c8 : 00000000`00000000 00000002`6766dd58 00000002`6766dd58 00000000`7ed5d4b4 : mysqld!mysql_execute_command+0x1e12 [D:\winx64-packages\build\src\sql\sql_parse.cc @ 4535]
    0f 00000001`40087f41 : 00000002`6db30528 00000000`00000000 00000002`6766dda0 00000000`7ed5d4b4 : mysqld!sp_instr_stmt::exec_core+0x18 [D:\winx64-packages\build\src\sql\sp_head.cc @ 3611]
    10 00000001`4008445f : 00000002`6db30528 00000000`7ed5d170 00000000`00000000 00000002`6db33220 : mysqld!sp_lex_keeper::reset_lex_and_exec_core+0xf1 [D:\winx64-packages\build\src\sql\sp_head.cc @ 3341]
    11 00000001`40083a8a : 00000002`6db33220 00000002`6db30528 00000002`76807fd0 00000002`6db30528 : mysqld!sp_instr_stmt::execute+0x11f [D:\winx64-packages\build\src\sql\sp_head.cc @ 3515]
    12 00000001`40085318 : 00000000`00000001 00000002`6db34580 00000000`00000001 00000000`00000000 : mysqld!sp_head::execute+0x3fa [D:\winx64-packages\build\src\sql\sp_head.cc @ 1371]
    13 00000001`3ffe9f91 : 00000000`00000000 00000000`00000000 00000000`00000000 ffffffff`ffffffff : mysqld!sp_head::execute_procedure+0x4e8 [D:\winx64-packages\build\src\sql\sp_head.cc @ 2311]
    14 00000001`3ffea512 : 00000002`76807fd0 00000002`6db30528 00000002`6db30528 00000002`a0cab128 : mysqld!do_execute_sp+0xd1 [D:\winx64-packages\build\src\sql\sql_parse.cc @ 2991]
    15 00000001`3fff178f : 00000001`3fdf0000 00000000`00000000 00000001`3fdf0000 00000000`00000000 : mysqld!Sql_cmd_call::execute+0x212 [D:\winx64-packages\build\src\sql\sql_parse.cc @ 3231]
    16 00000001`3fff21c4 : 00000002`6db30528 00000002`6db30528 00000000`7ed5e6f0 00000002`6db33720 : mysqld!mysql_execute_command+0x40ff [D:\winx64-packages\build\src\sql\sql_parse.cc @ 6040]
    17 00000001`3ffe8a0d : 00000002`6db30528 00000000`7ed5e640 00000002`a0cab04c 00000000`00000000 : mysqld!mysql_parse+0x164 [D:\winx64-packages\build\src\sql\sql_parse.cc @ 7821]
    18 00000001`3ffe9e8c : 00000002`6db30528 00000001`4012fcc9 00000002`0000001d 00000002`78d08980 : mysqld!dispatch_command+0x8ad [D:\winx64-packages\build\src\sql\sql_parse.cc @ 1858]
    19 00000001`4012ff94 : 00000002`6db30528 00000001`3d448990 00000000`00000000 00000002`78d08980 : mysqld!do_command+0x1bc [D:\winx64-packages\build\src\sql\sql_parse.cc @ 1401]
    1a 00000001`401300c9 : 00000000`00000000 00000002`78d08980 00000000`779ba788 00000000`00000000 : mysqld!threadpool_process_request+0x64 [D:\winx64-packages\build\src\sql\threadpool_common.cc @ 358]
    1b 00000000`779bceb4 : 00000002`3ea771b0 00000000`00000000 00000002`3ea77260 00000002`3ea77260 : mysqld!tp_callback+0x69 [D:\winx64-packages\build\src\sql\threadpool_common.cc @ 185]
    1c 00000000`77aa9c73 : 00000001`3d3d4100 00000002`8e1a2fe8 00000000`779ba748 00000001`3d3d4100 : ntdll!TppWorkpExecuteCallback+0xa4
    1d 00000000`778a556d : 00000000`00000008 00000001`00010007 00000001`3d3d4100 00000002`3ea77260 : ntdll!TppWorkerThread+0x893
    1e 00000000`77a0385d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
    1f 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d


 Comments   
Comment by Marko Mäkelä [ 2020-08-19 ]

This looks like a corruption of row_prebuilt_t::fetch_cache.
Have you already ruled out a hardware failure by running an extensive memory test? On GNU/Linux, memtester seems to work well, but you might have to boot the computer into memtest86 if nothing comparable exists that could be run within Microsoft Windows.
If the memory has been confirmed to work well, then I think that we would need the table schema and some SQL so that we can try to repeat the bug, because I do not remember any reports like this from our internal stress testing.

Comment by Andrey Kazachkov [ 2020-08-20 ]

> Have you already ruled out a hardware failure by running an extensive memory test?

OK, we will check memory. I will report about results.

Comment by Andrey Kazachkov [ 2020-08-28 ]

Memory is OK.

Comment by Andrey Kazachkov [ 2020-08-28 ]

We mamanged to resolve the problem by changing my.ini file

my.ini with problem is my.ini-20200820.zip
and my.ini with fix is my_ini__fixed.zip

Comment by Andrey Kazachkov [ 2020-08-28 ]

my.ini-20200820.zip my_ini__fixed.zip

Comment by Marko Mäkelä [ 2023-04-14 ]

This kind of bugs would best be caught by running an instrumented server (AppVerif, AddressSanitizer or similar). We make extensive use of AddressSanitizer in our internal InnoDB testing. It is possible that the bug is caused by some stray write outside InnoDB. The bulk of open heap-use-after-free or heap-use-after-poison bugs are outside InnoDB.

Generated at Thu Feb 08 09:22:57 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.