Merge #962 'Implement startuptime functions on top of profiling functions'

11 files changed, 151 insertions, 172 deletions

diff --git a/src/nvim/eval.c b/src/nvim/eval.c
index e72dd60dcf..77f327c124 100644
--- a/src/nvim/eval.c
+++ b/src/nvim/eval.c
@@ -9731,9 +9731,7 @@ static void f_has(typval_T *argvars, typval_T *rettv)
     "cmdline_info",
     "signs",
     "smartindent",
-#ifdef STARTUPTIME
     "startuptime",
-#endif
     "statusline",
     "spell",
     "syntax",
diff --git a/src/nvim/ex_cmds2.c b/src/nvim/ex_cmds2.c
index 7371ada9b8..afbb3b40f1 100644
--- a/src/nvim/ex_cmds2.c
+++ b/src/nvim/ex_cmds2.c
@@ -2261,10 +2261,6 @@ do_source (
   void                    *save_funccalp;
   int save_debug_break_level = debug_break_level;
   scriptitem_T            *si = NULL;
-#ifdef STARTUPTIME
-  struct timeval tv_rel;
-  struct timeval tv_start;
-#endif
   proftime_T wait_start;
 
   p = expand_env_save(fname);
@@ -2393,10 +2389,13 @@ do_source (
     firstline = p;
   }
 
-#ifdef STARTUPTIME
-  if (time_fd != NULL)
-    time_push(&tv_rel, &tv_start);
-#endif
+  // start measuring script load time if --startuptime was passed and
+  // time_fd was successfully opened afterwards.
+  proftime_T rel_time;
+  proftime_T start_time;
+  if (time_fd != NULL) {
+    time_push(&rel_time, &start_time);
+  }
 
   if (do_profiling == PROF_YES)
     prof_child_enter(&wait_start);              /* entering a child now */
@@ -2490,13 +2489,12 @@ do_source (
       smsg((char_u *)_("continuing in %s"), sourcing_name);
     verbose_leave();
   }
-#ifdef STARTUPTIME
+
   if (time_fd != NULL) {
     vim_snprintf((char *)IObuff, IOSIZE, "sourcing %s", fname);
-    time_msg((char *)IObuff, &tv_start);
-    time_pop(&tv_rel);
+    time_msg((char *)IObuff, &start_time);
+    time_pop(rel_time);
   }
-#endif
 
   /*
    * After a "finish" in debug mode, need to break at first command of next
diff --git a/src/nvim/garray.h b/src/nvim/garray.h
index 5a90da21c2..b32bab52f7 100644
--- a/src/nvim/garray.h
+++ b/src/nvim/garray.h
@@ -1,6 +1,9 @@
 #ifndef NVIM_GARRAY_H
 #define NVIM_GARRAY_H
 
+#include <stddef.h>  // for size_t
+
+#include "nvim/types.h"  // for char_u
 #include "nvim/log.h"
 
 /// Structure used for growing arrays.
diff --git a/src/nvim/globals.h b/src/nvim/globals.h
index 1f402f3ef9..f9d5a766c8 100644
--- a/src/nvim/globals.h
+++ b/src/nvim/globals.h
@@ -10,15 +10,36 @@
 
 #include <stdbool.h>
 
+// EXTERN is only defined in main.c. That's where global variables are
+// actually defined and initialized.
+#ifndef EXTERN
+# define EXTERN extern
+# define INIT(x)
+#else
+# ifndef INIT
+#  define INIT(x) x
+#  define DO_INIT
+# endif
+#endif
+
 #include "nvim/ex_eval.h"
 #include "nvim/mbyte.h"
 #include "nvim/menu.h"
 #include "nvim/syntax_defs.h"
+#include "nvim/types.h"
 
 /*
  * definition of global variables
  */
 
+#define IOSIZE         (1024+1)          // file I/O and sprintf buffer size
+
+#define MAX_MCO        6                 // maximum value for 'maxcombine'
+
+# define MSG_BUF_LEN 480                 // length of buffer for small messages
+# define MSG_BUF_CLEN  (MSG_BUF_LEN / 6) // cell length (worst case: utf-8
+                                         // takes 6 bytes for one cell)
+
 /* Values for "starting" */
 #define NO_SCREEN       2       /* no screen updating yet */
 #define NO_BUFFERS      1       /* not all buffers loaded yet */
@@ -1186,9 +1207,7 @@ EXTERN char bot_top_msg[] INIT(= N_("search hit BOTTOM, continuing at TOP"));
 /* For undo we need to know the lowest time possible. */
 EXTERN time_t starttime;
 
-#ifdef STARTUPTIME
 EXTERN FILE *time_fd INIT(= NULL);  /* where to write startup timing */
-#endif
 
 /*
  * Some compilers warn for not using a return value, but in some situations we
diff --git a/src/nvim/macros.h b/src/nvim/macros.h
index bff19f17dd..f8fd6ac6a2 100644
--- a/src/nvim/macros.h
+++ b/src/nvim/macros.h
@@ -116,12 +116,6 @@
 #  define mch_open_rw(n, f)     os_open((n), (f), 0)
 #endif
 
-#ifdef STARTUPTIME
-# define TIME_MSG(s) { if (time_fd != NULL) time_msg(s, NULL); }
-#else
-# define TIME_MSG(s)
-#endif
-
 # define REPLACE_NORMAL(s) (((s) & REPLACE_FLAG) && !((s) & VREPLACE_FLAG))
 
 # define UTF_COMPOSINGLIKE(p1, p2)  utf_composinglike((p1), (p2))
diff --git a/src/nvim/main.c b/src/nvim/main.c
index 344baa6b53..ac1366bfd9 100644
--- a/src/nvim/main.c
+++ b/src/nvim/main.c
@@ -45,6 +45,7 @@
 #include "nvim/option.h"
 #include "nvim/os_unix.h"
 #include "nvim/path.h"
+#include "nvim/profile.h"
 #include "nvim/quickfix.h"
 #include "nvim/screen.h"
 #include "nvim/strings.h"
@@ -710,16 +711,14 @@ main_loop (
 
       do_redraw = FALSE;
 
-#ifdef STARTUPTIME
       /* Now that we have drawn the first screen all the startup stuff
        * has been done, close any file for startup messages. */
       if (time_fd != NULL) {
         TIME_MSG("first screen update");
-        TIME_MSG("--- VIM STARTED ---");
+        TIME_MSG("--- NVIM STARTED ---");
         fclose(time_fd);
         time_fd = NULL;
       }
-#endif
     }
 
     /*
@@ -1466,16 +1465,14 @@ static void init_params(mparm_T *paramp, int argc, char **argv)
  */
 static void init_startuptime(mparm_T *paramp)
 {
-#ifdef STARTUPTIME
-  int i;
-  for (i = 1; i < paramp->argc; ++i) {
+  for (int i = 1; i < paramp->argc; i++) {
     if (STRICMP(paramp->argv[i], "--startuptime") == 0 && i + 1 < paramp->argc) {
       time_fd = mch_fopen(paramp->argv[i + 1], "a");
-      TIME_MSG("--- VIM STARTING ---");
+      time_start("--- NVIM STARTING ---");
       break;
     }
   }
-#endif
+
   starttime = time(NULL);
 }
 
@@ -2220,9 +2217,7 @@ static void usage(void)
   main_msg(_("-s <scriptin>\tRead Normal mode commands from file <scriptin>"));
   main_msg(_("-w <scriptout>\tAppend all typed commands to file <scriptout>"));
   main_msg(_("-W <scriptout>\tWrite all typed commands to file <scriptout>"));
-#ifdef STARTUPTIME
   main_msg(_("--startuptime <file>\tWrite startup timing messages to <file>"));
-#endif
   main_msg(_("-i <viminfo>\t\tUse <viminfo> instead of .viminfo"));
   main_msg(_("--api-msgpack-metadata\tDump API metadata information and exit"));
   main_msg(_("-h  or  --help\tPrint Help (this message) and exit"));
@@ -2248,90 +2243,3 @@ static void check_swap_exists_action(void)
 #endif
 
 #endif
-
-#if defined(STARTUPTIME) || defined(PROTO)
-
-static struct timeval prev_timeval;
-
-
-/*
- * Save the previous time before doing something that could nest.
- * set "*tv_rel" to the time elapsed so far.
- */
-void time_push(void *tv_rel, void *tv_start)
-{
-  *((struct timeval *)tv_rel) = prev_timeval;
-  gettimeofday(&prev_timeval, NULL);
-  ((struct timeval *)tv_rel)->tv_usec = prev_timeval.tv_usec
-    - ((struct timeval *)tv_rel)->tv_usec;
-  ((struct timeval *)tv_rel)->tv_sec = prev_timeval.tv_sec
-    - ((struct timeval *)tv_rel)->tv_sec;
-  if (((struct timeval *)tv_rel)->tv_usec < 0) {
-    ((struct timeval *)tv_rel)->tv_usec += 1000000;
-    --((struct timeval *)tv_rel)->tv_sec;
-  }
-  *(struct timeval *)tv_start = prev_timeval;
-}
-
-/*
- * Compute the previous time after doing something that could nest.
- * Subtract "*tp" from prev_timeval;
- * Note: The arguments are (void *) to avoid trouble with systems that don't
- * have struct timeval.
- */
-void 
-time_pop (
-    void *tp        /* actually (struct timeval *) */
-)
-{
-  prev_timeval.tv_usec -= ((struct timeval *)tp)->tv_usec;
-  prev_timeval.tv_sec -= ((struct timeval *)tp)->tv_sec;
-  if (prev_timeval.tv_usec < 0) {
-    prev_timeval.tv_usec += 1000000;
-    --prev_timeval.tv_sec;
-  }
-}
-
-static void time_diff(struct timeval *then, struct timeval *now)
-{
-  long usec;
-  long msec;
-
-  usec = now->tv_usec - then->tv_usec;
-  msec = (now->tv_sec - then->tv_sec) * 1000L + usec / 1000L,
-       usec = usec % 1000L;
-  fprintf(time_fd, "%03ld.%03ld", msec, usec >= 0 ? usec : usec + 1000L);
-}
-
-void 
-time_msg (
-    char *mesg,
-    void *tv_start      /* only for do_source: start time; actually
-                                 (struct timeval *) */
-)
-{
-  static struct timeval start;
-  struct timeval now;
-
-  if (time_fd != NULL) {
-    if (strstr(mesg, "STARTING") != NULL) {
-      gettimeofday(&start, NULL);
-      prev_timeval = start;
-      fprintf(time_fd, "\n\ntimes in msec\n");
-      fprintf(time_fd, " clock   self+sourced   self:  sourced script\n");
-      fprintf(time_fd, " clock   elapsed:              other lines\n\n");
-    }
-    gettimeofday(&now, NULL);
-    time_diff(&start, &now);
-    if (((struct timeval *)tv_start) != NULL) {
-      fprintf(time_fd, "  ");
-      time_diff(((struct timeval *)tv_start), &now);
-    }
-    fprintf(time_fd, "  ");
-    time_diff(&prev_timeval, &now);
-    prev_timeval = now;
-    fprintf(time_fd, ": %s\n", mesg);
-  }
-}
-
-#endif
diff --git a/src/nvim/profile.c b/src/nvim/profile.c
index 6a77d42205..ffc62c3c7e 100644
--- a/src/nvim/profile.c
+++ b/src/nvim/profile.c
@@ -6,6 +6,8 @@
 #include "nvim/os/time.h"
 #include "nvim/func_attr.h"
 
+#include "nvim/globals.h"  // for the global `time_fd` (startuptime)
+
 #ifdef INCLUDE_GENERATED_DECLARATIONS
 # include "profile.c.generated.h"
 #endif
@@ -182,3 +184,98 @@ int profile_cmp(proftime_T tm1, proftime_T tm2) FUNC_ATTR_CONST
 {
   return sgn64((int64_t)(tm2 - tm1));
 }
+
+/// globals for use in the startuptime related functionality (time_*).
+static proftime_T g_start_time;
+static proftime_T g_prev_time;
+
+/// time_push - save the previous time before doing something that could nest
+///
+/// After calling this function, the static global `g_prev_time` will
+/// contain the current time.
+///
+/// @param[out] rel to the time elapsed so far
+/// @param[out] start the current time
+void time_push(proftime_T *rel, proftime_T *start)
+{
+  proftime_T now = profile_start();
+
+  // subtract the previous time from now, store it in `rel`
+  *rel = profile_sub(now, g_prev_time);
+  *start = now;
+
+  // reset global `g_prev_time` for the next call
+  g_prev_time = now;
+}
+
+/// time_pop - compute the prev time after doing something that could nest
+///
+/// Subtracts `tp` from the static global `g_prev_time`.
+///
+/// @param tp the time to subtract
+void time_pop(proftime_T tp)
+{
+  g_prev_time -= tp;
+}
+
+/// time_diff - print the difference between `then` and `now`
+///
+/// the format is "msec.usec".
+static void time_diff(proftime_T then, proftime_T now)
+{
+  proftime_T diff = profile_sub(now, then);
+  fprintf(time_fd, "%07.3lf", (double) diff / 1.0E6);
+}
+
+/// time_start - initialize the startuptime code
+///
+/// Needs to be called once before calling other startuptime code (such as
+/// time_{push,pop,msg,...}).
+///
+/// @param message the message that will be displayed
+void time_start(const char *message)
+{
+  if (time_fd == NULL) {
+    return;
+  }
+
+  // intialize the global variables
+  g_prev_time = g_start_time = profile_start();
+
+  fprintf(time_fd, "\n\ntimes in msec\n");
+  fprintf(time_fd, " clock   self+sourced   self:  sourced script\n");
+  fprintf(time_fd, " clock   elapsed:              other lines\n\n");
+
+  time_msg(message, NULL);
+}
+
+/// time_msg - print out timing info
+///
+/// @warning don't forget to call `time_start()` once before calling this.
+///
+/// @param mesg the message to display next to the timing information
+/// @param start only for do_source: start time
+void time_msg(const char *mesg, const proftime_T *start)
+{
+  if (time_fd == NULL) {
+    return;
+  }
+
+  // print out the difference between `start` (init earlier) and `now`
+  proftime_T now = profile_start();
+  time_diff(g_start_time, now);
+
+  // if `start` was supplied, print the diff between `start` and `now`
+  if (start != NULL) {
+    fprintf(time_fd, "  ");
+    time_diff(*start, now);
+  }
+
+  // print the difference between the global `g_prev_time` and `now`
+  fprintf(time_fd, "  ");
+  time_diff(g_prev_time, now);
+
+  // reset `g_prev_time` and print the message
+  g_prev_time = now;
+  fprintf(time_fd, ": %s\n", mesg);
+}
diff --git a/src/nvim/profile.h b/src/nvim/profile.h
index 26d1ebe3a2..7b378577ce 100644
--- a/src/nvim/profile.h
+++ b/src/nvim/profile.h
@@ -6,6 +6,10 @@
 
 typedef uint64_t proftime_T;
 
+#define TIME_MSG(s) do { \
+    if (time_fd != NULL) time_msg(s, NULL); \
+  } while (0)
+
 #ifdef INCLUDE_GENERATED_DECLARATIONS
 # include "profile.h.generated.h"
 #endif
