From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: From: Serge Petrenko Message-Id: <0709FD38-5226-4C87-B853-4E65007A3B20@tarantool.org> Content-Type: multipart/alternative; boundary="Apple-Mail=_8298F786-BD15-4750-8EB2-B0F49386A02E" Mime-Version: 1.0 (Mac OS X Mail 12.4 \(3445.104.11\)) Subject: Re: [PATCH] test: fix box/on_shutdown flakiness Date: Wed, 26 Jun 2019 19:04:14 +0300 In-Reply-To: <20190626160213.29562-1-sergepetrenko@tarantool.org> References: <20190626160213.29562-1-sergepetrenko@tarantool.org> To: tarantool-patches@freelists.org Cc: Vladimir Davydov , Alexander Tikhonov List-ID: --Apple-Mail=_8298F786-BD15-4750-8EB2-B0F49386A02E Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 Resend for the mailing list -- Serge Petrenko sergepetrenko@tarantool.org > 26 =D0=B8=D1=8E=D0=BD=D1=8F 2019 =D0=B3., =D0=B2 19:02, Serge Petrenko = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0= =B0): >=20 > Replace prints that indicate on_shutdown trigger execution with > log.warn, which is more reliable. This eliminates occasional test > failures. Also instead of waiting for the server to start and = executing > grep_log, wait for the desired log entries to appear with wait_log. >=20 > Closes #4134 > --- > https://github.com/tarantool/tarantool/issues/4134 > = https://github.com/tarantool/tarantool/tree/sp/gh-4134-on-shutdown-test >=20 > test/box/on_shutdown.result | 20 +++++++++++++------- > test/box/on_shutdown.test.lua | 16 +++++++++------- > 2 files changed, 22 insertions(+), 14 deletions(-) >=20 > diff --git a/test/box/on_shutdown.result b/test/box/on_shutdown.result > index 4992b7de6..ccbdf45cb 100644 > --- a/test/box/on_shutdown.result > +++ b/test/box/on_shutdown.result > @@ -1,19 +1,22 @@ > env =3D require('test_run') > --- > ... > +log =3D require('log') > +--- > +... > test_run =3D env.new() > --- > ... > -- > -- gh-1607: on_shutdown triggers. > -- > -f =3D function() print('on_shutdown 1') end > +f =3D function() log.warn('on_shutdown 1') end > --- > ... > -g =3D function() print('on_shutdown 2') end > +g =3D function() log.warn('on_shutdown 2') end > --- > ... > -h =3D function() print('on_shutdown 3') end > +h =3D function() log.warn('on_shutdown 3') end > --- > ... > -- Check that on_shutdown triggers may yield > @@ -31,7 +34,7 @@ trig =3D function() > box.schema.space.create("shutdown") > box.space.shutdown:create_index("pk") > box.space.shutdown:insert{1,2,3} > - print('on_shutdown 4') > + log.warn('on_shutdown 4') > end; > --- > ... > @@ -52,8 +55,8 @@ _ =3D box.ctl.on_shutdown(h, g) > _ =3D box.ctl.on_shutdown(trig) > --- > ... > -test_run:cmd('restart server default') > -test_run:grep_log('default', 'on_shutdown 1', nil, {noreset=3Dtrue}) > +test_run:cmd('restart server default with wait=3DFalse') > +test_run:wait_log('default', 'on_shutdown 1', nil, 30, = {noreset=3Dtrue}) > --- > - on_shutdown 1 > ... > @@ -108,7 +111,10 @@ test_run:cmd("switch test") > --- > - true > ... > -_ =3D box.ctl.on_shutdown(function() print("on_shutdown 5") end) > +log =3D require('log') > +--- > +... > +_ =3D box.ctl.on_shutdown(function() log.warn("on_shutdown 5") end) > --- > ... > -- Check that we don't hang infinitely after os.exit() > diff --git a/test/box/on_shutdown.test.lua = b/test/box/on_shutdown.test.lua > index 9c3726dce..2a9143404 100644 > --- a/test/box/on_shutdown.test.lua > +++ b/test/box/on_shutdown.test.lua > @@ -1,12 +1,13 @@ > env =3D require('test_run') > +log =3D require('log') > test_run =3D env.new() >=20 > -- > -- gh-1607: on_shutdown triggers. > -- > -f =3D function() print('on_shutdown 1') end > -g =3D function() print('on_shutdown 2') end > -h =3D function() print('on_shutdown 3') end > +f =3D function() log.warn('on_shutdown 1') end > +g =3D function() log.warn('on_shutdown 2') end > +h =3D function() log.warn('on_shutdown 3') end > -- Check that on_shutdown triggers may yield > -- and perform some complicated actions. > fiber =3D require('fiber') > @@ -17,7 +18,7 @@ trig =3D function() > box.schema.space.create("shutdown") > box.space.shutdown:create_index("pk") > box.space.shutdown:insert{1,2,3} > - print('on_shutdown 4') > + log.warn('on_shutdown 4') > end; > test_run:cmd("setopt delimiter ''"); > _ =3D box.ctl.on_shutdown(f) > @@ -25,8 +26,8 @@ _ =3D box.ctl.on_shutdown(g) > -- Check that replacing triggers works > _ =3D box.ctl.on_shutdown(h, g) > _ =3D box.ctl.on_shutdown(trig) > -test_run:cmd('restart server default') > -test_run:grep_log('default', 'on_shutdown 1', nil, {noreset=3Dtrue}) > +test_run:cmd('restart server default with wait=3DFalse') > +test_run:wait_log('default', 'on_shutdown 1', nil, 30, = {noreset=3Dtrue}) > test_run:grep_log('default', 'on_shutdown 2', nil, {noreset=3Dtrue}) > test_run:grep_log('default', 'on_shutdown 3', nil, {noreset=3Dtrue}) > test_run:grep_log('default', 'on_shutdown 4', nil, {noreset=3Dtrue}) > @@ -43,7 +44,8 @@ test_run:cmd("stop server test") > require("fio").unlink(logfile) > test_run:cmd("start server test") > test_run:cmd("switch test") > -_ =3D box.ctl.on_shutdown(function() print("on_shutdown 5") end) > +log =3D require('log') > +_ =3D box.ctl.on_shutdown(function() log.warn("on_shutdown 5") end) > -- Check that we don't hang infinitely after os.exit() > -- even if the following code doesn't yield. > fiber =3D require("fiber") > --=20 > 2.20.1 (Apple Git-117) >=20 --Apple-Mail=_8298F786-BD15-4750-8EB2-B0F49386A02E Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 Resend for the mailing list



