Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Valgrind: invalid reads & writes by compaction thread #110

Open
slfritchie opened this issue Apr 5, 2014 · 13 comments
Open

Valgrind: invalid reads & writes by compaction thread #110

slfritchie opened this issue Apr 5, 2014 · 13 comments
Labels
Bug Kanban-Backlog resilience test
Milestone
2.0

Comments

@slfritchie
Copy link
Contributor

All of these messages appear to come from a single test case. I'll try to figure out if this is deterministic or not -- I haven't created a clever way to have QuickCheck recognize when valgrind spots an error. I have a manual way to do it, but it's manual and requires a huge amount of babysitting and is only worthwhile on 100% deterministic cases.

==5359== Thread 121:
==5359== Invalid read of size 4
==5359==    at 0x134778A5: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:106)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b3c is 60 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x134778C1: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:46)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b18 is 24 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x134778C7: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:49)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b30 is 48 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 1
==5359==    at 0x4C2DCAE: bcmp (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x134778DC: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (slice.h:89)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b48 is 72 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 1
==5359==    at 0x4C2DCC6: bcmp (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x134778DC: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (slice.h:89)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b49 is 73 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x134778E6: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:88)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b10 is 16 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x13476D80: leveldb::LRUCache2::LRU_Remove(leveldb::LRUHandle2*) (cache2.cc:238)
==5359==    by 0x134778FC: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:271)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b18 is 24 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x13476D84: leveldb::LRUCache2::LRU_Remove(leveldb::LRUHandle2*) (cache2.cc:238)
==5359==    by 0x134778FC: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:271)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b20 is 32 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 8
==5359==    at 0x13476D8C: leveldb::LRUCache2::LRU_Remove(leveldb::LRUHandle2*) (cache2.cc:239)
==5359==    by 0x134778FC: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:271)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b20 is 32 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid read of size 4
==5359==    at 0x13477448: leveldb::LRUCache2::Unref(leveldb::LRUHandle2*) (cache2.cc:621)
==5359==    by 0x13477907: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:272)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b38 is 56 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359== 
==5359== Invalid write of size 4
==5359==    at 0x13477450: leveldb::LRUCache2::Unref(leveldb::LRUHandle2*) (cache2.cc:621)
==5359==    by 0x13477907: leveldb::LRUCache2::Erase(leveldb::Slice const&, unsigned int) (cache2.cc:272)
==5359==    by 0x13463F0A: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:166)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==  Address 0x7fb03b38 is 56 bytes inside a block of size 87 free'd
==5359==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==5359==    by 0x1347796F: leveldb::LRUCache2::Release(leveldb::Cache::Handle*) (cache2.cc:254)
==5359==    by 0x13463F6E: leveldb::TableCache::Evict(unsigned long, bool) (table_cache.cc:162)
==5359==    by 0x134555EF: leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) (db_impl.cc:1433)
==5359==    by 0x1345582C: leveldb::DBImpl::BackgroundCompaction(leveldb::Compaction*) (db_impl.cc:1032)
==5359==    by 0x13456815: leveldb::DBImpl::BackgroundCall2(leveldb::Compaction*) (db_impl.cc:889)
==5359==    by 0x1345A7D0: leveldb::CompactionTask::operator()() (thread_tasks.h:124)
==5359==    by 0x1347EB7A: leveldb::HotThread::ThreadRoutine() (hot_threads.cc:102)
==5359==    by 0x5767E99: start_thread (pthread_create.c:308)
==5359==
@slfritchie
Copy link
Contributor Author

Oops, how about a couple more details?

eleveldb: commit 639f69c and then the patches on the slf-faulterl-introduction2 branch
leveldb: commit 6728f90cd7cc0afb5a1e4e839861bfac03dd1fe3 on the mv-imm-retry branch.

Not easily repeatable, sorry!

@matthewvon
Copy link
Contributor

This appears to be an error when shutting down the database that has an active compaction. Does that sound correct?

If so, would you attempt your test again with lines 1426 through 1435 of db/db_impl.cc commented out. Those lines were added due to valgrind testing a long time ago (like a year ago). Something may have changed.

@slfritchie
Copy link
Contributor Author

This appears to be an error when shutting down the database that has an active compaction.

