From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: From: Vladimir Davydov Subject: [PATCH 2/2] test: fix vinyl/errinj_ddl failure Date: Thu, 11 Apr 2019 13:13:38 +0300 Message-Id: In-Reply-To: References: In-Reply-To: References: To: tarantool-patches@freelists.org List-ID: The test fixes the following two test failures: | --- vinyl/errinj_ddl.result Tue Mar 19 17:52:48 2019 | +++ vinyl/errinj_ddl.reject Tue Mar 19 19:05:36 2019 | @@ -358,7 +358,7 @@ | ... | s.index.sk:stat().memory.rows | --- | -- 27 | +- 23 | ... | test_run:cmd('restart server default') | fiber = require('fiber') This happens, because creation of the test index can happen later than we expect. Fix it by adding an appropriate wait_cond. | --- vinyl/errinj_ddl.result Tue Mar 19 17:52:48 2019 | +++ vinyl/errinj_ddl.reject Tue Mar 19 18:07:55 2019 | @@ -504,6 +504,7 @@ | ... | _ = s1:create_index('sk', {parts = {2, 'unsigned'}}) | --- | +- error: Tuple field 2 required by space format is missing | ... | errinj.set("ERRINJ_VY_READ_PAGE_TIMEOUT", 0) | --- This one is due to a test transaction completing before DDL starts so that the transaction isn't aborted by DDL, as we expect. Fix it by making sure the transaction won't commit before DDL starts, again with the aid of wait_cond. | --- vinyl/errinj_ddl.result Wed Apr 10 18:59:57 2019 | +++ vinyl/errinj_ddl.reject Wed Apr 10 19:05:35 2019 | @@ -779,7 +779,7 @@ | ... | ch1:get() | --- | -- Transaction has been aborted by conflict | +- Duplicate key exists in unique index 'i1' in space 'test' | ... | ch2:get() | --- This test case fails, because we use a timeout to stall reading DML operations. This was initially a bad call, because under severe load (e.g. parallel test run), the timeout may fire before we get to execute the DDL request, which is supposed to abort the DML operations, in which case they won't be aborted. Fix this by replacing the timeout with a delay, as we should have done right from the start. Closes #4056 Closes #4057 --- src/box/vy_run.c | 6 +++++ src/lib/core/errinj.h | 1 + test/box/errinj.result | 50 ++++++++++++++++++++++-------------------- test/vinyl/errinj_ddl.result | 37 +++++++++++++++++++++---------- test/vinyl/errinj_ddl.test.lua | 29 ++++++++++++++---------- 5 files changed, 76 insertions(+), 47 deletions(-) diff --git a/src/box/vy_run.c b/src/box/vy_run.c index 03db2f50..de4d67ac 100644 --- a/src/box/vy_run.c +++ b/src/box/vy_run.c @@ -835,6 +835,12 @@ vy_page_read(struct vy_page *page, const struct vy_page_info *page_info, if (inj != NULL && inj->dparam > 0) usleep(inj->dparam * 1000000); + inj = errinj(ERRINJ_VY_READ_PAGE_DELAY, ERRINJ_BOOL); + if (inj != NULL) { + while (inj->bparam) + usleep(10000); + } + /* decode xlog tx */ const char *data_pos = data; const char *data_end = data + readen; diff --git a/src/lib/core/errinj.h b/src/lib/core/errinj.h index 6663b17c..5d9317d5 100644 --- a/src/lib/core/errinj.h +++ b/src/lib/core/errinj.h @@ -89,6 +89,7 @@ struct errinj { _(ERRINJ_VY_INDEX_DUMP, ERRINJ_INT, {.iparam = -1}) \ _(ERRINJ_VY_TASK_COMPLETE, ERRINJ_BOOL, {.bparam = false}) \ _(ERRINJ_VY_READ_PAGE, ERRINJ_BOOL, {.bparam = false}) \ + _(ERRINJ_VY_READ_PAGE_DELAY, ERRINJ_BOOL, {.bparam = false}) \ _(ERRINJ_VY_READ_PAGE_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \ _(ERRINJ_VY_SQUASH_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \ _(ERRINJ_VY_SCHED_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \ diff --git a/test/box/errinj.result b/test/box/errinj.result index af95134a..68b137a1 100644 --- a/test/box/errinj.result +++ b/test/box/errinj.result @@ -38,21 +38,23 @@ errinj.info() state: false ERRINJ_VYRUN_INDEX_GARBAGE: state: false + ERRINJ_VY_INDEX_FILE_RENAME: + state: false ERRINJ_VY_DELAY_PK_LOOKUP: state: false ERRINJ_VY_TASK_COMPLETE: state: false ERRINJ_PORT_DUMP: state: false - ERRINJ_RELAY_BREAK_LSN: - state: -1 + ERRINJ_VY_POINT_ITER_WAIT: + state: false ERRINJ_WAL_IO: state: false ERRINJ_WAL_FALLOCATE: state: 0 - ERRINJ_RELAY_EXIT_DELAY: - state: 0 - ERRINJ_SNAP_COMMIT_DELAY: + ERRINJ_WAL_BREAK_LSN: + state: -1 + ERRINJ_LOG_ROTATE: state: false ERRINJ_TUPLE_FORMAT_COUNT: state: -1 @@ -64,7 +66,7 @@ errinj.info() state: false ERRINJ_RELAY_REPORT_INTERVAL: state: 0 - ERRINJ_WAL_BREAK_LSN: + ERRINJ_RELAY_BREAK_LSN: state: -1 ERRINJ_VY_READ_PAGE_TIMEOUT: state: 0 @@ -72,18 +74,18 @@ errinj.info() state: false ERRINJ_SIO_READ_MAX: state: -1 - ERRINJ_VY_INDEX_FILE_RENAME: - state: false - ERRINJ_WAL_WRITE_DISK: - state: false ERRINJ_VY_RUN_FILE_RENAME: state: false + ERRINJ_WAL_WRITE_DISK: + state: false ERRINJ_VY_LOG_FILE_RENAME: state: false - ERRINJ_VY_RUN_WRITE: - state: false ERRINJ_HTTP_RESPONSE_ADD_WAIT: state: false + ERRINJ_VY_RUN_WRITE: + state: false + ERRINJ_SNAP_COMMIT_DELAY: + state: false ERRINJ_VY_LOG_FLUSH_DELAY: state: false ERRINJ_RELAY_FINAL_JOIN: @@ -96,34 +98,34 @@ errinj.info() state: false ERRINJ_WAL_ROTATE: state: false - ERRINJ_LOG_ROTATE: - state: false - ERRINJ_VY_POINT_ITER_WAIT: - state: false + ERRINJ_BUILD_INDEX: + state: -1 + ERRINJ_RELAY_EXIT_DELAY: + state: 0 ERRINJ_MEMTX_DELAY_GC: state: false ERRINJ_IPROTO_TX_DELAY: state: false - ERRINJ_BUILD_INDEX: - state: -1 ERRINJ_XLOG_READ: state: -1 - ERRINJ_XLOG_GARBAGE: - state: false ERRINJ_TUPLE_FIELD: state: false + ERRINJ_XLOG_GARBAGE: + state: false ERRINJ_INDEX_ALLOC: state: false + ERRINJ_VY_READ_PAGE_DELAY: + state: false ERRINJ_TESTING: state: false - ERRINJ_RELAY_SEND_DELAY: - state: false + ERRINJ_RELAY_TIMEOUT: + state: 0 ERRINJ_VY_SQUASH_TIMEOUT: state: 0 ERRINJ_VY_LOG_FLUSH: state: false - ERRINJ_RELAY_TIMEOUT: - state: 0 + ERRINJ_RELAY_SEND_DELAY: + state: false ... errinj.set("some-injection", true) --- diff --git a/test/vinyl/errinj_ddl.result b/test/vinyl/errinj_ddl.result index 794125e8..af5f73d4 100644 --- a/test/vinyl/errinj_ddl.result +++ b/test/vinyl/errinj_ddl.result @@ -287,8 +287,9 @@ ch = fiber.channel(1) _ = fiber.create(function() s:create_index('sk', {parts = {2, 'integer'}}) ch:put(true) end) --- ... -fiber.sleep(0.01) +test_run:wait_cond(function() return box.stat.vinyl().scheduler.tasks_inprogress > 0 end) --- +- true ... _ = s:delete{1} --- @@ -412,13 +413,13 @@ box.cfg{vinyl_cache = 0} s1 = box.schema.space.create('test1', {engine = 'vinyl'}) --- ... -_ = s1:create_index('pk', {page_size = 16}) +i1 = s1:create_index('pk', {page_size = 16}) --- ... s2 = box.schema.space.create('test2', {engine = 'vinyl'}) --- ... -_ = s2:create_index('pk') +i2 = s2:create_index('pk') --- ... pad = string.rep('x', 16) @@ -435,12 +436,12 @@ test_run:cmd("setopt delimiter ';'") --- - true ... -function async_replace(space, tuple, timeout) +function async_replace(space, tuple, wait_cond) local c = fiber.channel(1) fiber.create(function() box.begin() space:replace(tuple) - fiber.sleep(timeout) + test_run:wait_cond(wait_cond) local status = pcall(box.commit) c:put(status) end) @@ -452,10 +453,17 @@ test_run:cmd("setopt delimiter ''"); --- - true ... -c1 = async_replace(s1, {1}, 0.01) +-- Wait until DDL starts scanning the altered space. +lookup = i1:stat().lookup --- ... -c2 = async_replace(s2, {1}, 0.01) +wait_cond = function() return i1:stat().lookup > lookup end +--- +... +c1 = async_replace(s1, {1}, wait_cond) +--- +... +c2 = async_replace(s2, {1}, wait_cond) --- ... errinj.set("ERRINJ_VY_READ_PAGE_TIMEOUT", 0.001) @@ -492,10 +500,17 @@ s1:format() s1:format{} --- ... -c1 = async_replace(s1, {2}, 0.01) +-- Wait until DDL starts scanning the altered space. +lookup = i1:stat().lookup --- ... -c2 = async_replace(s2, {2}, 0.01) +wait_cond = function() return i1:stat().lookup > lookup end +--- +... +c1 = async_replace(s1, {2}, wait_cond) +--- +... +c2 = async_replace(s2, {2}, wait_cond) --- ... errinj.set("ERRINJ_VY_READ_PAGE_TIMEOUT", 0.001) @@ -737,7 +752,7 @@ test_run:cmd("setopt delimiter ''"); ... -- Issue a few DML requests that require reading disk. -- Stall disk reads. -errinj.set('ERRINJ_VY_READ_PAGE_TIMEOUT', 0.01) +errinj.set('ERRINJ_VY_READ_PAGE_DELAY', true) --- - ok ... @@ -758,7 +773,7 @@ s.index.i4:drop() --- ... -- Resume the DML requests. Check that they have been aborted. -errinj.set('ERRINJ_VY_READ_PAGE_TIMEOUT', 0) +errinj.set('ERRINJ_VY_READ_PAGE_DELAY', false) --- - ok ... diff --git a/test/vinyl/errinj_ddl.test.lua b/test/vinyl/errinj_ddl.test.lua index 84f33277..57af9c65 100644 --- a/test/vinyl/errinj_ddl.test.lua +++ b/test/vinyl/errinj_ddl.test.lua @@ -130,8 +130,7 @@ for i = 1, 5 do s:replace{i, i} end errinj.set("ERRINJ_VY_RUN_WRITE_DELAY", true) ch = fiber.channel(1) _ = fiber.create(function() s:create_index('sk', {parts = {2, 'integer'}}) ch:put(true) end) - -fiber.sleep(0.01) +test_run:wait_cond(function() return box.stat.vinyl().scheduler.tasks_inprogress > 0 end) _ = s:delete{1} _ = s:replace{2, -2} @@ -182,21 +181,21 @@ vinyl_cache = box.cfg.vinyl_cache box.cfg{vinyl_cache = 0} s1 = box.schema.space.create('test1', {engine = 'vinyl'}) -_ = s1:create_index('pk', {page_size = 16}) +i1 = s1:create_index('pk', {page_size = 16}) s2 = box.schema.space.create('test2', {engine = 'vinyl'}) -_ = s2:create_index('pk') +i2 = s2:create_index('pk') pad = string.rep('x', 16) for i = 101, 200 do s1:replace{i, i, pad} end box.snapshot() test_run:cmd("setopt delimiter ';'") -function async_replace(space, tuple, timeout) +function async_replace(space, tuple, wait_cond) local c = fiber.channel(1) fiber.create(function() box.begin() space:replace(tuple) - fiber.sleep(timeout) + test_run:wait_cond(wait_cond) local status = pcall(box.commit) c:put(status) end) @@ -204,8 +203,11 @@ function async_replace(space, tuple, timeout) end; test_run:cmd("setopt delimiter ''"); -c1 = async_replace(s1, {1}, 0.01) -c2 = async_replace(s2, {1}, 0.01) +-- Wait until DDL starts scanning the altered space. +lookup = i1:stat().lookup +wait_cond = function() return i1:stat().lookup > lookup end +c1 = async_replace(s1, {1}, wait_cond) +c2 = async_replace(s2, {1}, wait_cond) errinj.set("ERRINJ_VY_READ_PAGE_TIMEOUT", 0.001) s1:format{{'key', 'unsigned'}, {'value', 'unsigned'}} @@ -219,8 +221,11 @@ s2:get(1) ~= nil s1:format() s1:format{} -c1 = async_replace(s1, {2}, 0.01) -c2 = async_replace(s2, {2}, 0.01) +-- Wait until DDL starts scanning the altered space. +lookup = i1:stat().lookup +wait_cond = function() return i1:stat().lookup > lookup end +c1 = async_replace(s1, {2}, wait_cond) +c2 = async_replace(s2, {2}, wait_cond) errinj.set("ERRINJ_VY_READ_PAGE_TIMEOUT", 0.001) _ = s1:create_index('sk', {parts = {2, 'unsigned'}}) @@ -329,7 +334,7 @@ test_run:cmd("setopt delimiter ''"); -- Issue a few DML requests that require reading disk. -- Stall disk reads. -errinj.set('ERRINJ_VY_READ_PAGE_TIMEOUT', 0.01) +errinj.set('ERRINJ_VY_READ_PAGE_DELAY', true) ch1 = async(function() s:insert({1, 1, 1, 1}) end) ch2 = async(function() s:replace({2, 3, 2, 3}) end) @@ -340,7 +345,7 @@ ch4 = async(function() s:upsert({5, 5, 5, 5}, {{'+', 4, 1}}) end) s.index.i4:drop() -- Resume the DML requests. Check that they have been aborted. -errinj.set('ERRINJ_VY_READ_PAGE_TIMEOUT', 0) +errinj.set('ERRINJ_VY_READ_PAGE_DELAY', false) ch1:get() ch2:get() ch3:get() -- 2.11.0