Commit 7fddebc2 authored by filipe oliveira's avatar filipe oliveira Committed by Oran Agra
Browse files

Optimization: Use either monotonic or wall-clock to measure command execution...


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: default avatarOran Agra <oran@redislabs.com>
(cherry picked from commit 3cd8baf6)
parent 28d20b8f
...@@ -168,3 +168,13 @@ const char * monotonicInit() { ...@@ -168,3 +168,13 @@ const char * monotonicInit() {
return monotonic_info_string; 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;
}
...@@ -24,13 +24,22 @@ typedef uint64_t monotime; ...@@ -24,13 +24,22 @@ typedef uint64_t monotime;
/* Retrieve counter of micro-seconds relative to an arbitrary point in time. */ /* Retrieve counter of micro-seconds relative to an arbitrary point in time. */
extern monotime (*getMonotonicUs)(void); 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 /* 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. * needs to be called once, it may be called additional times without impact.
* Returns a printable string indicating the type of clock initialized. * Returns a printable string indicating the type of clock initialized.
* (The returned string is static and doesn't need to be freed.) */ * (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: /* Functions to measure elapsed time. Example:
* monotime myTimer; * monotime myTimer;
......
...@@ -1903,18 +1903,8 @@ void databasesCron(void) { ...@@ -1903,18 +1903,8 @@ void databasesCron(void) {
} }
} }
/* We take a cached value of the unix time in the global state because with static inline void updateCachedTimeWithUs(int update_daylight_info, const long long ustime) {
* virtual memory and aging there is to store the current time in objects at server.ustime = ustime;
* 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();
server.mstime = server.ustime / 1000; server.mstime = server.ustime / 1000;
time_t unixtime = server.mstime / 1000; time_t unixtime = server.mstime / 1000;
atomicSet(server.unixtime, unixtime); atomicSet(server.unixtime, unixtime);
...@@ -1932,6 +1922,21 @@ void updateCachedTime(int update_daylight_info) { ...@@ -1932,6 +1922,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) { void checkChildrenDone(void) {
int statloc = 0; int statloc = 0;
pid_t pid; pid_t pid;
...@@ -3709,7 +3714,6 @@ void slowlogPushCurrentCommand(client *c, struct redisCommand *cmd, ustime_t dur ...@@ -3709,7 +3714,6 @@ void slowlogPushCurrentCommand(client *c, struct redisCommand *cmd, ustime_t dur
*/ */
void call(client *c, int flags) { void call(client *c, int flags) {
long long dirty; long long dirty;
monotime call_timer;
int client_old_flags = c->flags; int client_old_flags = c->flags;
struct redisCommand *real_cmd = c->cmd; struct redisCommand *real_cmd = c->cmd;
static long long prev_err_count; static long long prev_err_count;
...@@ -3724,22 +3728,34 @@ void call(client *c, int flags) { ...@@ -3724,22 +3728,34 @@ void call(client *c, int flags) {
dirty = server.dirty; dirty = server.dirty;
prev_err_count = server.stat_total_error_replies; prev_err_count = server.stat_total_error_replies;
const long long call_timer = ustime();
/* Update cache time, in case we have nested calls we want to /* Update cache time, in case we have nested calls we want to
* update only on the first call*/ * update only on the first call*/
if (server.fixed_time_expire++ == 0) { 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); 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; c->duration = duration;
dirty = server.dirty-dirty; dirty = server.dirty-dirty;
if (dirty < 0) dirty = 0; if (dirty < 0) dirty = 0;
server.in_nested_call--;
/* Update failed command calls if required. /* Update failed command calls if required.
* We leverage a static variable (prev_err_count) to retain * We leverage a static variable (prev_err_count) to retain
* the counter across nested function calls and avoid logging * the counter across nested function calls and avoid logging
...@@ -4708,6 +4724,7 @@ sds genRedisInfoString(const char *section) { ...@@ -4708,6 +4724,7 @@ sds genRedisInfoString(const char *section) {
"redis_mode:%s\r\n" "redis_mode:%s\r\n"
"os:%s %s %s\r\n" "os:%s %s %s\r\n"
"arch_bits:%i\r\n" "arch_bits:%i\r\n"
"monotonic_clock:%s\r\n"
"multiplexing_api:%s\r\n" "multiplexing_api:%s\r\n"
"atomicvar_api:%s\r\n" "atomicvar_api:%s\r\n"
"gcc_version:%i.%i.%i\r\n" "gcc_version:%i.%i.%i\r\n"
...@@ -4731,6 +4748,7 @@ sds genRedisInfoString(const char *section) { ...@@ -4731,6 +4748,7 @@ sds genRedisInfoString(const char *section) {
mode, mode,
name.sysname, name.release, name.machine, name.sysname, name.release, name.machine,
server.arch_bits, server.arch_bits,
monotonicInfoString(),
aeGetApiName(), aeGetApiName(),
REDIS_ATOMIC_API, REDIS_ATOMIC_API,
#ifdef __GNUC__ #ifdef __GNUC__
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment