Merge pull request #839 from aktau/platform-abstract-time-fn

viml: impl profiling on top of uv_hrtime()

1 files changed, 119 insertions, 76 deletions

diff --git a/src/nvim/eval.c b/src/nvim/eval.c
index 3459b5c4a0..d82f71b836 100644
--- a/src/nvim/eval.c
+++ b/src/nvim/eval.c
@@ -18,6 +18,7 @@
 #include <stdbool.h>
 #include <math.h>
 
+#include "nvim/assert.h"
 #include "nvim/vim.h"
 #include "nvim/ascii.h"
 #ifdef HAVE_LOCALE_H
@@ -59,6 +60,7 @@
 #include "nvim/os_unix.h"
 #include "nvim/path.h"
 #include "nvim/popupmnu.h"
+#include "nvim/profile.h"
 #include "nvim/quickfix.h"
 #include "nvim/regexp.h"
 #include "nvim/screen.h"
@@ -1209,8 +1211,10 @@ void prof_child_enter(proftime_T *tm /* place to store waittime */
 {
   funccall_T *fc = current_funccal;
 
-  if (fc != NULL && fc->func->uf_profiling)
-    profile_start(&fc->prof_child);
+  if (fc != NULL && fc->func->uf_profiling) {
+    fc->prof_child = profile_start();
+  }
+
   script_prof_save(tm);
 }
 
@@ -1224,10 +1228,13 @@ void prof_child_exit(proftime_T *tm /* where waittime was stored */
   funccall_T *fc = current_funccal;
 
   if (fc != NULL && fc->func->uf_profiling) {
-    profile_end(&fc->prof_child);
-    profile_sub_wait(tm, &fc->prof_child);     /* don't count waiting time */
-    profile_add(&fc->func->uf_tm_children, &fc->prof_child);
-    profile_add(&fc->func->uf_tml_children, &fc->prof_child);
+    fc->prof_child = profile_end(fc->prof_child);
+    // don't count waiting time
+    fc->prof_child = profile_sub_wait(*tm, fc->prof_child);
+    fc->func->uf_tm_children =
+      profile_add(fc->func->uf_tm_children, fc->prof_child);
+    fc->func->uf_tml_children =
+      profile_add(fc->func->uf_tml_children, fc->prof_child);
   }
   script_prof_restore(tm);
 }
@@ -11646,66 +11653,101 @@ static void f_readfile(typval_T *argvars, typval_T *rettv)
 }
 
 
-/*
- * Convert a List to proftime_T.
- * Return FAIL when there is something wrong.
- */
-static int list2proftime(typval_T *arg, proftime_T *tm)
+/// list2proftime - convert a List to proftime_T
+///
+/// @param arg The input list, must be of type VAR_LIST and have
+///            exactly 2 items
+/// @param[out] tm The proftime_T representation of `arg`
+/// @return OK In case of success, FAIL in case of error
+static int list2proftime(typval_T *arg, proftime_T *tm) FUNC_ATTR_NONNULL_ALL
 {
-  long n1, n2;
-  int error = FALSE;
+  if (arg->v_type != VAR_LIST
+      || arg->vval.v_list == NULL
+      || arg->vval.v_list->lv_len != 2) {
+    return FAIL;
+  }
 
-  if (arg->v_type != VAR_LIST || arg->vval.v_list == NULL
-      || arg->vval.v_list->lv_len != 2)
+  int error = false;
+  varnumber_T n1 = list_find_nr(arg->vval.v_list, 0L, &error);
+  varnumber_T n2 = list_find_nr(arg->vval.v_list, 1L, &error);
+  if (error) {
     return FAIL;
-  n1 = list_find_nr(arg->vval.v_list, 0L, &error);
-  n2 = list_find_nr(arg->vval.v_list, 1L, &error);
-  tm->tv_sec = n1;
-  tm->tv_usec = n2;
-  return error ? FAIL : OK;
+  }
+
+  // in f_reltime() we split up the 64-bit proftime_T into two 32-bit
+  // values, now we combine them again.
+  union {
+    struct { varnumber_T low, high; } split;
+    proftime_T prof;
+  } u = { .split.high = n1, .split.low = n2 };
+
+  *tm = u.prof;
+
+  return OK;
 }
 
-/*
- * "reltime()" function
- */
-static void f_reltime(typval_T *argvars, typval_T *rettv)
+/// f_reltime - return an item that represents a time value
+///
+/// @param[out] rettv Without an argument it returns the current time. With
+///             one argument it returns the time passed since the argument.
+///             With two arguments it returns the time passed between
+///             the two arguments.
+static void f_reltime(typval_T *argvars, typval_T *rettv) FUNC_ATTR_NONNULL_ALL
 {
   proftime_T res;
   proftime_T start;
 
   if (argvars[0].v_type == VAR_UNKNOWN) {
-    /* No arguments: get current time. */
-    profile_start(&res);
+    // no arguments: get current time.
+    res = profile_start();
   } else if (argvars[1].v_type == VAR_UNKNOWN) {
-    if (list2proftime(&argvars[0], &res) == FAIL)
+    if (list2proftime(&argvars[0], &res) == FAIL) {
       return;
-    profile_end(&res);
+    }
+    res = profile_end(res);
   } else {
-    /* Two arguments: compute the difference. */
+    // two arguments: compute the difference.
     if (list2proftime(&argvars[0], &start) == FAIL
-        || list2proftime(&argvars[1], &res) == FAIL)
+        || list2proftime(&argvars[1], &res) == FAIL) {
       return;
-    profile_sub(&res, &start);
+    }
+    res = profile_sub(res, start);
   }
 
