Skip to content

Commit 6b6b2c5

Browse files
justincohCopilot
andauthored
fix: cache_item_count metric overcounting (openfga#2950)
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
1 parent 3123b03 commit 6b6b2c5

3 files changed

Lines changed: 84 additions & 3 deletions

File tree

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ Try to keep listed changes to a concise bulleted list of simple explanations of
1313
### Fixed
1414
- Fixed a few bugs. Two potential index out of bounds scenarios, and one cache of an invalid result. [#2942](https://github.com/openfga/openfga/pull/2942)
1515
- Fixed a race condition in check reducers causing non-deterministic nested handler execution due to canceled parent context. [#2947](https://github.com/openfga/openfga/pull/2947)
16+
- Fixed an issue where `cache_item_count` was incrementing on overwrites, causing the metric to steadily drift upward. [#2950](https://github.com/openfga/openfga/pull/2950)
1617

1718
## [1.11.6] - 2026-02-23
1819
### Added

pkg/storage/cache.go

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -133,7 +133,6 @@ func NewInMemoryLRUCache[T any](opts ...InMemoryLRUCacheOpt[T]) (*InMemoryLRUCac
133133
entityLabel = unspecifiedLabel
134134
}
135135

136-
cacheItemCount.WithLabelValues(entityLabel).Dec()
137136
cacheItemRemovedCount.WithLabelValues(entityLabel, reasonLabel).Inc()
138137
})
139138

@@ -163,12 +162,21 @@ func (i InMemoryLRUCache[T]) Set(key string, value T, ttl time.Duration) {
163162
if ttl >= oneYear {
164163
ttl = oneYear
165164
}
165+
166+
if ttl < 0 {
167+
return
168+
}
169+
170+
// Ignore the boolean return here as we always pass cost=1 and items are always admitted
166171
i.client.SetWithTTL(key, value, 1, ttl)
167172

173+
// Note: EstimatedSize is eventually consistent due to a shared lock in theine's maintenance routine.
174+
// It shouldn't matter in practice, but it may lag behind a few entries.
175+
cacheSizeFloat := float64(i.client.EstimatedSize())
168176
if item, ok := any(value).(CacheItem); ok {
169-
cacheItemCount.WithLabelValues(item.CacheEntityType()).Inc()
177+
cacheItemCount.WithLabelValues(item.CacheEntityType()).Set(cacheSizeFloat)
170178
} else {
171-
cacheItemCount.WithLabelValues(unspecifiedLabel).Inc()
179+
cacheItemCount.WithLabelValues(unspecifiedLabel).Set(cacheSizeFloat)
172180
}
173181
}
174182

pkg/storage/cache_test.go

Lines changed: 72 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,11 +6,13 @@ import (
66
"fmt"
77
"io"
88
"math"
9+
"strconv"
910
"strings"
1011
"testing"
1112
"time"
1213

1314
"github.com/oklog/ulid/v2"
15+
"github.com/prometheus/client_golang/prometheus/testutil"
1416
"github.com/stretchr/testify/require"
1517
"go.uber.org/goleak"
1618
"google.golang.org/protobuf/types/known/structpb"
@@ -421,6 +423,76 @@ func TestInMemoryCache(t *testing.T) {
421423
require.NotEqual(t, "value", result)
422424
})
423425

426+
t.Run("cache_item_count_doesnt_double_count_on_overwrite", func(t *testing.T) {
427+
cache, err := NewInMemoryLRUCache[string]()
428+
require.NoError(t, err)
429+
t.Cleanup(func() {
430+
goleak.VerifyNone(t)
431+
})
432+
defer cache.Stop()
433+
k := "key"
434+
435+
// Ensure metric is zero before we do anything
436+
cacheItemCount.WithLabelValues(unspecifiedLabel).Set(float64(0))
437+
438+
cache.Set(k, "value1", time.Second)
439+
440+
// This .Wait() is needed as cache client.EstimatedSize() is eventually consistent
441+
// due it its use of a shared mutex with theine's maintenance routine
442+
cache.client.Wait()
443+
444+
cache.Set(k, "value2", time.Second)
445+
before := testutil.ToFloat64(cacheItemCount.WithLabelValues(unspecifiedLabel))
446+
cache.client.Wait()
447+
448+
cache.Set(k, "value3", time.Second)
449+
after := testutil.ToFloat64(cacheItemCount.WithLabelValues(unspecifiedLabel))
450+
451+
// There should only be 1
452+
require.InDelta(t, 0, after, 1)
453+
454+
// Should not have changed further
455+
require.InDelta(t, 0, after-before, 0)
456+
})
457+
458+
t.Run("cache_item_count_decrements_after_deletes", func(t *testing.T) {
459+
cache, err := NewInMemoryLRUCache[string]()
460+
require.NoError(t, err)
461+
t.Cleanup(func() {
462+
goleak.VerifyNone(t)
463+
})
464+
defer cache.Stop()
465+
466+
// set 10 items in cache
467+
for i := range 10 {
468+
cache.Set(strconv.Itoa(i), "value"+strconv.Itoa(i), time.Second)
469+
}
470+
// Allow maintenance routine to finish
471+
cache.client.Wait()
472+
473+
// Set once more to ensure metric has caught up
474+
cache.Set("10", "value10", time.Second)
475+
476+
// this will return either 10 or 11 bc of race in EstimatedSize()
477+
before := testutil.ToFloat64(cacheItemCount.WithLabelValues(unspecifiedLabel))
478+
479+
// delete all 11 items in cache
480+
for i := range 11 {
481+
cache.Delete(strconv.Itoa(i))
482+
}
483+
// Allow maintenance routine to finish
484+
cache.client.Wait()
485+
486+
// The cache item count is only updated on Set()
487+
cache.Set("10", "value10", time.Second)
488+
489+
// this will be either 0 or 1 after the Set call above
490+
after := testutil.ToFloat64(cacheItemCount.WithLabelValues(unspecifiedLabel))
491+
492+
// expect before and after to differ by 9 elements, + or - 2 due to race
493+
require.InDelta(t, 9, before-after, 2)
494+
})
495+
424496
t.Run("stop_multiple_times", func(t *testing.T) {
425497
cache, err := NewInMemoryLRUCache[string]()
426498
require.NoError(t, err)

0 commit comments

Comments
 (0)