From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp36.i.mail.ru (smtp36.i.mail.ru [94.100.177.96]) (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 61724430D56 for ; Fri, 25 Oct 2019 19:19:21 +0300 (MSK) From: Serge Petrenko Message-Id: <79CC2F56-25A4-4635-8960-B157D79ACCAA@tarantool.org> Content-Type: multipart/alternative; boundary="Apple-Mail=_A0162564-72A2-47B5-BCAD-BFED433CA6B2" Mime-Version: 1.0 (Mac OS X Mail 12.4 \(3445.104.11\)) Date: Fri, 25 Oct 2019 19:19:20 +0300 In-Reply-To: References: <5b3c1fae-1c49-4b13-3a0e-0774c4add3fb@tarantool.org> Subject: Re: [Tarantool-patches] [tarantool-patches] [PATCH v2 2/2] lua: add fiber.top() listing fiber cpu consumption List-Id: Tarantool development List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Vladislav Shpilevoy Cc: tarantool-patches@freelists.org, tarantool-patches@dev.tarantool.org --Apple-Mail=_A0162564-72A2-47B5-BCAD-BFED433CA6B2 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 Hi! Found a test failure on our CI. The fix is below. Besides, it makes sense to turn this code off while fiber.top () is turned off. The changes are on the = branch. diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c index 883fbac36..09afa068e 100644 --- a/src/lib/core/fiber.c +++ b/src/lib/core/fiber.c @@ -93,22 +93,25 @@ static int (*fiber_invoke)(fiber_func f, va_list = ap); * This is a macro rather than a function, since it is used * in scheduler too. */ -#define clock_set_on_csw(caller) = \ -({ = \ - uint64_t clock; = \ - uint32_t cpu_id; = \ - clock =3D __rdtscp(&cpu_id); = \ - = \ - if (cpu_id =3D=3D cord()->cpu_id_last) { = \ - (caller)->clock_delta +=3D clock - cord()->clock_last; = \ - cord()->clock_delta +=3D clock - cord()->clock_last; = \ - } else { = \ - cord()->cpu_id_last =3D cpu_id; = \ - cord()->cpu_miss_count++; = \ - } = \ - cord()->clock_last =3D clock; = \ +#define clock_set_on_csw(caller) = \ +({ = \ + if (fiber_top_enabled) { = \ + uint64_t clock; = \ + uint32_t cpu_id; = \ + clock =3D __rdtscp(&cpu_id); = \ + = \ + if (cpu_id =3D=3D cord()->cpu_id_last) { = \ + (caller)->clock_delta +=3D clock - = cord()->clock_last; \ + cord()->clock_delta +=3D clock - = cord()->clock_last; \ + } else { = \ + cord()->cpu_id_last =3D cpu_id; = \ + cord()->cpu_miss_count++; = \ + } = \ + cord()->clock_last =3D clock; = \ + } = \ }) =20 +static bool fiber_top_enabled =3D false; =20 #else #define clock_set_on_csw(caller) ; @@ -1151,8 +1154,6 @@ fiber_top_init() ev_check_init(&cord()->check_event, loop_on_iteration_start); } =20 -static bool fiber_top_enabled =3D false; - bool fiber_top_is_enabled() { -- Serge Petrenko sergepetrenko@tarantool.org > 25 =D0=BE=D0=BA=D1=82. 2019 =D0=B3., =D0=B2 18:13, Serge Petrenko = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0= =B0): >=20 > Hi! Thank you for review! > I addressed your comments and answered inline. > Incremental diff is below. >=20 >> 23 =D0=BE=D0=BA=D1=82. 2019 =D0=B3., =D0=B2 0:18, Vladislav Shpilevoy = > = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0): >>=20 >> Thanks for the patch! >>=20 >> Sorry, the version in the email is a bit outdated. I >> pasted below the actual version from the branch. >>=20 >> See 9 comments below. >>=20 >>> lua: add fiber.top () listing fiber cpu = consumption >>>=20 >>> Implement a new function in Lua fiber library: top(). It returns = a table >>> of alive fibers (including the scheduler). Each table entry has = two >>> fields: average cpu consumption, which is calculated with = exponential >>> moving average over event loop iterations, and current cpu = consumption, >>> which shows fiber's cpu usage over the last event loop iteration. >>> The patch relies on CPU timestamp counter to measure each fiber's = time >>> share. >>>=20 >>> Closes #2694 >>>=20 >>> @TarantoolBot document >>> Title: fiber: new function `fiber.top ()` >>>=20 >>> `fiber.top ()` returns a table of all alive = fibers and lists their cpu >>> consumption. Let's take a look at the example: >>> ``` >>> tarantool> fiber.top () >>> --- >>> - 1: >>> cpu average (%): 10.779696493982 >>> cpu instant (%): 10.435256168573 >>=20 >> 1. Have you considered making these option names >> one word? 'cpu average (%)' -> 'average'. The >> same for instant. My motivation is that it could >> simplify wrappers which are going to use the top >> to show it in a GUI or something. You actually use >> it in the tests. >>=20 >> It would not hard readability IMO. It is obvious >> that top is in percents, and about CPU time. >=20 > No problem. >=20 >>=20 >>> 115: >>> cpu average (%): 5.4571279061075 >>> cpu instant (%): 5.9653973440576 >>> 120: >>> cpu average (%): 21.944382148464 >>> cpu instant (%): 23.849021825646 >>> 116: >>> cpu average (%): 8.6603872318158 >>> cpu instant (%): 9.6812031335093 >>> 119: >>> cpu average (%): 21.933168871944 >>> cpu instant (%): 20.007540530351 >>> cpu misses: 0 >>> 118: >>> cpu average (%): 19.342901995963 >>> cpu instant (%): 16.932679820703 >>> 117: >>> cpu average (%): 11.549674814981 >>> cpu instant (%): 13.128901177161 >>> ... >>> ``` >>=20 >> 2. This is super cool! >>=20 >> Could we give names to predefined fibers? For >> example, make an alias top.scheduler =3D top[1]. >>=20 >> So as in the console output I would see: >>=20 >> --- >> - scheduler: >> cpu average (%): 98.230148883023 >> cpu instant (%): 100 >>=20 >> Instead of '1'. Because personally I didn't >> even know that 1 is always the scheduler, and >> I would be confused to see a regular fiber >> consumed 99% of time in a console. >=20 > Hmm, what about this? >=20 > --- a/src/lua/fiber.c > +++ b/src/lua/fiber.c > @@ -325,13 +325,18 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx) > { > struct lua_State *L =3D (struct lua_State *) cb_ctx; > =20 > - lua_pushinteger(L, f->fid); > + /* Index system fibers by name instead of id */ > + if (f->fid <=3D FIBER_ID_MAX_RESERVED) { > + lua_pushstring(L, f->name); > + } else { > + lua_pushinteger(L, f->fid); > + } > lua_newtable(L); >=20 >=20 >>=20 >>> In the table above keys are fiber id's (and a single 'cpu misses' = key >>> which indicates the amount of times tx thread was rescheduled on = a >>> different cpu core. More on that later). >>> The two metrics available for each fiber are: >>> 1) cpu instant (per cent), >>> which indicates the share of time fiber was executing during the >>> previous event loop iteration >>> 2) cpu average (per cent), which is calculated as an exponential = moving >>> average of `cpu instant` values over all previous event loop = iterations. >>>=20 >>> More info on `cpu misses` field returned by `fiber.top = ()`: >>> `cpu misses` indicates the amount of times tx thread detected it = was >>> rescheduled on a different cpu core during the last event loop >>> iteration. >>> fiber.top () uses cpu timestamp counter to = measure each fiber's execution >>> time. However, each cpu core may have its own counter value (you = can >>> only rely on counter deltas if both measurements were taken on = the same >>> core, otherwise the delta may even get negative). >>> When tx thread is rescheduled to a different cpu core, tarantool = just >>> assumes cpu delta was zero for the lust measurement. This loweres >>> precision of our computations, so the bigger `cpu misses` value = the >>> lower the precision of fiber.top () results. >>>=20 >>> Fiber.top () doesn't work on arm architecture = at the moment. >>=20 >> 2. Have you done benchmarks how much top slows down fiber >> switching? It should not be hard to measure. Just switching. >> Lots of fibers which only yield. And measure loop iterations >> per second. Won't work? Or average/median duration of one >> loop iteration. >=20 > Hi! I tested context switches per second. > The results are in the issue comments: > = https://github.com/tarantool/tarantool/issues/2694#issuecomment-546381304 = > Performance degradation is between 10 and 16 per cent. >=20 >>>=20 >>> diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c >>> index b813c1739..bea49eb41 100644 >>> --- a/src/lib/core/fiber.c >>> +++ b/src/lib/core/fiber.c >>> @@ -37,11 +37,14 @@ >>> #include >>> #include >>> #include >>> - >>> #include "assoc.h" >>=20 >> 3. Sorry, looks like stray diff. Could you >> please drop it? >>=20 >=20 > Thanks for noticing! Fixed. >=20 >>> #include "memory.h" >>> #include "trigger.h" >>> @@ -82,6 +85,34 @@ static int (*fiber_invoke)(fiber_func f, va_list = ap); >>> err; = \ >>> }) >>>=20 >>> +#if ENABLE_FIBER_TOP >>> +/** >>> + * An action performed each time a context switch happens. >>> + * Used to count each fiber's processing time. >>> + * This is a macro rather than a function, since it is used >>> + * in scheduler too. >>=20 >> 4. Hm. Not sure if I understand. Ok, it is used in the scheduler, >> so why does it prevent making it a function? Caller is always >> struct fiber *, so you can make it a function taking fiber * >> parameter, can't you? >=20 > You cannot call functions from scheduler cos it doesn=E2=80=99t have a > stack AFAIU. I can make it an inline function if you want me to. >=20 >>=20 >>> + */ >>> +#define clock_set_on_csw(caller) = \ >>> +({ = \ >>> + uint64_t clock; = \ >>> + uint32_t cpu_id; = \ >>> + clock =3D __rdtscp(&cpu_id); = \ >>> + = \ >>> + if (cpu_id =3D=3D cord()->cpu_id_last) { = \ >>> + (caller)->clock_delta +=3D clock - cord()->clock_last; = \ >>> + cord()->clock_delta +=3D clock - cord()->clock_last; = \ >>> + } else { = \ >>> + cord()->cpu_id_last =3D cpu_id; = \ >>> + cord()->cpu_miss_count++; = \ >>> + } = \ >>> + cord()->clock_last =3D clock; = \ >>> +})> @@ -584,6 +617,7 @@ fiber_schedule_list(struct rlist *list) >>> } >>> last->caller =3D fiber(); >>> assert(fiber() =3D=3D &cord()->sched); >>> + clock_set_on_csw(fiber()); >>=20 >> 5. Am I right, that we need to update CPU consumption each >> time a context switch happens?=20 >=20 > Yep. >=20 >> If so, then by logic you >> would need to call clock_set_on_csw() on each fiber->csw++, >> correct? >=20 > Right. I also call clock_set_on_csw() on each event loop iteration > end. >=20 >>=20 >> Currently that happens in 2 places: fiber_call_impl() and >> fiber_yield(). In both these places you already call >> clock_set_on_csw(): >>=20 >> - You always call clock_set_on_csw() right before >> fiber_call_impl(); >>=20 >> - You call clock_set_on_csw() in fiber_yield(). >>=20 >> I would then move fiber->cws++ logic into your macros too. >> So all the context switch and CPU time tracking logic >> would be in one place. >>=20 >> The only problem is that your macros takes caller, but csw++ >> is done for callee. Probably we could increment it for the >> caller instead, I don't anything depends on that. >>=20 >> Also it would lead to increment of the scheduler's csw >> counter. Not sure whether it is ok. >=20 > Loop iteration end isn=E2=80=99t a context switch, but I still update > clocks here. I don=E2=80=99t want to increment csw here as a side > effect, so maybe leave csw increment as it is? >=20 >>=20 >> Like that (I didn't test it): >>=20 >> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D >>=20 >> diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c >> index bea49eb41..e9aac99d0 100644 >> --- a/src/lib/core/fiber.c >> +++ b/src/lib/core/fiber.c >> @@ -105,6 +105,7 @@ static int (*fiber_invoke)(fiber_func f, va_list = ap); >> cord()->cpu_id_last =3D cpu_id; = \ >> cord()->cpu_miss_count++; = \ >> } = \ >> + caller->csw++; = \ >> cord()->clock_last =3D clock; = \ >> }) >>=20 >> @@ -258,7 +259,7 @@ fiber_call_impl(struct fiber *callee) >> cord->fiber =3D callee; >>=20 >> callee->flags &=3D ~FIBER_IS_READY; >> - callee->csw++; >> + clock_set_on_csw(caller); >> ASAN_START_SWITCH_FIBER(asan_state, 1, >> callee->stack, >> callee->stack_size); >> @@ -277,7 +278,6 @@ fiber_call(struct fiber *callee) >> /** By convention, these triggers must not throw. */ >> if (! rlist_empty(&caller->on_yield)) >> trigger_run(&caller->on_yield, NULL); >> - clock_set_on_csw(caller); >> callee->caller =3D caller; >> callee->flags |=3D FIBER_IS_READY; >> caller->flags |=3D FIBER_IS_READY; >> @@ -511,7 +511,6 @@ fiber_yield(void) >> assert(callee->flags & FIBER_IS_READY || callee =3D=3D = &cord->sched); >> assert(! (callee->flags & FIBER_IS_DEAD)); >> cord->fiber =3D callee; >> - callee->csw++; >> callee->flags &=3D ~FIBER_IS_READY; >> ASAN_START_SWITCH_FIBER(asan_state, >> (caller->flags & FIBER_IS_DEAD) =3D=3D = 0, >> @@ -617,7 +616,6 @@ fiber_schedule_list(struct rlist *list) >> } >> last->caller =3D fiber(); >> assert(fiber() =3D=3D &cord()->sched); >> - clock_set_on_csw(fiber()); >> fiber_call_impl(first); >> } >>=20 >> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D >>=20 >>> fiber_call_impl(first); >>> } >>>=20 >>> @@ -1044,6 +1082,107 @@ fiber_destroy_all(struct cord *cord)> +bool >>> +fiber_top_is_enabled() >>> +{ >>> + return fiber_top_enabled; >>> +} >>> + >>> +inline void >>> +fiber_top_enable() >>=20 >> 6. Please, add 'static' modifier. Looks like >> this function is used inside this file only. >> The same for fiber_top_disable(). >=20 > It=E2=80=99s used in lua fiber module. >=20 >>=20 >>> +{ >>> + if (!fiber_top_enabled) { >>> + ev_prepare_start(cord()->loop, &cord()->prepare_event); >>> + ev_check_start(cord()->loop, &cord()->check_event); >>> + fiber_top_enabled =3D true; >>> + >>> + cord()->clock_acc =3D 0; >>> + cord()->cpu_miss_count_last =3D 0; >>> + cord()->clock_delta_last =3D 0; >>> + } >>> +} >>> @@ -1077,6 +1216,14 @@ cord_create(struct cord *cord, const char = *name) >>> ev_async_init(&cord->wakeup_event, fiber_schedule_wakeup); >>>=20 >>> ev_idle_init(&cord->idle_event, fiber_schedule_idle); >>> + >>> +#if ENABLE_FIBER_TOP >>> + /* fiber.top () currently works only for the = main thread. */ >>> + if (cord_is_main()) { >>> + fiber_top_init(); >>> + fiber_top_enable(); >>=20 >> 7. I think, we need to enable top by default only >> when we are sure that it does not affect performance. >=20 > Ok, disabled it by default. User can turn it on with > fiber.top_enable(). This also resolved the issue I had > with your swim test. >=20 > Looking at perf difference, maybe we can turn it on by default? >=20 >>=20 >>> + } >>> +#endif /* ENABLE_FIBER_TOP */ >>> cord_set_name(name); >>>=20 >>> #if ENABLE_ASAN >>> diff --git a/src/lua/fiber.c b/src/lua/fiber.c >>> index 336be60a2..2adff1536 100644 >>> --- a/src/lua/fiber.c >>> +++ b/src/lua/fiber.c >>> @@ -319,6 +319,61 @@ lbox_fiber_statof_nobt(struct fiber *f, void = *cb_ctx) >>> + >>> +static int >>> +lbox_fiber_top(struct lua_State *L) >>> +{ >>> + if (!fiber_top_is_enabled()) { >>> + luaL_error(L, "fiber.top () is = disabled. enable it with" >>=20 >> 8. 'enable' is a first word in the sentence. So probably >> it is 'Enable=E2=80=99. >=20 > Yep. Done. >=20 >>=20 >>> + " fiber.top_enable() first"); >>> + } >>> + lua_newtable(L); >>> + lua_pushliteral(L, "cpu misses"); >>> + lua_pushnumber(L, cord()->cpu_miss_count_last); >>> + lua_settable(L, -3); >>> + >>> + lbox_fiber_top_entry(&cord()->sched, L); >>> + fiber_stat(lbox_fiber_top_entry, L); >>> + >>> + return 1; >>> +} >>> diff --git a/test/app/fiber.result b/test/app/fiber.result >>> index 3c6115a33..196fae3b7 100644 >>> --- a/test/app/fiber.result >>> +++ b/test/app/fiber.result >>> @@ -1462,6 +1462,84 @@ fiber.join(fiber.self()) >>> --- >>> - error: the fiber is not joinable >>> ... >>> +sum =3D 0 >>> +--- >>> +... >>> +-- gh-2694 fiber.top () >>> +a =3D fiber.top () >>> +--- >>> +... >>> +-- scheduler is present in fiber.top () >>> +a[1] ~=3D nil >>> +--- >>> +- true >>> +... >>> +type(a["cpu misses"]) =3D=3D 'number' >>> +--- >>> +- true >>> +... >>> +sum_inst =3D 0 >>> +--- >>> +... >>> +sum_avg =3D 0 >>> +--- >>> +... >>> +test_run:cmd('setopt delimiter ";"') >>=20 >> 9. I would consider usage of '\' instead of a >> delimiter change for such a short piece of >> multiline code. But up to you. Just in case >> you didn't know about '\', because I didn't >> know either until recently. >>=20 >=20 >=20 > I didn=E2=80=99t know about =E2=80=98\=E2=80=99 as well. Thanks. >=20 >=20 > Here=E2=80=99s the incremental diff: >=20 > diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c > index bea49eb41..883fbac36 100644 > --- a/src/lib/core/fiber.c > +++ b/src/lib/core/fiber.c > @@ -37,6 +37,7 @@ > #include > #include > #include > + > #include "assoc.h" > #include "memory.h" > #include "trigger.h" > @@ -1221,7 +1222,6 @@ cord_create(struct cord *cord, const char *name) > /* fiber.top () currently works only for the = main thread. */ > if (cord_is_main()) { > fiber_top_init(); > - fiber_top_enable(); > } > #endif /* ENABLE_FIBER_TOP */ > cord_set_name(name); > diff --git a/src/lua/fiber.c b/src/lua/fiber.c > index 62f3ccce4..c38bd886f 100644 > --- a/src/lua/fiber.c > +++ b/src/lua/fiber.c > @@ -325,13 +325,18 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx) > { > struct lua_State *L =3D (struct lua_State *) cb_ctx; > =20 > - lua_pushinteger(L, f->fid); > + /* Index system fibers by name instead of id */ > + if (f->fid <=3D FIBER_ID_MAX_RESERVED) { > + lua_pushstring(L, f->name); > + } else { > + lua_pushinteger(L, f->fid); > + } > lua_newtable(L); > =20 > - lua_pushliteral(L, "cpu average (%)"); > + lua_pushliteral(L, "average"); > lua_pushnumber(L, f->clock_acc / (double)cord()->clock_acc * = 100); > lua_settable(L, -3); > - lua_pushliteral(L, "cpu instant (%)"); > + lua_pushliteral(L, "instant"); > lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100); > lua_settable(L, -3); > lua_settable(L, -3); > @@ -343,7 +348,7 @@ static int > lbox_fiber_top(struct lua_State *L) > { > if (!fiber_top_is_enabled()) { > - luaL_error(L, "fiber.top () is = disabled. enable it with" > + luaL_error(L, "fiber.top () is = disabled. Enable it with" > " fiber.top_enable() first"); > } > lua_newtable(L); > diff --git a/test/app/fiber.result b/test/app/fiber.result > index 196fae3b7..e45cd7639 100644 > --- a/test/app/fiber.result > +++ b/test/app/fiber.result > @@ -1466,11 +1466,19 @@ sum =3D 0 > --- > ... > -- gh-2694 fiber.top () > +fiber.top_enable() > +--- > +... > a =3D fiber.top () > --- > ... > +type(a) > +--- > +- table > +... > -- scheduler is present in fiber.top () > -a[1] ~=3D nil > +-- and is indexed by name > +a["sched"] ~=3D nil > --- > - true > ... > @@ -1484,21 +1492,19 @@ sum_inst =3D 0 > sum_avg =3D 0 > --- > ... > -test_run:cmd('setopt delimiter ";"') > ---- > -- true > -... > -for k, v in pairs(a) do > - if type(v) =3D=3D 'table' then > - sum_inst =3D sum_inst + v["cpu instant (%)"] > - sum_avg =3D sum_avg + v["cpu average (%)"] > - end > -end; > +-- update table to make sure > +-- a full event loop iteration > +-- has ended > +a =3D fiber.top () > --- > ... > -test_run:cmd('setopt delimiter ""'); > +for k, v in pairs(a) do\ > + if type(v) =3D=3D 'table' then\ > + sum_inst =3D sum_inst + v["instant"]\ > + sum_avg =3D sum_avg + v["average"]\ > + end\ > +end > --- > -- true > ... > sum_inst > --- > @@ -1518,11 +1524,11 @@ f =3D fiber.new(function() for i =3D 1,1000 do = end fiber.yield() tbl =3D fiber.top ()[f > while f:status() ~=3D 'dead' do fiber.sleep(0.01) end > --- > ... > -tbl["cpu average (%)"] > 0 > +tbl["average"] > 0 > --- > - true > ... > -tbl["cpu instant (%)"] > 0 > +tbl["instant"] > 0 > --- > - true > ... > @@ -1531,14 +1537,7 @@ fiber.top_disable() > ... > fiber.top () > --- > -- error: fiber.top () is disabled. enable it with = fiber.top_enable() first > -... > -fiber.top_enable() > ---- > -... > -type(fiber.top ()) > ---- > -- table > +- error: fiber.top () is disabled. Enable it with = fiber.top_enable() first > ... > -- cleanup > test_run:cmd("clear filter") > diff --git a/test/app/fiber.test.lua b/test/app/fiber.test.lua > index 15507c2c7..e30aba77e 100644 > --- a/test/app/fiber.test.lua > +++ b/test/app/fiber.test.lua > @@ -632,33 +632,39 @@ fiber.join(fiber.self()) > sum =3D 0 > =20 > -- gh-2694 fiber.top () > +fiber.top_enable() > + > a =3D fiber.top () > +type(a) > -- scheduler is present in fiber.top () > -a[1] ~=3D nil > +-- and is indexed by name > +a["sched"] ~=3D nil > type(a["cpu misses"]) =3D=3D 'number' > sum_inst =3D 0 > sum_avg =3D 0 > -test_run:cmd('setopt delimiter ";"') > -for k, v in pairs(a) do > - if type(v) =3D=3D 'table' then > - sum_inst =3D sum_inst + v["cpu instant (%)"] > - sum_avg =3D sum_avg + v["cpu average (%)"] > - end > -end; > -test_run:cmd('setopt delimiter ""'); > + > +-- update table to make sure > +-- a full event loop iteration > +-- has ended > +a =3D fiber.top () > +for k, v in pairs(a) do\ > + if type(v) =3D=3D 'table' then\ > + sum_inst =3D sum_inst + v["instant"]\ > + sum_avg =3D sum_avg + v["average"]\ > + end\ > +end > + > sum_inst > -- not exact due to accumulated integer division errors > sum_avg > 99 and sum_avg < 101 or sum_avg > tbl =3D nil > f =3D fiber.new(function() for i =3D 1,1000 do end fiber.yield() tbl = =3D fiber.top ()[fiber.self().id()] end) > while f:status() ~=3D 'dead' do fiber.sleep(0.01) end > -tbl["cpu average (%)"] > 0 > -tbl["cpu instant (%)"] > 0 > +tbl["average"] > 0 > +tbl["instant"] > 0 > =20 > fiber.top_disable() > fiber.top () > -fiber.top_enable() > -type(fiber.top ()) > =20 > -- cleanup > test_run:cmd("clear filter") >=20 > -- > Serge Petrenko > sergepetrenko@tarantool.org --Apple-Mail=_A0162564-72A2-47B5-BCAD-BFED433CA6B2 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8
Hi!
Found a test failure on our = CI.
The fix is below. Besides, it makes sense to = turn this code off while
fiber.top() is turned off. The changes are on the = branch.

diff = --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c
index = 883fbac36..09afa068e 100644
--- a/src/lib/core/fiber.c
+++ b/src/lib/core/fiber.c
@@ -93,22 +93,25 @@ = static int (*fiber_invoke)(fiber_func f, va_list ap);
  * This is a macro rather than a function, since = it is used
  * in scheduler too.
  */
-#define = clock_set_on_csw(caller) = \
-({ = \
- uint64_t clock; = \
- uint32_t = cpu_id; =   = \
- clock =3D = __rdtscp(&cpu_id); = \
- = \
- if (cpu_id =3D=3D = cord()->cpu_id_last) { \
- = (caller)->clock_delta +=3D clock - cord()->clock_last; \
- = cord()->clock_delta +=3D clock - cord()->clock_last; \
- = } else { = \
- = cord()->cpu_id_last =3D cpu_id; \
- = cord()->cpu_miss_count++; \
- = } = \
- = cord()->clock_last =3D clock; = \
+#define clock_set_on_csw(caller) =      \
+({ =    =   \
+ if (fiber_top_enabled) { =      \
+ = uint64_t clock; =      \
+ = uint32_t cpu_id;   =      \
+ clock =3D = __rdtscp(&cpu_id); =      \
+ =    =   \
+ if (cpu_id =3D=3D = cord()->cpu_id_last) {    =   \
+ = (caller)->clock_delta +=3D clock - cord()->clock_last; \
+ = cord()->clock_delta +=3D clock - = cord()->clock_last;   \
+ } = else { =      \
+ = cord()->cpu_id_last =3D cpu_id; =      \
+ = cord()->cpu_miss_count++;    =   \
+ } =      \
+ = cord()->clock_last =3D clock; =      \
+ } =      \
 })
 
+static bool = fiber_top_enabled =3D false;
 
 #else
 #define = clock_set_on_csw(caller) ;
@@ -1151,8 +1154,6 @@ = fiber_top_init()
  = ev_check_init(&cord()->check_event, = loop_on_iteration_start);
 }
 
-static bool fiber_top_enabled =3D false;
-
 bool
 fiber_top_is_enabled()
 {





25 =D0=BE=D0=BA=D1=82. 2019 =D0=B3., =D0=B2 18:13, Serge = Petrenko <sergepetrenko@tarantool.org> = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0):

Hi! Thank you = for review!
I addressed your comments and = answered inline.
Incremental diff is = below.

23 =D0=BE=D0=BA=D1=82. 2019 =D0=B3., =D0=B2 = 0:18, Vladislav Shpilevoy <v.shpilevoy@tarantool.org> = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0):

Thanks= for the patch!

Sorry, the version in the = email is a bit outdated. I
pasted below the actual version = from the branch.

See 9 comments below.

   lua: add fiber.top() listing fiber cpu consumption

   Implement a new function in = Lua fiber library: top(). It returns a table
   of alive fibers (including the scheduler). = Each table entry has two
   fields: average = cpu consumption, which is calculated with exponential
   moving average over event loop iterations, = and current cpu consumption,
   which shows = fiber's cpu usage over the last event loop iteration.
   The patch relies on CPU timestamp counter = to measure each fiber's time
   share.

   Closes #2694
   @TarantoolBot document
   Title: fiber: new function `fiber.top()`

   `fiber.top()` returns a table of all alive fibers and = lists their cpu
   consumption. Let's take = a look at the example:
   ```
   tarantool> fiber.top()
   ---
   - 1:
       cpu average (%): = 10.779696493982
       cpu instant (%): = 10.435256168573

1. Have you = considered making these option names
one word? 'cpu = average (%)' -> 'average'. The
same for instant. My = motivation is that it could
simplify wrappers which are = going to use the top
to show it in a GUI or something. You = actually use
it in the tests.

It would not hard readability IMO. It is obvious
that top is in percents, and about CPU time.

No problem.


     115:
       cpu average (%): = 5.4571279061075
       cpu instant (%): = 5.9653973440576
     120:
       cpu average (%): = 21.944382148464
       cpu instant (%): = 23.849021825646
     116:
       cpu average (%): = 8.6603872318158
       cpu instant (%): = 9.6812031335093
     119:
       cpu average (%): = 21.933168871944
       cpu instant (%): = 20.007540530351
     cpu misses: = 0
     118:
       cpu average (%): = 19.342901995963
       cpu instant (%): = 16.932679820703
     117:
       cpu average (%): = 11.549674814981
       cpu instant (%): = 13.128901177161
   ...
   ```

2. This is super cool!

Could we = give names to predefined fibers? For
example, make an = alias top.scheduler =3D top[1].

So as in = the console output I would see:

   ---
   - = scheduler:
       cpu = average (%): 98.230148883023
       cpu instant (%): = 100

Instead of '1'. Because personally I = didn't
even know that 1 is always the scheduler, and
I would be confused to see a regular fiber
consumed 99% of time in a console.

Hmm, what about this?

--- = a/src/lua/fiber.c
+++ b/src/lua/fiber.c
@@ = -325,13 +325,18 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx)
 {
      =   struct lua_State *L =3D (struct lua_State *) cb_ctx;
 
-     =   lua_pushinteger(L, f->fid);
+   =     /* Index system fibers by name instead of id */
+       if (f->fid <=3D = FIBER_ID_MAX_RESERVED) {
+       =         lua_pushstring(L, f->name);
+       } else {
+             =   lua_pushinteger(L, f->fid);
+   =     }
        = lua_newtable(L);



   In the = table above keys are fiber id's (and a single 'cpu misses' key
   which indicates the amount of times tx = thread was rescheduled on a
   different = cpu core. More on that later).
   The two = metrics available for each fiber are:
   1) = cpu instant (per cent),
   which indicates = the share of time fiber was executing during the
   previous event loop iteration
   2) cpu average (per cent), which is = calculated as an exponential moving
   average of `cpu instant` values over all = previous event loop iterations.

   More info on `cpu misses` field returned by = `fiber.top()`:
   `cpu misses` indicates the amount of times = tx thread detected it was
   rescheduled on = a different cpu core during the last event loop
   iteration.
   fiber.top() uses cpu = timestamp counter to measure each fiber's execution
   time. However, each cpu core may have its = own counter value (you can
   only rely on = counter deltas if both measurements were taken on the same
   core, otherwise the delta may even get = negative).
   When tx thread is rescheduled = to a different cpu core, tarantool just
   assumes cpu delta was zero for the lust = measurement. This loweres
   precision of = our computations, so the bigger `cpu misses` value the
   lower the precision of fiber.top() results.

   Fiber.top() doesn't work on arm architecture at the = moment.