+  // we have to store the 64-bit proftime_T inside of a list of int's
+  // (varnumber_T is defined as int). For all our supported platforms, int's
+  // are at least 32-bits wide. So we'll use two 32-bit values to store it.
+  union {
+    struct { varnumber_T low, high; } split;
+    proftime_T prof;
+  } u = { .prof = res };
+
+  // statically assert that the union type conv will provide the correct
+  // results, if varnumber_T or proftime_T change, the union cast will need
+  // to be revised.
+  STATIC_ASSERT(sizeof(u.prof) == sizeof(u) && sizeof(u.split) == sizeof(u),
+      "type punning will produce incorrect results on this platform");
+
   rettv_list_alloc(rettv);
-  long n1 = res.tv_sec;
-  long n2 = res.tv_usec;
-  list_append_number(rettv->vval.v_list, (varnumber_T)n1);
-  list_append_number(rettv->vval.v_list, (varnumber_T)n2);
+  list_append_number(rettv->vval.v_list, u.split.high);
+  list_append_number(rettv->vval.v_list, u.split.low);
 }
 
-/*
- * "reltimestr()" function
- */
+/// f_reltimestr - return a string that represents the value of {time}
+///
+/// @return The string representation of the argument, the format is the
+///         number of seconds followed by a dot, followed by the number
+///         of microseconds.
 static void f_reltimestr(typval_T *argvars, typval_T *rettv)
+  FUNC_ATTR_NONNULL_ALL
 {
   proftime_T tm;
 
   rettv->v_type = VAR_STRING;
   rettv->vval.v_string = NULL;
-  if (list2proftime(&argvars[0], &tm) == OK)
-    rettv->vval.v_string = vim_strsave((char_u *)profile_msg(&tm));
+  if (list2proftime(&argvars[0], &tm) == OK) {
+    rettv->vval.v_string = (char_u *) xstrdup(profile_msg(tm));
+  }
 }
 
 /*
@@ -12134,7 +12176,7 @@ static int search_cmn(typval_T *argvars, pos_T *match_pos, int *flagsp)
   }
 
   /* Set the time limit, if there is one. */
-  profile_setlimit(time_limit, &tm);
+  tm = profile_setlimit(time_limit);
 
   /*
    * This function does not accept SP_REPEAT and SP_RETCOUNT flags.
@@ -12426,7 +12468,7 @@ do_searchpair (
   p_cpo = empty_option;
 
   /* Set the time limit, if there is one. */
-  profile_setlimit(time_limit, &tm);
+  tm = profile_setlimit(time_limit);
 
   /* Make two search patterns: start/end (pat2, for in nested pairs) and
    * start/middle/end (pat3, for the top pair). */
@@ -17435,8 +17477,8 @@ static void func_do_profile(ufunc_T *fp)
   if (len == 0)
     len = 1;      /* avoid getting error for allocating zero bytes */
   fp->uf_tm_count = 0;