Quite likely. The valgrind errors happened while running the following test case 20 times in a row: https://gist.github.com/slfritchie/1d2900a7a53e53ef2e82 ... all 20 passed, and only 1 of the 20 runs managed to trigger any Valgrind complaints.

There are 8 open() & 7 close() calls in that test case. The faulterl C code is calling srand(3) at the beginning of each test run, but I only tiny amounts of clue about how the Debian Linux wheezy/sid version of glibc deals with multi-threaded calls to srand(3) and rand(3).

@slfritchie
Copy link
Contributor Author

While trying to reproduce this error according to Matthew's advice from 10 hours ago (about lines 1426-1435), I re-ran with the faulterl library LD_PRELOAD'ed but with the main fault injection configuration option disabling all fault injection. I managed to hit the same invalid reads & writes on the first try. So, fault injection appears not to be 100% necessary to hit this problem, yay.

Cut-and-paste the contents of the gist above into an Erlang shell to bind the variable Ch. Then run the test case using this command to run with fault injection disabled:

[true = eqc:check(eqc:testing_time(3*60, generic_qc_fsm:prop(false, false)), Ch) || _ <- lists:seq(1,100)].

@slfritchie slfritchie added the Bug label Apr 11, 2014
@matthewvon
Copy link
Contributor

How did valgrind change with the lines removed?

@slfritchie
Copy link
Contributor Author

