RDB/AOF loading times logged with millisecond precision

[redis.git] / src / db.c

diff --git a/src/db.c b/src/db.c
index afca3cddd12eb2b9a3f5d3df6aa684c389b16d97..669fba13e8e7d7f6b12494920ef965ec735f372a 100644 (file)
--- a/src/db.c
+++ b/src/db.c
@@ -6,35 +6,93 @@
  * C-level DB API
  *----------------------------------------------------------------------------*/
 
  * C-level DB API
  *----------------------------------------------------------------------------*/
 

+/* Important notes on lookup and disk store.
+ *
+ * When disk store is enabled on lookup we can have different cases.
+ *
+ * a) The key is in memory:
+ *    - If the key is not in IO_SAVEINPROG state we can access it.
+ *      As if it's just IO_SAVE this means we have the key in the IO queue
+ *      but can't be accessed by the IO thread (it requires to be
+ *      translated into an IO Job by the cache cron function.)
+ *    - If the key is in IO_SAVEINPROG we can't touch the key and have
+ *      to blocking wait completion of operations.
+ * b) The key is not in memory:
+ *    - If it's marked as non existing on disk as well (negative cache)
+ *      we don't need to perform the disk access.
+ *    - if the key MAY EXIST, but is not in memory, and it is marked as IO_SAVE
+ *      then the key can only be a deleted one. As IO_SAVE keys are never
+ *      evicted (dirty state), so the only possibility is that key was deleted.
+ *    - if the key MAY EXIST we need to blocking load it.
+ *      We check that the key is not in IO_SAVEINPROG state before accessing
+ *      the disk object. If it is in this state, we wait.
+ */
+
+void lookupWaitBusyKey(redisDb *db, robj *key) {
+    /* FIXME: wait just for this key, not everything */
+    waitEmptyIOJobsQueue();
+    processAllPendingIOJobs();
+    redisAssert((cacheScheduleIOGetFlags(db,key) & REDIS_IO_SAVEINPROG) == 0);
+}
+

 robj *lookupKey(redisDb *db, robj *key) {
     dictEntry *de = dictFind(db->dict,key->ptr);
     if (de) {
         robj *val = dictGetEntryVal(de);
 
 robj *lookupKey(redisDb *db, robj *key) {
     dictEntry *de = dictFind(db->dict,key->ptr);
     if (de) {
         robj *val = dictGetEntryVal(de);
 

-        if (server.vm_enabled) {
-            if (val->storage == REDIS_VM_MEMORY ||
-                val->storage == REDIS_VM_SWAPPING)
-            {
-                /* If we were swapping the object out, cancel the operation */
-                if (val->storage == REDIS_VM_SWAPPING)
-                    vmCancelThreadedIOJob(val);
-                /* Update the access time for the aging algorithm. */
-                val->lru = server.lruclock;
-            } else {
-                int notify = (val->storage == REDIS_VM_LOADING);
+        /* Update the access time for the aging algorithm.
+         * Don't do it if we have a saving child, as this will trigger
+         * a copy on write madness. */
+        if (server.bgsavechildpid == -1 && server.bgrewritechildpid == -1)
+            val->lru = server.lruclock;
+
+        if (server.ds_enabled &&
+            cacheScheduleIOGetFlags(db,key) & REDIS_IO_SAVEINPROG)
+        {
+            /* Need to wait for the key to get unbusy */
+            redisLog(REDIS_DEBUG,"Lookup found a key in SAVEINPROG state. Waiting. (Key was in the cache)");
+            lookupWaitBusyKey(db,key);
+        }
+        server.stat_keyspace_hits++;
+        return val;
+    } else {
+        time_t expire;
+        robj *val;
+
+        /* Key not found in the in memory hash table, but if disk store is
+         * enabled we may have this key on disk. If so load it in memory
+         * in a blocking way. */
+        if (server.ds_enabled && cacheKeyMayExist(db,key)) {
+            long flags = cacheScheduleIOGetFlags(db,key);
+
+            /* They key is not in cache, but it has a SAVE op in queue?
+             * The only possibility is that the key was deleted, since
+             * dirty keys are not evicted. */
+            if (flags & REDIS_IO_SAVE) {
+                server.stat_keyspace_misses++;
+                return NULL;
+            }

 
 

-                /* Our value was swapped on disk. Bring it at home. */
-                redisAssert(val->type == REDIS_VMPOINTER);
-                val = vmLoadObject(val);
-                dictGetEntryVal(de) = val;
+            /* At this point we need to blocking load the key in memory.
+             * The first thing we do is waiting here if the key is busy. */
+            if (flags & REDIS_IO_SAVEINPROG) {
+                redisLog(REDIS_DEBUG,"Lookup found a key in SAVEINPROG state. Waiting (while force loading).");
+                lookupWaitBusyKey(db,key);
+            }

 
 

-                /* Clients blocked by the VM subsystem may be waiting for
-                 * this key... */
-                if (notify) handleClientsBlockedOnSwappedKey(db,key);
+            redisLog(REDIS_DEBUG,"Force loading key %s via lookup", key->ptr);
+            val = dsGet(db,key,&expire);
+            if (val) {
+                int retval = dbAdd(db,key,val);
+                redisAssert(retval == REDIS_OK);
+                if (expire != -1) setExpire(db,key,expire);
+                server.stat_keyspace_hits++;
+                return val;
+            } else {
+                cacheSetKeyDoesNotExist(db,key);

             }
         }
             }
         }

-        return val;
-    } else {
+        server.stat_keyspace_misses++;

         return NULL;
     }
 }
         return NULL;
     }
 }


