[MDEV-22219] negative values on system variables longer equate to their maximium value Created: 2020-04-11  Updated: 2022-02-07  Resolved: 2021-04-07

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.3, 10.4, 10.5, 10.6
Fix Version/s: 10.6.0

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Daniel Black
Resolution: Fixed Votes: 0
Labels: affects-tests, not-10.1, not-10.2

Issue Links:
Duplicate
duplicates MDEV-26921 Setting table_definition_cache to -1 ... Closed
is duplicated by MDEV-24269 SIGSEGV in __memset_avx2_erms AND in ... Closed
Problem/Incident
causes MDEV-25386 MDEV-22219 Followup: small inconsiste... Confirmed
Relates
relates to MDEV-4774 Strangeness with max_binlog_stmt_cach... Closed
relates to MDEV-22501 Various issues when using --innodb-da... Closed

 Description   

# mysqld options required for replay:  --innodb-buffer-pool-size=-1

Leads to a standard OOM:

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

Core was generated by `/test/MD110420-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --lc-me'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f7158c64187 in kill () at ../sysdeps/unix/syscall-template.S:78
[Current thread is 1 (Thread 0x7f715a5ee7c0 (LWP 16677))]
(gdb) bt
#0  0x00007f7158c64187 in kill () at ../sysdeps/unix/syscall-template.S:78
#1  0x000056455d022df4 in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:341
#2  <signal handler called>
#3  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#4  0x00007f7158c65801 in __GI_abort () at abort.c:79
#5  0x000056455d63b5ac in ib::fatal_or_error::~fatal_or_error (this=0x7ffccfaa4420, __in_chrg=<optimized out>) at /test/10.5_dbg/storage/innobase/ut/ut0ut.cc:618
#6  0x000056455d401132 in ut_allocator<unsigned char, true>::allocate (this=this@entry=0x7ffccfaa4600, n_elements=3298534883328, file=file@entry=0x56455dd10600 "/test/10.5_dbg/storage/innobase/buf/buf0buf.cc", set_to_zero=set_to_zero@entry=true, throw_on_error=throw_on_error@entry=false) at /test/10.5_dbg/storage/innobase/include/ut0new.h:384
#7  0x000056455d6b7210 in buf_pool_t::create (this=0x56455e53c020 <buf_pool>) at /test/10.5_dbg/storage/innobase/buf/buf0buf.cc:1515
#8  0x000056455d5d16bd in srv_start (create_new_db=<optimized out>) at /test/10.5_dbg/storage/innobase/srv/srv0start.cc:1311
#9  0x000056455d3f6a93 in innodb_init (p=<optimized out>) at /test/10.5_dbg/storage/innobase/handler/ha_innodb.cc:4058
#10 0x000056455d027616 in ha_initialize_handlerton (plugin=0x7f7158186eb0) at /test/10.5_dbg/sql/handler.cc:584
#11 0x000056455cd9546d in plugin_initialize (tmp_root=tmp_root@entry=0x7ffccfaaac10, plugin=plugin@entry=0x7f7158186eb0, argc=argc@entry=0x56455e5bee40 <remaining_argc>, argv=argv@entry=0x7f7158040448, options_only=<optimized out>) at /test/10.5_dbg/sql/sql_plugin.cc:1459
#12 0x000056455cd96f34 in plugin_init (argc=argc@entry=0x56455e5bee40 <remaining_argc>, argv=<optimized out>, flags=1) at /test/10.5_dbg/sql/sql_plugin.cc:1752
#13 0x000056455cc77c67 in init_server_components () at /test/10.5_dbg/sql/mysqld.cc:4995
#14 0x000056455cc7e604 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /test/10.5_dbg/sql/mysqld.cc:5544
#15 0x000056455cc70823 in main (argc=<optimized out>, argv=<optimized out>) at /test/10.5_dbg/sql/main.cc:25

Due to:

2020-04-11  1:51:28 0 [Note] InnoDB: Initializing buffer pool, total size = 9223372036854775808, chunk size = 134217728
2020-04-11  1:51:59 0 [ERROR] mysqld: Can't lock aria control file '/ram/MD080420-mariadb-10.5.3-linux-x86_64-dbg/data/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
2020-04-11  1:52:27 0 [ERROR] [FATAL] InnoDB: Cannot allocate 3298534883352 bytes of memory after 60 retries over 60 seconds. OS error: Cannot allocate memory (12). Check if you should increase the swap file or ulimits of your operating system. Note that on most 32-bit computers the process memory space is limited to 2 GB or 4 GB.

Not sure where the 9223372036854775808 value comes from, but that (or the 3298534883352) would seem to be what causes the oversized alloc and subsequent OOM.

Also not sure why in the error log above the Aria error (Can't lock...) is there (no other instance running there);

$ ./bin/perror 11
OS error code  11:  Resource temporarily unavailable

This error does not appear when the server is started without the innodb-buffer-pool-size=-1 option.

MariaDB 10.1.45 (dbg) produces the following instead of OOM;

2020-04-11  1:43:45 139640253781952 [Warning] option 'innodb-buffer-pool-size': signed value -1 adjusted to 5242880

Bug confirmed present in:
MariaDB: 10.3.23 (dbg), 10.3.23 (opt), 10.4.13 (dbg), 10.4.13 (opt), 10.5.3 (dbg), 10.5.3 (opt)

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

Fix ideas? disallow signed values, or sanity check 0 to max, or check data types (difference between versions maybe?), or mirror 10.1/10.2 behavior



 Comments   
Comment by Daniel Black [ 2020-04-11 ]

10.5.3opt-364e7a9ae6b5fbf69494cec30733b5ad28738cbb

(gdb) watch  innobase_buffer_pool_size
 
(after a few switches based on min/max/default it gets to the parsing of the argument)
 
(gdb) n
getopt_ull (arg=0x7fffffffe19f "-1", optp=0x5555577994a0, err=0x7fffffffbb30) at /home/dan/repos/mariadb-server-10.5/mysys/my_getopt.c:1145
1145	  ulonglong num= eval_num_suffix_ull(arg, err, (char*) optp->name);
(gdb) s
eval_num_suffix_ull (option_name=0x555557795318 "innodb-buffer-pool-size", error=0x7fffffffbb30, argument=0x7fffffffe19f "-1")
    at /home/dan/repos/mariadb-server-10.5/mysys/my_getopt.c:1037
1037	  errno= 0;
(gdb) n
1038	  num= strtoull(argument, &endchar, 10);
(gdb) n
1039	  if (errno == ERANGE)
(gdb) p num
$1 = 18446744073709551615
(gdb) p errno
$2 = 0
(gdb) p argument 
$3 = 0x7fffffffe19f "-1"
(gdb) p endchar 
$4 = 0x7fffffffe1a1 ""

So no ERANGE error on a negative number which seems consistent with the fineprint of strtoull's man page.

Max size set a few instructions later based on LLONG_MAX https://github.com/MariaDB/server/blob/10.5/storage/innobase/handler/ha_innodb.cc#L19476

getopt_ull (arg=0x7fffffffe19f "-1", optp=0x5555577994a0, err=0x7fffffffbb30) at /home/dan/repos/mariadb-server-10.5/mysys/my_getopt.c:1146
1146	  return getopt_ull_limit_value(num, optp, NULL);
(gdb) 
2020-04-11 13:16:27 0 [Warning] option 'innodb-buffer-pool-size': unsigned value 18446744073709551615 adjusted to 9223372036853727232
 
Thread 1 "mysqld" hit Hardware watchpoint 1: innobase_buffer_pool_size
 
Old value = 134217728
New value = 9223372036853727232
setval (opts=0x5555577994a0, value=0x55555761f450 <innobase_buffer_pool_size>, argument=0x7fffffffe19f "-1", set_maximum_value=<optimized out>)
    at /home/dan/repos/mariadb-server-10.5/mysys/my_getopt.c:746
746	      break;
(gdb) p *opts
$7 = {name = 0x555557795318 "innodb-buffer-pool-size", id = 0, 
  comment = 0x555556740810 "The size of the memory buffer InnoDB uses to cache data and indexes of its tables.", 
  value = 0x55555761f450 <innobase_buffer_pool_size>, u_max_value = 0x55555761f450 <innobase_buffer_pool_size>, typelib = 0x0, var_type = 8, 
  arg_type = REQUIRED_ARG, def_value = 134217728, min_value = 5242880, max_value = 9223372036854775807, sub_size = 0, block_size = 1048576, 
  app_type = 0x5555576f8760}

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

Thank you danblack for the analysis!

Comment by Daniel Black [ 2020-04-12 ]

https://github.com/MariaDB/server/blob/10.5/unittest/mysys/my_getopt-t.c#L380-L386 described it as intentional (and questionable).

I tend to think, if that supporting a easy setting to a maximum is needed (is there? which variables make sense?), there should be a set global XXX='MAXIMUM' like there is for 'DEFAULT'.

Comment by Marko Mäkelä [ 2020-04-14 ]

danblack, thank you for the analysis. Indeed, strtoull() is not documented to return ERANGE for negative numbers, unless the non-negated number is out of range.

Originally, only strtoll() was being used. The strtoull() variant was introduced in MDEV-4774.

Later, in MariaDB 10.3.7, I changed innodb_buffer_pool_size to be unsigned, in an effort to reduce the amount of -Wconversion in InnoDB. (Finally, MDEV-21907 in 10.5.2 fixed all such warnings.)

Comment by Roel Van de Paar [ 2020-05-08 ]

This bug affects all unsigned parameters as I understand it, ref https://jira.mariadb.org/browse/MDEV-22501?focusedCommentId=152390&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-152390

Comment by Daniel Black [ 2021-04-07 ]

Merged fix into 10.6 that all negative values for unsigned returns an error.

I haven't done a set global ... = MAXIMIUM. Lets leave that as a separate issue.

There wasn't the interesting in a non-GA fix. So 10.6 it is.

Comment by Vicențiu Ciorbaru [ 2021-04-07 ]

danblack Please let dbart and greenman know that this is a change in behaviour and that users need to be informed, in release notes and in the knowledge base.

Comment by Daniel Black [ 2021-04-07 ]

https://mariadb.com/kb/en/mariadb-1060-release-notes/ has been updated.

Comment by Roel Van de Paar [ 2021-04-12 ]

Followup in MDEV-25386

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