From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp46.i.mail.ru (smtp46.i.mail.ru [94.100.177.106]) (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 11281440F3C for ; Fri, 15 Nov 2019 21:23:43 +0300 (MSK) From: Serge Petrenko Message-Id: <794D2738-DF93-410A-9F5D-D0CC8908CCC3@tarantool.org> Content-Type: multipart/alternative; boundary="Apple-Mail=_24F80FCE-8FF5-4282-A6FF-94A7D18147E8" Mime-Version: 1.0 (Mac OS X Mail 12.4 \(3445.104.11\)) Date: Fri, 15 Nov 2019 21:23:42 +0300 In-Reply-To: <20191115161138.qy3u42snfkourbh7@tkn_work_nb> References: <20191115161138.qy3u42snfkourbh7@tkn_work_nb> Subject: Re: [Tarantool-patches] [PATCH v2 1/2] fiber: reset clock stats on fiber.top_enable() List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Alexander Turenko Cc: tarantool-patches@dev.tarantool.org, Vladislav Shpilevoy --Apple-Mail=_24F80FCE-8FF5-4282-A6FF-94A7D18147E8 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 Hi! Thank you for your answer! Fixed codestyle and answered your question inline. -- Serge Petrenko sergepetrenko@tarantool.org > 15 =D0=BD=D0=BE=D1=8F=D0=B1. 2019 =D0=B3., =D0=B2 19:11, Alexander = Turenko =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0= =B0=D0=BB(=D0=B0): >=20 > I have no any knowledge around fiber.top(), just asked a question > because of curiosity. >=20 > WBR, Alexander Turenko. >=20 > On Fri, Nov 15, 2019 at 05:58:58PM +0300, Serge Petrenko wrote: >> We didn't refresh last remembered clock on fiber.top_enable() >> This means that the fiber issuing fiber.top_enable() would get a huge >> chunk of cpu time on its first yield. Fix this. >> Also reset clock_delta and cpu_miss_count. >>=20 >> If fiber.top() is issued on the same ev loop iteration as >> fiber.top_enable(), clock_delta_last is 0 for both cord and all the >> fibers, so report "instant" and "average" stats per last iteration as = 0 >> instead of NaN. >>=20 >> Follow-up #2694 >> --- >> src/lib/core/fiber.c | 21 +++++++++++++++++++++ >> src/lua/fiber.c | 12 ++++++++++-- >> 2 files changed, 31 insertions(+), 2 deletions(-) >>=20 >> diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c >> index aebaba7f0..258c094f5 100644 >> --- a/src/lib/core/fiber.c >> +++ b/src/lib/core/fiber.c >> @@ -1203,9 +1203,30 @@ fiber_top_enable() >> ev_check_start(cord()->loop, &cord()->check_event); >> fiber_top_enabled =3D true; >>=20 >> + /* >> + * Reset cord and fiber clock stats in order to >> + * count from zero even on reenable. >> + */ >> cord()->clock_acc =3D 0; >> cord()->cpu_miss_count_last =3D 0; >> cord()->clock_delta_last =3D 0; >> + cord()->clock_delta =3D 0; >> + >> + struct fiber * fiber; >=20 > Code style: struct fiber *fiber; Fixed >=20 >> + rlist_foreach_entry(fiber, &cord()->alive, link) { >> + fiber->clock_acc =3D 0; >> + fiber->clock_delta_last =3D 0; >> + fiber->clock_delta =3D 0; >> + fiber->cputime =3D 0; >> + } >> + >> + cord()->sched.clock_acc =3D 0; >> + cord()->sched.clock_delta_last =3D 0; >> + cord()->sched.clock_delta =3D 0; >> + cord()->sched.cputime =3D 0; >> + >> + cord()->clock_last =3D __rdtscp(&cord()->cpu_id_last); >> + cord()->cpu_miss_count =3D 0; >=20 > Should not we doing such clean up in fiber_top_disable() rather then > here? It doesn=E2=80=99t matter IMO. Well, yes, you don=E2=80=99t need a = cleanup when you call fiber.top_enable() for the first time, but, other than that, I see no = difference. >=20 >> struct timespec ts; >> if (clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts) !=3D 0) = { >> say_debug("clock_gettime(): failed to get this" >> diff --git a/src/lua/fiber.c b/src/lua/fiber.c >> index 8b3b22e55..647505643 100644 >> --- a/src/lua/fiber.c >> +++ b/src/lua/fiber.c >> @@ -335,11 +335,19 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx) >> lua_newtable(L); >>=20 >> lua_pushliteral(L, "average"); >> - lua_pushnumber(L, f->clock_acc / (double)cord()->clock_acc * = 100); >> + if (cord()->clock_acc) >> + lua_pushnumber(L, f->clock_acc / = (double)cord()->clock_acc * 100); >> + else >> + lua_pushnumber(L, 0); >> lua_settable(L, -3); >> + >> lua_pushliteral(L, "instant"); >> - lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100); >> + if (cord()->clock_delta_last) >> + lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100); >> + else >> + lua_pushnumber(L, 0); >> lua_settable(L, -3); >=20 > Code style: lines over 80 chars. Fixed >=20 >> + >> lua_pushliteral(L, "time"); >> lua_pushnumber(L, f->cputime / (double) FIBER_TIME_RES); >> lua_settable(L, -3); >> --=20 >> 2.21.0 (Apple Git-122) diff --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c index 258c094f5..c6aab18b2 100644 --- a/src/lib/core/fiber.c +++ b/src/lib/core/fiber.c @@ -1212,7 +1212,7 @@ fiber_top_enable() cord()->clock_delta_last =3D 0; cord()->clock_delta =3D 0; =20 - struct fiber * fiber; + struct fiber *fiber; rlist_foreach_entry(fiber, &cord()->alive, link) { fiber->clock_acc =3D 0; fiber->clock_delta_last =3D 0; diff --git a/src/lua/fiber.c b/src/lua/fiber.c index 647505643..9268b0a19 100644 --- a/src/lua/fiber.c +++ b/src/lua/fiber.c @@ -335,17 +335,21 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx) lua_newtable(L); =20 lua_pushliteral(L, "average"); - if (cord()->clock_acc) - lua_pushnumber(L, f->clock_acc / = (double)cord()->clock_acc * 100); - else + if (cord()->clock_acc) { + lua_pushnumber(L, f->clock_acc / + (double)cord()->clock_acc * 100); + } else { lua_pushnumber(L, 0); + } lua_settable(L, -3); =20 lua_pushliteral(L, "instant"); - if (cord()->clock_delta_last) - lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100); - else + if (cord()->clock_delta_last) { + lua_pushnumber(L, f->clock_delta_last / + (double)cord()->clock_delta_last * = 100); + } else { lua_pushnumber(L, 0); + } lua_settable(L, -3); =20 lua_pushliteral(L, "time"); --Apple-Mail=_24F80FCE-8FF5-4282-A6FF-94A7D18147E8 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 Hi! Thank you for your = answer!
Fixed codestyle and answered your question = inline.

--
Serge Petrenko
sergepetrenko@tarantool.org

15 = =D0=BD=D0=BE=D1=8F=D0=B1. 2019 =D0=B3., =D0=B2 19:11, Alexander Turenko = <alexander.turenko@tarantool.org> = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0):

