From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: From: Alexander Turenko Subject: [PATCH 2/2] test: rewrote xlog/checkpoint_daemon.test.lua Date: Thu, 25 Oct 2018 05:31:04 +0300 Message-Id: In-Reply-To: References: MIME-Version: 1.0 Content-Transfer-Encoding: 8bit To: Vladimir Davydov Cc: Alexander Turenko , Sergei Voronezhskii , tarantool-patches@freelists.org List-ID: Updated the test case for #2780 to check a last snapshot file modification time instead of search log messages. The test was flaky, because of small timeouts on Linux, but now we spinning on a condition check to achieve both stable results and fast execution. Follows up #2780. Fixes #3684. --- test/xlog/checkpoint_daemon.result | 90 ++++++++++++++++++++-------- test/xlog/checkpoint_daemon.test.lua | 84 +++++++++++++++++--------- 2 files changed, 121 insertions(+), 53 deletions(-) diff --git a/test/xlog/checkpoint_daemon.result b/test/xlog/checkpoint_daemon.result index d5ed666f2..3a75137d2 100644 --- a/test/xlog/checkpoint_daemon.result +++ b/test/xlog/checkpoint_daemon.result @@ -19,10 +19,10 @@ test_run:cleanup_cluster() box.cfg{checkpoint_interval = 0} --- ... -PERIOD = 0.03 +PERIOD = jit.os == 'Linux' and 0.03 or 1.5 --- ... -if jit.os ~= 'Linux' then PERIOD = 1.5 end +WAIT_COND_TIMEOUT = 10 --- ... space = box.schema.space.create('checkpoint_daemon') @@ -31,6 +31,50 @@ space = box.schema.space.create('checkpoint_daemon') index = space:create_index('pk', { type = 'tree', parts = { 1, 'unsigned' }}) --- ... +test_run:cmd("setopt delimiter ';'") +--- +- true +... +-- wait_snapshot* functions update these variables. +snaps = {}; +--- +... +xlogs = {}; +--- +... +-- Wait until tarantool creates a snapshot containing current +-- data slice. +function wait_snapshot(timeout) + snaps = {} + xlogs = {} + local signature_str = tostring(box.info.signature) + signature_str = string.rjust(signature_str, 20, '0') + local exp_snap_filename = string.format('%s.snap', signature_str) + return test_run:wait_cond(function() + snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) + xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) + return fio.basename(snaps[#snaps]) == exp_snap_filename + end, timeout) +end; +--- +... +-- Wait until snapshots count will be equal to the +-- checkpoint_count option. +function wait_snapshot_gc(timeout) + snaps = {} + xlogs = {} + return test_run:wait_cond(function() + snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) + xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) + return #snaps == box.cfg.checkpoint_count + end, timeout) +end; +--- +... +test_run:cmd("setopt delimiter ''"); +--- +- true +... box.cfg{checkpoint_interval = PERIOD, checkpoint_count = 2 } --- ... @@ -45,9 +89,9 @@ for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end --- ... --- wait for last snapshot -fiber.sleep(1.5 * PERIOD) +wait_snapshot(WAIT_COND_TIMEOUT) --- +- true ... -- third xlog for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end @@ -57,23 +101,11 @@ for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end --- ... --- wait for last snapshot -test_run:cmd("setopt delimiter ';'") +wait_snapshot(WAIT_COND_TIMEOUT) --- - true ... -for i = 1, 100 do - fiber.sleep(PERIOD) - snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) - xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) - - if #snaps == 2 then - break - end -end; ---- -... -test_run:cmd("setopt delimiter ''"); +wait_snapshot_gc(WAIT_COND_TIMEOUT) --- - true ... @@ -85,20 +117,30 @@ test_run:cmd("setopt delimiter ''"); --- - true ... -fio.basename(snaps[1], '.snap') >= fio.basename(xlogs[1], '.xlog') +-- gh-2780: check that a last snapshot mtime will be changed at +-- least two times. +test_run:cmd("setopt delimiter ';'") --- - true ... --- gh-2780 check that scheduled snapshots are performed -fiber.sleep(3 * PERIOD) +last_mtime = fio.stat(snaps[#snaps]).mtime; --- ... --- check that it's not first snapshot -test_run:grep_log("default", "saving snapshot", 400) == nil +mtime_changes_cnt = 0; +--- +... +test_run:wait_cond(function() + local mtime = fio.stat(snaps[#snaps]).mtime + if mtime ~= last_mtime then + mtime_changes_cnt = mtime_changes_cnt + 1 + last_mtime = mtime + end + return mtime_changes_cnt == 2 +end, WAIT_COND_TIMEOUT); --- - true ... -test_run:grep_log("default", "making snapshot", 400) ~= nil +test_run:cmd("setopt delimiter ''"); --- - true ... diff --git a/test/xlog/checkpoint_daemon.test.lua b/test/xlog/checkpoint_daemon.test.lua index 4a0aafa84..f34906217 100644 --- a/test/xlog/checkpoint_daemon.test.lua +++ b/test/xlog/checkpoint_daemon.test.lua @@ -8,13 +8,46 @@ test_run:cleanup_cluster() box.cfg{checkpoint_interval = 0} -PERIOD = 0.03 -if jit.os ~= 'Linux' then PERIOD = 1.5 end - +PERIOD = jit.os == 'Linux' and 0.03 or 1.5 +WAIT_COND_TIMEOUT = 10 space = box.schema.space.create('checkpoint_daemon') index = space:create_index('pk', { type = 'tree', parts = { 1, 'unsigned' }}) +test_run:cmd("setopt delimiter ';'") + +-- wait_snapshot* functions update these variables. +snaps = {}; +xlogs = {}; + +-- Wait until tarantool creates a snapshot containing current +-- data slice. +function wait_snapshot(timeout) + snaps = {} + xlogs = {} + local signature_str = tostring(box.info.signature) + signature_str = string.rjust(signature_str, 20, '0') + local exp_snap_filename = string.format('%s.snap', signature_str) + return test_run:wait_cond(function() + snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) + xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) + return fio.basename(snaps[#snaps]) == exp_snap_filename + end, timeout) +end; + +-- Wait until snapshots count will be equal to the +-- checkpoint_count option. +function wait_snapshot_gc(timeout) + snaps = {} + xlogs = {} + return test_run:wait_cond(function() + snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) + xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) + return #snaps == box.cfg.checkpoint_count + end, timeout) +end; + +test_run:cmd("setopt delimiter ''"); box.cfg{checkpoint_interval = PERIOD, checkpoint_count = 2 } @@ -23,41 +56,34 @@ no = 1 for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end -- second xlog for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end --- wait for last snapshot -fiber.sleep(1.5 * PERIOD) + +wait_snapshot(WAIT_COND_TIMEOUT) + -- third xlog for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end -- fourth xlog for i = 1, box.cfg.rows_per_wal + 10 do space:insert { no } no = no + 1 end --- wait for last snapshot - -test_run:cmd("setopt delimiter ';'") - -for i = 1, 100 do - fiber.sleep(PERIOD) - snaps = fio.glob(fio.pathjoin(box.cfg.memtx_dir, '*.snap')) - xlogs = fio.glob(fio.pathjoin(box.cfg.wal_dir, '*.xlog')) - - if #snaps == 2 then - break - end -end; - -test_run:cmd("setopt delimiter ''"); - - +wait_snapshot(WAIT_COND_TIMEOUT) +wait_snapshot_gc(WAIT_COND_TIMEOUT) #snaps == 2 or snaps #xlogs > 0 -fio.basename(snaps[1], '.snap') >= fio.basename(xlogs[1], '.xlog') - --- gh-2780 check that scheduled snapshots are performed -fiber.sleep(3 * PERIOD) --- check that it's not first snapshot -test_run:grep_log("default", "saving snapshot", 400) == nil -test_run:grep_log("default", "making snapshot", 400) ~= nil +-- gh-2780: check that a last snapshot mtime will be changed at +-- least two times. +test_run:cmd("setopt delimiter ';'") +last_mtime = fio.stat(snaps[#snaps]).mtime; +mtime_changes_cnt = 0; +test_run:wait_cond(function() + local mtime = fio.stat(snaps[#snaps]).mtime + if mtime ~= last_mtime then + mtime_changes_cnt = mtime_changes_cnt + 1 + last_mtime = mtime + end + return mtime_changes_cnt == 2 +end, WAIT_COND_TIMEOUT); +test_run:cmd("setopt delimiter ''"); -- restore default options box.cfg{checkpoint_interval = 3600 * 4, checkpoint_count = 4 } -- 2.19.1