Today's status:

  • The paranoid_checks value is eleveldb's default
  • Eleveldb commit: 2a72ad3
    • Which is based off of today's develop branch at commit 9ab8ed6
  • Leveldb commit: f4cf10d2ba1b999f10805ac35f22145e80932544 (today's develop)
    • Plus the diff below

It looks like the develop branch of the leveldb repo has moved recently? So your line numbers are off. I took my best guess and applied this patch:

diff --git a/db/db_impl.cc b/db/db_impl.cc
index d30e60a..be4d74b 100644
--- a/db/db_impl.cc
+++ b/db/db_impl.cc
@@ -1432,13 +1432,13 @@ Status DBImpl::DoCompactionWork(CompactionState* compact

     // cleanup Riak modification that adds extra reference
     //  to overlap levels files.
-    if (compact->compaction->level() < config::kNumOverlapLevels)
-    {
-        for (size_t i = 0; i < compact->outputs.size(); i++) {
-            const CompactionState::Output& out = compact->outputs[i];
-            versions_->GetTableCache()->Evict(out.number, true);
-        }   // for
-    }   // if
+//per-MvM:    if (compact->compaction->level() < config::kNumOverlapLevels)
+//per-MvM:    {
+//per-MvM:        for (size_t i = 0; i < compact->outputs.size(); i++) {
+//per-MvM:            const CompactionState::Output& out = compact->outputs[i];
+//per-MvM:            versions_->GetTableCache()->Evict(out.number, true);
+//per-MvM:        }   // for
+//per-MvM:    }   // if
   }
   if (status.ok() && compact->builder != NULL) {
     status = FinishCompactionOutputFile(compact, input);

And I saw this Valgrind complaint:

==2268== Thread 75:
==2268== Invalid write of size 8
==2268==    at 0x1344A840: eleveldb::RefObject::~RefObject() (refobjects.cc:51)
==2268==    by 0x1344AA58: eleveldb::DbObject::~DbObject() (refobjects.cc:290)
==2268==    by 0x1344A933: eleveldb::ErlRefObject::RefDec() (refobjects.cc:181)
==2268==    by 0x1344A5FC: eleveldb::LevelIteratorWrapper::~LevelIteratorWrapper() (refobjects.h:146)
==2268==    by 0x1344A95D: eleveldb::RefObject::RefDec() (refobjects.cc:73)
==2268==    by 0x1344D7A5: eleveldb::MoveTask::~MoveTask() (refobjects.h:146)
==2268==    by 0x1344A95D: eleveldb::RefObject::RefDec() (refobjects.cc:73)
==2268==    by 0x1344BA51: eleveldb::eleveldb_write_thread_worker(void*) (threading.cc:382)
==2268==    by 0x549338: erl_drv_thread_wrapper (erl_drv_thread.c:117)
==2268==    by 0x612A14: thr_wrapper (ethread.c:106)
==2268==    by 0x5767E99: start_thread (pthread_create.c:308)
==2268==  Address 0x633c568 is 40 bytes inside a block of size 216 free'd
==2268==    at 0x4C2A82E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2268==    by 0x5A624A: erts_sys_free (sys.c:2553)
==2268==    by 0x52607F: erts_free (erl_alloc.h:239)
==2268==    by 0x526AB7: erts_bin_free (erl_binary.h:307)
==2268==    by 0x52C7A0: sweep_off_heap (erl_gc.c:2309)
==2268==    by 0x52A7D5: major_collection (erl_gc.c:1384)
==2268==    by 0x527486: erts_garbage_collect (erl_gc.c:437)
==2268==    by 0x5831FF: new_fun (beam_emu.c:6186)
==2268==    by 0x57EF8A: process_main (beam_cold.h:200)
==2268==    by 0x4B6244: sched_thread_func (erl_process.c:5801)
==2268==    by 0x612A14: thr_wrapper (ethread.c:106)
==2268==    by 0x5767E99: start_thread (pthread_create.c:308)
==2268==

@matthewvon
Copy link
Contributor

The first valgrind report was a nuisance issue. This second one is bad. The second one suggests the database actually closed before an iterator completed.

I can think of two scenarios:

  1. your test intentionally closes the db before releasing the iterator … one code path.
  2. your test closed the iterator first, but there is a prefetch running in the background … second code path. In this case, something did not honor the reference count while closing the database.

Do you know if your test intentionally creates scenario one? Independently, need to watch to see if the original valgrind report ever occurs again.

@matthewvon
Copy link
Contributor

There is now an eleveldb/mv-tuning7 branch (parallel to leveldb mv-tuning7) that addresses the likely scenario producing the second Valgrind report. This is by no means a comprehensive fix to the imagined "API calls after db close" scenario. It is more of a proof of concept / understanding.

@slfritchie
Copy link
Contributor Author

I can think of two scenarios:

  1. your test intentionally closes the db before releasing the iterator … one code path.

Not without an error in the Erlang compiler or VM that fails to execute code in the after block at https://github.com/basho/eleveldb/blob/slf-faulterl-introduction2/src/eleveldb.erl#L329-L339

  1. your test closed the iterator first, but there is a prefetch running in the background … second code path.

That's a bit interesting. Lines 329-339 show that the fold is always running to completion/exception throwing before returning control to the QuickCheck test code. It seems like the signal from leveldb that the iterator has found the right edge of the keyspace by some_iterator->Valid() returning false. The eleveldb wrapper appears to turn that into {error, invalid_iterator}, which the Erlang fold_loop() code uses to stop calling iterator_move(). Is it possible for prefetch to keep trying to do something after some_iterator->Valid() really returns false?

@matthewvon
Copy link
Contributor

Theory of the moment is that I interpreted the second Valgrind stack incorrectly. My new interpretation is that "Invalid write of size 8" at refobjects.cc:51 is really an attempt to update the performance counters. The performance counter code is expected (by me) to create a shared memory map and never unmap it. Maybe something unmaps it implicitly in the test cycle? Continuing to research this interpretation for now.

@slfritchie
Copy link
Contributor Author

New symptom, discussed this afternoon with @matthewvon:

=5189== Warning: set address range perms: large range [0x1088d5040, 0x11e7b16b0) (undefined)
==5189== Warning: set address range perms: large range [0xf29f8030, 0x1088d46c0) (noaccess)
==5189== Warning: set address range perms: large range [0x1088d5030, 0x11e7b16c0) (noaccess)

@slfritchie slfritchie added the test label May 1, 2014
@evanmcc evanmcc added this to the 2.0-RC milestone May 12, 2014
@cmeiklejohn cmeiklejohn modified the milestones: 2.0.1, 2.0-RC Jun 3, 2014
@cmeiklejohn
Copy link
Contributor

Moving to 2.0.1.

@matthewvon matthewvon modified the milestones: 2.0, 2.0.1 Jun 3, 2014
@matthewvon
Copy link
Contributor

Moved back to 2.0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Bug Kanban-Backlog resilience test
Projects
None yet
Milestone
2.0
Development

No branches or pull requests
4 participants
@evanmcc @cmeiklejohn @slfritchie @matthewvon