I have no any knowledge around fiber.top(), just asked a = question
because of curiosity.

WBR, Alexander Turenko.

On Fri, = Nov 15, 2019 at 05:58:58PM +0300, Serge Petrenko wrote:
We = didn't refresh last remembered clock on fiber.top_enable()
This means that the fiber issuing fiber.top_enable() would = get a huge
chunk of cpu time on its first yield. Fix = this.
Also reset clock_delta and cpu_miss_count.

If fiber.top() is issued on the same ev loop = iteration as
fiber.top_enable(), clock_delta_last is 0 for = both cord and all the
fibers, so report "instant" and = "average" stats per last iteration as 0
instead of NaN.

Follow-up #2694
---
src/lib/core/fiber.c | 21 +++++++++++++++++++++
src/lua/fiber.c      | 12 ++++++++++--
2 files changed, 31 insertions(+), 2 deletions(-)

diff --git a/src/lib/core/fiber.c = b/src/lib/core/fiber.c
index aebaba7f0..258c094f5 = 100644
--- a/src/lib/core/fiber.c
+++ = b/src/lib/core/fiber.c
@@ -1203,9 +1203,30 @@ = fiber_top_enable()
ev_check_start(cord()->loop, = &cord()->check_event);
fiber_top_enabled =3D true;

+ /*
+  * = Reset cord and fiber clock stats in order to
+  * = count from zero even on reenable.
+ =  */
cord()->clock_acc =3D 0;
= = cord()->cpu_miss_count_last =3D 0;
= cord()->clock_delta_last =3D 0;
+ = cord()->clock_delta =3D 0;
+
+ struct = fiber * fiber;