26 =D0=B8=D1=8E=D0=BD=D1=8F 2019 =D0=B3., =D0=B2 19:02, Serge = Petrenko <sergepetrenko@tarantool.org> = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0):

Replace prints that indicate on_shutdown trigger execution = with
log.warn, which is more reliable. This eliminates = occasional test
failures. Also instead of waiting for the = server to start and executing
grep_log, wait for the = desired log entries to appear with wait_log.

Closes #4134
---
https://github.com/tarantool/tarantool/issues/4134
https://github.com/tarantool/tarantool/tree/sp/gh-4134-on-shutd= own-test

test/box/on_shutdown.result =   | 20 +++++++++++++-------
= test/box/on_shutdown.test.lua | 16 +++++++++-------
2 = files changed, 22 insertions(+), 14 deletions(-)

diff --git a/test/box/on_shutdown.result = b/test/box/on_shutdown.result
index 4992b7de6..ccbdf45cb = 100644
--- a/test/box/on_shutdown.result
+++ = b/test/box/on_shutdown.result
@@ -1,19 +1,22 @@
env =3D require('test_run')
---
= ...
+log =3D require('log')
+---
+...
test_run =3D env.new()
= ---
...
--
-- gh-1607: = on_shutdown triggers.
--
-f =3D function() = print('on_shutdown 1') end
+f =3D function() = log.warn('on_shutdown 1') end
---
...
-g =3D function() print('on_shutdown 2') end
+g = =3D function() log.warn('on_shutdown 2') end
---
...
-h =3D function() print('on_shutdown 3') = end
+h =3D function() log.warn('on_shutdown 3') end
---
...
-- Check that = on_shutdown triggers may yield
@@ -31,7 +34,7 @@ trig =3D = function()
=     box.schema.space.create("shutdown")
=     box.space.shutdown:create_index("pk")
    box.space.shutdown:insert{1,2,3}
