Optimization: Use either monotonic or wall-clock to measure command execution time, to regain up to 4% execution time (#10502)

In #7491 (part of redis 6.2), we started using the monotonic timer instead of mstime to measure
command execution time for stats, apparently this meant sampling the clock 3 times per command
rather than two (wince we also need the wall-clock time).
In some cases this causes a significant overhead.

This PR fixes that by avoiding the use of monotonic timer, except for the cases were we know it
should be extremely fast.
This PR also adds a new INFO field called `monotonic_clock` that shows which clock redis is using.

Co-authored-by: Oran Agra <oran@redislabs.com>

3 files changed, 57 insertions, 20 deletions

diff --git a/src/monotonic.c b/src/monotonic.c
index 5bb4f03bf..608fa351c 100644
--- a/src/monotonic.c
+++ b/src/monotonic.c
@@ -168,3 +168,13 @@ const char * monotonicInit() {
 
     return monotonic_info_string;
 }
+
+const char *monotonicInfoString() {
+    return monotonic_info_string;
+}
+
+monotonic_clock_type monotonicGetType() {
+    if (getMonotonicUs == getMonotonicUs_posix)
+        return MONOTONIC_CLOCK_POSIX;
+    return MONOTONIC_CLOCK_HW;
+}
diff --git a/src/monotonic.h b/src/monotonic.h
index 4e82f9d53..32cf70638 100644
--- a/src/monotonic.h
+++ b/src/monotonic.h
@@ -24,13 +24,22 @@ typedef uint64_t monotime;
 /* Retrieve counter of micro-seconds relative to an arbitrary point in time.  */
 extern monotime (*getMonotonicUs)(void);
 
+typedef enum monotonic_clock_type {
+    MONOTONIC_CLOCK_POSIX,
+    MONOTONIC_CLOCK_HW,
+} monotonic_clock_type;
 
 /* Call once at startup to initialize the monotonic clock.  Though this only
  * needs to be called once, it may be called additional times without impact.
  * Returns a printable string indicating the type of clock initialized.
  * (The returned string is static and doesn't need to be freed.)  */
-const char * monotonicInit();
+const char *monotonicInit();
 
+/* Return a string indicating the type of monotonic clock being used. */
+const char *monotonicInfoString();
+
+/* Return the type of monotonic clock being used. */
+monotonic_clock_type monotonicGetType();
 
 /* Functions to measure elapsed time.  Example:
  *     monotime myTimer;
diff --git a/src/server.c b/src/server.c
index 0145a81f4..c2e2be8fa 100644
--- a/src/server.c
+++ b/src/server.c
@@ -1015,18 +1015,8 @@ void databasesCron(void) {
     }
 }
 
-/* We take a cached value of the unix time in the global state because with
- * virtual memory and aging there is to store the current time in objects at
- * every object access, and accuracy is not needed. To access a global var is
- * a lot faster than calling time(NULL).
- *
- * This function should be fast because it is called at every command execution
- * in call(), so it is possible to decide if to update the daylight saving
- * info or not using the 'update_daylight_info' argument. Normally we update
- * such info only when calling this function from serverCron() but not when
- * calling it from call(). */
-void updateCachedTime(int update_daylight_info) {
-    server.ustime = ustime();
+static inline void updateCachedTimeWithUs(int update_daylight_info, const long long ustime) {
+    server.ustime = ustime;
     server.mstime = server.ustime / 1000;
     time_t unixtime = server.mstime / 1000;
     atomicSet(server.unixtime, unixtime);
@@ -1044,6 +1034,21 @@ void updateCachedTime(int update_daylight_info) {
     }
 }
 
+/* We take a cached value of the unix time in the global state because with
+ * virtual memory and aging there is to store the current time in objects at
+ * every object access, and accuracy is not needed. To access a global var is
+ * a lot faster than calling time(NULL).
+ *
+ * This function should be fast because it is called at every command execution
+ * in call(), so it is possible to decide if to update the daylight saving
+ * info or not using the 'update_daylight_info' argument. Normally we update
+ * such info only when calling this function from serverCron() but not when
+ * calling it from call(). */
+void updateCachedTime(int update_daylight_info) {
+    const long long us = ustime();
+    updateCachedTimeWithUs(update_daylight_info, us);
+}
+
 void checkChildrenDone(void) {
     int statloc = 0;
     pid_t pid;
@@ -3208,7 +3213,6 @@ int incrCommandStatsOnError(struct redisCommand *cmd, int flags) {
  */
 void call(client *c, int flags) {
     long long dirty;
-    monotime call_timer;
     uint64_t client_old_flags = c->flags;
     struct redisCommand *real_cmd = c->realcmd;
 
@@ -3233,22 +3237,34 @@ void call(client *c, int flags) {
     dirty = server.dirty;
     incrCommandStatsOnError(NULL, 0);
 
+    const long long call_timer = ustime();
+
     /* Update cache time, in case we have nested calls we want to
      * update only on the first call*/
     if (server.fixed_time_expire++ == 0) {
-        updateCachedTime(0);
+        updateCachedTimeWithUs(0,call_timer);
     }
-    server.in_nested_call++;
 
-    elapsedStart(&call_timer);
+    monotime monotonic_start = 0;
+    if (monotonicGetType() == MONOTONIC_CLOCK_HW)
+        monotonic_start = getMonotonicUs();
+
+    server.in_nested_call++;
     c->cmd->proc(c);
-    const long duration = elapsedUs(call_timer);
+    server.in_nested_call--;
+
+    /* In order to avoid performance implication due to querying the clock using a system call 3 times,
+     * we use a monotonic clock, when we are sure its cost is very low, and fall back to non-monotonic call otherwise. */
+    ustime_t duration;
+    if (monotonicGetType() == MONOTONIC_CLOCK_HW)
+        duration = getMonotonicUs() - monotonic_start;
+    else
+        duration = ustime() - call_timer;
+
     c->duration = duration;
     dirty = server.dirty-dirty;
     if (dirty < 0) dirty = 0;
 
-    server.in_nested_call--;
-
     /* Update failed command calls if required. */
 
     if (!incrCommandStatsOnError(real_cmd, ERROR_COMMAND_FAILED) && c->deferred_reply_errors) {
@@ -5135,6 +5151,7 @@ sds genRedisInfoString(dict *section_dict, int all_sections, int everything) {
             "redis_mode:%s\r\n"
             "os:%s %s %s\r\n"
             "arch_bits:%i\r\n"
+            "monotonic_clock:%s\r\n"
             "multiplexing_api:%s\r\n"
             "atomicvar_api:%s\r\n"
             "gcc_version:%i.%i.%i\r\n"
@@ -5158,6 +5175,7 @@ sds genRedisInfoString(dict *section_dict, int all_sections, int everything) {
             mode,
             name.sysname, name.release, name.machine,
             server.arch_bits,
+            monotonicInfoString(),
             aeGetApiName(),
             REDIS_ATOMIC_API,
 #ifdef __GNUC__