2. Have you done = benchmarks how much top slows down fiber
switching? It = should not be hard to measure. Just switching.
Lots of = fibers which only yield. And measure loop iterations
per = second. Won't work? Or average/median duration of one
loop = iteration.

Hi! I tested context switches per = second.
The results are in the issue = comments:
https://github.com/tarantool/tarantool/issues/2694#issuecomment= -546381304
Performance = degradation is between 10 and 16 per cent.


diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c
index b813c1739..bea49eb41 100644
--- = a/src/lib/core/fiber.c
+++ b/src/lib/core/fiber.c
@@ -37,11 +37,14 @@
#include = <stdlib.h>
#include <string.h>
#include <pmatomic.h>
-
#include "assoc.h"

3.= Sorry, looks like stray diff. Could you
please drop = it?


Thanks for noticing! = Fixed.

#include = "memory.h"
#include "trigger.h"
@@ -82,6 = +85,34 @@ static int (*fiber_invoke)(fiber_func f, va_list ap);
= err; = = = = = = = = \
})

+#if = ENABLE_FIBER_TOP
+/**
+ * An action = performed each time a context switch happens.
+ * Used to = count each fiber's processing time.
+ * This is a macro = rather than a function, since it is used
+ * in scheduler = too.

4. Hm. Not sure if I = understand. Ok, it is used in the scheduler,
so why does = it prevent making it a function? Caller is always
struct = fiber *, so you can make it a function taking fiber *
parameter, can't you?

You cannot call functions from = scheduler cos it doesn=E2=80=99t have a
stack = AFAIU. I can make it an inline function if you want me to.


+ */
+#define clock_set_on_csw(caller) \
+({ \
+ = uint64_t clock; \
+ uint32_t cpu_id;   \
+ = clock =3D __rdtscp(&cpu_id); \
+ \
+ = if (cpu_id =3D=3D cord()->cpu_id_last) { \
+ = = (caller)->clock_delta +=3D clock - cord()->clock_last; \
+ = = cord()->clock_delta +=3D clock - cord()->clock_last; \
+ = } else { \
+ cord()->cpu_id_last =3D = cpu_id; = = = = \
+ cord()->cpu_miss_count++; \
+ = } = = = = = = = = \
+ cord()->clock_last =3D = clock; = = = = = \
+})> @@ -584,6 +617,7 @@ = fiber_schedule_list(struct rlist *list)
}
= last->caller =3D fiber();
= assert(fiber() =3D=3D &cord()->sched);
+ = clock_set_on_csw(fiber());

