From 51bd9da1fdf3d4bb0d4f81234f33003c16db9a51 Mon Sep 17 00:00:00 2001 From: antirez Date: Thu, 13 Feb 2014 15:09:41 +0100 Subject: [PATCH] Update cached time in rdbLoad() callback. server.unixtime and server.mstime are cached less precise timestamps that we use every time we don't need an accurate time representation and a syscall would be too slow for the number of calls we require. Such an example is the initialization and update process of the last interaction time with the client, that is used for timeouts. However rdbLoad() can take some time to load the DB, but at the same time it did not updated the time during DB loading. This resulted in the bug described in issue #1535, where in the replication process the slave loads the DB, creates the redisClient representation of its master, but the timestamp is so old that the master, under certain conditions, is sensed as already "timed out". Thanks to @yoav-steinberg and Redis Labs Inc for the bug report and analysis. --- src/rdb.c | 4 ++++ src/redis.c | 20 ++++++++++++-------- src/redis.h | 1 + 3 files changed, 17 insertions(+), 8 deletions(-) diff --git a/src/rdb.c b/src/rdb.c index 60dd7113e..1a472dbc7 100644 --- a/src/rdb.c +++ b/src/rdb.c @@ -1065,6 +1065,10 @@ void rdbLoadProgressCallback(rio *r, const void *buf, size_t len) { if (server.loading_process_events_interval_bytes && (r->processed_bytes + len)/server.loading_process_events_interval_bytes > r->processed_bytes/server.loading_process_events_interval_bytes) { + /* The DB can take some non trivial amount of time to load. Update + * our cached time since it is used to create and update the last + * interaction time with clients and for other important things. */ + updateCachedTime(); if (server.masterhost && server.repl_state == REDIS_REPL_TRANSFER) replicationSendNewlineToMaster(); loadingProgress(r->processed_bytes); diff --git a/src/redis.c b/src/redis.c index 1b61946e7..e50dc6072 100644 --- a/src/redis.c +++ b/src/redis.c @@ -1001,6 +1001,15 @@ 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) */ +void updateCachedTime(void) { + server.unixtime = time(NULL); + server.mstime = mstime(); +} + /* This is our timer interrupt, called server.hz times per second. * Here is where we do a number of things that need to be done asynchronously. * For instance: @@ -1030,12 +1039,8 @@ int serverCron(struct aeEventLoop *eventLoop, long long id, void *clientData) { * handler if we don't return here fast enough. */ if (server.watchdog_period) watchdogScheduleSignal(server.watchdog_period); - /* 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 faster than calling time(NULL) */ - server.unixtime = time(NULL); - server.mstime = mstime(); + /* Update the time cache. */ + updateCachedTime(); run_with_period(100) trackOperationsPerSecond(); @@ -1676,12 +1681,11 @@ void initServer() { server.ops_sec_idx = 0; server.ops_sec_last_sample_time = mstime(); server.ops_sec_last_sample_ops = 0; - server.unixtime = time(NULL); - server.mstime = mstime(); server.lastbgsave_status = REDIS_OK; server.aof_last_write_status = REDIS_OK; server.aof_last_write_errno = 0; server.repl_good_slaves_count = 0; + updateCachedTime(); /* Create the serverCron() time event, that's our main way to process * background operations. */ diff --git a/src/redis.h b/src/redis.h index d7a9eea0a..618dfac43 100644 --- a/src/redis.h +++ b/src/redis.h @@ -1154,6 +1154,7 @@ void populateCommandTable(void); void resetCommandTableStats(void); void adjustOpenFilesLimit(void); void closeListeningSockets(int unlink_unix_socket); +void updateCachedTime(); /* Set data type */ robj *setTypeCreate(robj *value);