facebook / mysql-5.6

Facebook's branch of the Oracle MySQL database. This includes MyRocks.
http://myrocks.io
Other
2.49k stars 713 forks source link

Debug assertion "last_val > 0" when auto_inc_inc > 1 and ullong_max underflow #907

Open george-lorch opened 5 years ago

george-lorch commented 5 years ago

The following. simple test case illustrates the issue:

DROP DATABASE IF EXISTS test; CREATE DATABASE test; USE test; CREATE TABLE t1(c1 BIGINT UNSIGNED AUTO_INCREMENT,KEY (c1)) engine=RocksDB; INSERT INTO t1 VALUES(18446744073709551613); SET @@session.auto_increment_increment=2; INSERT INTO t1 VALUES(); INSERT INTO t1 VALUES();

The first insert after the "SET @@session.auto_increment_increment=2;" will get this expected error

ERROR 1467 (HY000): Failed to read auto-increment value from storage engine

The next insert hits the assertion with the following call stack:

mysqld: /home/glorch/dev/ps/facebook-mysql/storage/rocksdb/ha_rocksdb.cc:11474: virtual void myrocks::ha_rocksdb::get_auto_increment(ulonglong, ulonglong, ulonglong, ulonglong, ulonglong): Assertion `last_val > 0' failed.

Thread 11 "my-oneconnectio" received signal SIGABRT, Aborted. [Switching to Thread 0x7fffe87f8700 (LWP 2302)] __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. (gdb) bt

0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51

1 0x00007ffff5915801 in __GI_abort () at abort.c:79

2 0x00007ffff590539a in __assert_fail_base (fmt=0x7ffff5a8c7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x555557438fe6 "last_val > 0",

file=file@entry=0x555557433348 "/home/glorch/dev/ps/facebook-mysql/storage/rocksdb/ha_rocksdb.cc", line=line@entry=11474, 
function=function@entry=0x55555743fa00 <myrocks::ha_rocksdb::get_auto_increment(unsigned long long, unsigned long long, unsigned long long, unsigned long long*, unsigned long long*)::__PRETTY_FUNCTION__> "virtual void myrocks::ha_rocksdb::get_auto_increment(ulonglong, ulonglong, ulonglong, ulonglong*, ulonglong*)") at assert.c:92

3 0x00007ffff5905412 in __GI___assert_fail (assertion=0x555557438fe6 "last_val > 0", file=0x555557433348 "/home/glorch/dev/ps/facebook-mysql/storage/rocksdb/ha_rocksdb.cc", line=11474,

function=0x55555743fa00 <myrocks::ha_rocksdb::get_auto_increment(unsigned long long, unsigned long long, unsigned long long, unsigned long long*, unsigned long long*)::__PRETTY_FUNCTION__> "virtual void myrocks::ha_rocksdb::get_auto_increment(ulonglong, ulonglong, ulonglong, ulonglong*, ulonglong*)") at assert.c:101

4 0x0000555556c02f89 in myrocks::ha_rocksdb::get_auto_increment (this=0x7fffbc00b710, off=1, inc=2, nb_desired_values=1, first_value=0x7fffe87f4fe0, nb_reserved_values=0x7fffe87f4fe8) at /home/glorch/dev/ps/facebook-mysql/storage/rocksdb/ha_rocksdb.cc:11474

5 0x000055555629b713 in handler::update_auto_increment (this=0x7fffbc00b710) at /home/glorch/dev/ps/facebook-mysql/sql/handler.cc:3718

6 0x0000555556bfa612 in myrocks::ha_rocksdb::write_row (this=0x7fffbc00b710, buf=0x7fffbc016100 "\377") at /home/glorch/dev/ps/facebook-mysql/storage/rocksdb/ha_rocksdb.cc:9107

7 0x00005555562a4fb6 in handler::ha_write_row (this=0x7fffbc00b710, buf=0x7fffbc016100 "\377") at /home/glorch/dev/ps/facebook-mysql/sql/handler.cc:7926

8 0x0000555556495324 in write_record (thd=0x555558468480, table=0x7fffbc00adb0, info=0x7fffe87f53b0, update=0x7fffe87f5430) at /home/glorch/dev/ps/facebook-mysql/sql/sql_insert.cc:1889

9 0x0000555556492f81 in mysql_insert (thd=0x555558468480, table_list=0x7fffbc007a10, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /home/glorch/dev/ps/facebook-mysql/sql/sql_insert.cc:1030

10 0x00005555564be4a3 in mysql_execute_command (thd=0x555558468480, statement_start_time=0x7fffe87f6718, post_parse=0x7fffe87f6878) at /home/glorch/dev/ps/facebook-mysql/sql/sql_parse.cc:4575

11 0x00005555564c78b4 in mysql_parse (thd=0x555558468480, rawbuf=0x7fffbc007930 "INSERT INTO t1 VALUES()", length=23, parser_state=0x7fffe87f7170, last_timer=0x7fffe87f6878, async_commit=0x7fffe87f6843 "")

at /home/glorch/dev/ps/facebook-mysql/sql/sql_parse.cc:7896

12 0x00005555564b742e in dispatch_command (command=COM_QUERY, thd=0x555558468480, packet=0x55555851d3d1 "INSERT INTO t1 VALUES()", packet_length=23) at /home/glorch/dev/ps/facebook-mysql/sql/sql_parse.cc:1919

13 0x00005555564b52b8 in do_command (thd=0x555558468480) at /home/glorch/dev/ps/facebook-mysql/sql/sql_parse.cc:1193

14 0x000055555646f598 in do_handle_one_connection (thd_arg=0x555558468480) at /home/glorch/dev/ps/facebook-mysql/sql/sql_connect.cc:1148

15 0x000055555646ef8d in handle_one_connection (arg=0x555558468480) at /home/glorch/dev/ps/facebook-mysql/sql/sql_connect.cc:969

16 0x0000555556bd600a in pfs_spawn_thread (arg=0x5555584136f0) at /home/glorch/dev/ps/facebook-mysql/storage/perfschema/pfs.cc:1860

17 0x00007ffff660c6db in start_thread (arg=0x7fffe87f8700) at pthread_create.c:463

18 0x00007ffff59f688f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

george-lorch commented 5 years ago

email discussions with @lth and some additional testing tells us that the logic here https://github.com/facebook/mysql-5.6/blob/fb-mysql-5.6.35/storage/rocksdb/ha_rocksdb.cc#L11540-LL11541 is slightly off. We get into a situation where new_val is equal to ullong_max, thus new_val + 1 rolls us over to 0, which is what gets stored as the new auto_inc value for the table and then eventually leads to the assertion on the next time through get_auto_increment.

A simple change to this logic solves the problem and prevents us from either underflowing or from giving out any more values. We change:

while (!auto_incr.compare_exchange_weak(last_val, std::min(new_val + 1, max_val)));

to

while (!auto_incr.compare_exchange_weak(last_val, std::min(new_val, max_val - 1) + 1));