Uploaded image for project: 'TokuFT'
  1. FT-665

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.

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects versions: None
    • Labels:
      None
    • Sprint:

      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==

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              George O. Lorch III George Lorch
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: