Skip to content

/mysql-5.6 forked from facebook/mysql-5.6

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Clone in Desktop Download ZIP

Loading…

New issue

many segfaults during concurrent insert benchmark #69

Closed
mdcallag opened this Issue · 9 comments

Labels

bug

Milestone

No milestone

Assignee

@maykov maykov

4 participants

@mdcallag @yoshinorim @spetrunia @maykov
@mdcallag
Owner
mdcallag commented

I get many segfaults while running concurrent insert benchmark in a loop. The database is dropped at test start, then one table with 3 secondary indexes is created per user, then inserts are done, repeat. So there are many rows to be dropped during compaction for tables/indexes that have been dropped.

This test used a recent build that was stable for a 10 day run of linkbench.

Stack traces are at https://gist.github.com/mdcallag/37885eda0a35c49b4d1a
my.cnf is https://gist.github.com/mdcallag/1a540de3f1891f06bdb4

script to run test is here and assumes root/pw is username/password:
https://gist.github.com/mdcallag/10740552212c8b768db2

command line using the script above saved as np2.sh is:
for i in $( seq 1 100 ); do bash np2.sh 32000000 rocksdb "" ; done

@mdcallag mdcallag added the bug label
@mdcallag
@mdcallag
Owner
mdcallag commented

After many segfaults & recoveries the server was idle. I did "mysqladmin shutdown" and that hangs. PMP shows this: https://gist.github.com/mdcallag/020a784318af2c317c21

The tail of the db error log is:
2015-05-23 07:33:41 860122 [Note] RocksDB: Finished filtering dropped index 23563
2015-05-23 07:33:41 860122 [Note] RocksDB: Finished filtering dropped index 23383
2015-05-23 07:33:41 860122 [Note] RocksDB: Finished filtering dropped index 23382
2015-05-23 07:33:41 860122 [Note] RocksDB: Finished filtering dropped index 23381
2015-05-23 07:33:42 860122 [Note] RocksDB: Compacting away elements from dropped index 23525: 288000
2015-05-23 08:01:11 860122 [Note] COM_SHUTDOWN received from host/user = localhost/root
2015-05-23 08:01:11 860122 [Note] Got signal 15 to shutdown mysqld
2015-05-23 08:01:11 860122 [Note] /data/mysql/myrocks/libexec/mysqld: Normal shutdown

2015-05-23 08:01:11 860122 [Note] Giving 73 client threads a chance to die gracefully
2015-05-23 08:01:11 860122 [Note] Event Scheduler: Purging the queue. 0 events
2015-05-23 08:01:11 860122 [Note] Shutting down slave threads
2015-05-23 08:01:13 860122 [Note] Forcefully disconnecting 51 remaining clients
2015-05-23 08:01:13 860122 [Warning] /data/mysql/myrocks/libexec/mysqld: Forcing close of thread 47 user: 'root'

2015-05-23 08:01:13 860122 [Warning] /data/mysql/myrocks/libexec/mysqld: Forcing close of thread 48 user: 'root'

2015-05-23 08:01:13 860122 [Warning] /data/mysql/myrocks/libexec/mysqld: Forcing close of thread 49 user: 'root'

@yoshinorim
Owner
yoshinorim commented

Does hangup on shutdown still repeat with Herman's recent diff (43ad45d)?

@yoshinorim
Owner
yoshinorim commented

I assume the following race condition happened. 

ha_rocksdb::delete_table()
 Dropped_indices_manager::add_indices()
  put xlock
   map update
  put unlock
    <---- Properties Collector find()
 ddl_manager.remove()
  remove xlock
   map erase
  remove unlock
@mdcallag
Owner
mdcallag commented
@spetrunia
Collaborator
spetrunia commented