5. Am I right, that we need to update CPU consumption each
time a context switch happens? 

Yep.

If so, then by logic you
would need to call = clock_set_on_csw() on each fiber->csw++,
correct?

Right. I also call clock_set_on_csw() on each event = loop iteration
end.


Currently that happens in 2 places: = fiber_call_impl() and
fiber_yield(). In both these places = you already call
clock_set_on_csw():

   - You always call clock_set_on_csw() right = before
     fiber_call_impl();

   - You call = clock_set_on_csw() in fiber_yield().

I = would then move fiber->cws++ logic into your macros too.
So all the context switch and CPU time tracking logic
would be in one place.

The only = problem is that your macros takes caller, but csw++
is = done for callee. Probably we could increment it for the
caller instead, I don't anything depends on that.

Also it would lead to increment of the = scheduler's csw
counter. Not sure whether it is ok.

Loop iteration end isn=E2=80=99t a = context switch, but I still update
clocks here. I = don=E2=80=99t want to increment csw here as a side
effect, so maybe leave csw increment as it is?


Like that (I didn't test it):

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D

diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c
index bea49eb41..e9aac99d0 100644
--- = a/src/lib/core/fiber.c
+++ b/src/lib/core/fiber.c
@@ -105,6 +105,7 @@ static int (*fiber_invoke)(fiber_func f, = va_list ap);
cord()->cpu_id_last =3D = cpu_id; = = = = \
cord()->cpu_miss_count++; \
= } = = = = = = = = \
+ caller->csw++; \
= cord()->clock_last =3D clock; \
})

