From 3cd8baf61610416aab45e0bcedcaab9beae80184 Mon Sep 17 00:00:00 2001 From: filipe oliveira Date: Wed, 20 Apr 2022 12:00:30 +0100 Subject: [PATCH] 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 --- src/monotonic.c | 10 +++++++++ src/monotonic.h | 11 +++++++++- src/server.c | 56 ++++++++++++++++++++++++++++++++----------------- 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__