From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtpng3.m.smailru.net (smtpng3.m.smailru.net [94.100.177.149]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id 37D25440F3C for ; Fri, 15 Nov 2019 19:27:06 +0300 (MSK) Date: Fri, 15 Nov 2019 19:27:02 +0300 From: Alexander Turenko Message-ID: <20191115162702.3xvug7ctjrkvy3xy@tkn_work_nb> References: <5fa2b099f3a4716a8418d2ddd6afd71a8a2f1198.1573828446.git.sergepetrenko@tarantool.org> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline In-Reply-To: <5fa2b099f3a4716a8418d2ddd6afd71a8a2f1198.1573828446.git.sergepetrenko@tarantool.org> Subject: Re: [Tarantool-patches] [PATCH v2 2/2] app/fiber: wait till a full event loop iteration ends List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Serge Petrenko Cc: tarantool-patches@dev.tarantool.org, v.shpilevoy@tarantool.org I don't mind against the patch, while I have no enough context to evaluate its correctness. I see that the test fails rarely after the patchset, but still do, when I run it in 16 jobs: $ (cd test && ./test-run.py $(yes fiber.test.lua | head -n 1000)) <...> [016] app/fiber.test.lua [ fail ] [016] [016] Test failed! Result content mismatch: [016] --- app/fiber.result Fri Nov 15 18:14:05 2019 [016] +++ app/fiber.reject Fri Nov 15 19:15:58 2019 [016] @@ -1517,7 +1517,7 @@ [016] -- not exact due to accumulated integer division errors [016] sum_avg > 99 and sum_avg < 101 or sum_avg [016] --- [016] -- true [016] +- 109.27001355629 [016] ... [016] tbl = nil [016] --- Values are from 81.78153580673 to 367.42178027752. Don't sure whether it is urgent enough to push the partial fix. I'll wait for now. WBR, Alexander Turenko. On Fri, Nov 15, 2019 at 05:58:59PM +0300, Serge Petrenko wrote: > fiber.top() fills in statistics every event loop iteration, > so if it was just enabled, fiber.top() may contain 'inf's and > 'nan's in fiber cpu usage averages because total time consumed by > the main thread was not yet accounted for. > Same stands for viewing top() results for a freshly created fiber: > its metrics will be zero since it hasn't lived a full ev loop iteration > yet. > Fix this by delaying the test till top() results are meaningful and add > minor refactoring. > > Follow-up #2694 > --- > test/app/fiber.result | 28 +++++++++++++++++++--------- > test/app/fiber.test.lua | 26 ++++++++++++++++++-------- > 2 files changed, 37 insertions(+), 17 deletions(-) > > diff --git a/test/app/fiber.result b/test/app/fiber.result > index 4a094939f..b4e448282 100644 > --- a/test/app/fiber.result > +++ b/test/app/fiber.result > @@ -1469,6 +1469,12 @@ sum = 0 > fiber.top_enable() > --- > ... > +-- Wait till a full event loop iteration passes, so that > +-- top() contains meaningful results. On the ev loop iteration > +-- following fiber.top_enable() results will be zero. > +while fiber.top().cpu["1/sched"].instant == 0 do fiber.yield() end > +--- > +... > a = fiber.top() > --- > ... > @@ -1504,9 +1510,9 @@ for k, v in pairs(a) do\ > end > --- > ... > -sum_inst > +sum_inst > 99 and sum_inst < 101 or sum_inst > --- > -- 100 > +- true > ... > -- not exact due to accumulated integer division errors > sum_avg > 99 and sum_avg < 101 or sum_avg > @@ -1517,24 +1523,28 @@ tbl = nil > --- > ... > f = fiber.new(function()\ > - for i = 1,1000 do end\ > - fiber.yield()\ > - tbl = fiber.top().cpu[fiber.self().id()..'/'..fiber.self().name()]\ > + local fiber_key = fiber.self().id()..'/'..fiber.self().name()\ > + tbl = fiber.top().cpu[fiber_key]\ > + while tbl.time == 0 do\ > + for i = 1,1000 do end\ > + fiber.yield()\ > + tbl = fiber.top().cpu[fiber_key]\ > + end\ > end) > --- > ... > -while f:status() ~= 'dead' do fiber.sleep(0.01) end > +while f:status() ~= 'dead' do fiber.yield() end > --- > ... > -tbl["average"] > 0 > +tbl.average > 0 > --- > - true > ... > -tbl["instant"] > 0 > +tbl.instant > 0 > --- > - true > ... > -tbl["time"] > 0 > +tbl.time > 0 > --- > - true > ... > diff --git a/test/app/fiber.test.lua b/test/app/fiber.test.lua > index 38b85d554..e2834216b 100644 > --- a/test/app/fiber.test.lua > +++ b/test/app/fiber.test.lua > @@ -634,6 +634,12 @@ sum = 0 > -- gh-2694 fiber.top() > fiber.top_enable() > > + > +-- Wait till a full event loop iteration passes, so that > +-- top() contains meaningful results. On the ev loop iteration > +-- following fiber.top_enable() results will be zero. > +while fiber.top().cpu["1/sched"].instant == 0 do fiber.yield() end > + > a = fiber.top() > type(a) > -- scheduler is present in fiber.top() > @@ -652,19 +658,23 @@ for k, v in pairs(a) do\ > sum_avg = sum_avg + v["average"]\ > end > > -sum_inst > +sum_inst > 99 and sum_inst < 101 or sum_inst > -- not exact due to accumulated integer division errors > sum_avg > 99 and sum_avg < 101 or sum_avg > tbl = nil > f = fiber.new(function()\ > - for i = 1,1000 do end\ > - fiber.yield()\ > - tbl = fiber.top().cpu[fiber.self().id()..'/'..fiber.self().name()]\ > + local fiber_key = fiber.self().id()..'/'..fiber.self().name()\ > + tbl = fiber.top().cpu[fiber_key]\ > + while tbl.time == 0 do\ > + for i = 1,1000 do end\ > + fiber.yield()\ > + tbl = fiber.top().cpu[fiber_key]\ > + end\ > end) > -while f:status() ~= 'dead' do fiber.sleep(0.01) end > -tbl["average"] > 0 > -tbl["instant"] > 0 > -tbl["time"] > 0 > +while f:status() ~= 'dead' do fiber.yield() end > +tbl.average > 0 > +tbl.instant > 0 > +tbl.time > 0 > > fiber.top_disable() > fiber.top() > -- > 2.21.0 (Apple Git-122) >