[PATCH 1/2] test: wait until expected value appear in log
Alexander Turenko
alexander.turenko at tarantool.org
Mon Oct 15 03:29:52 MSK 2018
Hi, Sergei!
I give some general comments below.
Please, update if you are agree with my comments and review the patch
with Vladimir.
WBR, Alexander Turenko.
On Wed, Oct 10, 2018 at 10:56:26AM +0300, Sergei Voronezhskii wrote:
> Sleep for the constant time can't fit the case when we need to wait for
> snapshot. System load may change app timings and we got flaky test.
> Need to check logfile with delay until timeout or log has expected
> entry.
>
> Fixes #3684
>
> Part of #2436, #3232
> ---
> test/xlog/checkpoint_daemon.result | 22 +++++++++++++++++-----
> test/xlog/checkpoint_daemon.test.lua | 21 ++++++++++++++++-----
> 2 files changed, 33 insertions(+), 10 deletions(-)
>
> diff --git a/test/xlog/checkpoint_daemon.test.lua b/test/xlog/checkpoint_daemon.test.lua
> index 4a0aafa84..02f2768d9 100644
> --- a/test/xlog/checkpoint_daemon.test.lua
> +++ b/test/xlog/checkpoint_daemon.test.lua
> @@ -44,9 +44,21 @@ for i = 1, 100 do
> end
> end;
>
> -test_run:cmd("setopt delimiter ''");
> -
> +function wait_cond(fn, timeout, delay)
> + timeout = timeout or 1.0
> + delay = delay or 0.001
> + local t1 = fiber.time()
> + while not fn() do
> + local work_time = fiber.time() - t1
> + if work_time > timeout then
> + return false
> + end
> + fiber.sleep(delay)
> + end
> + return true
> +end;
>
> +test_run:cmd("setopt delimiter ''");
>
I think it would be better to allow to reuse this pattern across tests:
place the function into test_run.lua and create a wrapper around
'grep_log', say, 'wait_log'. In this case timeout should not be
hardcoded and always should come from a test. Delay can be hardcoded.
When I need precise time I use clock.monotonic64(), because fiber.time()
value is updated sporadically depending on fiber scheduling / fiber pool
mechanics. Maybe that is not the case and fiber.time() is okay here,
just note to think about.
> #snaps == 2 or snaps
> #xlogs > 0
> @@ -54,10 +66,9 @@ test_run:cmd("setopt delimiter ''");
> 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
> +wait_cond(function() return test_run:grep_log("default", "saving snapshot", 400) == nil end)
> +wait_cond(function() return test_run:grep_log("default", "making snapshot", 400) ~= nil end)
>
Now we don't check that 'saving snapshot' does not appear during some
time period. Maybe we should check it after 'making snapshot'.
> -- restore default options
> box.cfg{checkpoint_interval = 3600 * 4, checkpoint_count = 4 }
> --
> 2.18.0
>
More information about the Tarantool-patches
mailing list