@@ -258,7 +259,7 @@ fiber_call_impl(struct = fiber *callee)
cord->fiber =3D callee;

callee->flags &=3D = ~FIBER_IS_READY;
- callee->csw++;
+ = clock_set_on_csw(caller);
= ASAN_START_SWITCH_FIBER(asan_state, 1,
= callee->stack,
callee->stack_size);
@@ -277,7 +278,6 @@ fiber_call(struct fiber *callee)
= /** By convention, these triggers must not throw. */
= if (! rlist_empty(&caller->on_yield))
= trigger_run(&caller->on_yield, NULL);
- = clock_set_on_csw(caller);
= callee->caller =3D caller;
= callee->flags |=3D FIBER_IS_READY;
= caller->flags |=3D FIBER_IS_READY;
@@ -511,7 = +511,6 @@ fiber_yield(void)
assert(callee->flags & = FIBER_IS_READY || callee =3D=3D &cord->sched);
assert(! = (callee->flags & FIBER_IS_DEAD));
= cord->fiber =3D callee;
- = callee->csw++;
callee->flags &=3D = ~FIBER_IS_READY;
= ASAN_START_SWITCH_FIBER(asan_state,
= (caller->flags & FIBER_IS_DEAD) =3D=3D 0,
@@ = -617,7 +616,6 @@ fiber_schedule_list(struct rlist *list)
= }
last->caller =3D fiber();
= assert(fiber() =3D=3D &cord()->sched);
- = clock_set_on_csw(fiber());
= fiber_call_impl(first);
}

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D

