Bug #109869 Connection failure
Submitted: 1 Feb 2023 6:27 Modified: 2 Feb 2023 11:55
Reporter: Zohaib Faruqui Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:8 OS:Linux
Assigned to: MySQL Verification Team CPU Architecture:Any

[1 Feb 2023 6:27] Zohaib Faruqui
Description:
2023-01-31T05:28:55.529217Z 13306 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and 
will be removed in a future release. Please use caching_sha2_password instead'
2023-01-31T08:46:33.082596Z 18678 [ERROR] [MY-013995] [InnoDB] [FATAL] Field number: 38 too large, Total fields in Record: 38.
2023-01-31T08:46:33.082719Z 18678 [ERROR] [MY-013183] [InnoDB] Assertion failure: rem0wrec.cc:142:ib::fatal triggered thread 1402858560
48896
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/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
2023-01-31T08:46:33Z UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
BuildID[sha1]=13fe4cc6857ad6fa2a5024c674977ce812a055cc
Thread pointer: 0x7f966400d410
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f96d89ddc50 thread_stack 0x100000
/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x41) [0x5646b2dcffc1]
/usr/sbin/mysqld(print_fatal_signal(int)+0x39b) [0x5646b1c5478b]
/usr/sbin/mysqld(my_server_abort()+0x76) [0x5646b1c548d6]
/usr/sbin/mysqld(my_abort()+0xe) [0x5646b2dc9fae]
/usr/sbin/mysqld(ut_dbg_assertion_failed(char const*, char const*, unsigned long)+0x349) [0x5646b3060d39]
/usr/sbin/mysqld(ib::fatal::~fatal()+0xd5) [0x5646b3063545]
/usr/sbin/mysqld(+0x248490e) [0x5646b2f7090e]
/usr/sbin/mysqld(rec_offs_nth_extern(dict_index_t const*, unsigned long const*, unsigned long)+0x5c) [0x5646b2f70b2c]
/usr/sbin/mysqld(+0x24d3be4) [0x5646b2fbfbe4]
/usr/sbin/mysqld(row_sel_store_mysql_rec(unsigned char*, row_prebuilt_t*, unsigned char const*, dtuple_t const*, bool, dict_index_t con
st*, dict_index_t const*, unsigned long const*, bool, lob::undo_vers_t*, mem_block_info_t*&)+0x32e) [0x5646b2fc24ce]
/usr/sbin/mysqld(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long)+0x3504) [0x5646b2fc7c2
4]
/usr/sbin/mysqld(ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function)+0x341) [0x5646b2e2c0c1]
/usr/sbin/mysqld(ha_innobase::index_first(unsigned char*)+0x36) [0x5646b2df7466]
/usr/sbin/mysqld(ha_innobase::rnd_next(unsigned char*)+0x47) [0x5646b2e2c727]
/usr/sbin/mysqld(handler::ha_rnd_next(unsigned char*)+0xfe) [0x5646b1d64f0e]
/usr/sbin/mysqld(TableScanIterator::Read()+0x83) [0x5646b1ebd083]
/usr/sbin/mysqld(filesort(THD*, Filesort*, RowIterator*, unsigned long, unsigned long long, Filesort_info*, Sort_result*, unsigned long
 long*)+0x945) [0x5646b1d50675]
/usr/sbin/mysqld(SortingIterator::DoSort()+0x72) [0x5646b1ebec02]
/usr/sbin/mysqld(SortingIterator::Init()+0x34) [0x5646b1ebec94]
/usr/sbin/mysqld(LimitOffsetIterator::Init()+0x1a) [0x5646b203232a]
/usr/sbin/mysqld(Query_expression::ExecuteIteratorQuery(THD*)+0x30d) [0x5646b1bbeb9d]
/usr/sbin/mysqld(Query_expression::execute(THD*)+0x30) [0x5646b1bbeea0]

How to repeat:
Error occurred all of a sudden, to be honest I don't know how to re produce.
It just simply restarting my service again and again and again
[2 Feb 2023 11:55] MySQL Verification Team
Hi,

You have a data corruption. Could happen due to RAM failure, storage system failure or something else. Follow https://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html (or, better, contact our support team).
[6 Dec 2024 14:50] Przemyslaw Malkowski
I believe this is caused by columns added via the INSTANT algorithm.
I can easily reproduce this crash on versions 8.0.33 up to 8.0.39 when some columns are added in custom positions, resulting in the physical_pos out of order, i.e.:

MySQL > select id,name,ordinal_position,hidden,se_private_data from mysql.columns where table_id=(select id from mysql.tables where name='instant_t') order by ordinal_position;
+-------+-------------+------------------+---------+---------------------------------------------------------------+
| id    | name        | ordinal_position | hidden  | se_private_data                                               |
+-------+-------------+------------------+---------+---------------------------------------------------------------+
| 13714 | id          |                1 | Visible | physical_pos=0;table_id=1173;                                 |
| 13715 | n1          |                2 | Visible | default_null=1;physical_pos=28;table_id=1173;version_added=1; |
| 13716 | a           |                3 | Visible | physical_pos=3;table_id=1173;                                 |
...
| 13736 | w           |               23 | Visible | physical_pos=23;table_id=1173;                                |
| 13737 | n2          |               24 | Visible | default_null=1;physical_pos=29;table_id=1173;version_added=2; |
| 13738 | n3          |               25 | Visible | default_null=1;physical_pos=30;table_id=1173;version_added=2; |
| 13739 | x           |               26 | Visible | physical_pos=24;table_id=1173;                                |
| 13740 | y           |               27 | Visible | physical_pos=25;table_id=1173;                                |
| 13741 | z           |               28 | Visible | physical_pos=26;table_id=1173;                                |
| 13742 | q           |               29 | Visible | physical_pos=27;table_id=1173;                                |
| 13743 | DB_TRX_ID   |               30 | SE      | physical_pos=1;table_id=1173;                                 |
| 13744 | DB_ROLL_PTR |               31 | SE      | physical_pos=2;table_id=1173;                                 |
+-------+-------------+------------------+---------+---------------------------------------------------------------+

