[MDEV-22266] Diagnostics_area::sql_errno() const: Assertion `m_status == DA_ERROR' failed on SELECT after setting tmp_disk_table_size. Created: 2020-04-17  Updated: 2022-04-12  Resolved: 2022-04-12

Status: Closed
Project: MariaDB Server
Component/s: Information Schema, Views
Affects Version/s: 10.4, 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.4.25, 10.5.16, 10.6.8, 10.7.4

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Rucha Deodhar
Resolution: Fixed Votes: 0
Labels: not-10.2, not-10.3, regression-10.4, regression-10.6

Issue Links:
Relates
relates to MDEV-23316 Wrong result or Assertion `m_status =... Open
relates to MDEV-14836 Assertion `m_status == DA_ERROR' fail... Closed
relates to MDEV-19840 Assertion `m_status == DA_ERROR' fail... Open
relates to MDEV-23212 Limited tmp_disk_table_size causes wr... Confirmed

 Description   

SET @@tmp_disk_table_size=16384;
CREATE VIEW v AS SELECT 'a';
SELECT table_name FROM INFORMATION_SCHEMA.views;

Leads to:

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

mysqld: /test/10.5_dbg/sql/sql_error.h:1036: uint Diagnostics_area::sql_errno() const: Assertion `m_status == DA_ERROR' 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 0x7fcd668c3700 (LWP 10020))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1  0x000055ec7862621e in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
#2  0x000055ec77dcc08f 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  0x00007fcd65007801 in __GI_abort () at abort.c:79
#6  0x00007fcd64ff739a in __assert_fail_base (fmt=0x7fcd6517e7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55ec78775490 "m_status == DA_ERROR", file=file@entry=0x55ec78775c28 "/test/10.5_dbg/sql/sql_error.h", line=line@entry=1036, function=function@entry=0x55ec787b4e00 <_ZZNK16Diagnostics_area9sql_errnoEvE19__PRETTY_FUNCTION__> "uint Diagnostics_area::sql_errno() const") at assert.c:92
#7  0x00007fcd64ff7412 in __GI___assert_fail (assertion=assertion@entry=0x55ec78775490 "m_status == DA_ERROR", file=file@entry=0x55ec78775c28 "/test/10.5_dbg/sql/sql_error.h", line=line@entry=1036, function=function@entry=0x55ec787b4e00 <_ZZNK16Diagnostics_area9sql_errnoEvE19__PRETTY_FUNCTION__> "uint Diagnostics_area::sql_errno() const") at assert.c:101
#8  0x000055ec77bb5ba4 in Diagnostics_area::sql_errno (this=0x7fcd3901ab80) at /test/10.5_dbg/sql/sql_error.h:1036
#9  fill_schema_table_by_open (thd=thd@entry=0x7fcd39015088, mem_root=mem_root@entry=0x7fcd668bf480, is_show_fields_or_keys=is_show_fields_or_keys@entry=false, table=table@entry=0x7fcd390810a0, schema_table=schema_table@entry=0x55ec792bfe00 <schema_tables+2496>, orig_db_name=orig_db_name@entry=0x7fcd39078158, orig_table_name=0x7fcd393dc320, open_tables_state_backup=0x7fcd668bf4c0, can_deadlock=false) at /test/10.5_dbg/sql/sql_show.cc:4610
#10 0x000055ec77bcb9de in get_all_tables (thd=0x7fcd39015088, tables=0x7fcd39074780, cond=<optimized out>) at /test/10.5_dbg/sql/sql_show.cc:5233
#11 0x000055ec77bcc974 in get_schema_tables_result (join=join@entry=0x7fcd39075d38, executed_place=executed_place@entry=PROCESSED_BY_JOIN_EXEC) at /test/10.5_dbg/sql/sql_show.cc:8647
#12 0x000055ec77ba02c3 in JOIN::exec_inner (this=this@entry=0x7fcd39075d38) at /test/10.5_dbg/sql/sql_select.cc:4420
#13 0x000055ec77ba0c6b in JOIN::exec (this=this@entry=0x7fcd39075d38) at /test/10.5_dbg/sql/sql_select.cc:4244
#14 0x000055ec77b9ef80 in mysql_select (thd=thd@entry=0x7fcd39015088, tables=<optimized out>, fields=..., conds=0x0, og_num=0, order=<optimized out>, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7fcd39075d10, unit=0x7fcd39019090, select_lex=0x7fcd39074160) at /test/10.5_dbg/sql/sql_select.cc:4668
#15 0x000055ec77b9f2af in handle_select (thd=thd@entry=0x7fcd39015088, lex=lex@entry=0x7fcd39018fc8, result=result@entry=0x7fcd39075d10, setup_tables_done_option=setup_tables_done_option@entry=0) at /test/10.5_dbg/sql/sql_select.cc:417
#16 0x000055ec77b2999a in execute_sqlcom_select (thd=thd@entry=0x7fcd39015088, all_tables=0x7fcd39074780) at /test/10.5_dbg/sql/sql_parse.cc:6168
#17 0x000055ec77b223ed in mysql_execute_command (thd=thd@entry=0x7fcd39015088) at /test/10.5_dbg/sql/sql_parse.cc:3901
#18 0x000055ec77b2f9d1 in mysql_parse (thd=thd@entry=0x7fcd39015088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fcd668c2450, 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
#19 0x000055ec77b1b719 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fcd39015088, packet=packet@entry=0x7fcd39067089 "SELECT table_name FROM INFORMATION_SCHEMA.views", packet_length=packet_length@entry=47, 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
#20 0x000055ec77b19f6f in do_command (thd=0x7fcd39015088) at /test/10.5_dbg/sql/sql_parse.cc:1358
#21 0x000055ec77c74a53 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7fcd3d4433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
#22 0x000055ec77c74d82 in handle_one_connection (arg=arg@entry=0x7fcd3d4433a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
#23 0x000055ec780d5080 in pfs_spawn_thread (arg=0x7fcd64445888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#24 0x00007fcd65cea6db in start_thread (arg=0x7fcd668c3700) at pthread_create.c:463
#25 0x00007fcd650e888f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (dbg), 10.1.45 (opt), 10.2.32 (dbg), 10.2.32 (opt), 10.3.23 (dbg), 10.3.23 (opt), 10.4.13 (dbg), 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)

The testcases passes without any errors or warnings on MariaDB 10.4.13 (dbg):

10.4.13>SET @@tmp_disk_table_size=16384;
Query OK, 0 rows affected (0.000 sec)
10.4.13>CREATE VIEW v AS SELECT 'a';
Query OK, 0 rows affected (0.004 sec)
10.4.13>SELECT table_name FROM INFORMATION_SCHEMA.views;
+------------+
| table_name |
+------------+
| v          |
| user       |
+------------+
2 rows in set (0.032 sec)



 Comments   
Comment by Oleksandr Byelkin [ 2020-04-17 ]

IMHO there is 2 bugs here:
1) schema_table_store_record generated error lost
2) somehow we get HA_ERR_RECORD_FILE_FULL but table points to ARIA hton already (there was no such errors before) instead of HEAP which cause error returning instead of converting heap to aria in create_internal_tmp_table_from_heap()

Comment by Oleksandr Byelkin [ 2020-06-12 ]

according to documentation tmp_disk_table_size should not limit temporary table of information schema (it is second bug)

Comment by Oleksandr Byelkin [ 2020-06-12 ]

So asfter discussion with Serg we decided that erro is correct, procession of errors in information schema is brocken, but it will not lead to crash on non-debug version of the server (that is why priority decreased).

Comment by Roel Van de Paar [ 2020-06-13 ]

sanja serg Thank you. What changed in 10.5 to cause this (as bug is only in 10.5)?

Comment by Sergei Golubchik [ 2020-06-13 ]

commit de9ef03ae6a
Author: Sergei Golubchik <serg@mariadb.com>
Date:   Wed Sep 18 14:18:08 2019 +0200
 
    fix max_rows calculations for internal on-disk temp tables

Comment by Elena Stepanova [ 2020-07-14 ]

serg:
Strange, my bisect points at

commit ac93d7d674cd9955c940055d9777e98a1fbaf1cd
Author: Alexander Barkov <bar@mariadb.com>
Date:   Sat May 25 11:40:48 2019 +0400
 
    MDEV-19593 Split create_schema_table() into virtual methods in Type_handler

I also have a similar test case which fails the same way on older versions. Filed it separately the MDEV-23316, to keep this one as a regression since it's been identified as such.

Comment by Rucha Deodhar [ 2022-01-27 ]

Can't repeat anymore:

SET @old_tmp_disk_table_size= @@tmp_disk_table_size;
SET @@tmp_disk_table_size=16384;
CREATE VIEW v AS SELECT 'a';
SELECT table_name FROM INFORMATION_SCHEMA.views;
table_name
v
Warnings:
Error	1114	The table '(temporary)' is full
Error	1286	Unknown storage engine 'InnoDB'
Error	1033	Incorrect information in file: './mysql/tables_priv.frm'
Error	1033	Incorrect information in file: './mysql/slow_log.frm'
Error	1033	Incorrect information in file: './mysql/proxies_priv.frm'
Error	1033	Incorrect information in file: './mysql/procs_priv.frm'
Error	1033	Incorrect information in file: './mysql/proc.frm'
Error	1286	Unknown storage engine 'InnoDB'
Error	1286	Unknown storage engine 'InnoDB'
Error	1033	Incorrect information in file: './mysql/global_priv.frm'
Error	1033	Incorrect information in file: './mysql/general_log.frm'
Error	1033	Incorrect information in file: './mysql/event.frm'
Error	1033	Incorrect information in file: './mysql/columns_priv.frm'
SET @@tmp_disk_table_size=@old_tmp_disk_table_size;
DROP VIEW v;

Comment by Roel Van de Paar [ 2022-01-28 ]

Whilst the crash may not be repeatable, the errors look concerning and the previous mentioned bugs present were not addressed? Additionally, the errors look different on my instance:

10.5.14 e44439ab7354c5dff20707325694839e9346fb27 (Debug)

10.5.14-dbg>SET @@tmp_disk_table_size=16384;
Query OK, 0 rows affected (0.000 sec)
 
10.5.14-dbg>CREATE VIEW v AS SELECT 'a';
Query OK, 0 rows affected (0.004 sec)
 
10.5.14-dbg>SELECT table_name FROM INFORMATION_SCHEMA.views;
+------------+
| table_name |
+------------+
| v          |
+------------+
1 row in set, 12 warnings (0.072 sec)
 
10.5.14-dbg>SHOW WARNINGS;
+-------+------+-----------------------------------------------------------------+
| Level | Code | Message                                                         |
+-------+------+-----------------------------------------------------------------+
| Error | 1114 | The table '(temporary)' is full                                 |
| Error | 1033 | Incorrect information in file: './mysql/tables_priv.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/slow_log.frm'           |
| Error | 1033 | Incorrect information in file: './mysql/proxies_priv.frm'       |
| Error | 1033 | Incorrect information in file: './mysql/procs_priv.frm'         |
| Error | 1033 | Incorrect information in file: './mysql/proc.frm'               |
| Error | 1033 | Incorrect information in file: './mysql/innodb_table_stats.frm' |
| Error | 1033 | Incorrect information in file: './mysql/innodb_index_stats.frm' |
| Error | 1033 | Incorrect information in file: './mysql/global_priv.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/general_log.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/event.frm'              |
| Error | 1033 | Incorrect information in file: './mysql/columns_priv.frm'       |
+-------+------+-----------------------------------------------------------------+
12 rows in set (0.000 sec)

And optimized:

10.5.14 e44439ab7354c5dff20707325694839e9346fb27 (Optimized)

10.5.14-opt>SHOW WARNINGS;
+-------+------+-----------------------------------------------------------------+
| Level | Code | Message                                                         |
+-------+------+-----------------------------------------------------------------+
| Error | 1114 | The table '(temporary)' is full                                 |
| Error | 1033 | Incorrect information in file: './mysql/procs_priv.frm'         |
| Error | 1033 | Incorrect information in file: './mysql/columns_priv.frm'       |
| Error | 1033 | Incorrect information in file: './mysql/innodb_index_stats.frm' |
| Error | 1033 | Incorrect information in file: './mysql/innodb_table_stats.frm' |
+-------+------+-----------------------------------------------------------------+
5 rows in set (0.000 sec)

I have reopened the ticket for the errors and the bugs mentioned earlier to be looked into.

Comment by Sergei Golubchik [ 2022-01-31 ]

it's totally normal that if the server cannot create a temporary table, you'll get an error about it.

As a fix we could increase the minimal allowed value for @@tmp_disk_table_size

Comment by Roel Van de Paar [ 2022-01-31 ]

serg I agree (re: error). That said, the errors in mysql db are somewhat random, and more importantly a failure to create a table should not yield issues in mysql db?

Comment by Roel Van de Paar [ 2022-03-23 ]

sys/sys_config.frm corruption, and difference between "194 warnings" vs "64 rows in set".

10.9.0 5be92887c2caacb45af87b1131db952ce627e83a (Debug)

10.9.0-dbg>SET @@tmp_disk_table_size=16384;
Query OK, 0 rows affected (0.000 sec)
 
10.9.0-dbg>CREATE VIEW v AS SELECT 'a';
Query OK, 0 rows affected (0.011 sec)
 
10.9.0-dbg>SELECT table_name FROM INFORMATION_SCHEMA.views;
+------------+
| table_name |
+------------+
| v          |
+------------+
1 row in set, 194 warnings (0.255 sec)
 
10.9.0-dbg>SHOW WARNINGS;
+-------+------+-------------------------------------------------------+
| Level | Code | Message                                               |
+-------+------+-------------------------------------------------------+
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1033 | Incorrect information in file: './sys/sys_config.frm' |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
| Error | 1114 | The table '(temporary)' is full                       |
+-------+------+-------------------------------------------------------+
64 rows in set (0.000 sec)

Comment by Roel Van de Paar [ 2022-03-23 ]

Different versions furthermore give different outcomes. 10.2 and 10.3 are fine/not affected:

10.3.35 6a2d88c132221ea07dd322060089c85ff5e469b5 (Debug)

10.3.35-dbg>SET @@tmp_disk_table_size=16384;
Query OK, 0 rows affected (0.000 sec)
 
10.3.35-dbg>CREATE VIEW v AS SELECT 'a';
Query OK, 0 rows affected (0.005 sec)
 
10.3.35-dbg>SELECT table_name FROM INFORMATION_SCHEMA.views;
+------------+
| table_name |
+------------+
| v          |
+------------+
1 row in set (0.089 sec)
 
10.3.35-dbg>SHOW WARNINGS;
Empty set (0.000 sec)

10.4-10.5 Have a set of corruptions of mysql tables, but the number of warnings reported and shown matches:

10.5.16 73fee39ea62037780c59161507e89dd76c10b7a3 (Debug)

10.5.16-dbg>SET @@tmp_disk_table_size=16384;
Query OK, 0 rows affected (0.000 sec)
 
10.5.16-dbg>CREATE VIEW v AS SELECT 'a';
Query OK, 0 rows affected (0.006 sec)
 
10.5.16-dbg>SELECT table_name FROM INFORMATION_SCHEMA.views;
+------------+
| table_name |
+------------+
| v          |
+------------+
1 row in set, 12 warnings (0.149 sec)
 
10.5.16-dbg>SHOW WARNINGS;
+-------+------+-----------------------------------------------------------------+
| Level | Code | Message                                                         |
+-------+------+-----------------------------------------------------------------+
| Error | 1114 | The table '(temporary)' is full                                 |
| Error | 1033 | Incorrect information in file: './mysql/tables_priv.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/slow_log.frm'           |
| Error | 1033 | Incorrect information in file: './mysql/proxies_priv.frm'       |
| Error | 1033 | Incorrect information in file: './mysql/procs_priv.frm'         |
| Error | 1033 | Incorrect information in file: './mysql/proc.frm'               |
| Error | 1033 | Incorrect information in file: './mysql/innodb_table_stats.frm' |
| Error | 1033 | Incorrect information in file: './mysql/innodb_index_stats.frm' |
| Error | 1033 | Incorrect information in file: './mysql/global_priv.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/general_log.frm'        |
| Error | 1033 | Incorrect information in file: './mysql/event.frm'              |
| Error | 1033 | Incorrect information in file: './mysql/columns_priv.frm'       |
+-------+------+-----------------------------------------------------------------+
12 rows in set (0.000 sec)

And 10.6 to 10.9 have the outcome from the previous comment: sys corruption and differing numbers of warnings reported vs output.
There are thus two regressions, one in 10.4 and one in 10.6

Comment by Rucha Deodhar [ 2022-04-11 ]

Patch: https://github.com/MariaDB/server/commit/3327bb6098c42e82a72bfc5f8080b2e6cf79a025

Comment by Rucha Deodhar [ 2022-04-11 ]

The mismatch in number of warnings between "194 warnings" vs "64 rows in set" is because of max_error_count variable which has default value of 64. If you set the value of this variable to much higher say 300, you will see all the warnings in rows and it will also match with 194 warnings.
About the corrupted tables, the error that occurs because of insufficient tmp_disk_table_size variable is not reported correctly and we continue to execute the statement. But because the previous error ( about table being full) is not reported correctly, this error moves up the stack and is wrongly reported as parsing error which gives corrupted table error message.
As for the innodb error, it occurs even when tmp_disk_table_size is not insufficient is default but the internal error handler takes care of it and the error doesn't show. But when tmp_disk_table_size is insufficient, the fatal error which wasn't reported moves up the stack so internal error handler is not called. So it shows errors.

Comment by Oleksandr Byelkin [ 2022-04-12 ]

OK to push

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