[MDEV-22256] Assertion `length == pack_length()' failed in Field_timestamp_with_dec::sort_string Created: 2020-04-16  Updated: 2022-01-10  Resolved: 2021-12-30

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Delete
Affects Version/s: 10.1, 10.2, 10.3, 10.4, 10.5
Fix Version/s: 10.2.42, 10.3.33, 10.4.23, 10.5.14, 10.6.6, 10.7.2, 10.8.1

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Alexander Barkov
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Relates
relates to MDEV-21831 Assertion `length == pack_length()' f... Closed

 Description    

# mysqld options required for replay:  --sql_mode= 
SET @@SESSION.max_sort_length=4;
 
CREATE TABLE t (c TIMESTAMP(1)) ENGINE=InnoDB;
 
INSERT INTO t VALUES(0);
 
DELETE FROM t ORDER BY c;

Leads to:

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
mysqld: /test/10.5_dbg/sql/field.h:3220: virtual void Field_timestamp_with_dec::sort_string(uchar*, uint): Assertion `length == pack_length()' failed.

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
Core was generated by `/test/MD110420-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x7fdd7f90a700 (LWP 23456))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x0000557fbfd5e21e in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x0000557fbf50408f in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x00007fdd7e04e801 in __GI_abort () at abort.c:79
 
#6  0x00007fdd7e03e39a in __assert_fail_base (fmt=0x7fdd7e1c57d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x557fc00639b1 "length == pack_length()", file=file@entry=0x557fbfead529 "/test/10.5_dbg/sql/field.h", line=line@entry=3220, function=function@entry=0x557fc005d9e0 <Field_timestamp_with_dec::sort_string(unsigned char*, unsigned int)::__PRETTY_FUNCTION__> "virtual void Field_timestamp_with_dec::sort_string(uchar*, uint)") at assert.c:92
 
#7  0x00007fdd7e03e412 in __GI___assert_fail (assertion=assertion@entry=0x557fc00639b1 "length == pack_length()", file=file@entry=0x557fbfead529 "/test/10.5_dbg/sql/field.h", line=line@entry=3220, function=function@entry=0x557fc005d9e0 <Field_timestamp_with_dec::sort_string(unsigned char*, unsigned int)::__PRETTY_FUNCTION__> "virtual void Field_timestamp_with_dec::sort_string(uchar*, uint)") at assert.c:101
 
#8  0x0000557fbf4f63ec in Field_timestamp_with_dec::sort_string (this=0x7fdd5204a0c8, to=0x7fdd52173088 '\245' <repeats 200 times>..., length=4) at /test/10.5_dbg/sql/field.h:3220
 
#9  0x0000557fbf4de05c in Field::make_sort_key_part (this=this@entry=0x7fdd5204a0c8, buff=<optimized out>, buff@entry=0x7fdd52173088 '\245' <repeats 200 times>..., length=<optimized out>) at /test/10.5_dbg/sql/field.cc:1035
 
#10 0x0000557fbf4feaa9 in make_sortkey (to=0x7fdd52173088 '\245' <repeats 200 times>..., param=0x7fdd7f907a90) at /test/10.5_dbg/sql/filesort.cc:3004
 
#11 make_sortkey (param=param@entry=0x7fdd7f907a90, to=0x7fdd52173088 '\245' <repeats 200 times>..., ref_pos=ref_pos@entry=0x7fdd5204a3b0 "", using_packed_sortkeys=using_packed_sortkeys@entry=false) at /test/10.5_dbg/sql/filesort.cc:1338
 
#12 0x0000557fbf50272f in find_all_keys (found_rows=0x7fdd5214a5f0, pq=0x0, tempfile=0x7fdd7f907b30, buffpek_pointers=0x7fdd7f907ca0, fs_info=0x7fdd5214a400, select=0x0, param=0x7fdd7f907a90, thd=0x7fdd52015088) at /test/10.5_dbg/sql/filesort.cc:955
 
#13 filesort (thd=thd@entry=0x7fdd52015088, table=table@entry=0x7fdd520bf088, filesort=filesort@entry=0x7fdd7f908380, tracker=0x7fdd52074f18, join=join@entry=0x0, first_table_bit=first_table_bit@entry=0) at /test/10.5_dbg/sql/filesort.cc:356
 
