[MDEV-11740] my_seek: Assertion `pos != (~(my_off_t) 0)' failed while using a corrupt system table Created: 2017-01-07  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2, 10.3, 10.4, 10.5
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: None

Attachments: File data.tar.gz    

 Description   

10.2 08d0a2a8cf

mysqld: /data/src/10.2/mysys/my_seek.c:53: my_seek: Assertion `pos != (~(my_off_t) 0)' failed.
180904 23:25:35 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f99e9045ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x00005638218aeb9d in my_seek (fd=451, pos=18446744073709551615, whence=0, MyFlags=0) at /data/src/10.2/mysys/my_seek.c:53
#9  0x000056382181a598 in inline_mysql_file_seek (src_file=0x563821c17030 "/data/src/10.2/storage/myisam/mi_dynrec.c", src_line=1911, file=451, pos=18446744073709551615, whence=0, flags=0) at /data/src/10.2/include/mysql/psi/mysql_file.h:1229
#10 0x000056382181fb00 in _mi_get_block_info (info=0x7f99e80ffd60, file=451, filepos=18446744073709551615) at /data/src/10.2/storage/myisam/mi_dynrec.c:1911
#11 0x000056382181b423 in unlink_deleted_block (info=0x7f996cfe37d0, block_info=0x7f99e80ffff0) at /data/src/10.2/storage/myisam/mi_dynrec.c:461
#12 0x000056382181c93b in _mi_write_part_record (info=0x7f996cfe37d0, filepos=1156, length=115, next_filepos=388, record=0x7f99e8100090, reclength=0x7f99e8100088, flag=0x7f99e81000ac) at /data/src/10.2/storage/myisam/mi_dynrec.c:732
#13 0x000056382181b007 in write_dynamic_record (info=0x7f996cfe37d0, record=0x7f996d031af8 "_<\360\004test\002sp\002\002sp\001\001\002\002\t", reclength=111) at /data/src/10.2/storage/myisam/mi_dynrec.c:371
#14 0x000056382181ada0 in _mi_write_blob_record (info=0x7f996cfe37d0, record=0x7f996cfec6a8 "\360test", ' ' <repeats 188 times>, "sp     "...) at /data/src/10.2/storage/myisam/mi_dynrec.c:295
#15 0x000056382183f165 in mi_write (info=0x7f996cfe37d0, record=0x7f996cfec6a8 "\360test", ' ' <repeats 188 times>, "sp     "...) at /data/src/10.2/storage/myisam/mi_write.c:146
#16 0x00005638217fb69d in ha_myisam::write_row (this=0x7f996cfebf28, buf=0x7f996cfec6a8 "\360test", ' ' <repeats 188 times>, "sp     "...) at /data/src/10.2/storage/myisam/ha_myisam.cc:922
#17 0x0000563821164671 in handler::ha_write_row (this=0x7f996cfebf28, buf=0x7f996cfec6a8 "\360test", ' ' <repeats 188 times>, "sp     "...) at /data/src/10.2/sql/handler.cc:5959
#18 0x00005638212ccbdd in sp_create_routine (thd=0x7f996c000b00, type=TYPE_ENUM_PROCEDURE, sp=0x7f996cfde388) at /data/src/10.2/sql/sp.cc:1262
#19 0x0000563820ee81ca in mysql_execute_command (thd=0x7f996c000b00) at /data/src/10.2/sql/sql_parse.cc:5711
#20 0x0000563820eeeb4c in mysql_parse (thd=0x7f996c000b00, rawbuf=0x7f996c010fb8 "CREATE PROCEDURE sp() BEGIN END", length=31, parser_state=0x7f99e8101250, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:8009
#21 0x0000563820edc5ca in dispatch_command (command=COM_QUERY, thd=0x7f996c000b00, packet=0x7f996c0191e1 "CREATE PROCEDURE sp() BEGIN END", packet_length=31, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1824
#22 0x0000563820edaf2d in do_command (thd=0x7f996c000b00) at /data/src/10.2/sql/sql_parse.cc:1378
#23 0x000056382102c7c8 in do_handle_one_connection (connect=0x5638250e5580) at /data/src/10.2/sql/sql_connect.cc:1335
#24 0x000056382102c555 in handle_one_connection (arg=0x5638250e5580) at /data/src/10.2/sql/sql_connect.cc:1241
#25 0x00007f99ead1c494 in start_thread (arg=0x7f99e8102700) at pthread_create.c:333
#26 0x00007f99e910293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
Query (0x7f996c010fb8): CREATE PROCEDURE sp() BEGIN END
Connection ID (thread ID): 9
Status: NOT_KILLED

