TestStatsGroupOperations is failing under: github.com/rclone/rclone/fs/accounting

[yuvalif]

my env is rhel9:

go version
go version go1.22.5 (Red Hat 1.22.5-1.el9) linux/amd64

when running locally make quicktest on latest master branch i get:

--- FAIL: TestStatsGroupOperations (0.01s)
    --- FAIL: TestStatsGroupOperations/memory_is_reclaimed (0.01s)
        stats_groups_test.go:118: {Alloc:7987360 TotalAlloc:19579664 Sys:32068872 Lookups:0 Mallocs:27686 Frees:12883 HeapAlloc:7987360 HeapSys:24150016 HeapIdle:14909440 HeapInuse:9240576 HeapReleased:3833856 HeapObjects:14803 StackInuse:1
015808 StackSys:1015808 MSpanInuse:179680 MSpanSys:195840 MCacheInuse:96000 MCacheSys:109200 BuckHashSys:1452038 GCSys:2631104 OtherSys:2514866 NextGC:16529160 LastGC:1738058799183340225 PauseTotalNs:852929 PauseNs:[75684 527036 145512 1046
97 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
 0 0 0 0 0 0 0 0 0 0 0 0 0] PauseEnd:[1738058799164610773 1738058799170600088 1738058799178122862 1738058799183340225 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] NumGC:4 NumForcedGC:1 GCCPUFraction:0.03563909239518123 EnableGC:true DebugGC:false BySize:[{Size
:0 Mallocs:0 Frees:0} {Size:8 Mallocs:2809 Frees:120} {Size:16 Mallocs:13905 Frees:5736} {Size:24 Mallocs:1991 Frees:886} {Size:32 Mallocs:1660 Frees:777} {Size:48 Mallocs:3021 Frees:2370} {Size:64 Mallocs:377 Frees:149} {Size:80 Mallocs:17
9 Frees:114} {Size:96 Mallocs:223 Frees:65} {Size:112 Mallocs:828 Frees:655} {Size:128 Mallocs:146 Frees:99} {Size:144 Mallocs:15 Frees:2} {Size:160 Mallocs:133 Frees:58} {Size:176 Mallocs:16 Frees:6} {Size:192 Mallocs:4 Frees:3} {Size:208
Mallocs:176 Frees:133} {Size:224 Mallocs:76 Frees:75} {Size:240 Mallocs:2 Frees:0} {Size:256 Mallocs:69 Frees:17} {Size:288 Mallocs:190 Frees:186} {Size:320 Mallocs:58 Frees:47} {Size:352 Mallocs:10 Frees:3} {Size:384 Mallocs:9 Frees:3} {Si
ze:416 Mallocs:116 Frees:97} {Size:448 Mallocs:171 Frees:20} {Size:480 Mallocs:15 Frees:1} {Size:512 Mallocs:15 Frees:14} {Size:576 Mallocs:8 Frees:3} {Size:640 Mallocs:5 Frees:2} {Size:704 Mallocs:49 Frees:28} {Size:768 Mallocs:3 Frees:2}
{Size:896 Mallocs:20 Frees:11} {Size:1024 Mallocs:28 Frees:22} {Size:1152 Mallocs:7 Frees:0} {Size:1280 Mallocs:2 Frees:2} {Size:1408 Mallocs:30 Frees:10} {Size:1536 Mallocs:2 Frees:0} {Size:1792 Mallocs:18 Frees:9} {Size:2048 Mallocs:36 Fr
ees:16} {Size:2304 Mallocs:2 Frees:1} {Size:2688 Mallocs:2 Frees:1} {Size:3072 Mallocs:13 Frees:3} {Size:3200 Mallocs:0 Frees:0} {Size:3456 Mallocs:11 Frees:9} {Size:4096 Mallocs:19 Frees:16} {Size:4864 Mallocs:2 Frees:1} {Size:5376 Mallocs
:10 Frees:6} {Size:6144 Mallocs:4 Frees:3} {Size:6528 Mallocs:0 Frees:0} {Size:6784 Mallocs:0 Frees:0} {Size:6912 Mallocs:0 Frees:0} {Size:8192 Mallocs:12 Frees:5} {Size:9472 Mallocs:81 Frees:0} {Size:9728 Mallocs:1 Frees:0} {Size:10240 Mal
locs:0 Frees:0} {Size:10880 Mallocs:8 Frees:7} {Size:12288 Mallocs:1 Frees:1} {Size:13568 Mallocs:0 Frees:0} {Size:14336 Mallocs:4 Frees:3} {Size:16384 Mallocs:0 Frees:0} {Size:18432 Mallocs:0 Frees:0}]}
            {Alloc:7996336 TotalAlloc:20715536 Sys:32331016 Lookups:0 Mallocs:40249 Frees:25441 HeapAlloc:7996336 HeapSys:24051712 HeapIdle:14802944 HeapInuse:9248768 HeapReleased:6340608 HeapObjects:14808 StackInuse:1114112 StackSys:111411
2 MSpanInuse:205760 MSpanSys:212160 MCacheInuse:96000 MCacheSys:109200 BuckHashSys:1452246 GCSys:2661968 OtherSys:2729618 NextGC:16552952 LastGC:1738058799189923273 PauseTotalNs:941108 PauseNs:[75684 527036 145512 104697 88179 0 0 0 0 0 0 0
 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
 0 0 0 0] PauseEnd:[1738058799164610773 1738058799170600088 1738058799178122862 1738058799183340225 1738058799189923273 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] NumGC:5 NumForcedGC:2 GCCPUFraction:0.03550169578522774 EnableGC:true DebugGC:false BySize:[{Size
:0 Mallocs:0 Frees:0} {Size:8 Mallocs:2810 Frees:121} {Size:16 Mallocs:16650 Frees:8482} {Size:24 Mallocs:1992 Frees:887} {Size:32 Mallocs:1661 Frees:778} {Size:48 Mallocs:8021 Frees:7373} {Size:64 Mallocs:378 Frees:150} {Size:80 Mallocs:17
9 Frees:114} {Size:96 Mallocs:2223 Frees:2065} {Size:112 Mallocs:828 Frees:655} {Size:128 Mallocs:147 Frees:102} {Size:144 Mallocs:15 Frees:2} {Size:160 Mallocs:133 Frees:58} {Size:176 Mallocs:16 Frees:6} {Size:192 Mallocs:4 Frees:3} {Size:
208 Mallocs:217 Frees:175} {Size:224 Mallocs:76 Frees:75} {Size:240 Mallocs:2 Frees:0} {Size:256 Mallocs:73 Frees:18} {Size:288 Mallocs:190 Frees:186} {Size:320 Mallocs:58 Frees:47} {Size:352 Mallocs:10 Frees:3} {Size:384 Mallocs:9 Frees:3}
 {Size:416 Mallocs:117 Frees:98} {Size:448 Mallocs:177 Frees:20} {Size:480 Mallocs:1015 Frees:1001} {Size:512 Mallocs:16 Frees:15} {Size:576 Mallocs:8 Frees:3} {Size:640 Mallocs:5 Frees:2} {Size:704 Mallocs:49 Frees:28} {Size:768 Mallocs:3
Frees:2} {Size:896 Mallocs:21 Frees:12} {Size:1024 Mallocs:28 Frees:22} {Size:1152 Mallocs:8 Frees:1} {Size:1280 Mallocs:2 Frees:2} {Size:1408 Mallocs:30 Frees:10} {Size:1536 Mallocs:2 Frees:0} {Size:1792 Mallocs:19 Frees:10} {Size:2048 Mal
locs:39 Frees:16} {Size:2304 Mallocs:3 Frees:2} {Size:2688 Mallocs:2 Frees:1} {Size:3072 Mallocs:13 Frees:3} {Size:3200 Mallocs:0 Frees:0} {Size:3456 Mallocs:11 Frees:9} {Size:4096 Mallocs:20 Frees:17} {Size:4864 Mallocs:3 Frees:2} {Size:53
76 Mallocs:10 Frees:6} {Size:6144 Mallocs:4 Frees:3} {Size:6528 Mallocs:0 Frees:0} {Size:6784 Mallocs:0 Frees:0} {Size:6912 Mallocs:0 Frees:0} {Size:8192 Mallocs:13 Frees:6} {Size:9472 Mallocs:82 Frees:1} {Size:9728 Mallocs:1 Frees:0} {Size
:10240 Mallocs:0 Frees:0} {Size:10880 Mallocs:9 Frees:8} {Size:12288 Mallocs:1 Frees:1} {Size:13568 Mallocs:0 Frees:0} {Size:14336 Mallocs:5 Frees:4} {Size:16384 Mallocs:1 Frees:1} {Size:18432 Mallocs:0 Frees:0}]}
        stats_groups_test.go:121: HeapObjects = 14808, expected 14803
2025/01/28 10:06:39 NOTICE: Bandwidth limit set to {1Mi 1Mi}
2025/01/28 10:06:39 NOTICE: Bandwidth limit set to {10Mi 1Mi}
2025/01/28 10:06:39 NOTICE: Bandwidth limit reset to unlimited
FAIL
FAIL    github.com/rclone/rclone/fs/accounting  1.039s

[ncw]

Hmm, that test is marked as unreliable

rclone/fs/accounting/stats_groups_test.go

Lines 96 to 97 in dc9c872

	t.Run("memory is reclaimed", func(t *testing.T) {
	testy.SkipUnreliable(t)

So I suggest you ignore that.

If you want to run like the rclone CI does then export CI=1 and all those tests will be skipped!

[yuvalif]

thanks @ncw !

[darthShadow]

FWIW, the issue here seems to be that the heap count post GC is higher than the heap count before GC. If that's handled, it should still fall within the reasonable limit of 1%. Do we want a fix for that case or leave it as is?