Then, running a series of large DELETE queries triggers the following crash:

2024-12-06T14:29:51.593718Z 14 [ERROR] [MY-013995] [InnoDB] [FATAL] Field number: 28 too large, Total fields in Record: 4.
2024-12-06T14:29:51.593749Z 14 [ERROR] [MY-013183] [InnoDB] Assertion failure: rem0wrec.cc:143:ib::fatal triggered thread 139784214247168
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/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
2024-12-06T14:29:51Z UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
BuildID[sha1]=fca49e9dc9269e9757ff439d237d0a86b4258394
Thread pointer: 0x7f21a8001be0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f220c6f6be0 thread_stack 0x100000
/opt/mysql/8.0.39/bin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x2e) [0x20890be]
/opt/mysql/8.0.39/bin/mysqld(print_fatal_signal(int)+0x35f) [0xfcf0bf]
/opt/mysql/8.0.39/bin/mysqld(my_server_abort()+0x6e) [0xfcf1fe]
/opt/mysql/8.0.39/bin/mysqld(my_abort()+0xa) [0x20837aa]
/opt/mysql/8.0.39/bin/mysqld(ut_dbg_assertion_failed(char const*, char const*, unsigned long)+0x312) [0x2293462]
/opt/mysql/8.0.39/bin/mysqld() [0x2295c42]
/opt/mysql/8.0.39/bin/mysqld() [0x21dacb0]
/opt/mysql/8.0.39/bin/mysqld(rec_offs_nth_extern(dict_index_t const*, unsigned long const*, unsigned long)+0x58) [0x21daee8]
/opt/mysql/8.0.39/bin/mysqld() [0x221bab3]
/opt/mysql/8.0.39/bin/mysqld(row_sel_store_mysql_rec(unsigned char*, row_prebuilt_t*, unsigned char const*, dtuple_t const*, bool, dict_index_t const*, dict_index_t const*, unsigned long const*, bool, lob::undo_vers_t*, mem_block_info_t*&)+0x280) [0x221d000]
/opt/mysql/8.0.39/bin/mysqld(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long)+0x2bed) [0x222196d]
/opt/mysql/8.0.39/bin/mysqld(ha_innobase::general_fetch(unsigned char*, unsigned int, unsigned int)+0x1d0) [0x20e5a30]
/opt/mysql/8.0.39/bin/mysqld(handler::ha_index_next(unsigned char*)+0x240) [0x10db290]
/opt/mysql/8.0.39/bin/mysqld(handler::read_range_next()+0x3d) [0x10dbdad]
/opt/mysql/8.0.39/bin/mysqld(ha_innobase::read_range_next()+0x1c) [0x20b423c]
/opt/mysql/8.0.39/bin/mysqld(handler::multi_range_read_next(char**)+0x45) [0x10dbe45]
/opt/mysql/8.0.39/bin/mysqld(handler::ha_multi_range_read_next(char**)+0x28) [0x10d84c8]
/opt/mysql/8.0.39/bin/mysqld(IndexRangeScanIterator::Read()+0x48) [0x12dbbf8]
/opt/mysql/8.0.39/bin/mysqld(Sql_cmd_delete::delete_from_single_table(THD*)+0xd05) [0x132ff45]
/opt/mysql/8.0.39/bin/mysqld(Sql_cmd_dml::execute(THD*)+0x1d4) [0xec3004]
/opt/mysql/8.0.39/bin/mysqld(mysql_execute_command(THD*, bool)+0xb0f) [0xe6b71f]
/opt/mysql/8.0.39/bin/mysqld(dispatch_sql_command(THD*, Parser_state*)+0x4f4) [0xe6f384]
/opt/mysql/8.0.39/bin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0xd24) [0xe70644]
/opt/mysql/8.0.39/bin/mysqld(do_command(THD*)+0x1fe) [0xe72a4e]
/opt/mysql/8.0.39/bin/mysqld() [0xfbfb98]
/opt/mysql/8.0.39/bin/mysqld() [0x26fdc55]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f22254ad609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f222467a353]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f21a8c71af0): delete from db1.instant_t where a like "V%"

Apparently, one of the improvements implemented in MySQL 8.0.40 fixed this bug, particularly these seem potentially related:
* InnoDB: InnoDB did not allow updating a REDUNDANT table column that was altered with NULL as the default value using the INSTANT algorithm. Instead, MySQL unexpectedly halted. (Bug #36840107)
* InnoDB: It was possible for the MySQL server to halt unexpectedly when executing a DELETE or UPDATE statement after a column was dropped using the INSTANT algorithm. (Bug #36723117)

Having said that, I am no longer able to repeat this on 8.0.40.