= fiber_call_impl(first);
}

@@ -1044,6 +1082,107 @@ fiber_destroy_all(struct cord = *cord)> +bool
+fiber_top_is_enabled()
+{+ = return fiber_top_enabled;
+}
+
+inline void
+fiber_top_enable()

6. Please, add 'static' modifier. = Looks like
this function is used inside this file only.
The same for fiber_top_disable().

It=E2=80=99s used in lua fiber module.


+{
+ if (!fiber_top_enabled) {
+ = = ev_prepare_start(cord()->loop, = &cord()->prepare_event);
+ = ev_check_start(cord()->loop, &cord()->check_event);
+ = = fiber_top_enabled =3D true;
+
+ = cord()->clock_acc =3D 0;
+ = cord()->cpu_miss_count_last =3D 0;
+ = cord()->clock_delta_last =3D 0;
+ }
+}
@@ -1077,6 +1216,14 @@ cord_create(struct = cord *cord, const char *name)
= ev_async_init(&cord->wakeup_event, = fiber_schedule_wakeup);

= ev_idle_init(&cord->idle_event, fiber_schedule_idle);
+
+#if ENABLE_FIBER_TOP
+ /* fiber.top() currently works only for the main thread. = */
+ if (cord_is_main()) {
+ = fiber_top_init();
+ fiber_top_enable();

7. I think, we need to enable top = by default only
when we are sure that it does not affect = performance.

Ok, disabled it by default. User can turn it on = with
fiber.top_enable(). This also resolved the = issue I had
with your swim test.

Looking at perf = difference, maybe we can turn it on by default?


+ }
+#endif /* ENABLE_FIBER_TOP */
= cord_set_name(name);

