From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: From: Vladimir Davydov Subject: [PATCH v2] vinyl: fix false-positive assertion at exit Date: Thu, 31 May 2018 11:32:28 +0300 Message-Id: In-Reply-To: <20180530185336.GE18850@atlas> References: <20180530185336.GE18850@atlas> To: kostja@tarantool.org Cc: tarantool-patches@freelists.org List-ID: latch_destroy() and fiber_cond_destroy() are basically no-op. All they do is check that latch/cond is not used. When a global latch or cond object is destroyed at exit, it may still have users and this is OK as we don't stop fibers at exit. In vinyl this results in the following false-positive assertion failures: src/latch.h:81: latch_destroy: Assertion `l->owner == NULL' failed. src/fiber_cond.c:49: fiber_cond_destroy: Assertion `rlist_empty(&c->waiters)' failed. Remove "destruction" of vy_log::latch to suppress the first one. Wake up all fibers waiting on vy_quota::cond before destruction to suppress the second one. Add some test cases. Closes #3412 --- https://github.com/tarantool/tarantool/issues/3412 https://github.com/tarantool/tarantool/commits/gh-3412-vy-fix-assert-at-exit Changes in v2: - Reduce the number of records written by the test to make it run faster. src/box/vy_log.c | 6 +++- src/box/vy_quota.h | 1 + src/errinj.h | 1 + test/box/errinj.result | 18 ++++++------ test/vinyl/errinj.result | 68 ++++++++++++++++++++++++++++++++++++++++++++++ test/vinyl/errinj.test.lua | 25 +++++++++++++++++ 6 files changed, 110 insertions(+), 9 deletions(-) diff --git a/src/box/vy_log.c b/src/box/vy_log.c index c31a588e..b1684665 100644 --- a/src/box/vy_log.c +++ b/src/box/vy_log.c @@ -770,6 +770,11 @@ vy_log_flush(void) diag_set(ClientError, ER_INJECTION, "vinyl log flush"); return -1; }); + struct errinj *delay = errinj(ERRINJ_VY_LOG_FLUSH_DELAY, ERRINJ_BOOL); + if (delay != NULL && delay->bparam) { + while (delay->bparam) + fiber_sleep(0.001); + } struct journal_entry *entry = journal_entry_new(vy_log.tx_size); if (entry == NULL) @@ -815,7 +820,6 @@ void vy_log_free(void) { xdir_destroy(&vy_log.dir); - latch_destroy(&vy_log.latch); region_destroy(&vy_log.pool); diag_destroy(&vy_log.tx_diag); } diff --git a/src/box/vy_quota.h b/src/box/vy_quota.h index 89f88bdc..e4701ce1 100644 --- a/src/box/vy_quota.h +++ b/src/box/vy_quota.h @@ -97,6 +97,7 @@ vy_quota_create(struct vy_quota *q, vy_quota_exceeded_f quota_exceeded_cb) static inline void vy_quota_destroy(struct vy_quota *q) { + fiber_cond_broadcast(&q->cond); fiber_cond_destroy(&q->cond); } diff --git a/src/errinj.h b/src/errinj.h index ed69b6cb..fa4c9610 100644 --- a/src/errinj.h +++ b/src/errinj.h @@ -93,6 +93,7 @@ struct errinj { _(ERRINJ_VY_SCHED_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \ _(ERRINJ_VY_GC, ERRINJ_BOOL, {.bparam = false}) \ _(ERRINJ_VY_LOG_FLUSH, ERRINJ_BOOL, {.bparam = false}) \ + _(ERRINJ_VY_LOG_FLUSH_DELAY, ERRINJ_BOOL, {.bparam = false}) \ _(ERRINJ_RELAY_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \ _(ERRINJ_RELAY_REPORT_INTERVAL, ERRINJ_DOUBLE, {.dparam = 0}) \ _(ERRINJ_RELAY_FINAL_SLEEP, ERRINJ_BOOL, {.bparam = false}) \ diff --git a/test/box/errinj.result b/test/box/errinj.result index 9e3a0bfa..15753e10 100644 --- a/test/box/errinj.result +++ b/test/box/errinj.result @@ -54,6 +54,8 @@ errinj.info() state: false ERRINJ_VY_RUN_WRITE: state: false + ERRINJ_VY_LOG_FLUSH_DELAY: + state: false ERRINJ_RELAY_FINAL_SLEEP: state: false ERRINJ_VY_RUN_DISCARD: @@ -68,24 +70,24 @@ errinj.info() state: 0 ERRINJ_IPROTO_TX_DELAY: state: false + ERRINJ_BUILD_SECONDARY: + state: -1 ERRINJ_TUPLE_FIELD: state: false - ERRINJ_INDEX_ALLOC: - state: false ERRINJ_XLOG_GARBAGE: state: false - ERRINJ_VY_RUN_WRITE_TIMEOUT: - state: 0 + ERRINJ_INDEX_ALLOC: + state: false ERRINJ_RELAY_TIMEOUT: state: 0 ERRINJ_TESTING: state: false - ERRINJ_VY_LOG_FLUSH: - state: false + ERRINJ_VY_RUN_WRITE_TIMEOUT: + state: 0 ERRINJ_VY_SQUASH_TIMEOUT: state: 0 - ERRINJ_BUILD_SECONDARY: - state: -1 + ERRINJ_VY_LOG_FLUSH: + state: false ERRINJ_VY_INDEX_DUMP: state: -1 ... diff --git a/test/vinyl/errinj.result b/test/vinyl/errinj.result index 91351086..c9a0140e 100644 --- a/test/vinyl/errinj.result +++ b/test/vinyl/errinj.result @@ -1320,3 +1320,71 @@ ret s:drop() --- ... +-- +-- gh-3412 - assertion failure at exit in case: +-- * there is a fiber waiting for quota +-- * there is a pending vylog write +-- +test_run:cmd("create server low_quota with script='vinyl/low_quota.lua'") +--- +- true +... +test_run:cmd("start server low_quota with args='1048576'") +--- +- true +... +test_run:cmd('switch low_quota') +--- +- true +... +_ = box.schema.space.create('test', {engine = 'vinyl'}) +--- +... +_ = box.space.test:create_index('pk') +--- +... +box.error.injection.set('ERRINJ_VY_RUN_WRITE_STMT_TIMEOUT', 0.01) +--- +- ok +... +fiber = require('fiber') +--- +... +pad = string.rep('x', 100 * 1024) +--- +... +_ = fiber.create(function() for i = 1, 11 do box.space.test:replace{i, pad} end end) +--- +... +repeat fiber.sleep(0.001) q = box.info.vinyl().quota until q.limit - q.used < pad:len() +--- +... +test_run:cmd("restart server low_quota with args='1048576'") +box.error.injection.set('ERRINJ_VY_LOG_FLUSH_DELAY', true) +--- +- ok +... +fiber = require('fiber') +--- +... +pad = string.rep('x', 100 * 1024) +--- +... +_ = fiber.create(function() for i = 1, 11 do box.space.test:replace{i, pad} end end) +--- +... +repeat fiber.sleep(0.001) q = box.info.vinyl().quota until q.limit - q.used < pad:len() +--- +... +test_run:cmd('switch default') +--- +- true +... +test_run:cmd("stop server low_quota") +--- +- true +... +test_run:cmd("cleanup server low_quota") +--- +- true +... diff --git a/test/vinyl/errinj.test.lua b/test/vinyl/errinj.test.lua index 9724a69b..8c287405 100644 --- a/test/vinyl/errinj.test.lua +++ b/test/vinyl/errinj.test.lua @@ -513,3 +513,28 @@ errinj.set("ERRINJ_VY_DELAY_PK_LOOKUP", false) while ret == nil do fiber.sleep(0.01) end ret s:drop() + +-- +-- gh-3412 - assertion failure at exit in case: +-- * there is a fiber waiting for quota +-- * there is a pending vylog write +-- +test_run:cmd("create server low_quota with script='vinyl/low_quota.lua'") +test_run:cmd("start server low_quota with args='1048576'") +test_run:cmd('switch low_quota') +_ = box.schema.space.create('test', {engine = 'vinyl'}) +_ = box.space.test:create_index('pk') +box.error.injection.set('ERRINJ_VY_RUN_WRITE_STMT_TIMEOUT', 0.01) +fiber = require('fiber') +pad = string.rep('x', 100 * 1024) +_ = fiber.create(function() for i = 1, 11 do box.space.test:replace{i, pad} end end) +repeat fiber.sleep(0.001) q = box.info.vinyl().quota until q.limit - q.used < pad:len() +test_run:cmd("restart server low_quota with args='1048576'") +box.error.injection.set('ERRINJ_VY_LOG_FLUSH_DELAY', true) +fiber = require('fiber') +pad = string.rep('x', 100 * 1024) +_ = fiber.create(function() for i = 1, 11 do box.space.test:replace{i, pad} end end) +repeat fiber.sleep(0.001) q = box.info.vinyl().quota until q.limit - q.used < pad:len() +test_run:cmd('switch default') +test_run:cmd("stop server low_quota") +test_run:cmd("cleanup server low_quota") -- 2.11.0