缓存数据“消失”之谜

标签：缓存 hash 流程消失缓存数据 modelCache Println 模型之谜

吃一堑，长一智。

“邪门！真是邪门！”自从踏入 Go 的领域之后，奇事怪事接连不断。很多看上去似乎没啥问题的代码，可就是有问题，可怎么也看不出问题所在。

问题背景

事情是这样的：有两个流程和一个缓存数据：

流程一：接收 kafka 数据，解析模型数据，并存入缓存 modelCache: localCache[hash]Model 里；

流程二：接收告警数据，计算对应的 hash，从 modelCache 中取出对应 hash 的 model ，进行后续的匹配。

奇怪在哪里呢？

在流程一中，通过打日志，发现 hash 对应的模型确实是存在的；然而在流程二中从 modelCache 里怎么也取不到这个 hash 对应的模型。

排查过程

走查代码

简单走查了下代码，检查了下初始化、依赖注入、使用方式等，没看出问题。

打印日志

为了方便查看，我把流程中都加了 "denoise detection" 关键字，这样就能看到所有相关流程的日志。

取不到模型，自然第一时间想到就是 hash 是不是对不上？于是我把 hash 打出来，是一个 hash。再通过 hash 搜索，发现也是同一个 hash。

进而想到，会不会在流程中设置缓存之后，又有地方把缓存给清了？于是，我把清缓存的所有地方都注释掉了。可是还是拿不到模型。

我又在流程的结束处打印缓存里的信息，是有的。

真是奇怪啊！加载模型的时候缓存是有的，流程结束时缓存也是有的，中间也没有清缓存的地方，为啥另一个流程来取的时候就没有了呢？

试试替代方案

为了调通流程，我就先用 Map 来直接替代缓存了。发现在一个流程中把模型存入 map 然后在另一个流程中取出 map 的模型是可行的。

有了替代方案，心里多少踏实了一点。

进一步探查

难道是在不同线程中运行取不到？可都是访问的同一个单例对象的公共缓存，且取不到模型的日志是在加载模型之后，应该也不存在时间先后导致的问题。为了验证这个问题，我写了个单测，特地在一个协程里加载模型，在另一个协程里访问模型，是取得到的。

实在令人百思不得其解啊！

func TestDenoiseModelLoad(t *testing.T) {
	str := `
{
    "version_id": "1706608200001",
    "is_end": true,
    "detection_reduction_model": [{
        "tenant_id": "77fc7d4a115bb8b512fa",
        "model_key_hash": "9b7867b3dbf1533d7dbb87e1e2cc2c155bd136f72d53be2d7f36a72132d441d1",
        "detection_method": "BYPASSUAC_FILE_MONITOR",
        "detection_type": "BypassUAC",
        "detection_model_id": "490262997608955948",
        "reduction_process_entity": ["C:\\Windows\\System32\\dllhost.exe", "dllhost.exe"],
        "profiles": [{
            "create_time": 1706608200001,
            "reduction_rule_type": null,
            "reduction_process_command_serial": "{\"serial\":\"C:\\\\WINDOWS\\\\system32\\\\DllHost.exe /Processid:{3AD05575-8857-4850-9277-11B85BDB8E09}\",\"info\":[],\"rem\":1}",
            "reduction_file_path_serial": "{\"serial\":\"C:\\\\Windows\\\\assembly\\\\NativeImages_v4.*.*_*\\\\Accessibility\\\\*\\\\Accessibility_测试.ni.dll\",\"info\":[{\"pos\":36,\"type\":\"[NUM]\",\"vals\":[]},{\"pos\":38,\"type\":\"[NUM]\",\"vals\":[]},{\"pos\":40,\"type\":\"[NUM]\",\"vals\":[]},{\"pos\":56,\"type\":\"[GEN]\",\"vals\":[]}],\"rem\":4}",
            "reduction_rule_id": "44a20767-ee56-4061-b284-fb9f9b1a9627"
        }]
    }]
}`

	denoiseMap := denoise_utils.LoadModelBySDK(str)
	fmt.Println(denoiseMap)

	modelCache := cache.NewLocalCache[denoisemodels.BaseModelDispatch](
		cache.WithCapacity(1000),
		cache.WithTTL(time.Hour*2))
	for modelHash, model := range denoiseMap {
		modelCache.Set(modelHash, model)
	}

	go func() {
		model, _ := modelCache.Get("9b7867b3dbf1533d7dbb87e1e2cc2c155bd136f72d53be2d7f36a72132d441d1")
		fmt.Println(model)
	}()
}