Code style: = struct fiber *fiber;

Fixed


+ rlist_foreach_entry(fiber, = &cord()->alive, link) {
+ = fiber->clock_acc =3D 0;
+ = fiber->clock_delta_last =3D 0;
+ = fiber->clock_delta =3D 0;
+ = fiber->cputime =3D 0;
+ }
+
+ cord()->sched.clock_acc =3D = 0;
+ cord()->sched.clock_delta_last = =3D 0;
+ cord()->sched.clock_delta =3D = 0;
+ cord()->sched.cputime =3D = 0;
+
+ cord()->clock_last =3D = __rdtscp(&cord()->cpu_id_last);
+ = cord()->cpu_miss_count =3D 0;

Should not we doing such clean up in fiber_top_disable() = rather then
here?

It doesn=E2=80=99t = matter IMO. Well, yes, you don=E2=80=99t need a cleanup when you = call
fiber.top_enable() for the first time, but, = other than that, I see no difference.


struct timespec ts;
= = if (clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts) !=3D 0) {
= = = say_debug("clock_gettime(): failed to get this"
diff = --git a/src/lua/fiber.c b/src/lua/fiber.c
index = 8b3b22e55..647505643 100644
--- a/src/lua/fiber.c
+++ b/src/lua/fiber.c
@@ -335,11 +335,19 @@ = lbox_fiber_top_entry(struct fiber *f, void *cb_ctx)
= lua_newtable(L);

= lua_pushliteral(L, "average");
- = lua_pushnumber(L, f->clock_acc / (double)cord()->clock_acc = * 100);
+ if (cord()->clock_acc)
+ = = lua_pushnumber(L, f->clock_acc / (double)cord()->clock_acc = * 100);
+ else
+ = lua_pushnumber(L, 0);
lua_settable(L, -3);
+
lua_pushliteral(L, "instant");
- = lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100);
+ if = (cord()->clock_delta_last)
+ = lua_pushnumber(L, f->clock_delta_last / = (double)cord()->clock_delta_last * 100);
+ else
+ = = lua_pushnumber(L, 0);
lua_settable(L, -3);

Code style: lines over 80 = chars.

Fixed


+
= lua_pushliteral(L, "time");
= lua_pushnumber(L, f->cputime / (double) FIBER_TIME_RES);
= lua_settable(L, -3);
-- 
2.21.0 = (Apple Git-122)


diff = --git a/src/lib/core/fiber.c b/src/lib/core/fiber.c
index = 258c094f5..c6aab18b2 100644
--- a/src/lib/core/fiber.c
+++ b/src/lib/core/fiber.c
@@ -1212,7 +1212,7 = @@ fiber_top_enable()
        =         cord()->clock_delta_last =3D 0;
              =   cord()->clock_delta =3D 0;
 
-             =   struct fiber * fiber;
+     =           struct fiber *fiber;
              =   rlist_foreach_entry(fiber, &cord()->alive, link) {
                =         fiber->clock_acc =3D 0;
                =         fiber->clock_delta_last =3D 0;
diff --git a/src/lua/fiber.c b/src/lua/fiber.c
index 647505643..9268b0a19 100644
--- = a/src/lua/fiber.c
+++ b/src/lua/fiber.c
@@ = -335,17 +335,21 @@ lbox_fiber_top_entry(struct fiber *f, void = *cb_ctx)
      =   lua_newtable(L);
 
  =       lua_pushliteral(L, "average");
-       if (cord()->clock_acc)
-             =   lua_pushnumber(L, f->clock_acc / = (double)cord()->clock_acc * 100);
-     =   else
+       if = (cord()->clock_acc) {
+       =         lua_pushnumber(L, f->clock_acc /
+               =               =     (double)cord()->clock_acc * 100);
+       } else {
  =               lua_pushnumber(L, = 0);
+       }
  =       lua_settable(L, -3);
 
        lua_pushliteral(L, = "instant");
-       if = (cord()->clock_delta_last)
-       =         lua_pushnumber(L, = f->clock_delta_last / (double)cord()->clock_delta_last * 100);
-       else
+       if = (cord()->clock_delta_last) {
+     =           lua_pushnumber(L, = f->clock_delta_last /
+       =                     =       (double)cord()->clock_delta_last * = 100);
+       } else {
              =   lua_pushnumber(L, 0);
+     =   }
      =   lua_settable(L, -3);
 
 =       lua_pushliteral(L, "time");

= --Apple-Mail=_24F80FCE-8FF5-4282-A6FF-94A7D18147E8--