The failure happens after a crash recovery, when the system table (in this case mysql.proc) is corrupted. Apparently it's a debug assertion only. A non-debug build produces an error instead:

MariaDB [test]> CREATE PROCEDURE sp() BEGIN END;
ERROR 126 (HY000): Index for table './mysql/proc.MYI' is corrupt; try to repair it
MariaDB [test]> show warnings;
+-------+------+------------------------------------------------------------------+
| Level | Code | Message                                                          |
+-------+------+------------------------------------------------------------------+
| Error |  145 | Table './mysql/proc' is marked as crashed and should be repaired |
| Error | 1194 | Table 'proc' is marked as crashed and should be repaired         |
| Error | 1034 | 1 client is using or hasn't closed the table properly            |
| Error | 1034 | Found 1156 deleted space in delete link chain. Should be 1440    |
| Error | 1034 | Found 4 deleted rows in delete link chain. Should be 5           |
| Error | 1034 | record delete-link-chain corrupted                               |
| Error | 1034 | Number of rows changed from 3 to 2                               |
| Error |  126 | Index for table './mysql/proc.MYI' is corrupt; try to repair it  |
| Error | 1304 | PROCEDURE sp already exists                                      |
+-------+------+------------------------------------------------------------------+
9 rows in set (0.00 sec)

REPAIR TABLE helps, both for non-debug error and debug failure.

To reproduce, unpack the attached data.tar.gz, start a 10.2 server on it (all default options will do), and run

CREATE PROCEDURE sp() BEGIN END;

or alike.

Note:
It would be helpful for testing purposes if the assertion failure got fixed, as it affects various crash-recovery scenarios, but I understand that it's not a high-priority task, since 10.4 switches system tables to Aria, and whatever failures we get out of it are going to be different.



 Comments   
Comment by Alice Sherepa [ 2020-10-28 ]

I am getting the same assertion with 10.5 (crashing the slave and then recovery)

mysqld: /10.5/mysys/my_seek.c:53: my_seek: Assertion `pos != (~(my_off_t) 0)' failed.
 
Server version: 10.5.7-MariaDB-debug-log
 
linux/raise.c:51(__GI_raise)[0x7f807f472535]
stdlib/abort.c:81(__GI_abort)[0x7f807f47240f]
mysys/my_seek.c:58(my_seek)[0x55bb175a67fb]
myisam/mi_dynrec.c:1912(_mi_get_block_info)[0x55bb17599c34]
myisam/mi_dynrec.c:462(unlink_deleted_block)[0x55bb1759fbcb]
myisam/mi_dynrec.c:900(update_dynamic_record)[0x55bb17598513]
myisam/mi_dynrec.c:273(_mi_update_dynamic_record)[0x55bb17608257]
myisam/mi_update.c:156(mi_update)[0x55bb1754ca6b]
myisam/ha_myisam.cc:1918(ha_myisam::update_row(unsigned char const*, unsigned char const*))[0x55bb161f4c33]
sql/handler.cc:7197(handler::ha_update_row(unsigned char const*, unsigned char const*))[0x55bb16559147]
sql/log_event_server.cc:8347(Update_rows_log_event::do_exec_row(rpl_group_info*))[0x55bb16543e3a]
sql/log_event_server.cc:5672(Rows_log_event::do_apply_event(rpl_group_info*))[0x55bb1578699f]
sql/log_event.h:1498(Log_event::apply_event(rpl_group_info*))[0x55bb15768bb4]
sql/slave.cc:4004(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x55bb15769921]
sql/slave.cc:4191(apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*))[0x55bb15f4138d]
sql/rpl_parallel.cc:61(rpt_handle_event(rpl_parallel_thread::queued_event*, rpl_parallel_thread*))[0x55bb15f48a4e]
sql/rpl_parallel.cc:1362(handle_rpl_parallel_thread)[0x55bb16ac0c96]
nptl/pthread_create.c:487(start_thread)[0x7f807ff42fa3]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f807f5494cf]

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