-    print('on_shutdown 4')
+ =    log.warn('on_shutdown 4')
end;
---
...
@@ -52,8 +55,8 @@ _ =3D = box.ctl.on_shutdown(h, g)
_ =3D = box.ctl.on_shutdown(trig)
---
...
-test_run:cmd('restart server default')
-test_run:grep_log('default', 'on_shutdown 1', nil, = {noreset=3Dtrue})
+test_run:cmd('restart server default = with wait=3DFalse')
+test_run:wait_log('default', = 'on_shutdown 1', nil, 30, {noreset=3Dtrue})
---
- on_shutdown 1
...
@@ -108,7 = +111,10 @@ test_run:cmd("switch test")
---
= - true
...
-_ =3D = box.ctl.on_shutdown(function() print("on_shutdown 5") end)
+log =3D require('log')
+---
+...
+_ =3D box.ctl.on_shutdown(function() = log.warn("on_shutdown 5") end)
---
...
-- Check that we don't hang infinitely after os.exit()
diff --git a/test/box/on_shutdown.test.lua = b/test/box/on_shutdown.test.lua
index 9c3726dce..2a9143404 = 100644
--- a/test/box/on_shutdown.test.lua
+++= b/test/box/on_shutdown.test.lua
@@ -1,12 +1,13 @@
env =3D require('test_run')
+log =3D = require('log')
test_run =3D env.new()

--
-- gh-1607: on_shutdown triggers.
--
-f =3D function() print('on_shutdown 1') = end
-g =3D function() print('on_shutdown 2') end
-h =3D function() print('on_shutdown 3') end
+f = =3D function() log.warn('on_shutdown 1') end
+g =3D = function() log.warn('on_shutdown 2') end
+h =3D function() = log.warn('on_shutdown 3') end
-- Check that on_shutdown = triggers may yield
-- and perform some complicated = actions.
fiber =3D require('fiber')
@@ = -17,7 +18,7 @@ trig =3D function()
=     box.schema.space.create("shutdown")
=     box.space.shutdown:create_index("pk")
    box.space.shutdown:insert{1,2,3}
-    print('on_shutdown 4')
+ =    log.warn('on_shutdown 4')
end;
test_run:cmd("setopt delimiter ''");
_ =3D = box.ctl.on_shutdown(f)
@@ -25,8 +26,8 @@ _ =3D = box.ctl.on_shutdown(g)
-- Check that replacing triggers = works
_ =3D box.ctl.on_shutdown(h, g)
_ =3D = box.ctl.on_shutdown(trig)
-test_run:cmd('restart server = default')
-test_run:grep_log('default', 'on_shutdown 1', = nil, {noreset=3Dtrue})
+test_run:cmd('restart server = default with wait=3DFalse')
+test_run:wait_log('default', = 'on_shutdown 1', nil, 30, {noreset=3Dtrue})
= test_run:grep_log('default', 'on_shutdown 2', nil, {noreset=3Dtrue})
test_run:grep_log('default', 'on_shutdown 3', nil, = {noreset=3Dtrue})
test_run:grep_log('default', = 'on_shutdown 4', nil, {noreset=3Dtrue})
@@ -43,7 +44,8 @@ = test_run:cmd("stop server test")
= require("fio").unlink(logfile)
test_run:cmd("start server = test")
test_run:cmd("switch test")
-_ =3D = box.ctl.on_shutdown(function() print("on_shutdown 5") end)
+log =3D require('log')
+_ =3D = box.ctl.on_shutdown(function() log.warn("on_shutdown 5") end)
-- Check that we don't hang infinitely after os.exit()
-- even if the following code doesn't yield.
= fiber =3D require("fiber")
--
2.20.1 (Apple = Git-117)


= --Apple-Mail=_8298F786-BD15-4750-8EB2-B0F49386A02E--