#14 0x0000557fbf6c92a5 in mysql_delete (thd=thd@entry=0x7fdd52015088, table_list=0x7fdd52074180, conds=<optimized out>, order_list=order_list@entry=0x7fdd52019b30, limit=18446744073709551615, options=<optimized out>, result=0x0) at /test/10.5_dbg/sql/sql_delete.cc:636
 
#15 0x0000557fbf25c99b in mysql_execute_command (thd=thd@entry=0x7fdd52015088) at /test/10.5_dbg/sql/sql_parse.cc:4749
 
#16 0x0000557fbf2679d1 in mysql_parse (thd=thd@entry=0x7fdd52015088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fdd7f909450, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7953
 
#17 0x0000557fbf253719 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fdd52015088, packet=packet@entry=0x7fdd52067089 "DELETE FROM t ORDER BY c", packet_length=packet_length@entry=24, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1839
 
#18 0x0000557fbf251f6f in do_command (thd=0x7fdd52015088) at /test/10.5_dbg/sql/sql_parse.cc:1358
 
#19 0x0000557fbf3aca53 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7fdd568433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
 
#20 0x0000557fbf3acd82 in handle_one_connection (arg=arg@entry=0x7fdd568433a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
 
#21 0x0000557fbf80d080 in pfs_spawn_thread (arg=0x7fdd7d445888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#22 0x00007fdd7ed316db in start_thread (arg=0x7fdd7f90a700) at pthread_create.c:463
 
#23 0x00007fdd7e12f88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.1.45 (dbg), 10.2.32 (dbg), 10.3.23 (dbg), 10.4.13 (dbg), 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (opt), 10.2.32 (opt), 10.3.23 (opt), 10.4.13 (opt), 10.5.2 (opt), 10.5.3 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

 Comments   
Comment by Roel Van de Paar [ 2020-04-22 ]

Secondary testcase

# mysqld options required for replay:  --sql_mode=
 
USE test;
 
SET @@SESSION.max_sort_length=1;
 
CREATE TEMPORARY TABLE t(c DATETIME);
 
INSERT INTO t VALUES(0);
 
DELETE FROM t ORDER BY c;

Almost identical stack, this on is in Field_datetime_with_dec::sort_string. INT instead of DATETIME does not reproduce the issue.

Comment by Roel Van de Paar [ 2020-04-30 ]

Third testcase

# mysqld options required for replay:  --sql_mode=
 
USE test;
 
SET @@SESSION.max_sort_length=4;
 
CREATE TEMPORARY TABLE t1(c INET6,d DATE);
 
INSERT INTO t1 VALUES(0,0);
 
SELECT c FROM t1 ORDER BY c;

Almost identical stack, this on is in Field_inet6::sort_string and only reproduces on 10.5.2 (dbg) and 10.5.3 (dbg) due to INET6 syntax.

Comment by Elena Stepanova [ 2020-07-30 ]

A different but apparently closely related assertion

CREATE TABLE t1 (a INET6);
 
INSERT INTO t1 VALUES ('::'),('f::f');
 
SET SESSION max_sort_length= 8;
 
SELECT CASE 1 WHEN 0 THEN 'foo' ELSE a END AS f FROM t1 GROUP BY f WITH ROLLUP;