#if = ENABLE_ASAN
diff --git a/src/lua/fiber.c = b/src/lua/fiber.c
index 336be60a2..2adff1536 100644
--- a/src/lua/fiber.c
+++ b/src/lua/fiber.c
@@ -319,6 +319,61 @@ lbox_fiber_statof_nobt(struct fiber *f, = void *cb_ctx)
+
+static int
+lbox_fiber_top(struct lua_State *L)
+{
+ = if (!fiber_top_is_enabled()) {
+ = luaL_error(L, "fiber.top() is disabled. enable it with"

8. 'enable' is a first word in = the sentence. So probably
it is 'Enable=E2=80=99.

Yep. Done.


+       = ;" fiber.top_enable() first");
+ }
+ = lua_newtable(L);
+ lua_pushliteral(L, "cpu = misses");
+ lua_pushnumber(L, = cord()->cpu_miss_count_last);
+ = lua_settable(L, -3);
+
+ = lbox_fiber_top_entry(&cord()->sched, L);
+ = fiber_stat(lbox_fiber_top_entry, L);
+
+ = return 1;
+}
diff --git = a/test/app/fiber.result b/test/app/fiber.result
index = 3c6115a33..196fae3b7 100644
--- a/test/app/fiber.result
+++ b/test/app/fiber.result
@@ -1462,6 +1462,84 = @@ fiber.join(fiber.self())
---
- error: the = fiber is not joinable
...
+sum =3D 0
+---
+...
+-- gh-2694 fiber.top()
+a =3D fiber.top()
+---
+...
+-- scheduler is present in fiber.top()
+a[1] ~=3D nil
+---
+- true
+...
+type(a["cpu misses"]) =3D=3D 'number'
+---
+- true
+...
+sum_inst =3D 0
+---
+...
+sum_avg =3D 0
+---
+...
+test_run:cmd('setopt = delimiter ";"')