I was able to repeat with the current tree (7f7c355, it includes the mentioned Herman's diff).

psergey@pslp2:~/issue69$ bash np2.sh 32000000 rocksdb ""
ERROR 1008 (HY000) at line 1: Can't drop database 'ib'; database doesn't exist
1 processes, 32000000 rows-per-process, 1655 seconds, 19335.3 rows-per-second, 19335.3 rows-per-second-per-user
2 processes, 16000000 rows-per-process, 1351 seconds, 23686.1 rows-per-second, 11843.0 rows-per-second-per-user
3 processes, 10666666 rows-per-process, 1375 seconds, 23272.7 rows-per-second, 7757.5 rows-per-second-per-user
4 processes, 8000000 rows-per-process, 1383 seconds, 23138.1 rows-per-second, 5784.5 rows-per-second-per-user
5 processes, 6400000 rows-per-process, 1377 seconds, 23238.9 rows-per-second, 4647.7 rows-per-second-per-user

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffadffb700 (LWP 26578)]
__memmove_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1515
1515    ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S: No such file or directory.
(gdb) wher
#0  __memmove_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1515
#1  0x0000000000bddd77 in std::__copy_move<false, true, std::random_access_iterator_tag>::__copy_m<long> (__first=0x7fff00000001, 
    __last=0x7fff60254788, __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_algobase.h:372
#2  0x0000000000bddcad in std::__copy_move_a<false, long const*, long*> (__first=0x7fff00000001, __last=0x7fff60254788, __result=0x7ffd93dab010)
    at /usr/include/c++/4.8/bits/stl_algobase.h:390
#3  0x0000000000bddbfb in std::__copy_move_a2<false, __gnu_cxx::__normal_iterator<long const*, std::vector<long, std::allocator<long> > >, long*> (
    __first=..., __last=..., __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_algobase.h:428
#4  0x0000000000bddaa7 in std::copy<__gnu_cxx::__normal_iterator<long const*, std::vector<long, std::allocator<long> > >, long*> (__first=..., 
    __last=..., __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_algobase.h:460
#5  0x0000000000bdd7fb in std::__uninitialized_copy<true>::__uninit_copy<__gnu_cxx::__normal_iterator<long const*, std::vector<long, std::allocator<long> > >, long*> (__first=..., __last=..., __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_uninitialized.h:93
#6  0x0000000000bdd287 in std::uninitialized_copy<__gnu_cxx::__normal_iterator<long const*, std::vector<long, std::allocator<long> > >, long*> (
    __first=..., __last=..., __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_uninitialized.h:117
#7  0x0000000000bdcb0c in std::__uninitialized_copy_a<__gnu_cxx::__normal_iterator<long const*, std::vector<long, std::allocator<long> > >, long*, long> (__first=..., __last=..., __result=0x7ffd93dab010) at /usr/include/c++/4.8/bits/stl_uninitialized.h:258
#8  0x0000000000bdbd85 in std::vector<long, std::allocator<long> >::vector (this=0x7fff98005a40, __x=...)
    at /usr/include/c++/4.8/bits/stl_vector.h:316
#9  0x0000000000bd9b34 in MyRocksTablePropertiesCollector::IndexStats::IndexStats (this=0x7fff98005a20)
    at /home/psergey/dev-git/mysql-5.6-rocksdb-look-4/storage/rocksdb/properties_collector.h:9
#10 0x0000000000bde9f9 in RDBSE_KEYDEF::RDBSE_KEYDEF (this=0x7fff98005a00, k=...)
    at /home/psergey/dev-git/mysql-5.6-rocksdb-look-4/storage/rocksdb/rdb_datadic.cc:121
#11 0x0000000000be1319 in Table_ddl_manager::find (this=0x1a9cbe0 <ddl_manager>, index_number=44)
    at /home/psergey/dev-git/mysql-5.6-rocksdb-look-4/storage/rocksdb/rdb_datadic.cc:1322
#12 0x0000000000bc2d84 in compute_optimizer_stats () at /home/psergey/dev-git/mysql-5.6-rocksdb-look-4/storage/rocksdb/ha_rocksdb.cc:4971
#13 0x0000000000bc4a39 in background_thread () at /home/psergey/dev-git/mysql-5.6-rocksdb-look-4/storage/rocksdb/ha_rocksdb.cc:5444
#14 0x00007ffff650d182 in start_thread (arg=0x7fffadffb700) at pthread_create.c:312

It sees, we are trying to copy RDBSE_KEYDEF::index_stats which contains garbage in the instance of RDBSE_KEYDEF we're copying from

@yoshinorim
Owner
yoshinorim commented