diff --git a/src/nvim/types.h b/src/nvim/types.h
index 9d53722014..c18c6abb4b 100644
--- a/src/nvim/types.h
+++ b/src/nvim/types.h
@@ -24,4 +24,13 @@ typedef uintptr_t long_u;
  */
 typedef unsigned char char_u;
 
+// The u8char_T can hold one decoded UTF-8 character. We normally use 32
+// bits now, since some Asian characters don't fit in 16 bits. u8char_T is
+// only used for displaying, it could be 16 bits to save memory.
+#ifdef UNICODE16
+typedef uint16_t u8char_T;
+#else
+typedef uint32_t u8char_T;
+#endif
+
 #endif /* NVIM_TYPES_H */
diff --git a/src/nvim/version.c b/src/nvim/version.c
index 183e643753..c10fc970ab 100644
--- a/src/nvim/version.c
+++ b/src/nvim/version.c
@@ -145,11 +145,7 @@ static char *(features[]) = {
   "+scrollbind",
   "+signs",
   "+smartindent",
-#ifdef STARTUPTIME
   "+startuptime",
-#else  // ifdef STARTUPTIME
-  "-startuptime",
-#endif  // ifdef STARTUPTIME
   "+statusline",
   "+syntax",
   "+tag_binary",
diff --git a/src/nvim/vim.h b/src/nvim/vim.h
index e324a8bedc..5d903633e4 100644
--- a/src/nvim/vim.h
+++ b/src/nvim/vim.h
@@ -61,18 +61,6 @@ Error: configure did not run properly.Check auto/config.log.
 
 # define MAX_TYPENR 65535
 
-/*
- * The u8char_T can hold one decoded UTF-8 character.
- * We normally use 32 bits now, since some Asian characters don't fit in 16
- * bits.  u8char_T is only used for displaying, it could be 16 bits to save
- * memory.
- */
-# ifdef UNICODE16
-typedef uint16_t u8char_T;
-# else
-typedef uint32_t u8char_T;
-# endif
-
 #include "nvim/keymap.h"
 #include "nvim/term_defs.h"
 #include "nvim/macros.h"
@@ -258,15 +246,8 @@ enum {
 
 #define LSIZE       512         /* max. size of a line in the tags file */
 
-#define IOSIZE     (1024+1)     /* file i/o and sprintf buffer size */
-
 #define DIALOG_MSG_SIZE 1000    /* buffer size for dialog_msg() */
 
-# define MSG_BUF_LEN 480        /* length of buffer for small messages */
-# define MSG_BUF_CLEN  (MSG_BUF_LEN / 6)    /* cell length (worst case: utf-8
-                                               takes 6 bytes for one cell) */
-
-
 /*
  * Maximum length of key sequence to be mapped.
  * Must be able to hold an Amiga resize report.
@@ -392,37 +373,11 @@ enum {
  */
 #define vim_iswhite(x)  ((x) == ' ' || (x) == '\t')
 
-/*
- * EXTERN is only defined in main.c.  That's where global variables are
- * actually defined and initialized.
- */
-#ifndef EXTERN
-# define EXTERN extern
-# define INIT(x)
-#else
-# ifndef INIT
-#  define INIT(x) x
-#  define DO_INIT
-# endif
-#endif
-
-# define MAX_MCO        6       /* maximum value for 'maxcombine' */
-
 /* Maximum number of bytes in a multi-byte character.  It can be one 32-bit
  * character of up to 6 bytes, or one 16-bit character of up to three bytes
  * plus six following composing characters of three bytes each. */
 # define MB_MAXBYTES    21
 
-
-
-
-
-
-
-
-#include "nvim/buffer_defs.h"         /* buffer and windows */
-#include "nvim/ex_cmds_defs.h"        /* Ex command defines */
-
 /* This has to go after the include of proto.h, as proto/gui.pro declares
  * functions of these names. The declarations would break if the defines had
  * been seen at that stage.  But it must be before globals.h, where error_ga
@@ -436,11 +391,9 @@ enum {
 # define USE_MCH_ERRMSG
 #endif
 
-
-
-
 #include "nvim/globals.h"        /* global variables and messages */
-
+#include "nvim/buffer_defs.h"         /* buffer and windows */
+#include "nvim/ex_cmds_defs.h"        /* Ex command defines */
 
 # ifdef USE_ICONV
 #  ifndef EILSEQ