-  profile_zero(&fp->uf_tm_self);
-  profile_zero(&fp->uf_tm_total);
+  fp->uf_tm_self = profile_zero();
+  fp->uf_tm_total = profile_zero();
 
   if (fp->uf_tml_count == NULL) {
     fp->uf_tml_count = xcalloc(len, sizeof(int));
@@ -17488,8 +17530,8 @@ void func_dump_profile(FILE *fd)
           fprintf(fd, "Called 1 time\n");
         else
           fprintf(fd, "Called %d times\n", fp->uf_tm_count);
-        fprintf(fd, "Total time: %s\n", profile_msg(&fp->uf_tm_total));
-        fprintf(fd, " Self time: %s\n", profile_msg(&fp->uf_tm_self));
+        fprintf(fd, "Total time: %s\n", profile_msg(fp->uf_tm_total));
+        fprintf(fd, " Self time: %s\n", profile_msg(fp->uf_tm_self));
         fprintf(fd, "\n");
         fprintf(fd, "count  total (s)   self (s)\n");
 
@@ -17556,14 +17598,14 @@ static void prof_func_line(
 {
   if (count > 0) {
     fprintf(fd, "%5d ", count);
-    if (prefer_self && profile_equal(total, self))
+    if (prefer_self && profile_equal(*total, *self))
       fprintf(fd, "           ");
     else
-      fprintf(fd, "%s ", profile_msg(total));
-    if (!prefer_self && profile_equal(total, self))
+      fprintf(fd, "%s ", profile_msg(*total));
+    if (!prefer_self && profile_equal(*total, *self))
       fprintf(fd, "           ");
     else
-      fprintf(fd, "%s ", profile_msg(self));
+      fprintf(fd, "%s ", profile_msg(*self));
   } else
     fprintf(fd, "                            ");
 }
@@ -17573,11 +17615,9 @@ static void prof_func_line(
  */
 static int prof_total_cmp(const void *s1, const void *s2)
 {
-  ufunc_T     *p1, *p2;
-
-  p1 = *(ufunc_T **)s1;
-  p2 = *(ufunc_T **)s2;
-  return profile_cmp(&p1->uf_tm_total, &p2->uf_tm_total);
+  ufunc_T *p1 = *(ufunc_T **)s1;
+  ufunc_T *p2 = *(ufunc_T **)s2;
+  return profile_cmp(p1->uf_tm_total, p2->uf_tm_total);
 }
 
 /*
@@ -17585,11 +17625,9 @@ static int prof_total_cmp(const void *s1, const void *s2)
  */
 static int prof_self_cmp(const void *s1, const void *s2)
 {
-  ufunc_T     *p1, *p2;
-
-  p1 = *(ufunc_T **)s1;
-  p2 = *(ufunc_T **)s2;
-  return profile_cmp(&p1->uf_tm_self, &p2->uf_tm_self);
+  ufunc_T *p1 = *(ufunc_T **)s1;
+  ufunc_T *p2 = *(ufunc_T **)s2;
+  return profile_cmp(p1->uf_tm_self, p2->uf_tm_self);
 }
 
 
@@ -18018,8 +18056,8 @@ call_user_func (
     if (fp->uf_profiling
         || (fc->caller != NULL && fc->caller->func->uf_profiling)) {
       ++fp->uf_tm_count;
-      profile_start(&call_start);
-      profile_zero(&fp->uf_tm_children);
+      call_start = profile_start();
+      fp->uf_tm_children = profile_zero();
     }
     script_prof_save(&wait_start);
   }
@@ -18046,13 +18084,16 @@ call_user_func (
   if (do_profiling == PROF_YES && (fp->uf_profiling
                                    || (fc->caller != NULL &&
                                        fc->caller->func->uf_profiling))) {
-    profile_end(&call_start);
-    profile_sub_wait(&wait_start, &call_start);
-    profile_add(&fp->uf_tm_total, &call_start);
-    profile_self(&fp->uf_tm_self, &call_start, &fp->uf_tm_children);
+    call_start = profile_end(call_start);
+    call_start = profile_sub_wait(wait_start, call_start);
+    fp->uf_tm_total = profile_add(fp->uf_tm_total, call_start);
+    fp->uf_tm_self = profile_self(fp->uf_tm_self, call_start,
+        fp->uf_tm_children);
     if (fc->caller != NULL && fc->caller->func->uf_profiling) {
-      profile_add(&fc->caller->func->uf_tm_children, &call_start);
-      profile_add(&fc->caller->func->uf_tml_children, &call_start);
+      fc->caller->func->uf_tm_children =
+        profile_add(fc->caller->func->uf_tm_children, call_start);
+      fc->caller->func->uf_tml_children =
+        profile_add(fc->caller->func->uf_tml_children, call_start);
     }
   }
 
@@ -18415,9 +18456,9 @@ void func_line_start(void *cookie)
     while (fp->uf_tml_idx > 0 && FUNCLINE(fp, fp->uf_tml_idx) == NULL)
       --fp->uf_tml_idx;
     fp->uf_tml_execed = FALSE;
-    profile_start(&fp->uf_tml_start);
-    profile_zero(&fp->uf_tml_children);
-    profile_get_wait(&fp->uf_tml_wait);
+    fp->uf_tml_start = profile_start();
+    fp->uf_tml_children = profile_zero();
+    fp->uf_tml_wait = profile_get_wait();
   }
 }
 
@@ -18444,11 +18485,13 @@ void func_line_end(void *cookie)
   if (fp->uf_profiling && fp->uf_tml_idx >= 0) {
     if (fp->uf_tml_execed) {
       ++fp->uf_tml_count[fp->uf_tml_idx];
-      profile_end(&fp->uf_tml_start);
-      profile_sub_wait(&fp->uf_tml_wait, &fp->uf_tml_start);
-      profile_add(&fp->uf_tml_total[fp->uf_tml_idx], &fp->uf_tml_start);
-      profile_self(&fp->uf_tml_self[fp->uf_tml_idx], &fp->uf_tml_start,
-          &fp->uf_tml_children);
+      fp->uf_tml_start = profile_end(fp->uf_tml_start);
+      fp->uf_tml_start = profile_sub_wait(fp->uf_tml_wait, fp->uf_tml_start);
+      fp->uf_tml_total[fp->uf_tml_idx] =
+        profile_add(fp->uf_tml_total[fp->uf_tml_idx], fp->uf_tml_start);
+      fp->uf_tml_self[fp->uf_tml_idx] =
+        profile_self(fp->uf_tml_self[fp->uf_tml_idx], fp->uf_tml_start,
+          fp->uf_tml_children);
     }
     fp->uf_tml_idx = -1;
   }