ctest - drd_mid_test_stress7 reports Probably a race condition: condition variable <nr> has been signaled but the associated mutex <nr> is not locked by the signalling thread.

Description

Reproduced on local hardware. Also appears in the following with slightly different stacks but same frwlocks involved in same areas:

  • drd_mid_test_stress0

  • drd_mid_test_stress1

  • drd_mid_test_stress2

  • drd_mid_test_stress3

  • drd_mid_test_stress4

  • drd_mid_test_stress5

  • drd_mid_test_stress6

  • drd_mid_test_stress_with_verify

  • drd_mid_test_stress_openclose

  • drd_tiny_test_stress_openclose

  • drd_tiny_test_stress2

==11812== Thread 39:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5440965: toku_cond_signal(toku_cond*) [clone .26009] (toku_pthread.h:336)
==11812== by 0x546299D: toku_cachetable_get_and_pin_nonblocking(cachefile*, blocknum_s, unsigned int, void*, long, CACHETABLE_WRITE_CALLBACK, int (cachefile*, ctpair*, int, blocknum_s, unsigned int, void*, void, pair_attr_s, int*, void*), bool (void*, void*), int (void*, void*, void*, int, pair_attr_s*), pair_lock_type, void*, unlockers*) [clone .constprop.778] (cachetable.cc:4296)
==11812== by 0x548F7BF: ft_search_node(ft_handle*, ftnode*, ft_search*, int, int (unsigned int, void const*, unsigned int, void const*, void*, bool), void*, bool*, ft_cursor*, unlockers*, ancestors*, pivot_bounds const&, bool) [clone .39045.6352] (ft-cachetable-wrappers.cc:241)
==11812== by 0x548F8E9: ft_search_node(ft_handle*, ftnode*, ft_search*, int, int (unsigned int, void const*, unsigned int, void const*, void*, bool), void*, bool*, ft_cursor*, unlockers*, ancestors*, pivot_bounds const&, bool) [clone .39045.6352] (ft-ops.cc:3603)
==11812== by 0x5493608: toku_ft_search(ft_handle*, ft_search*, int (unsigned int, void const*, unsigned int, void const*, void*, bool), void*, ft_cursor*, bool) (ft-ops.cc:3906)
==11812== by 0x5493990: toku_c_getf_set(__toku_dbc*, unsigned int, _toku_dbt*, int (_toku_dbt const*, __toku_dbt const*, void*), void*) [clone .part.3.6681] (cursor.cc:395)
==11812== by 0x54D3738: db_getf_set(__toku_db*, __toku_db_txn*, unsigned int, _toku_dbt*, int (_toku_dbt const*, __toku_dbt const*, void*), void*) [clone .part.33.8477.9830] (ydb_db.cc:229)
==11812== by 0x54D57ED: autotxn_db_getf_set(__toku_db*, __toku_db_txn*, unsigned int, _toku_dbt*, int (_toku_dbt const*, __toku_dbt const*, void*), void*) [clone .8562] (ydb_db.h:160)
==11812== by 0x4081B7: ptquery_op(__toku_db_txn*, arg*, void*, void*) [clone .3776] (threaded_stress_test_helpers.h:1205)
==11812== by 0x4094A9: worker(void*) [clone .3460] (threaded_stress_test_helpers.h:589)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Thread 35:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BB80: toku_unpin_ftnode(ft*, ftnode*) (cachetable.cc:1937)
==11812== by 0x54EAA3F: toku_ft_flush_some_child(ft*, ftnode*, flusher_advice*) (ft-flusher.cc:1563)
==11812== by 0x54B9C32: toku_ft_hot_optimize(ft_handle*, __toku_dbt*, __toku_dbt*, int (void*, float), void*, unsigned long*) [clone .9755] (ft-hot-flusher.cc:365)
==11812== by 0x405AEE: hot_op(__toku_db_txn*, arg*, void*, void*) [clone .3561] (threaded_stress_test_helpers.h:1646)
==11812== by 0x4094A9: worker(void*) [clone .3460] (threaded_stress_test_helpers.h:589)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5953181: start_thread (pthread_create.c:312)
==11812== by 0x4F4147C: clone (clone.S:111)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BB80: toku_unpin_ftnode(ft*, ftnode*) (cachetable.cc:1937)
==11812== by 0x54EAA97: toku_ft_flush_some_child(ft*, ftnode*, flusher_advice*) (ft-flusher.cc:1581)
==11812== by 0x54EAA0B: toku_ft_flush_some_child(ft*, ftnode*, flusher_advice*) (ft-flusher.cc:1627)
==11812== by 0x54B9C32: toku_ft_hot_optimize(ft_handle*, __toku_dbt*, __toku_dbt*, int (void*, float), void*, unsigned long*) [clone .9755] (ft-hot-flusher.cc:365)
==11812== by 0x405AEE: hot_op(__toku_db_txn*, arg*, void*, void*) [clone .3561] (threaded_stress_test_helpers.h:1646)
==11812== by 0x4094A9: worker(void*) [clone .3460] (threaded_stress_test_helpers.h:589)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5953181: start_thread (pthread_create.c:312)
==11812== by 0x4F4147C: clone (clone.S:111)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Thread 38:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BB80: toku_unpin_ftnode(ft*, ftnode*) (cachetable.cc:1937)
==11812== by 0x54EB2D2: inject_message_in_locked_node(ft*, ftnode*, int, ft_msg const&, unsigned long*, txn_gc_info*) [clone .38757] (ft-ops.cc:1640)
==11812== by 0x54EC208: inject_message_at_this_blocknum(ft*, blocknum_s, unsigned int, ft_msg const&, unsigned long*, txn_gc_info*) [clone .38765] (ft-ops.cc:1777)
==11812== by 0x54B48E0: push_something_in_subtree(ft*, ftnode*, int, ft_msg const&, unsigned long*, txn_gc_info*, int, char, bool) [clone .38804.9235] (ft-ops.cc:2005)
==11812== by 0x54B4B8A: push_something_in_subtree(ft*, ftnode*, int, ft_msg const&, unsigned long*, txn_gc_info*, int, char, bool) [clone .38804.9235] (ft-ops.cc:1969)
==11812== by 0x54B6644: toku_ft_root_put_msg(ft*, ft_msg const&, txn_gc_info*) (ft-ops.cc:2119)
==11812== by 0x54B69EB: ft_send_update_msg(ft_handle*, ft_msg const&, tokutxn*) [clone .38823] (ft-ops.cc:2588)
==11812== by 0x54B6D34: toku_ft_maybe_update(ft_handle*, __toku_dbt const*, __toku_dbt const*, tokutxn*, bool, __toku_lsn, bool) (ft-ops.cc:2619)
==11812== by 0x54C63FA: autotxn_db_update(__toku_db*, __toku_db_txn*, __toku_dbt const*, __toku_dbt const*, unsigned int) (ydb_write.cc:344)
==11812== by 0x409EAF: update_op(__toku_db_txn*, arg*, void*, void*) [clone .3770] (threaded_stress_test_helpers.h:1546)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Thread 3:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BB80: toku_unpin_ftnode(ft*, ftnode*) (cachetable.cc:1937)
==11812== by 0x54B1C7B: flush_node_fun(void*) [clone .34663] (ft-flusher.cc:1918)
==11812== by 0x5431A63: work_on_kibbutz(void*) [clone .79626] (kibbutz.cc:184)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5953181: start_thread (pthread_create.c:312)
==11812== by 0x4F4147C: clone (clone.S:111)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Thread 7:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BB80: toku_unpin_ftnode(ft*, ftnode*) (cachetable.cc:1937)
==11812== by 0x54EAA5A: toku_ft_flush_some_child(ft*, ftnode*, flusher_advice*) (ft-flusher.cc:1630)
==11812== by 0x54B1CE4: flush_node_fun(void*) [clone .34663] (ft-flusher.cc:1926)
==11812== by 0x5431A63: work_on_kibbutz(void*) [clone .79626] (kibbutz.cc:184)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5953181: start_thread (pthread_create.c:312)
==11812== by 0x4F4147C: clone (clone.S:111)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==
==11812== Thread 38:
==11812== Probably a race condition: condition variable 0x69ba318 has been signaled but the associated mutex 0x69ba2e8 is not locked by the signalling thread.
==11812== at 0x4C35C28: pthread_cond_signal@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5456CAF: cachetable_unpin_internal(cachefile*, ctpair*, cachetable_dirty, pair_attr_s, bool) [clone .isra.39.26805.10825] (toku_pthread.h:336)
==11812== by 0x545BD37: toku_rollback_log_unpin(tokutxn*, rollback_log_node*) (cachetable.cc:1937)
==11812== by 0x54B6C6B: toku_ft_maybe_update(ft_handle*, __toku_dbt const*, __toku_dbt const*, tokutxn*, bool, __toku_lsn, bool) (log_code.cc:2091)
==11812== by 0x54C63FA: autotxn_db_update(__toku_db*, __toku_db_txn*, __toku_dbt const*, __toku_dbt const*, unsigned int) (ydb_write.cc:344)
==11812== by 0x409EAF: update_op(__toku_db_txn*, arg*, void*, void*) [clone .3770] (threaded_stress_test_helpers.h:1546)
==11812== by 0x4094A9: worker(void*) [clone .3460] (threaded_stress_test_helpers.h:589)
==11812== by 0x4C30E7B: ??? (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5953181: start_thread (pthread_create.c:312)
==11812== by 0x4F4147C: clone (clone.S:111)
==11812== cond 0x69ba318 was first observed at:
==11812== at 0x4C34AB8: pthread_cond_init@* (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x543B467: toku_cond_init(toku_cond*, pthread_condattr_t const*) [clone .25988] [clone .constprop.864] (toku_pthread.h:292)
==11812== by 0x5427B95: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3663)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812== mutex 0x69ba2e8 was first observed at:
==11812== at 0x4C32F22: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_drd-amd64-linux.so)
==11812== by 0x5420A60: toku_mutex_init(toku_mutex*, pthread_mutexattr_t const*) [clone .26019] [clone .constprop.587] (toku_pthread.h:163)
==11812== by 0x5427B7D: toku_cachetable_create(cachetable*, long, __toku_lsn, tokulogger) (cachetable.cc:3661)
==11812== by 0x54E3F13: env_open(__toku_db_env*, char const*, unsigned int, int) [clone .3981] (ydb.cc:974)
==11812== by 0x402033: main (threaded_stress_test_helpers.h:2200)
==11812==

Environment

None

Status

Assignee

Unassigned

Reporter

George Lorch

Labels

None

External issue ID

None

Freshdesk Tickets

None

Fix versions

Priority

Minor
Configure