[MDEV-26507] Assertion `tmp != ((long long) 0x8000000000000000LL)' failed in TIME_from_longlong_datetime_packed Created: 2021-08-30  Updated: 2022-09-28  Resolved: 2022-04-10

Status: Closed
Project: MariaDB Server
Component/s: Temporal Types
Affects Version/s: 10.5, 10.6, 10.7
Fix Version/s: 10.5.16, 10.6.8, 10.7.4, 10.8.3

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

Issue Links:
Blocks
is blocked by MDEV-27673 Warning after "select progress from i... Closed
Relates
relates to MDEV-21406 Wrong result or Assertion `tmp != ((l... Confirmed
relates to MDEV-24510 Assertion `tmp != ((long long) 0x8000... Closed

 Description   

Whilst the assert and testcase area looks similar to MDEV-24510, the affected versions are different and no sql_buffer_result change is required here.

SET SESSION sql_mode='ALLOW_INVALID_DATES';
SELECT * FROM sys.x$innodb_lock_waits;

Leads to:

10.7.0 05e29e177df243b700392b797e26cae43fd3181e (Debug)

mysqld: /test/10.7_dbg/sql/compat56.cc:271: void TIME_from_longlong_datetime_packed(MYSQL_TIME*, longlong): Assertion `tmp != ((long long) 0x8000000000000000LL)' failed.

10.7.0 05e29e177df243b700392b797e26cae43fd3181e (Debug)

Core was generated by `/test/MD280821-mariadb-10.7.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x150015745700 (LWP 138020))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000015002c5c6859 in __GI_abort () at abort.c:79
#2  0x000015002c5c6729 in __assert_fail_base (fmt=0x15002c75c588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x56541cd7ddf8 "tmp != ((long long) 0x8", '0' <repeats 15 times>, "LL)", file=0x56541cd7dbe8 "/test/10.7_dbg/sql/compat56.cc", line=271, function=<optimized out>) at assert.c:92
#3  0x000015002c5d7f36 in __GI___assert_fail (assertion=assertion@entry=0x56541cd7ddf8 "tmp != ((long long) 0x8", '0' <repeats 15 times>, "LL)", file=file@entry=0x56541cd7dbe8 "/test/10.7_dbg/sql/compat56.cc", line=line@entry=271, function=function@entry=0x56541cd7ddb8 "void TIME_from_longlong_datetime_packed(MYSQL_TIME*, longlong)") at assert.c:101
#4  0x000056541c23f89a in TIME_from_longlong_datetime_packed (ltime=ltime@entry=0x150015743090, tmp=tmp@entry=-9223372036854775808) at /test/10.7_dbg/sql/compat56.cc:271
#5  0x000056541c24f827 in Field_datetimef::get_TIME (this=<optimized out>, ltime=0x150015743090, pos=0x14ffe003f77a "", fuzzydate={m_mode = date_mode_t::CONV_NONE}) at /test/10.7_dbg/sql/field.cc:7122
#6  0x000056541c26fab7 in Field_datetimef::get_date (this=<optimized out>, ltime=<optimized out>, fuzzydate=<optimized out>) at /test/10.7_dbg/sql/field.h:3930
#7  0x000056541c26a31e in Field_temporal::save_in_field (this=0x14ffe003b7a0, to=0x14ffe0095248) at /test/10.7_dbg/sql/sql_basic_types.h:281
#8  0x000056541c0df325 in Field::store_field (this=<optimized out>, from=<optimized out>) at /test/10.7_dbg/sql/field.h:908
#9  0x000056541c2702bc in field_conv_incompatible (to=to@entry=0x14ffe0095248, from=from@entry=0x14ffe003b7a0) at /test/10.7_dbg/sql/field_conv.cc:850
#10 0x000056541c27185d in field_conv (to=to@entry=0x14ffe0095248, from=from@entry=0x14ffe003b7a0) at /test/10.7_dbg/sql/field_conv.cc:861
#11 0x000056541bfee18e in Create_tmp_table::finalize (this=this@entry=0x150015743240, thd=thd@entry=0x14ffe0000db8, table=table@entry=0x14ffe0093050, param=param@entry=0x14ffe008f1f8, do_not_open=do_not_open@entry=true, keep_row_order=keep_row_order@entry=false) at /test/10.7_dbg/sql/sql_select.cc:19230
#12 0x000056541bfeed94 in create_tmp_table (thd=0x14ffe0000db8, param=0x14ffe008f1f8, fields=@0x14ffe0038d70: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14ffe0017418, last = 0x14ffe0026f18, elements = 26}, <No data fields>}, group=group@entry=0x0, distinct=distinct@entry=false, save_sum_fields=save_sum_fields@entry=false, select_options=2201707875072, rows_limit=18446744073709551615, table_alias=0x56541d331fe0 <empty_clex_str>, do_not_open=true, keep_row_order=false) at /test/10.7_dbg/sql/sql_select.cc:19605
#13 0x000056541bffeddd in JOIN::create_postjoin_aggr_table (this=this@entry=0x14ffe0038a18, tab=tab@entry=0x14ffe008c910, table_fields=table_fields@entry=0x14ffe0038d70, table_group=0x0, save_sum_fields=<optimized out>, distinct=distinct@entry=false, keep_row_order=false) at /test/10.7_dbg/sql/sql_select.cc:4010
#14 0x000056541c000044 in JOIN::make_aggr_tables_info (this=this@entry=0x14ffe0038a18) at /test/10.7_dbg/sql/sql_select.cc:3589
#15 0x000056541c0132ee in JOIN::optimize_stage2 (this=this@entry=0x14ffe0038a18) at /test/10.7_dbg/sql/sql_select.cc:3225
#16 0x000056541c014f7b in JOIN::optimize_inner (this=this@entry=0x14ffe0038a18) at /test/10.7_dbg/sql/sql_select.cc:2479
#17 0x000056541c015186 in JOIN::optimize (this=this@entry=0x14ffe0038a18) at /test/10.7_dbg/sql/sql_select.cc:1809
#18 0x000056541bf284ab in mysql_derived_optimize (thd=0x14ffe0000db8, lex=0x14ffe0005058, derived=0x14ffe0014328) at /test/10.7_dbg/sql/sql_derived.cc:1064
#19 0x000056541bf27af2 in mysql_handle_single_derived (lex=0x14ffe0005058, derived=derived@entry=0x14ffe0014328, phases=phases@entry=4) at /test/10.7_dbg/sql/sql_derived.cc:200
#20 0x000056541c014ff9 in JOIN::optimize_inner (this=this@entry=0x14ffe0038470) at /test/10.7_dbg/sql/sql_select.cc:2285
#21 0x000056541c015186 in JOIN::optimize (this=this@entry=0x14ffe0038470) at /test/10.7_dbg/sql/sql_select.cc:1809
#22 0x000056541c0157ff in mysql_select (thd=thd@entry=0x14ffe0000db8, tables=0x14ffe0014328, fields=@0x14ffe0013fc8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14ffe00142b8, last = 0x14ffe0082878, elements = 26}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x14ffe002e748, unit=0x14ffe0005120, select_lex=0x14ffe0013d28) at /test/10.7_dbg/sql/sql_select.cc:4977
#23 0x000056541c015b03 in handle_select (thd=thd@entry=0x14ffe0000db8, lex=lex@entry=0x14ffe0005058, result=result@entry=0x14ffe002e748, setup_tables_done_option=setup_tables_done_option@entry=0) at /test/10.7_dbg/sql/sql_select.cc:545
#24 0x000056541bf777ee in execute_sqlcom_select (thd=thd@entry=0x14ffe0000db8, all_tables=0x14ffe0014328) at /test/10.7_dbg/sql/sql_parse.cc:6256
#25 0x000056541bf84678 in mysql_execute_command (thd=thd@entry=0x14ffe0000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.7_dbg/sql/sql_parse.cc:3946
#26 0x000056541bf70b83 in mysql_parse (thd=thd@entry=0x14ffe0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x150015744400) at /test/10.7_dbg/sql/sql_parse.cc:8030
#27 0x000056541bf7f788 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14ffe0000db8, packet=packet@entry=0x14ffe000b739 "SELECT * FROM sys.x$innodb_lock_waits", packet_length=packet_length@entry=37, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_class.h:1358
#28 0x000056541bf82b90 in do_command (thd=0x14ffe0000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1404
#29 0x000056541c0f8f2e in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56541fa01f88, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
#30 0x000056541c0f9533 in handle_one_connection (arg=arg@entry=0x56541fa01f88) at /test/10.7_dbg/sql/sql_connect.cc:1312
#31 0x000056541c562586 in pfs_spawn_thread (arg=0x56541f8e8068) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
#32 0x000015002cad5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#33 0x000015002c6c3293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.6.5 (dbg), 10.7.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.41 (dbg), 10.2.41 (opt), 10.3.32 (dbg), 10.3.32 (opt), 10.4.22 (dbg), 10.4.22 (opt), 10.5.13 (dbg), 10.5.13 (opt), 10.6.5 (opt), 10.7.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.35 (dbg), 5.7.35 (opt), 8.0.26 (dbg), 8.0.26 (opt)



 Comments   
Comment by Vladislav Vaintroub [ 2021-09-23 ]

I removed the "caused by". Roel, adding a view does not cause a regression in C++. If one is inventive, you can create a similar view, mostly likely, it would crash the same in any version.

Comment by Roel Van de Paar [ 2021-09-23 ]

"Added view" here is x$innodb_lock_waits in sys schema introduced in 10.6.

Comment by Roel Van de Paar [ 2021-09-23 ]

With thanks wlad for the idea/comments/discussion.

CREATE ALGORITHM=TEMPTABLE VIEW i AS SELECT a.trx_started FROM INFORMATION_SCHEMA.innodb_lock_waits w JOIN INFORMATION_SCHEMA.innodb_trx a ORDER BY a.trx_wait_started;
SET SESSION sql_mode='ALLOW_INVALID_DATES';
SELECT * FROM i;

Leads to:

10.6.5 1e9c922fa726b22f4522f2a4de0fcb6595404086 (Debug)

mysqld: /test/10.6_dbg/sql/compat56.cc:271: void TIME_from_longlong_datetime_packed(MYSQL_TIME*, longlong): Assertion `tmp != ((long long) 0x8000000000000000LL)' failed.

10.6.5 1e9c922fa726b22f4522f2a4de0fcb6595404086 (Debug)

Core was generated by `/test/MD180921-mariadb-10.6.5-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x14909469c700 (LWP 310731))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000014909827b859 in __GI_abort () at abort.c:79
#2  0x000014909827b729 in __assert_fail_base (fmt=0x149098411588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5561015d9018 "tmp != ((long long) 0x8", '0' <repeats 15 times>, "LL)", file=0x5561015d8e08 "/test/10.6_dbg/sql/compat56.cc", line=271, function=<optimized out>) at assert.c:92
#3  0x000014909828cf36 in __GI___assert_fail (assertion=assertion@entry=0x5561015d9018 "tmp != ((long long) 0x8", '0' <repeats 15 times>, "LL)", file=file@entry=0x5561015d8e08 "/test/10.6_dbg/sql/compat56.cc", line=line@entry=271, function=function@entry=0x5561015d8fd8 "void TIME_from_longlong_datetime_packed(MYSQL_TIME*, longlong)") at assert.c:101
#4  0x0000556100a4d46a in TIME_from_longlong_datetime_packed (ltime=ltime@entry=0x14909469a090, tmp=tmp@entry=-9223372036854775808) at /test/10.6_dbg/sql/compat56.cc:271
#5  0x0000556100a5d3f7 in Field_datetimef::get_TIME (this=<optimized out>, ltime=0x14909469a090, pos=0x14904802f0d2 "", fuzzydate={m_mode = date_mode_t::CONV_NONE}) at /test/10.6_dbg/sql/field.cc:7122
#6  0x0000556100a7d685 in Field_datetimef::get_date (this=<optimized out>, ltime=<optimized out>, fuzzydate=<optimized out>) at /test/10.6_dbg/sql/field.h:3930
#7  0x0000556100a77eec in Field_temporal::save_in_field (this=0x1490480243e0, to=0x1490480368b0) at /test/10.6_dbg/sql/sql_basic_types.h:281
#8  0x00005561008ed783 in Field::store_field (this=<optimized out>, from=<optimized out>) at /test/10.6_dbg/sql/field.h:908
#9  0x0000556100a7de8a in field_conv_incompatible (to=to@entry=0x1490480368b0, from=from@entry=0x1490480243e0) at /test/10.6_dbg/sql/field_conv.cc:850
#10 0x0000556100a7f42b in field_conv (to=to@entry=0x1490480368b0, from=from@entry=0x1490480243e0) at /test/10.6_dbg/sql/field_conv.cc:861
#11 0x00005561007fc4dc in Create_tmp_table::finalize (this=this@entry=0x14909469a240, thd=thd@entry=0x149048000db8, table=table@entry=0x149048035a60, param=param@entry=0x14904802b620, do_not_open=do_not_open@entry=true, keep_row_order=keep_row_order@entry=false) at /test/10.6_dbg/sql/sql_select.cc:19241
#12 0x00005561007fd0e2 in create_tmp_table (thd=0x149048000db8, param=0x14904802b620, fields=@0x1490480292c0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x149048029610, last = 0x149048017a10, elements = 2}, <No data fields>}, group=group@entry=0x0, distinct=distinct@entry=false, save_sum_fields=save_sum_fields@entry=false, select_options=2201707875072, rows_limit=18446744073709551615, table_alias=0x556101babb80 <empty_clex_str>, do_not_open=true, keep_row_order=false) at /test/10.6_dbg/sql/sql_select.cc:19616
#13 0x000055610080d119 in JOIN::create_postjoin_aggr_table (this=this@entry=0x149048028f68, tab=tab@entry=0x1490480331f0, table_fields=table_fields@entry=0x1490480292c0, table_group=0x0, save_sum_fields=<optimized out>, distinct=distinct@entry=false, keep_row_order=false) at /test/10.6_dbg/sql/sql_select.cc:4012
#14 0x000055610080e380 in JOIN::make_aggr_tables_info (this=this@entry=0x149048028f68) at /test/10.6_dbg/sql/sql_select.cc:3591
#15 0x000055610082161c in JOIN::optimize_stage2 (this=this@entry=0x149048028f68) at /test/10.6_dbg/sql/sql_select.cc:3227
#16 0x00005561008232b1 in JOIN::optimize_inner (this=this@entry=0x149048028f68) at /test/10.6_dbg/sql/sql_select.cc:2479
#17 0x00005561008234bc in JOIN::optimize (this=this@entry=0x149048028f68) at /test/10.6_dbg/sql/sql_select.cc:1809
#18 0x00005561007481cb in mysql_derived_optimize (thd=0x149048000db8, lex=0x149048005058, derived=0x149048014600) at /test/10.6_dbg/sql/sql_derived.cc:1064
#19 0x0000556100747812 in mysql_handle_single_derived (lex=0x149048005058, derived=derived@entry=0x149048014600, phases=phases@entry=4) at /test/10.6_dbg/sql/sql_derived.cc:200
#20 0x000055610082332f in JOIN::optimize_inner (this=this@entry=0x1490480289c0) at /test/10.6_dbg/sql/sql_select.cc:2285
#21 0x00005561008234bc in JOIN::optimize (this=this@entry=0x1490480289c0) at /test/10.6_dbg/sql/sql_select.cc:1809
#22 0x0000556100823b35 in mysql_select (thd=thd@entry=0x149048000db8, tables=0x149048014600, fields=@0x1490480142c8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x1490480145b8, last = 0x1490480145b8, elements = 1}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x149048019e70, unit=0x149048005120, select_lex=0x149048014028) at /test/10.6_dbg/sql/sql_select.cc:4979
#23 0x0000556100823e39 in handle_select (thd=thd@entry=0x149048000db8, lex=lex@entry=0x149048005058, result=result@entry=0x149048019e70, setup_tables_done_option=setup_tables_done_option@entry=0) at /test/10.6_dbg/sql/sql_select.cc:545
#24 0x00005561007976af in execute_sqlcom_select (thd=thd@entry=0x149048000db8, all_tables=0x149048014600) at /test/10.6_dbg/sql/sql_parse.cc:6256
#25 0x00005561007a4538 in mysql_execute_command (thd=thd@entry=0x149048000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.6_dbg/sql/sql_parse.cc:3946
#26 0x0000556100790a27 in mysql_parse (thd=thd@entry=0x149048000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14909469b400) at /test/10.6_dbg/sql/sql_parse.cc:8030
#27 0x000055610079f64a in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x149048000db8, packet=packet@entry=0x14904800b769 "SELECT * FROM i", packet_length=packet_length@entry=15, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1358
#28 0x00005561007a2a50 in do_command (thd=0x149048000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1404
#29 0x000055610090738c in do_handle_one_connection (connect=<optimized out>, connect@entry=0x556104c806d8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1418
#30 0x0000556100907991 in handle_one_connection (arg=arg@entry=0x556104c806d8) at /test/10.6_dbg/sql/sql_connect.cc:1312
#31 0x0000556100db6f2e in pfs_spawn_thread (arg=0x556104b8d5a8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#32 0x000014909878a609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#33 0x0000149098378293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.13 (dbg), 10.6.5 (dbg), 10.7.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.41 (dbg), 10.2.41 (opt), 10.3.32 (dbg), 10.3.32 (opt), 10.4.22 (dbg), 10.4.22 (opt), 10.5.13 (opt), 10.6.5 (opt), 10.7.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.35 (dbg), 5.7.35 (opt), 8.0.26 (dbg), 8.0.26 (opt)

Comment by Roel Van de Paar [ 2021-09-23 ]

The issue seems lightly sporadic.

10.2-10.4 Still does not seem affected (whilst the SQL succeeds).

10.3.32 b112c9dfaacbcb7c3548414c6f402114663223dc (Debug)

10.3.32-dbg>CREATE ALGORITHM=TEMPTABLE VIEW i AS SELECT a.trx_started FROM INFORMATION_SCHEMA.innodb_lock_waits w JOIN INFORMATION_SCHEMA.innodb_trx a ORDER BY a.trx_wait_started;
Query OK, 0 rows affected (0.009 sec)
 
10.3.32-dbg>SET SESSION sql_mode='ALLOW_INVALID_DATES';
Query OK, 0 rows affected (0.001 sec)
 
10.3.32-dbg>SELECT * FROM i;
Empty set (0.004 sec)

Comment by Vladislav Vaintroub [ 2021-11-08 ]

I debugged that for so long, so now bar as proud owner of temporal can continue
I strongly suspect MDEV-24510 is duplicate of this one

Comment by Alexander Barkov [ 2022-01-10 ]

A smaller script repeating the same problem:

CREATE OR REPLACE TABLE t1 (a int);
CREATE OR REPLACE ALGORITHM=TEMPTABLE VIEW i AS
  SELECT a.created
  FROM t1 w JOIN INFORMATION_SCHEMA.routines a
  WHERE a.routine_name='not existing'
  ORDER BY a.last_altered;
SET SESSION sql_mode='ALLOW_INVALID_DATES';
SELECT * FROM i;

Comment by Alexander Barkov [ 2022-01-14 ]

The problem appeared after this merge:

commit 898521e2dd8a4a6706cba01b6ef0a7cea4114fd0 (HEAD -> 10.5)
Merge: 571bcf9aaaf 199863d72b7
Author: Marko Mäkelä <marko.makela@mariadb.com>
Date:   Fri Oct 30 11:15:30 2020 +0200
 
    Merge 10.4 into 10.5

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