#include #include #include #include "nvim/profile.h" #include "nvim/os/time.h" #include "nvim/func_attr.h" #include "nvim/os/os_defs.h" #include "nvim/globals.h" // for the global `time_fd` (startuptime) #ifdef INCLUDE_GENERATED_DECLARATIONS # include "profile.c.generated.h" #endif /// functions for profiling static proftime_T prof_wait_time; /// profile_start - return the current time /// /// @return the current time proftime_T profile_start(void) FUNC_ATTR_WARN_UNUSED_RESULT { return os_hrtime(); } /// profile_end - compute the time elapsed /// /// @return the elapsed time from `tm` until now. proftime_T profile_end(proftime_T tm) FUNC_ATTR_WARN_UNUSED_RESULT { return os_hrtime() - tm; } /// profile_msg - return a string that represents the time in `tm` /// /// @warning Do not modify or free this string, not multithread-safe. /// /// @param tm The time to be represented /// @return a static string representing `tm` in the /// form "seconds.microseconds". const char *profile_msg(proftime_T tm) FUNC_ATTR_WARN_UNUSED_RESULT { static char buf[50]; snprintf(buf, sizeof(buf), "%10.6lf", (double)tm / 1000000000.0); return buf; } /// profile_setlimit - return the time `msec` into the future /// /// @param msec milliseconds, the maximum number of milliseconds is /// (2^63 / 10^6) - 1 = 9.223372e+12. /// @return if msec > 0, returns the time msec past now. Otherwise returns /// the zero time. proftime_T profile_setlimit(int64_t msec) FUNC_ATTR_WARN_UNUSED_RESULT { if (msec <= 0) { // no limit return profile_zero(); } assert(msec <= (INT64_MAX / 1000000LL) - 1); proftime_T nsec = (proftime_T) msec * 1000000ULL; return os_hrtime() + nsec; } /// profile_passed_limit - check if current time has passed `tm` /// /// @return true if the current time is past `tm`, false if not or if the /// timer was not set. bool profile_passed_limit(proftime_T tm) FUNC_ATTR_WARN_UNUSED_RESULT { if (tm == 0) { // timer was not set return false; } return profile_cmp(os_hrtime(), tm) < 0; } /// profile_zero - obtain the zero time /// /// @return the zero time proftime_T profile_zero(void) FUNC_ATTR_CONST { return 0; } /// profile_divide - divide the time `tm` by `count`. /// /// @return 0 if count <= 0, otherwise tm / count proftime_T profile_divide(proftime_T tm, int count) FUNC_ATTR_CONST { if (count <= 0) { return profile_zero(); } return (proftime_T) round((double) tm / (double) count); } /// profile_add - add the time `tm2` to `tm1` /// /// @return `tm1` + `tm2` proftime_T profile_add(proftime_T tm1, proftime_T tm2) FUNC_ATTR_CONST { return tm1 + tm2; } /// profile_sub - subtract `tm2` from `tm1` /// /// @return `tm1` - `tm2` proftime_T profile_sub(proftime_T tm1, proftime_T tm2) FUNC_ATTR_CONST { return tm1 - tm2; } /// profile_self - add the `self` time from the total time and the /// children's time /// /// @return if `total` <= `children`, then self, otherwise `self` + `total` - /// `children` proftime_T profile_self(proftime_T self, proftime_T total, proftime_T children) FUNC_ATTR_CONST { // check that the result won't be negative, which can happen with // recursive calls. if (total <= children) { return self; } // add the total time to self and subtract the children's time from self return profile_sub(profile_add(self, total), children); } /// profile_get_wait - get the current waittime /// /// @return the current waittime proftime_T profile_get_wait(void) FUNC_ATTR_PURE { return prof_wait_time; } /// profile_set_wait - set the current waittime void profile_set_wait(proftime_T wait) { prof_wait_time = wait; } /// profile_sub_wait - subtract the passed waittime since `tm` /// /// @return `tma` - (waittime - `tm`) proftime_T profile_sub_wait(proftime_T tm, proftime_T tma) FUNC_ATTR_PURE { proftime_T tm3 = profile_sub(profile_get_wait(), tm); return profile_sub(tma, tm3); } /// profile_equal - check if `tm1` is equal to `tm2` /// /// @return true if `tm1` == `tm2` bool profile_equal(proftime_T tm1, proftime_T tm2) FUNC_ATTR_CONST { return tm1 == tm2; } /// sgn64 - calculates the sign of a 64-bit integer /// /// @return -1, 0, or +1 static inline int sgn64(int64_t x) FUNC_ATTR_CONST { return (int) ((x > 0) - (x < 0)); } /// profile_cmp - compare profiling times /// /// Only guarantees correct results if both input times are not more than /// 150 years apart. /// /// @return <0, 0 or >0 if `tm2` < `tm1`, `tm2` == `tm1` or `tm2` > `tm1` 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); }