From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from localhost (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id AF8DE248E5 for ; Thu, 4 Jul 2019 10:02:52 -0400 (EDT) Received: from turing.freelists.org ([127.0.0.1]) by localhost (turing.freelists.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id DFoeAlb0Bu1X for ; Thu, 4 Jul 2019 10:02:52 -0400 (EDT) Received: from smtp52.i.mail.ru (smtp52.i.mail.ru [94.100.177.112]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTPS id 17358247C9 for ; Thu, 4 Jul 2019 10:02:51 -0400 (EDT) Date: Thu, 4 Jul 2019 17:02:28 +0300 From: Alexander Turenko Subject: [tarantool-patches] Re: [PATCH] test: fix box/on_shutdown flakiness Message-ID: <20190704140228.gvlfhrhjna56ba2d@tkn_work_nb> References: <20190626160213.29562-1-sergepetrenko@tarantool.org> <0709FD38-5226-4C87-B853-4E65007A3B20@tarantool.org> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: Sender: tarantool-patches-bounce@freelists.org Errors-to: tarantool-patches-bounce@freelists.org Reply-To: tarantool-patches@freelists.org List-Help: List-Unsubscribe: List-software: Ecartis version 1.0.0 List-Id: tarantool-patches List-Subscribe: List-Owner: List-post: List-Archive: To: Serge Petrenko Cc: tarantool-patches@freelists.org LuaJIT's print uses fwrite(..., stdout) + putchar('\n'). As far as I see, we call triggers right from a signal handler. It [seems][1] that fwrite() and putchar() should not be used in a signal handler. Maybe we should mention this in the documentation or move fiber_call() outside of the signal handler. The patch is okay. I verified that it does its work: flaky fails are gone. Pushed to master and 2.1. [1]: https://stackoverflow.com/a/16891799/1598057 WBR, Alexander Turenko. On Wed, Jul 03, 2019 at 04:53:24PM +0300, Serge Petrenko wrote: > RESEND > -- > Serge Petrenko > sergepetrenko@tarantool.org > > > > > > 26 июня 2019 г., в 19:04, Serge Petrenko написал(а): > > > > Resend for the mailing list > > -- > > Serge Petrenko > > sergepetrenko@tarantool.org > > > > > > > > > >> 26 июня 2019 г., в 19:02, Serge Petrenko > написал(а): > >> > >> 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-shutdown-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 = require('test_run') > >> --- > >> ... > >> +log = require('log') > >> +--- > >> +... > >> test_run = env.new() > >> --- > >> ... > >> -- > >> -- gh-1607: on_shutdown triggers. > >> -- > >> -f = function() print('on_shutdown 1') end > >> +f = function() log.warn('on_shutdown 1') end > >> --- > >> ... > >> -g = function() print('on_shutdown 2') end > >> +g = function() log.warn('on_shutdown 2') end > >> --- > >> ... > >> -h = function() print('on_shutdown 3') end > >> +h = function() log.warn('on_shutdown 3') end > >> --- > >> ... > >> -- Check that on_shutdown triggers may yield > >> @@ -31,7 +34,7 @@ trig = 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 @@ _ = box.ctl.on_shutdown(h, g) > >> _ = box.ctl.on_shutdown(trig) > >> --- > >> ... > >> -test_run:cmd('restart server default') > >> -test_run:grep_log('default', 'on_shutdown 1', nil, {noreset=true}) > >> +test_run:cmd('restart server default with wait=False') > >> +test_run:wait_log('default', 'on_shutdown 1', nil, 30, {noreset=true}) > >> --- > >> - on_shutdown 1 > >> ... > >> @@ -108,7 +111,10 @@ test_run:cmd("switch test") > >> --- > >> - true > >> ... > >> -_ = box.ctl.on_shutdown(function() print("on_shutdown 5") end) > >> +log = require('log') > >> +--- > >> +... > >> +_ = 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 = require('test_run') > >> +log = require('log') > >> test_run = env.new() > >> > >> -- > >> -- gh-1607: on_shutdown triggers. > >> -- > >> -f = function() print('on_shutdown 1') end > >> -g = function() print('on_shutdown 2') end > >> -h = function() print('on_shutdown 3') end > >> +f = function() log.warn('on_shutdown 1') end > >> +g = function() log.warn('on_shutdown 2') end > >> +h = function() log.warn('on_shutdown 3') end > >> -- Check that on_shutdown triggers may yield > >> -- and perform some complicated actions. > >> fiber = require('fiber') > >> @@ -17,7 +18,7 @@ trig = 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 ''"); > >> _ = box.ctl.on_shutdown(f) > >> @@ -25,8 +26,8 @@ _ = box.ctl.on_shutdown(g) > >> -- Check that replacing triggers works > >> _ = box.ctl.on_shutdown(h, g) > >> _ = box.ctl.on_shutdown(trig) > >> -test_run:cmd('restart server default') > >> -test_run:grep_log('default', 'on_shutdown 1', nil, {noreset=true}) > >> +test_run:cmd('restart server default with wait=False') > >> +test_run:wait_log('default', 'on_shutdown 1', nil, 30, {noreset=true}) > >> test_run:grep_log('default', 'on_shutdown 2', nil, {noreset=true}) > >> test_run:grep_log('default', 'on_shutdown 3', nil, {noreset=true}) > >> test_run:grep_log('default', 'on_shutdown 4', nil, {noreset=true}) > >> @@ -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") > >> -_ = box.ctl.on_shutdown(function() print("on_shutdown 5") end) > >> +log = require('log') > >> +_ = 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 = require("fiber") > >> -- > >> 2.20.1 (Apple Git-117) > >> > > >