9. I would = consider usage of '\' instead of a
delimiter change for = such a short piece of
multiline code. But up to you. Just = in case
you didn't know about '\', because I didn't
know either until recently.


I didn=E2=80=99t know about =E2=80=98\=E2= =80=99 as well. Thanks.


Here=E2=80=99s the = incremental diff:

diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c
index bea49eb41..883fbac36 100644
--- = a/src/lib/core/fiber.c
+++ b/src/lib/core/fiber.c
@@ -37,6 +37,7 @@
 #include = <stdlib.h>
 #include <string.h>
 #include <pmatomic.h>
+
 #include "assoc.h"
 #include = "memory.h"
 #include "trigger.h"
@@ = -1221,7 +1222,6 @@ cord_create(struct cord *cord, const char *name)
  /* fiber.top() currently works = only for the main thread. */
  if = (cord_is_main()) {
  fiber_top_init();
- = fiber_top_enable();
  }
 #endif /* ENABLE_FIBER_TOP */
  = cord_set_name(name);
diff --git a/src/lua/fiber.c = b/src/lua/fiber.c
index 62f3ccce4..c38bd886f 100644
--- a/src/lua/fiber.c
+++ b/src/lua/fiber.c
@@ -325,13 +325,18 @@ lbox_fiber_top_entry(struct fiber *f, = void *cb_ctx)
 {
  struct = lua_State *L =3D (struct lua_State *) cb_ctx;
 
- = lua_pushinteger(L, f->fid);
+ /* Index = system fibers by name instead of id */
+ if = (f->fid <=3D FIBER_ID_MAX_RESERVED) {
+ = lua_pushstring(L, f->name);
+ } else = {
+ lua_pushinteger(L, f->fid);
+ }
  lua_newtable(L);
 
- = lua_pushliteral(L, "cpu average (%)");
+ = lua_pushliteral(L, "average");
  = lua_pushnumber(L, f->clock_acc / (double)cord()->clock_acc = * 100);
  lua_settable(L, -3);
- = lua_pushliteral(L, "cpu instant (%)");
+ = lua_pushliteral(L, "instant");
  = lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100);
  = lua_settable(L, -3);
  = lua_settable(L, -3);