I haven't been able to repeat the crash. @spetrunia: I think ha_rocksdb::delete_table() should keep holding x lock on both Dropped_indices_manager::add_indices() and ddl_manager.remove(), otherwise callers of Table_ddl_manager::find() may read stale object. Do you think this is the cause of this crash?

@maykov maykov self-assigned this
@maykov
Owner
maykov commented

I might know, what is the problem. Dropped_indices_manager::add_indices has this:
// zero out old pointers so they aren't freed
memset(old_tbl->key_descr, 0, sizeof(RDBSE_KEYDEF*) * old_tbl->n_keys);

Then, Table_ddl_manager::remove has this:
if (tbl->key_descr) // rename function sets this to null
for (uint keyno = 0; keyno < tbl->n_keys; keyno++)
index_num_to_keydef.erase(tbl->key_descr[keyno]->get_index_number());

So, it might be that index_num_to_keydef assoc never gets erased for these indexes.

@maykov
@maykov maykov referenced this issue from a commit
@maykov maykov Fix for the sigsev (issue #69) … 
Summary:
I couldn't repro the original bug. However, storing the nake pointer in index_num_to_keydef and not owning it was pretty unsafe. I changed it to store the table name and index number.
#69

Test Plan: rocksdb.records_in_range and rocksdb.statistics

Reviewers: hermanlee4, yoshinorim, spetrunia

Differential Revision: https://reviews.facebook.net/D39345
 5871269
@maykov maykov referenced this issue from a commit
@maykov maykov Using the global ddl_manager in table definition … 
Summary:
We discussed with herman that I should be using the global ddl_manager pointer exposed in one of his commits. This implements this idea. Also a few other CR items are addressed. Should be self descriptive.
#69

Test Plan: reran rocksdb suite, still no crash. Some tests fail for unrelated reasons.

Reviewers: yoshinorim, spetrunia, hermanlee4

Reviewed By: hermanlee4

Differential Revision: https://reviews.facebook.net/D39855
 da013b0
@yoshinorim yoshinorim closed this
@maykov maykov referenced this issue from a commit
@maykov maykov Fix for the sigsev (issue #69) … 
Summary:
I couldn't repro the original bug. However, storing the nake pointer in index_num_to_keydef and not owning it was pretty unsafe. I changed it to store the table name and index number.
#69

Test Plan: rocksdb.records_in_range and rocksdb.statistics

Reviewers: hermanlee4, yoshinorim, spetrunia

Differential Revision: https://reviews.facebook.net/D39345
 33c0cfb
@maykov maykov referenced this issue from a commit
@maykov maykov Using the global ddl_manager in table definition … 
Summary:
We discussed with herman that I should be using the global ddl_manager pointer exposed in one of his commits. This implements this idea. Also a few other CR items are addressed. Should be self descriptive.
#69

Test Plan: reran rocksdb suite, still no crash. Some tests fail for unrelated reasons.

Reviewers: yoshinorim, spetrunia, hermanlee4

Reviewed By: hermanlee4

Differential Revision: https://reviews.facebook.net/D39855
 6f4f234
@maykov maykov referenced this issue from a commit in facebook/mysql-5.6
@maykov maykov Fix for the sigsev (issue #69) … 
Summary:
I couldn't repro the original bug. However, storing the nake pointer in index_num_to_keydef and not owning it was pretty unsafe. I changed it to store the table name and index number.
MySQLOnRocksDB#69

Test Plan: rocksdb.records_in_range and rocksdb.statistics

Reviewers: hermanlee4, yoshinorim, spetrunia

Differential Revision: https://reviews.facebook.net/D39345
 bf45783
@maykov maykov referenced this issue from a commit in facebook/mysql-5.6
@maykov maykov Using the global ddl_manager in table definition … 
Summary:
We discussed with herman that I should be using the global ddl_manager pointer exposed in one of his commits. This implements this idea. Also a few other CR items are addressed. Should be self descriptive.
MySQLOnRocksDB#69

Test Plan: reran rocksdb suite, still no crash. Some tests fail for unrelated reasons.

Reviewers: yoshinorim, spetrunia, hermanlee4

Reviewed By: hermanlee4

Differential Revision: https://reviews.facebook.net/D39855
 ea14128
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.