From ff02157fc7dcd6112059d5d10128307ad3ac7ed8 Mon Sep 17 00:00:00 2001
From: Vladimir Davydov <vdavydov.dev@gmail.com>
Date: Tue, 29 May 2018 16:16:28 +0300
Subject: [PATCH] vinyl: fix false-positive assertion at exit

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
---
 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 c31a588e0b..b168466549 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 89f88bdc70..e4701ce12a 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 ed69b6cb00..fa4c961040 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 9e3a0bfab4..15753e10d1 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 9135108665..c9a0140e88 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 9724a69b82..8c2874058b 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")
-- 
GitLab