@@ -343,7 +348,7 @@ static = int
 lbox_fiber_top(struct lua_State *L)
 {
  if (!fiber_top_is_enabled()) {
- = luaL_error(L, "fiber.top() is disabled. enable it with"
+ = luaL_error(L, "fiber.top() is disabled. Enable it with"
        " = fiber.top_enable() first");
  }
  lua_newtable(L);
diff --git = a/test/app/fiber.result b/test/app/fiber.result
index = 196fae3b7..e45cd7639 100644
--- a/test/app/fiber.result
+++ b/test/app/fiber.result
@@ -1466,11 = +1466,19 @@ sum =3D 0
 ---
 ...
 -- gh-2694 fiber.top()
+fiber.top_enable()
+---
+...
 a =3D fiber.top()
 ---
 ...
+type(a)
+---
+- table
+...
 -- scheduler = is present in fiber.top()
-a[1] = ~=3D nil
+-- and is indexed by name
+a["sched"] ~=3D nil
 ---
 - true
 ...
@@ = -1484,21 +1492,19 @@ sum_inst =3D 0
 sum_avg =3D 0
 ---
 ...
-test_run:cmd('setopt delimiter ";"')
----
-- true
-...
-for k, v in = pairs(a) do
-    if type(v) =3D=3D 'table' = then
-        sum_inst =3D = sum_inst + v["cpu instant (%)"]
-      =   sum_avg =3D sum_avg + v["cpu average (%)"]
-    end
-end;
+-- = update table to make sure
+-- a full event loop = iteration
+-- has ended
+a =3D fiber.top()
 ---
 ...
-test_run:cmd('setopt delimiter = ""');
+for k, v in pairs(a) do\
+  =   if type(v) =3D=3D 'table' then\
+    =     sum_inst =3D sum_inst + v["instant"]\
+        sum_avg =3D sum_avg + = v["average"]\
+    end\
+end ---
-- true
 ...
 sum_inst
 ---
@@ = -1518,11 +1524,11 @@ f =3D fiber.new(function() for i =3D 1,1000 do end = fiber.yield() tbl =3D fiber.top()[f
 while f:status() ~=3D 'dead' do fiber.sleep(0.01) = end
 ---
 ...
-tbl["cpu average (%)"] > 0
+tbl["average"] = > 0
 ---
 - true
 ...
-tbl["cpu instant (%)"] > 0
+tbl["instant"] > 0
 ---
 - true
 ...
@@ = -1531,14 +1537,7 @@ fiber.top_disable()
 ...
 fiber.top()
 ---
-- = error: fiber.top() is disabled. = enable it with fiber.top_enable() first
-...
-fiber.top_enable()
----
-...
-type(fiber.top())
----
-- table
+- error: fiber.top() is disabled. = Enable it with fiber.top_enable() first
 ...
 -- cleanup
 test_run:cmd("clear = filter")
diff --git a/test/app/fiber.test.lua = b/test/app/fiber.test.lua
index 15507c2c7..e30aba77e = 100644
--- a/test/app/fiber.test.lua
+++ = b/test/app/fiber.test.lua
@@ -632,33 +632,39 @@ = fiber.join(fiber.self())
 sum =3D 0
 
 -- gh-2694 fiber.top()
+fiber.top_enable()
+
 a =3D fiber.top()
+type(a)
 -- = scheduler is present in fiber.top()
-a[1] ~=3D nil
+--= and is indexed by name
+a["sched"] ~=3D nil
 type(a["cpu misses"]) =3D=3D 'number'
 sum_inst =3D 0
 sum_avg =3D 0
-test_run:cmd('setopt delimiter ";"')
-for k, v = in pairs(a) do
-    if type(v) =3D=3D = 'table' then
-        sum_inst =3D = sum_inst + v["cpu instant (%)"]
-      =   sum_avg =3D sum_avg + v["cpu average (%)"]
-    end
-end;
-test_run:cmd('setopt delimiter ""');
+
+-- update table to make sure
+-- a full event = loop iteration
+-- has ended
+a =3D fiber.top()
+for k, v in pairs(a) do\
+    if type(v) =3D=3D 'table' then\
+        sum_inst =3D sum_inst + = v["instant"]\
+        sum_avg =3D = sum_avg + v["average"]\
+    end\
+end
+
 sum_inst
 -- not exact due to accumulated integer division = errors
 sum_avg > 99 and sum_avg < 101 or = sum_avg
 tbl =3D nil
 f =3D = fiber.new(function() for i =3D 1,1000 do end fiber.yield() tbl =3D fiber.top()[fiber.self().id()] end)
 while f:status() ~=3D 'dead' do fiber.sleep(0.01) = end
-tbl["cpu average (%)"] > 0
-tbl["cpu = instant (%)"] > 0
+tbl["average"] > 0
+tbl["instant"] > 0
 
 fiber.top_disable()
 fiber.top()
-fiber.top_enable()
-type(fiber.top())
 
 -- cleanup
 test_run:cmd("clear filter")

--
Serge Petrenko
sergepetrenko@tarantool.org

= --Apple-Mail=_A0162564-72A2-47B5-BCAD-BFED433CA6B2--