10.5 f99de891

 
mariadbd: /data/src/10.5/plugin/type_inet/sql_type_inet.cc:1397: virtual void Type_handler_inet6::make_sort_key_part(uchar*, Item*, const SORT_FIELD_ATTR*, Sort_param*) const: Assertion `Inet6::binary_length() == sort_field->length' failed.
 
200730 21:14:20 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007fc0b9a9ef12 in __GI___assert_fail (assertion=0x56505fe7ef28 "Inet6::binary_length() == sort_field->length", file=0x56505fe7eb30 "/data/src/10.5/plugin/type_inet/sql_type_inet.cc", line=1397, function=0x56505fe7f360 <Type_handler_inet6::make_sort_key_part(unsigned char*, Item*, SORT_FIELD_ATTR const*, Sort_param*) const::__PRETTY_FUNCTION__> "virtual void Type_handler_inet6::make_sort_key_part(uchar*, Item*, const SORT_FIELD_ATTR*, Sort_param*) const") at assert.c:101
 
#8  0x000056505f825a5e in Type_handler_inet6::make_sort_key_part (this=0x565060f6c730 <type_handler_inet6>, to=0x7fc0a4065299 '\245' <repeats 200 times>..., item=0x7fc0a40141c8, sort_field=0x7fc0a4017e20, param=0x7fc0b4639080) at /data/src/10.5/plugin/type_inet/sql_type_inet.cc:1397
 
#9  0x000056505ee59a7a in make_sortkey (param=0x7fc0b4639080, to=0x7fc0a4065298 "\001", '\245' <repeats 199 times>...) at /data/src/10.5/sql/filesort.cc:3002
 
#10 0x000056505ee554b5 in make_sortkey (param=0x7fc0b4639080, to=0x7fc0a4065298 "\001", '\245' <repeats 199 times>..., ref_pos=0x7fc0a40f85f8 "", using_packed_sortkeys=false) at /data/src/10.5/sql/filesort.cc:1338
 
#11 0x000056505ee541ce in find_all_keys (thd=0x7fc0a4000b18, param=0x7fc0b4639080, select=0x7fc0a4017310, fs_info=0x7fc0a4064f40, buffpek_pointers=0x7fc0b46392a0, tempfile=0x7fc0b4639130, pq=0x0, found_rows=0x7fc0a4065130) at /data/src/10.5/sql/filesort.cc:957
 
#12 0x000056505ee52093 in filesort (thd=0x7fc0a4000b18, table=0x7fc0a41a7598, filesort=0x7fc0a40176a0, tracker=0x7fc0a4017d90, join=0x7fc0a4015580, first_table_bit=1) at /data/src/10.5/sql/filesort.cc:357
 
#13 0x000056505eb909d9 in create_sort_index (thd=0x7fc0a4000b18, join=0x7fc0a4015580, tab=0x7fc0a40169d0, fsort=0x7fc0a40176a0) at /data/src/10.5/sql/sql_select.cc:23875
 
#14 0x000056505eb8aba2 in st_join_table::sort_table (this=0x7fc0a40169d0) at /data/src/10.5/sql/sql_select.cc:21625
 
#15 0x000056505eb8a77d in join_init_read_record (tab=0x7fc0a40169d0) at /data/src/10.5/sql/sql_select.cc:21564
 
#16 0x000056505eb88525 in sub_select (join=0x7fc0a4015580, join_tab=0x7fc0a40169d0, end_of_records=false) at /data/src/10.5/sql/sql_select.cc:20638
 
#17 0x000056505eb87a40 in do_select (join=0x7fc0a4015580, procedure=0x0) at /data/src/10.5/sql/sql_select.cc:20175
 
#18 0x000056505eb5b4ab in JOIN::exec_inner (this=0x7fc0a4015580) at /data/src/10.5/sql/sql_select.cc:4450
 
#19 0x000056505eb5a5d7 in JOIN::exec (this=0x7fc0a4015580) at /data/src/10.5/sql/sql_select.cc:4231
 
#20 0x000056505eb5bd08 in mysql_select (thd=0x7fc0a4000b18, tables=0x7fc0a40143d8, fields=..., conds=0x0, og_num=1, order=0x0, group=0x7fc0a4014c08, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fc0a4015558, unit=0x7fc0a4004b30, select_lex=0x7fc0a40139d0) at /data/src/10.5/sql/sql_select.cc:4655
 
#21 0x000056505eb4b9ae in handle_select (thd=0x7fc0a4000b18, lex=0x7fc0a4004a68, result=0x7fc0a4015558, setup_tables_done_option=0) at /data/src/10.5/sql/sql_select.cc:429
 
#22 0x000056505eb10f00 in execute_sqlcom_select (thd=0x7fc0a4000b18, all_tables=0x7fc0a40143d8) at /data/src/10.5/sql/sql_parse.cc:6209
 
#23 0x000056505eb081a7 in mysql_execute_command (thd=0x7fc0a4000b18) at /data/src/10.5/sql/sql_parse.cc:3931
 
#24 0x000056505eb15d4d in mysql_parse (thd=0x7fc0a4000b18, rawbuf=0x7fc0a40138d0 "SELECT CASE 1 WHEN 0 THEN 'foo' ELSE a END AS f FROM t1 GROUP BY f WITH ROLLUP", length=78, parser_state=0x7fc0b463a520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7993
 
#25 0x000056505eb02046 in dispatch_command (command=COM_QUERY, thd=0x7fc0a4000b18, packet=0x7fc0a41af1e9 "", packet_length=78, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1867
 
#26 0x000056505eb0077e in do_command (thd=0x7fc0a4000b18) at /data/src/10.5/sql/sql_parse.cc:1348
 
#27 0x000056505eca607a in do_handle_one_connection (connect=0x565062e8db48, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
 
#28 0x000056505eca5de2 in handle_one_connection (arg=0x565062e8db48) at /data/src/10.5/sql/sql_connect.cc:1312
 
#29 0x000056505f1e4126 in pfs_spawn_thread (arg=0x565062e8d778) at /data/src/10.5/storage/perfschema/pfs.cc:2201
 
#30 0x00007fc0bba274a4 in start_thread (arg=0x7fc0b463b700) at pthread_create.c:456
 
#31 0x00007fc0b9b5bd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Same test case without ROLLUP (or slightly modified in other ways) produces the assertion failure reported in the previous comment:

CREATE TABLE t1 (a INET6);
 
INSERT INTO t1 VALUES ('::'),('f::f');
 
SET SESSION max_sort_length= 8;
 
SELECT CASE 1 WHEN 0 THEN 'foo' ELSE a END AS f FROM t1 GROUP BY f;


mariadbd: /data/src/10.5/plugin/type_inet/sql_type_inet.cc:703: virtual void Field_inet6::sort_string(uchar*, uint): Assertion `length == pack_length()' failed.
 
