Increase cacheContextLifetime to reduce false reports (#32011) (#32023

)

Backport #32011 by @wolfogre

Replace #32001.

To prevent the context cache from being misused for long-term work
(which would result in using invalid cache without awareness), the
context cache is designed to exist for a maximum of 10 seconds. This
leads to many false reports, especially in the case of slow SQL.

This PR increases it to 5 minutes to reduce false reports.

5 minutes is not a very safe value, as a lot of changes may have
occurred within that time frame. However, as far as I know, there has
not been a case of misuse of context cache discovered so far, so I think
5 minutes should be OK.

Please note that after this PR, if warning logs are found again, it
should get attention, at that time it can be almost 100% certain that it
is a misuse.

Co-authored-by: Jason Song <[email protected]>

modules/cache/context.go

@@ -63,9 +63,9 @@ func (cc *cacheContext) isDiscard() bool {
 }
 
 // cacheContextLifetime is the max lifetime of cacheContext.
-// Since cacheContext is used to cache data in a request level context, 10s is enough.
-// If a cacheContext is used more than 10s, it's probably misuse.
-const cacheContextLifetime = 10 * time.Second
+// Since cacheContext is used to cache data in a request level context, 5 minutes is enough.
+// If a cacheContext is used more than 5 minutes, it's probably misuse.
+const cacheContextLifetime = 5 * time.Minute
 
 var timeNow = time.Now
 
@@ -131,7 +131,7 @@ func GetContextData(ctx context.Context, tp, key any) any {
 		if c.Expired() {
 			// The warning means that the cache context is misused for long-life task,
 			// it can be resolved with WithNoCacheContext(ctx).
-			log.Warn("cache context is expired, may be misused for long-life tasks: %v", c)
+			log.Warn("cache context is expired, is highly likely to be misused for long-life tasks: %v", c)
 			return nil
 		}
 		return c.Get(tp, key)
@@ -144,7 +144,7 @@ func SetContextData(ctx context.Context, tp, key, value any) {
 		if c.Expired() {
 			// The warning means that the cache context is misused for long-life task,
 			// it can be resolved with WithNoCacheContext(ctx).
-			log.Warn("cache context is expired, may be misused for long-life tasks: %v", c)
+			log.Warn("cache context is expired, is highly likely to be misused for long-life tasks: %v", c)
 			return
 		}
 		c.Put(tp, key, value)
@@ -157,7 +157,7 @@ func RemoveContextData(ctx context.Context, tp, key any) {
 		if c.Expired() {
 			// The warning means that the cache context is misused for long-life task,
 			// it can be resolved with WithNoCacheContext(ctx).
-			log.Warn("cache context is expired, may be misused for long-life tasks: %v", c)
+			log.Warn("cache context is expired, is highly likely to be misused for long-life tasks: %v", c)
 			return
 		}
 		c.Delete(tp, key)

modules/cache/context_test.go

@@ -45,7 +45,7 @@ func TestWithCacheContext(t *testing.T) {
 		timeNow = now
 	}()
 	timeNow = func() time.Time {
-		return now().Add(10 * time.Second)
+		return now().Add(5 * time.Minute)
 	}
 	v = GetContextData(ctx, field, "my_config1")
 	assert.Nil(t, v)