[MDEV-27855] Assertion `! is_set() || m_can_overwrite_status' failed from throw_bounds_warning in connection with sort_buffer_size sizing Created: 2022-02-16  Updated: 2023-12-11

Status: Confirmed
Project: MariaDB Server
Component/s: Variables
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: affects-tests


 Description   

Same assert as in MDEV-27688, but assumed to be a different issue.

# mysqld options required for replay:  --maximum-sort_buffer_size=1M                                                    
SET sql_mode='traditional';
SET STATEMENT sort_buffer_size=100000 FOR SHOW SESSION VARIABLES LIKE 'sort_buffer_size';  # Repeat until the crash is observed.

Leads to:

10.9.0 b5852ffbeebc3000982988383daeefb0549e058a (Debug)

mysqld: /test/10.9_dbg/sql/sql_error.cc:457: void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*): Assertion `! is_set() || m_can_overwrite_status' failed.

10.9.0 b5852ffbeebc3000982988383daeefb0549e058a (Debug)

Core was generated by `/test/MD140222-mariadb-10.9.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 0x153c40121700 (LWP 2856834))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000153c5619f859 in __GI_abort () at abort.c:79
#2  0x0000153c5619f729 in __assert_fail_base (fmt=0x153c56335588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x56027eb0efa8 "! is_set() || m_can_overwrite_status", file=0x56027eb0ed18 "/test/10.9_dbg/sql/sql_error.cc", line=457, function=<optimized out>) at assert.c:92
#3  0x0000153c561b0f36 in __GI___assert_fail (assertion=assertion@entry=0x56027eb0efa8 "! is_set() || m_can_overwrite_status", file=file@entry=0x56027eb0ed18 "/test/10.9_dbg/sql/sql_error.cc", line=line@entry=457, function=function@entry=0x56027eb0ef20 "void Diagnostics_area::set_error_status(uint, const char*, const char*, const Sql_user_condition_identity&, const Sql_condition*)") at assert.c:101
#4  0x000056027dde8e7d in Diagnostics_area::set_error_status (this=this@entry=0x153be0006d20, sql_errno=sql_errno@entry=1231, message=message@entry=0x153c4011fbb0 "Variable 'sort_buffer_size' can't be set to the value of '2097152'", sqlstate=sqlstate@entry=0x56027eb2fa70 "42000", ucid=@0x153c4011f950: {m_user_condition_value = 0x0}, error_condition=0x0) at /test/10.9_dbg/sql/sql_error.h:1019
#5  0x000056027ddc2465 in THD::raise_condition (this=this@entry=0x153be0000db8, cond=cond@entry=0x153c4011f940) at /test/10.9_dbg/sql/sql_class.cc:1121
#6  0x000056027dcf98e8 in THD::raise_condition (this=this@entry=0x153be0000db8, sql_errno=sql_errno@entry=1231, sqlstate=sqlstate@entry=0x56027eaec878 "", level=<optimized out>, msg=msg@entry=0x153c4011fbb0 "Variable 'sort_buffer_size' can't be set to the value of '2097152'") at /test/10.9_dbg/sql/sql_class.h:4818
#7  0x000056027dceba7f in my_message_sql (error=1231, str=0x153c4011fbb0 "Variable 'sort_buffer_size' can't be set to the value of '2097152'", MyFlags=0) at /test/10.9_dbg/sql/mysqld.cc:3280
#8  0x000056027e9524e6 in my_error (nr=nr@entry=1231, MyFlags=MyFlags@entry=0) at /test/10.9_dbg/mysys/my_error.c:124
#9  0x000056027dd3e47e in throw_bounds_warning (thd=thd@entry=0x153be0000db8, name=0x56027eb4f6bc "sort_buffer_size", fixed=fixed@entry=true, is_unsigned=<optimized out>, v=v@entry=2097152) at /test/10.9_dbg/sql/set_var.cc:485
#10 0x000056027dfe8e37 in Sys_var_integer<unsigned long long, 8ul, (enum_mysql_show_type)4>::do_check (this=0x56027f4a94c0 <Sys_sort_buffer>, thd=0x153be0000db8, var=0x153be001c9d8) at /test/10.9_dbg/sql/set_var.h:258
#11 0x000056027dd3d295 in sys_var::check (this=0x56027f4a94c0 <Sys_sort_buffer>, thd=thd@entry=0x153be0000db8, var=var@entry=0x153be001c9d8) at /test/10.9_dbg/sql/set_var.cc:246
#12 0x000056027dd3e2e8 in set_var::check (this=0x153be001c9d8, thd=0x153be0000db8) at /test/10.9_dbg/sql/set_var.cc:810
#13 0x000056027dd3e9f8 in sql_set_variables (thd=0x153be0000db8, var_list=var_list@entry=0x153be0006110, free=free@entry=false) at /test/10.9_dbg/sql/set_var.cc:738
#14 0x000056027de0b187 in LEX::restore_set_statement_var (this=0x153be00050f0) at /test/10.9_dbg/sql/sql_lex.cc:5926
#15 0x000056027de404de in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x153be0000db8, packet=<optimized out>, packet@entry=0x153be000b889 "", packet_length=packet_length@entry=88, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:2468
#16 0x000056027de413f8 in do_command (thd=0x153be0000db8, blocking=blocking@entry=true) at /test/10.9_dbg/sql/sql_parse.cc:1402
#17 0x000056027dfbbfc4 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x560281a7b848, put_in_cache=put_in_cache@entry=true) at /test/10.9_dbg/sql/sql_connect.cc:1418
#18 0x000056027dfbc5c9 in handle_one_connection (arg=arg@entry=0x560281a7b848) at /test/10.9_dbg/sql/sql_connect.cc:1312
#19 0x000056027e442d67 in pfs_spawn_thread (arg=0x56028198e9a8) at /test/10.9_dbg/storage/perfschema/pfs.cc:2201
#20 0x0000153c566ae609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#21 0x0000153c5629c293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.42 (dbg), 10.3.33 (dbg), 10.4.23 (dbg), 10.5.14 (dbg), 10.6.6 (dbg), 10.7.2 (dbg), 10.8.1 (dbg), 10.9.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.42 (opt), 10.3.33 (opt), 10.4.23 (opt), 10.5.14 (opt), 10.6.6 (opt), 10.7.2 (opt), 10.8.1 (opt), 10.9.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.36 (dbg), 5.7.36 (opt), 8.0.27 (dbg), 8.0.27 (opt)



 Comments   
Comment by Jason (Inactive) [ 2023-11-21 ]

The default value of sort_buffer_size is 2097152.
The problem is that for this statement:

SET STATEMENT sort_buffer_size=100000 FOR SHOW SESSION VARIABLES LIKE 'sort_buffer_size';

It sets sort_buffer_size to 100000 for the duration of the statement which is allowed. The server was started with --maximum-sort_buffer_size=1M , and when the statement finishes it tries to restore the sort_buffer_size back to 2097152. But it cannot restore sort_buffer_size to 2097152 because the server command line option says that it cannot exceed 1M, so this results in an error (sql_mode='traditional' makes it a hard error instead of a warning). The assertion fails because the select is already complete and my_eof() had already been called by the time the error is detected.

Comment by Sergei Petrunia [ 2023-11-29 ]

Roel, for the future: this doesn't look like query optimizer issue, at all.

Comment by Jason (Inactive) [ 2023-11-29 ]

It seems to me that the root cause is that when the server is started with --maximum-sort_buffer_size=1M, it still sets the default value of sort_buffer_size > 1M.

# sql/mysqld --maximum-sort_buffer_size=1M
 
# client/mysql -e "show variables like 'sort_buffer_size'"
+------------------+---------+
| Variable_name    | Value   |
+------------------+---------+
| sort_buffer_size | 2097152 |
+------------------+---------+

This seems to me to be counter-intuitive to what a user would expect to happen. If the command line argument says that the maximum sort_buffer_size is 1M, I expect that sort_buffer_size should not exceed 1M. If the default value were set correctly below the command line argument threshold, then restoring the variable after the SET STATEMENT ... FOR ... would work.

Comment by Sergei Petrunia [ 2023-11-30 ]

when the server is started with --maximum-sort_buffer_size=1M, it still sets the default value of sort_buffer_size > 1M

jasoncu, agree.

It's interesting that INFORMATION_SCHEMA table lists GLOBAL_VALUE_ORIGIN as CONFIG (not COMPILE-TIME), but the max value is not what maximum-sort_buffer_size has specified:

MariaDB [information_schema]> select * from SYSTEM_VARIABLES where variable_name='sort_buffer_size' limit 1\G
*************************** 1. row ***************************
        VARIABLE_NAME: SORT_BUFFER_SIZE
        SESSION_VALUE: 2097152
         GLOBAL_VALUE: 2097152
  GLOBAL_VALUE_ORIGIN: CONFIG
        DEFAULT_VALUE: 2097152
       VARIABLE_SCOPE: SESSION
        VARIABLE_TYPE: BIGINT UNSIGNED
     VARIABLE_COMMENT: Each thread that needs to do a sort allocates a buffer of this size
    NUMERIC_MIN_VALUE: 1024
    NUMERIC_MAX_VALUE: 18446744073709551615
   NUMERIC_BLOCK_SIZE: 1
      ENUM_VALUE_LIST: NULL
            READ_ONLY: NO
COMMAND_LINE_ARGUMENT: REQUIRED
    GLOBAL_VALUE_PATH: /home/psergey/my-local.cnf

This all needs to be fixed (perhaps by Runtime team, but still).

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