200730 21:16:22 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007fcacb014f12 in __GI___assert_fail (assertion=0x55770d4e3d07 "length == pack_length()", file=0x55770d4e3b30 "/data/src/10.5/plugin/type_inet/sql_type_inet.cc", line=703, function=0x55770d4e5440 <Field_inet6::sort_string(unsigned char*, unsigned int)::__PRETTY_FUNCTION__> "virtual void Field_inet6::sort_string(uchar*, uint)") at assert.c:101
 
#8  0x000055770ce8e549 in Field_inet6::sort_string (this=0x7fcab4065e00, to=0x7fcab407acc9 '\245' <repeats 200 times>..., length=8) at /data/src/10.5/plugin/type_inet/sql_type_inet.cc:703
 
#9  0x000055770c487b24 in Field::make_sort_key_part (this=0x7fcab4065e00, buff=0x7fcab407acc9 '\245' <repeats 200 times>..., length=8) at /data/src/10.5/sql/field.cc:1035
 
#10 0x000055770c4bea11 in make_sortkey (param=0x7fcac5baefb0, to=0x7fcab407acc8 "\001", '\245' <repeats 199 times>...) at /data/src/10.5/sql/filesort.cc:2994
 
#11 0x000055770c4ba4b5 in make_sortkey (param=0x7fcac5baefb0, to=0x7fcab407acc8 "\001", '\245' <repeats 199 times>..., ref_pos=0x7fcab4065fe8 "x\264\006\264\312\177", using_packed_sortkeys=false) at /data/src/10.5/sql/filesort.cc:1338
 
#12 0x000055770c4b91ce in find_all_keys (thd=0x7fcab4000b18, param=0x7fcac5baefb0, select=0x0, fs_info=0x7fcab407aa40, buffpek_pointers=0x7fcac5baf1d0, tempfile=0x7fcac5baf060, pq=0x0, found_rows=0x7fcab407ac30) at /data/src/10.5/sql/filesort.cc:957
 
#13 0x000055770c4b7093 in filesort (thd=0x7fcab4000b18, table=0x7fcab40650e0, filesort=0x7fcab4017668, tracker=0x7fcab4017818, join=0x7fcab4015570, first_table_bit=1) at /data/src/10.5/sql/filesort.cc:357
 
#14 0x000055770c1f59d9 in create_sort_index (thd=0x7fcab4000b18, join=0x7fcab4015570, tab=0x7fcab4016c88, fsort=0x7fcab4017668) at /data/src/10.5/sql/sql_select.cc:23875
 
#15 0x000055770c1efba2 in st_join_table::sort_table (this=0x7fcab4016c88) at /data/src/10.5/sql/sql_select.cc:21625
 
#16 0x000055770c1ef77d in join_init_read_record (tab=0x7fcab4016c88) at /data/src/10.5/sql/sql_select.cc:21564
 
