diff --git a/src/db.c b/src/db.c index 535d493954..1b9d54c304 100644 --- a/src/db.c +++ b/src/db.c @@ -101,6 +101,7 @@ void updateLFU(robj *val) { robj *lookupKey(serverDb *db, robj *key, int flags) { int dict_index = getKVStoreIndexForKey(key->ptr); robj *val = dbFindWithDictIndex(db, key->ptr, dict_index); + bool is_expired = false; if (val) { /* Forcing deletion of expired keys on a replica makes the replica * inconsistent with the primary. We forbid it on readonly replicas, but @@ -117,6 +118,7 @@ robj *lookupKey(serverDb *db, robj *key, int flags) { if (expireIfNeededWithDictIndex(db, key, val, expire_flags, dict_index) != KEY_VALID) { /* The key is no longer valid. */ val = NULL; + is_expired = true; } } @@ -141,7 +143,12 @@ robj *lookupKey(serverDb *db, robj *key, int flags) { /* TODO: Use separate hits stats for WRITE */ } else { if (!(flags & (LOOKUP_NONOTIFY | LOOKUP_WRITE))) notifyKeyspaceEvent(NOTIFY_KEY_MISS, "keymiss", key, db->id); - if (!(flags & (LOOKUP_NOSTATS | LOOKUP_WRITE))) server.stat_keyspace_misses++; + if (!(flags & (LOOKUP_NOSTATS | LOOKUP_WRITE))) { + server.stat_keyspace_misses++; + if (is_expired) { + server.stat_keyspace_expiration_misses++; + } + } /* TODO: Use separate misses stats and notify event for WRITE */ } @@ -1822,13 +1829,16 @@ long long getExpire(serverDb *db, robj *key) { return getExpireWithDictIndex(db, key, dict_index); } -void deleteExpiredKeyAndPropagateWithDictIndex(serverDb *db, robj *keyobj, int dict_index) { +void deleteExpiredKeyAndPropagateWithDictIndex(serverDb *db, robj *keyobj, int dict_index, bool lazy) { mstime_t expire_latency; latencyStartMonitor(expire_latency); dbGenericDeleteWithDictIndex(db, keyobj, server.lazyfree_lazy_expire, DB_FLAG_KEY_EXPIRED, dict_index); latencyEndMonitor(expire_latency); latencyAddSampleIfNeeded("expire-del", expire_latency); notifyKeyspaceEvent(NOTIFY_EXPIRED, "expired", keyobj, db->id); + if (lazy) { + notifyKeyspaceEvent(NOTIFY_LAZY_EXPIRED, "lazyexpired", keyobj, db->id); + } signalModifiedKey(NULL, db, keyobj); propagateDeletion(db, keyobj, server.lazyfree_lazy_expire); server.stat_expiredkeys++; @@ -1837,7 +1847,7 @@ void deleteExpiredKeyAndPropagateWithDictIndex(serverDb *db, robj *keyobj, int d /* Delete the specified expired key and propagate expire. */ void deleteExpiredKeyAndPropagate(serverDb *db, robj *keyobj) { int dict_index = getKVStoreIndexForKey(keyobj->ptr); - deleteExpiredKeyAndPropagateWithDictIndex(db, keyobj, dict_index); + deleteExpiredKeyAndPropagateWithDictIndex(db, keyobj, dict_index, false); } /* Delete the specified expired key from overwriting and propagate the DEL or UNLINK. */ @@ -1998,7 +2008,7 @@ static keyStatus expireIfNeededWithDictIndex(serverDb *db, robj *key, robj *val, key = createStringObject(key->ptr, sdslen(key->ptr)); } /* Delete the key */ - deleteExpiredKeyAndPropagateWithDictIndex(db, key, dict_index); + deleteExpiredKeyAndPropagateWithDictIndex(db, key, dict_index, true); if (static_key) { decrRefCount(key); } diff --git a/src/notify.c b/src/notify.c index d10d7dd9b9..570207fcc8 100644 --- a/src/notify.c +++ b/src/notify.c @@ -59,6 +59,7 @@ int keyspaceEventsStringToFlags(char *classes) { case 'm': flags |= NOTIFY_KEY_MISS; break; case 'd': flags |= NOTIFY_MODULE; break; case 'n': flags |= NOTIFY_NEW; break; + case 'X': flags |= NOTIFY_LAZY_EXPIRED; break; default: return -1; } } @@ -91,6 +92,7 @@ sds keyspaceEventsFlagsToString(int flags) { if (flags & NOTIFY_KEYSPACE) res = sdscatlen(res, "K", 1); if (flags & NOTIFY_KEYEVENT) res = sdscatlen(res, "E", 1); if (flags & NOTIFY_KEY_MISS) res = sdscatlen(res, "m", 1); + if (flags & NOTIFY_LAZY_EXPIRED) res = sdscatlen(res, "X", 1); return res; } diff --git a/src/server.c b/src/server.c index 144841eff9..a99d02c454 100644 --- a/src/server.c +++ b/src/server.c @@ -2649,6 +2649,7 @@ void resetServerStats(void) { server.stat_total_eviction_exceeded_time = 0; server.stat_last_eviction_exceeded_time = 0; server.stat_keyspace_misses = 0; + server.stat_keyspace_expiration_misses = 0; server.stat_keyspace_hits = 0; server.stat_active_defrag_hits = 0; server.stat_active_defrag_misses = 0; @@ -5930,6 +5931,7 @@ sds genValkeyInfoString(dict *section_dict, int all_sections, int everything) { "current_eviction_exceeded_time:%lld\r\n", current_eviction_exceeded_time / 1000, "keyspace_hits:%lld\r\n", server.stat_keyspace_hits, "keyspace_misses:%lld\r\n", server.stat_keyspace_misses, + "keyspace_expiration_misses:%lld\r\n", server.stat_keyspace_expiration_misses, "pubsub_channels:%llu\r\n", kvstoreSize(server.pubsub_channels), "pubsub_patterns:%lu\r\n", dictSize(server.pubsub_patterns), "pubsubshard_channels:%llu\r\n", kvstoreSize(server.pubsubshard_channels), diff --git a/src/server.h b/src/server.h index 29cbdc5c65..db85fdf24a 100644 --- a/src/server.h +++ b/src/server.h @@ -632,6 +632,7 @@ typedef enum { #define NOTIFY_LOADED (1 << 12) /* module only key space notification, indicate a key loaded from rdb */ #define NOTIFY_MODULE (1 << 13) /* d, module key space notification */ #define NOTIFY_NEW (1 << 14) /* n, new key notification */ +#define NOTIFY_LAZY_EXPIRED (1 << 15) /* X, lazy expire key notification */ #define NOTIFY_ALL \ (NOTIFY_GENERIC | NOTIFY_STRING | NOTIFY_LIST | NOTIFY_SET | NOTIFY_HASH | NOTIFY_ZSET | NOTIFY_EXPIRED | \ NOTIFY_EVICTED | NOTIFY_STREAM | NOTIFY_MODULE) /* A flag */ @@ -1670,6 +1671,7 @@ struct valkeyServer { monotime stat_last_eviction_exceeded_time; /* Timestamp of current eviction start, unit us */ long long stat_keyspace_hits; /* Number of successful lookups of keys */ long long stat_keyspace_misses; /* Number of failed lookups of keys */ + long long stat_keyspace_expiration_misses; /* Number of failed lookups of keys due to expiration */ long long stat_active_defrag_hits; /* number of allocations moved */ long long stat_active_defrag_misses; /* number of allocations scanned but not moved */ long long stat_active_defrag_key_hits; /* number of keys with moved allocations */ diff --git a/tests/unit/info.tcl b/tests/unit/info.tcl index 4a638cac80..159d3d88a6 100644 --- a/tests/unit/info.tcl +++ b/tests/unit/info.tcl @@ -504,6 +504,37 @@ start_server {tags {"info" "external:skip" "debug_defrag:skip"}} { $r2 close wait_for_watched_clients_count 0 } + + test {stats: keyspace misses} { + # disable active expire cycle + r debug set-active-expire 0 + + # clear stats before test + r config resetstat + + # test keyspace misses + r set k1 "v1" PX 1 + + # before expiration, k1 is in db + set before [r info stats] + + # wait for key to expire + after 100 + + # after expiration, k1 is not in db + r get k1 + r get k2 + set after [r info stats] + + # check keyspace misses + assert_equal [getInfoProperty $before keyspace_misses] 0 + assert_equal [getInfoProperty $before keyspace_expiration_misses] 0 + assert_equal [getInfoProperty $after keyspace_misses] 2 + assert_equal [getInfoProperty $after keyspace_expiration_misses] 1 + + # rollback active expire cycle + r debug set-active-expire 1 + } } } diff --git a/tests/unit/pubsub.tcl b/tests/unit/pubsub.tcl index 53b70bf552..109add6f4a 100644 --- a/tests/unit/pubsub.tcl +++ b/tests/unit/pubsub.tcl @@ -436,6 +436,48 @@ start_server {tags {"pubsub network"}} { $rd1 close } + test "Keyspace notifications: lazy expired events" { + # disable active expire + r debug set-active-expire 0 + r config set notify-keyspace-events KEX + r del foo + set rd1 [valkey_deferring_client] + assert_equal {1} [psubscribe $rd1 *] + r set foo bar PX 1 + wait_for_condition 50 100 { + [r exists foo] == 0 + } else { + fail "Key does not lazy expire?!" + } + assert_equal "pmessage * __keyspace@${db}__:foo lazyexpired" [$rd1 read] + assert_equal "pmessage * __keyevent@${db}__:lazyexpired foo" [$rd1 read] + $rd1 close + # enable active expire + r debug set-active-expire 1 + } + + test "Keyspace notifications: expired and lazy expired events" { + # disable active expire + r debug set-active-expire 0 + r config set notify-keyspace-events KEXx + r del foo + set rd1 [valkey_deferring_client] + assert_equal {1} [psubscribe $rd1 *] + r set foo bar PX 1 + wait_for_condition 50 100 { + [r exists foo] == 0 + } else { + fail "Key does not lazy expire?!" + } + assert_equal "pmessage * __keyspace@${db}__:foo expired" [$rd1 read] + assert_equal "pmessage * __keyevent@${db}__:expired foo" [$rd1 read] + assert_equal "pmessage * __keyspace@${db}__:foo lazyexpired" [$rd1 read] + assert_equal "pmessage * __keyevent@${db}__:lazyexpired foo" [$rd1 read] + $rd1 close + # enable active expire + r debug set-active-expire 1 + } + test "Keyspace notifications: evicted events" { r config set notify-keyspace-events Ee r config set maxmemory-policy allkeys-lru