请教同事

我去问了下公司比较厉害的一位同事，他运行了下缓存实现的多线程访问的测试用例，也没有看出问题。不过他提醒了一句：会不会是取到的不是同一个缓存？

也许有可能。他建议我打印这个缓存的地址看看。我打印了一下（如上图所示），发现地址也是一致的！难道是初始化时有问题？但这是一个依赖注入，理论上，注入是没有问题的。

灵光一现

直觉上，我觉得，这要么是个天坑，要么是一个很小的细节导致，但是我暂时不知道它藏在哪里。不过，基本可以肯定的是，所依赖的缓存实现很可能是没有问题的，虽然我一度怀疑它有问题，甚至想用另一个缓存实现来替代下。

现在，似乎越来越迷惑了，但越来越接近真相了。我感觉它近在咫尺，但我还是看不到它。

突然，有一个想法跃入我的脑海：既然加载模型取不到，而在流程结束时又取得到，而缓存又是在同一个对象里访问的，那么它究竟是在什么时候消失的呢？

想到一个主意：我在流程的结束处，每隔 5s 打印一次缓存信息。如果每隔 5s 能取到模型信息，那就没理由在告警来的时候又取不到。

说干就干。我加了一些日志。重新部署，然后查看日志，发现：流程结束后模型是能取到的，但是隔 5s 后就取不到了。读者，看到这里，你想到了什么？

真相大白

我写了个测试用例。发现隔几秒后真的取不到。

咦？按理来说，不应该啊，API 怎么会犯这种错误？我又把 timex.Hours*2 *改成 timex.Hours*100000000*2，还是取不到。

func TestLocalCache(t *testing.T) {
	var emptyCache cache.LocalCache[denoisemodels.BaseModelDispatch]
	fmt.Println(&emptyCache)

	modelCache := cache.NewLocalCache[denoisemodels.BaseModelDispatch](
		cache.WithCapacity(1000),
		cache.WithTTL(timex.Hours*2))

	fmt.Println(&modelCache)

	modelCache.Set("d3aec278bab046cc9d31e6d72897153a103ec81ca8c658ec2bcecc5fad238e81", &behavior.BehaviorModelDispatch{})
	modelGet, ok := modelCache.Get("d3aec278bab046cc9d31e6d72897153a103ec81ca8c658ec2bcecc5fad238e81")
	fmt.Println(modelGet)
	fmt.Println(ok)

	time.Sleep(time.Second * 5)

	modelGet2, ok := modelCache.Get("d3aec278bab046cc9d31e6d72897153a103ec81ca8c658ec2bcecc5fad238e81")
	fmt.Println(modelGet2)
	fmt.Println(ok)
}

然后请 TL 帮忙一起看下。突然发现，自定义的 timex.Hours = 24，但实际上 Go 表示时间间隔，有个 Duration 的概念。应该是用 time.Hour*2，其中 Hour 的定义如下。

改成 time.Hour 就能够取到模型了！

const (
	Nanosecond  Duration = 1
	Microsecond          = 1000 * Nanosecond
	Millisecond          = 1000 * Microsecond
	Second               = 1000 * Millisecond
	Minute               = 60 * Second
	Hour                 = 60 * Minute
)

启示

遇到令人费解的问题，怎么办呢？

走查代码。看看有木有肉眼可见的细小错误。
打详细日志。如果是长流程，可以加相同的前缀日志，或者同一个业务ID，方便通过一个关键字看到全流程。
推测可能性，根据可能性设计实验，排除可能性。
不要急躁。冷静下来，仔细思考，可能有哪些原因。
遇到不解的问题，写单测验证想法（是否合理）。
一定要注意那些最基础的地方，你觉得最不太可能出问题的地方。
拷贝代码，一定要仔细审查代码。可能有细小差别，却能产生迥异结果。
程序世界里，事出必有因。

标签：缓存,hash,流程,消失,缓存数据,modelCache,Println,模型,之谜
From： https://www.cnblogs.com/lovesqcc/p/18137149