#17 0x000055770c2043ef in AGGR_OP::end_send (this=0x7fcab4017508) at /data/src/10.5/sql/sql_select.cc:28926
 
#18 0x000055770c1ecfc1 in sub_select_postjoin_aggr (join=0x7fcab4015570, join_tab=0x7fcab4016c88, end_of_records=true) at /data/src/10.5/sql/sql_select.cc:20351
 
#19 0x000055770c1ed324 in sub_select (join=0x7fcab4015570, join_tab=0x7fcab40168e0, end_of_records=true) at /data/src/10.5/sql/sql_select.cc:20586
 
#20 0x000055770c1ecaa6 in do_select (join=0x7fcab4015570, procedure=0x0) at /data/src/10.5/sql/sql_select.cc:20177
 
#21 0x000055770c1c04ab in JOIN::exec_inner (this=0x7fcab4015570) at /data/src/10.5/sql/sql_select.cc:4450
 
#22 0x000055770c1bf5d7 in JOIN::exec (this=0x7fcab4015570) at /data/src/10.5/sql/sql_select.cc:4231
 
#23 0x000055770c1c0d08 in mysql_select (thd=0x7fcab4000b18, tables=0x7fcab40143c8, fields=..., conds=0x0, og_num=1, order=0x0, group=0x7fcab4014bf8, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fcab4015548, unit=0x7fcab4004b30, select_lex=0x7fcab40139c0) at /data/src/10.5/sql/sql_select.cc:4655
 
#24 0x000055770c1b09ae in handle_select (thd=0x7fcab4000b18, lex=0x7fcab4004a68, result=0x7fcab4015548, setup_tables_done_option=0) at /data/src/10.5/sql/sql_select.cc:429
 
#25 0x000055770c175f00 in execute_sqlcom_select (thd=0x7fcab4000b18, all_tables=0x7fcab40143c8) at /data/src/10.5/sql/sql_parse.cc:6209
 
#26 0x000055770c16d1a7 in mysql_execute_command (thd=0x7fcab4000b18) at /data/src/10.5/sql/sql_parse.cc:3931
 
#27 0x000055770c17ad4d in mysql_parse (thd=0x7fcab4000b18, rawbuf=0x7fcab40138d0 "SELECT CASE 1 WHEN 0 THEN 'foo' ELSE a END AS f FROM t1 GROUP BY f", length=66, parser_state=0x7fcac5bb0520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7993
 
#28 0x000055770c167046 in dispatch_command (command=COM_QUERY, thd=0x7fcab4000b18, packet=0x7fcab41af1e9 "", packet_length=66, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1867
 
#29 0x000055770c16577e in do_command (thd=0x7fcab4000b18) at /data/src/10.5/sql/sql_parse.cc:1348
 
#30 0x000055770c30b07a in do_handle_one_connection (connect=0x55770f11bb88, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
 
#31 0x000055770c30ade2 in handle_one_connection (arg=0x55770f11bb88) at /data/src/10.5/sql/sql_connect.cc:1312
 
#32 0x000055770c849126 in pfs_spawn_thread (arg=0x55770f11b7b8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
 
#33 0x00007fcaccf9d4a4 in start_thread (arg=0x7fcac5bb1700) at pthread_create.c:456
 
#34 0x00007fcacb0d1d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Roel Van de Paar [ 2021-08-19 ]

The issue is minor but it does affect tests. Changed.

Comment by Oleksandr Byelkin [ 2021-11-05 ]

bar It looks like something with types, if no, just return it to me please

Comment by Alexander Barkov [ 2021-12-29 ]

This problem does not seem to be repeatable in the latest version.
The patches for MDEV-21580 and MDEV-22715 fixed this.

Comment by Alexander Barkov [ 2021-12-30 ]

The problem itself was fixed earlier by:

  • MDEV-21580
  • MDEV-22715
  • commit b31912fd3525be526cd2852e376bd7d1e7ec4d31 

    Author: Sergei Golubchik <serg@mariadb.org>
    		 
    Date:   Tue Nov 3 23:38:31 2020 +0100
    		 
     
    		 
        MDEV-24033: SIGSEGV in __memcmp_avx2_movbe from queue_insert | SIGSEGV in __
    		 
    memcmp_avx2_movbe from native_compare
    		 
        
        don't allow too small max_sort_length values

Added only 10.2 specific and 10.5 specific tests in two different commints.

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