@@ -72,6 +130,7 @@ int dbAdd(redisDb *db, robj *key, robj *val) {
     } else {
         sds copy = sdsdup(key->ptr);
         dictAdd(db->dict, copy, val);
     } else {
         sds copy = sdsdup(key->ptr);
         dictAdd(db->dict, copy, val);

+        if (server.ds_enabled) cacheSetKeyMayExist(db,key);

         return REDIS_OK;
     }
 }
         return REDIS_OK;
     }
 }


@@ -81,14 +140,19 @@ int dbAdd(redisDb *db, robj *key, robj *val) {
  *
  * On update (key already existed) 0 is returned. Otherwise 1. */
 int dbReplace(redisDb *db, robj *key, robj *val) {
  *
  * On update (key already existed) 0 is returned. Otherwise 1. */
 int dbReplace(redisDb *db, robj *key, robj *val) {

-    if (dictFind(db->dict,key->ptr) == NULL) {
+    robj *oldval;
+    int retval;
+
+    if ((oldval = dictFetchValue(db->dict,key->ptr)) == NULL) {

         sds copy = sdsdup(key->ptr);
         dictAdd(db->dict, copy, val);
         sds copy = sdsdup(key->ptr);
         dictAdd(db->dict, copy, val);

-        return 1;
+        retval = 1;

     } else {
         dictReplace(db->dict, key->ptr, val);
     } else {
         dictReplace(db->dict, key->ptr, val);

-        return 0;
+        retval = 0;

     }
     }

+    if (server.ds_enabled) cacheSetKeyMayExist(db,key);
+    return retval;

 }
 
 int dbExists(redisDb *db, robj *key) {
 }
 
 int dbExists(redisDb *db, robj *key) {


@@ -123,18 +187,22 @@ robj *dbRandomKey(redisDb *db) {
 
 /* Delete a key, value, and associated expiration entry if any, from the DB */
 int dbDelete(redisDb *db, robj *key) {
 
 /* Delete a key, value, and associated expiration entry if any, from the DB */
 int dbDelete(redisDb *db, robj *key) {

-    /* If VM is enabled make sure to awake waiting clients for this key:
-     * deleting the key will kill the I/O thread bringing the key from swap
-     * to memory, so the client will never be notified and unblocked if we
-     * don't do it now. */
-    if (server.vm_enabled) handleClientsBlockedOnSwappedKey(db,key);
+    /* If diskstore is enabled make sure to awake waiting clients for this key
+     * as it is not really useful to wait for a key already deleted to be
+     * loaded from disk. */
+    if (server.ds_enabled) {
+        handleClientsBlockedOnSwappedKey(db,key);
+        cacheSetKeyDoesNotExist(db,key);
+    }
+

     /* Deleting an entry from the expires dict will not free the sds of
      * the key, because it is shared with the main dictionary. */
     if (dictSize(db->expires) > 0) dictDelete(db->expires,key->ptr);
     return dictDelete(db->dict,key->ptr) == DICT_OK;
 }
 
     /* Deleting an entry from the expires dict will not free the sds of
      * the key, because it is shared with the main dictionary. */
     if (dictSize(db->expires) > 0) dictDelete(db->expires,key->ptr);
     return dictDelete(db->dict,key->ptr) == DICT_OK;
 }
 

-/* Empty the whole database */
+/* Empty the whole database.
+ * If diskstore is enabled this function will just flush the in-memory cache. */

 long long emptyDb() {
     int j;
     long long removed = 0;
 long long emptyDb() {
     int j;
     long long removed = 0;


@@ -143,6 +211,7 @@ long long emptyDb() {
         removed += dictSize(server.db[j].dict);
         dictEmpty(server.db[j].dict);
         dictEmpty(server.db[j].expires);
         removed += dictSize(server.db[j].dict);
         dictEmpty(server.db[j].dict);
         dictEmpty(server.db[j].expires);

+        if (server.ds_enabled) dictEmpty(server.db[j].io_negcache);

     }
     return removed;
 }
     }
     return removed;
 }


@@ -154,27 +223,50 @@ int selectDb(redisClient *c, int id) {
     return REDIS_OK;
 }
 
     return REDIS_OK;
 }
 

+/*-----------------------------------------------------------------------------
+ * Hooks for key space changes.
+ *
+ * Every time a key in the database is modified the function
+ * signalModifiedKey() is called.
+ *
+ * Every time a DB is flushed the function signalFlushDb() is called.
+ *----------------------------------------------------------------------------*/
+
+void signalModifiedKey(redisDb *db, robj *key) {
+    touchWatchedKey(db,key);
+    if (server.ds_enabled)
+        cacheScheduleIO(db,key,REDIS_IO_SAVE);
+}
+
+void signalFlushedDb(int dbid) {
+    touchWatchedKeysOnFlush(dbid);
+}
+

 /*-----------------------------------------------------------------------------
  * Type agnostic commands operating on the key space
  *----------------------------------------------------------------------------*/
 
 void flushdbCommand(redisClient *c) {
     server.dirty += dictSize(c->db->dict);
 /*-----------------------------------------------------------------------------
  * Type agnostic commands operating on the key space
  *----------------------------------------------------------------------------*/
 
 void flushdbCommand(redisClient *c) {
     server.dirty += dictSize(c->db->dict);

-    touchWatchedKeysOnFlush(c->db->id);
+    signalFlushedDb(c->db->id);

     dictEmpty(c->db->dict);
     dictEmpty(c->db->expires);
     dictEmpty(c->db->dict);
     dictEmpty(c->db->expires);

+    if (server.ds_enabled) dsFlushDb(c->db->id);

     addReply(c,shared.ok);
 }
 
 void flushallCommand(redisClient *c) {
     addReply(c,shared.ok);
 }
 
 void flushallCommand(redisClient *c) {

-    touchWatchedKeysOnFlush(-1);
+    signalFlushedDb(-1);

     server.dirty += emptyDb();
     addReply(c,shared.ok);
     if (server.bgsavechildpid != -1) {
         kill(server.bgsavechildpid,SIGKILL);
         rdbRemoveTempFile(server.bgsavechildpid);
     }
     server.dirty += emptyDb();
     addReply(c,shared.ok);
     if (server.bgsavechildpid != -1) {
         kill(server.bgsavechildpid,SIGKILL);
         rdbRemoveTempFile(server.bgsavechildpid);
     }

-    rdbSave(server.dbfilename);
+    if (server.ds_enabled)
+        dsFlushDb(-1);
+    else
+        rdbSave(server.dbfilename);

     server.dirty++;
 }
 
     server.dirty++;
 }
 


@@ -182,10 +274,22 @@ void delCommand(redisClient *c) {
     int deleted = 0, j;
 
     for (j = 1; j < c->argc; j++) {
     int deleted = 0, j;
 
     for (j = 1; j < c->argc; j++) {

+        if (server.ds_enabled) {
+            lookupKeyRead(c->db,c->argv[j]);
+            /* FIXME: this can be optimized a lot, no real need to load
+             * a possibly huge value. */
+        }

         if (dbDelete(c->db,c->argv[j])) {
         if (dbDelete(c->db,c->argv[j])) {

-            touchWatchedKey(c->db,c->argv[j]);
+            signalModifiedKey(c->db,c->argv[j]);

             server.dirty++;
             deleted++;
             server.dirty++;
             deleted++;

+        } else if (server.ds_enabled) {
+            if (cacheKeyMayExist(c->db,c->argv[j]) &&
+                dsExists(c->db,c->argv[j]))
+            {
+                cacheScheduleIO(c->db,c->argv[j],REDIS_IO_SAVE);
+                deleted = 1;
+            }

         }
     }
     addReplyLongLong(c,deleted);
         }
     }
     addReplyLongLong(c,deleted);


@@ -204,7 +308,7 @@ void selectCommand(redisClient *c) {
     int id = atoi(c->argv[1]->ptr);
 
     if (selectDb(c,id) == REDIS_ERR) {
     int id = atoi(c->argv[1]->ptr);
 
     if (selectDb(c,id) == REDIS_ERR) {

-        addReplySds(c,sdsnew("-ERR invalid DB index\r\n"));
+        addReplyError(c,"invalid DB index");

     } else {
         addReply(c,shared.ok);
     }
     } else {
         addReply(c,shared.ok);
     }


@@ -228,11 +332,9 @@ void keysCommand(redisClient *c) {
     sds pattern = c->argv[1]->ptr;
     int plen = sdslen(pattern), allkeys;
     unsigned long numkeys = 0;
     sds pattern = c->argv[1]->ptr;
     int plen = sdslen(pattern), allkeys;
     unsigned long numkeys = 0;

-    robj *lenobj = createObject(REDIS_STRING,NULL);
+    void *replylen = addDeferredMultiBulkLength(c);

 
     di = dictGetIterator(c->db->dict);
 
     di = dictGetIterator(c->db->dict);

-    addReply(c,lenobj);
-    decrRefCount(lenobj);

     allkeys = (pattern[0] == '*' && pattern[1] == '\0');
     while((de = dictNext(di)) != NULL) {
         sds key = dictGetEntryKey(de);
     allkeys = (pattern[0] == '*' && pattern[1] == '\0');
     while((de = dictNext(di)) != NULL) {
         sds key = dictGetEntryKey(de);


@@ -248,17 +350,15 @@ void keysCommand(redisClient *c) {
         }
     }
     dictReleaseIterator(di);
         }
     }
     dictReleaseIterator(di);

-    lenobj->ptr = sdscatprintf(sdsempty(),"*%lu\r\n",numkeys);
+    setDeferredMultiBulkLength(c,replylen,numkeys);

 }
 
 void dbsizeCommand(redisClient *c) {
 }
 
 void dbsizeCommand(redisClient *c) {

-    addReplySds(c,
-        sdscatprintf(sdsempty(),":%lu\r\n",dictSize(c->db->dict)));
+    addReplyLongLong(c,dictSize(c->db->dict));

 }
 
 void lastsaveCommand(redisClient *c) {
 }
 
 void lastsaveCommand(redisClient *c) {

-    addReplySds(c,
-        sdscatprintf(sdsempty(),":%lu\r\n",server.lastsave));
+    addReplyLongLong(c,server.lastsave);

 }
 
 void typeCommand(redisClient *c) {
 }
 
 void typeCommand(redisClient *c) {


@@ -267,50 +367,24 @@ void typeCommand(redisClient *c) {
 
     o = lookupKeyRead(c->db,c->argv[1]);
     if (o == NULL) {
 
     o = lookupKeyRead(c->db,c->argv[1]);
     if (o == NULL) {

-        type = "+none";
+        type = "none";

     } else {
         switch(o->type) {
     } else {
         switch(o->type) {

-        case REDIS_STRING: type = "+string"; break;
-        case REDIS_LIST: type = "+list"; break;
-        case REDIS_SET: type = "+set"; break;
-        case REDIS_ZSET: type = "+zset"; break;
-        case REDIS_HASH: type = "+hash"; break;
-        default: type = "+unknown"; break;
+        case REDIS_STRING: type = "string"; break;
+        case REDIS_LIST: type = "list"; break;
+        case REDIS_SET: type = "set"; break;
+        case REDIS_ZSET: type = "zset"; break;
+        case REDIS_HASH: type = "hash"; break;
+        default: type = "unknown"; break;

         }
     }
         }
     }

-    addReplySds(c,sdsnew(type));
-    addReply(c,shared.crlf);
-}
-
-void saveCommand(redisClient *c) {
-    if (server.bgsavechildpid != -1) {
-        addReplySds(c,sdsnew("-ERR background save in progress\r\n"));
-        return;
-    }
-    if (rdbSave(server.dbfilename) == REDIS_OK) {
-        addReply(c,shared.ok);
-    } else {
-        addReply(c,shared.err);
-    }
-}
-
-void bgsaveCommand(redisClient *c) {
-    if (server.bgsavechildpid != -1) {
-        addReplySds(c,sdsnew("-ERR background save already in progress\r\n"));
-        return;
-    }
-    if (rdbSaveBackground(server.dbfilename) == REDIS_OK) {
-        char *status = "+Background saving started\r\n";
-        addReplySds(c,sdsnew(status));
-    } else {
-        addReply(c,shared.err);
-    }
+    addReplyStatus(c,type);

 }
 
 void shutdownCommand(redisClient *c) {
     if (prepareForShutdown() == REDIS_OK)
         exit(0);
 }
 
 void shutdownCommand(redisClient *c) {
     if (prepareForShutdown() == REDIS_OK)
         exit(0);

-    addReplySds(c, sdsnew("-ERR Errors trying to SHUTDOWN. Check logs.\r\n"));
+    addReplyError(c,"Errors trying to SHUTDOWN. Check logs.");

 }
 
 void renameGenericCommand(redisClient *c, int nx) {
 }
 
 void renameGenericCommand(redisClient *c, int nx) {


@@ -335,8 +409,8 @@ void renameGenericCommand(redisClient *c, int nx) {
         dbReplace(c->db,c->argv[2],o);
     }
     dbDelete(c->db,c->argv[1]);
         dbReplace(c->db,c->argv[2],o);
     }
     dbDelete(c->db,c->argv[1]);

-    touchWatchedKey(c->db,c->argv[1]);
-    touchWatchedKey(c->db,c->argv[2]);
+    signalModifiedKey(c->db,c->argv[1]);
+    signalModifiedKey(c->db,c->argv[2]);

     server.dirty++;
     addReply(c,nx ? shared.cone : shared.ok);
 }
     server.dirty++;
     addReply(c,nx ? shared.cone : shared.ok);
 }


@@ -435,16 +509,14 @@ time_t getExpire(redisDb *db, robj *key) {
  * will be consistent even if we allow write operations against expiring
  * keys. */
 void propagateExpire(redisDb *db, robj *key) {
  * will be consistent even if we allow write operations against expiring
  * keys. */
 void propagateExpire(redisDb *db, robj *key) {

-    struct redisCommand *cmd;

     robj *argv[2];
 
     robj *argv[2];
 

-    cmd = lookupCommand("del");

     argv[0] = createStringObject("DEL",3);
     argv[1] = key;
     incrRefCount(key);
 
     if (server.appendonly)
     argv[0] = createStringObject("DEL",3);
     argv[1] = key;
     incrRefCount(key);
 
     if (server.appendonly)

-        feedAppendOnlyFile(cmd,db->id,argv,2);
+        feedAppendOnlyFile(server.delCommand,db->id,argv,2);

     if (listLength(server.slaves))
         replicationFeedSlaves(server.slaves,db->id,argv,2);
 
     if (listLength(server.slaves))
         replicationFeedSlaves(server.slaves,db->id,argv,2);
 


@@ -455,6 +527,8 @@ void propagateExpire(redisDb *db, robj *key) {
 int expireIfNeeded(redisDb *db, robj *key) {
     time_t when = getExpire(db,key);
 
 int expireIfNeeded(redisDb *db, robj *key) {
     time_t when = getExpire(db,key);
 

+    if (when < 0) return 0; /* No expire for this key */
+

     /* If we are running in the context of a slave, return ASAP:
      * the slave key expiration is controlled by the master that will
      * send us synthesized DEL operations for expired keys.
     /* If we are running in the context of a slave, return ASAP:
      * the slave key expiration is controlled by the master that will
      * send us synthesized DEL operations for expired keys.


@@ -466,14 +540,11 @@ int expireIfNeeded(redisDb *db, robj *key) {
         return time(NULL) > when;
     }
 
         return time(NULL) > when;
     }
 

-    if (when < 0) return 0;
-

     /* Return when this key has not expired */
     if (time(NULL) <= when) return 0;
 
     /* Delete the key */
     server.stat_expiredkeys++;
     /* Return when this key has not expired */
     if (time(NULL) <= when) return 0;
 
     /* Delete the key */
     server.stat_expiredkeys++;

-    server.dirty++;

     propagateExpire(db,key);
     return dbDelete(db,key);
 }
     propagateExpire(db,key);
     return dbDelete(db,key);
 }


@@ -484,7 +555,7 @@ int expireIfNeeded(redisDb *db, robj *key) {
 
 void expireGenericCommand(redisClient *c, robj *key, robj *param, long offset) {
     dictEntry *de;
 
 void expireGenericCommand(redisClient *c, robj *key, robj *param, long offset) {
     dictEntry *de;

-    time_t seconds;
+    long seconds;

 
     if (getLongFromObjectOrReply(c, param, &seconds, NULL) != REDIS_OK) return;
 
 
     if (getLongFromObjectOrReply(c, param, &seconds, NULL) != REDIS_OK) return;
 


@@ -498,13 +569,13 @@ void expireGenericCommand(redisClient *c, robj *key, robj *param, long offset) {
     if (seconds <= 0) {
         if (dbDelete(c->db,key)) server.dirty++;
         addReply(c, shared.cone);
     if (seconds <= 0) {
         if (dbDelete(c->db,key)) server.dirty++;
         addReply(c, shared.cone);

-        touchWatchedKey(c->db,key);
+        signalModifiedKey(c->db,key);

         return;
     } else {
         time_t when = time(NULL)+seconds;
         setExpire(c->db,key,when);
         addReply(c,shared.cone);
         return;
     } else {
         time_t when = time(NULL)+seconds;
         setExpire(c->db,key,when);
         addReply(c,shared.cone);

-        touchWatchedKey(c->db,key);
+        signalModifiedKey(c->db,key);

         server.dirty++;
         return;
     }
         server.dirty++;
         return;
     }