trickster icon indicating copy to clipboard operation
trickster copied to clipboard

Data Race observed in pkg/proxy/engines

Open crandles opened this issue 8 months ago • 2 comments

Observed via CI, have yet to reproduce locally, assume it is intermittent.

  • https://github.com/trickstercache/trickster/actions/runs/14234721400/job/39891872593
2025-04-03T04:10:24.0648843Z === RUN   TestDeltaProxyCacheRequestRangeMissChunks
2025-04-03T04:10:24.0649117Z ==================
2025-04-03T04:10:24.0649310Z WARNING: DATA RACE
2025-04-03T04:10:24.0649527Z Read at 0x00c0005e0010 by goroutine 1361:
2025-04-03T04:10:24.0649941Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.WriteCache()
2025-04-03T04:10:24.0650906Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/cache.go:435 +0x684
2025-04-03T04:10:24.0652167Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest.func2()
2025-04-03T04:10:24.0653447Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:422 +0x5aa
2025-04-03T04:10:24.0654324Z 
2025-04-03T04:10:24.0654576Z Previous write at 0x00c0005e0010 by goroutine 1313:
2025-04-03T04:10:24.0655588Z   github.com/trickstercache/trickster/v2/pkg/timeseries.(*TimeRangeQuery).NormalizeExtent()
2025-04-03T04:10:24.0656356Z       /home/runner/work/trickster/trickster/pkg/timeseries/timerangequery.go:95 +0x1ad
2025-04-03T04:10:24.0656980Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest()
2025-04-03T04:10:24.0658052Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:95 +0x937
2025-04-03T04:10:24.0659364Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.(*TestClient).QueryRangeHandler()
2025-04-03T04:10:24.0660796Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/client_test.go:378 +0x1f1
2025-04-03T04:10:24.0661541Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.TestDeltaProxyCacheRequestRangeMissChunks()
2025-04-03T04:10:24.0662410Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache_chunk_test.go:720 +0x247d
2025-04-03T04:10:24.0662883Z   testing.tRunner()
2025-04-03T04:10:24.0663312Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0663888Z   testing.(*T).Run.gowrap1()
2025-04-03T04:10:24.0664335Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x44
2025-04-03T04:10:24.0664596Z 
2025-04-03T04:10:24.0664698Z Goroutine 1361 (running) created at:
2025-04-03T04:10:24.0665153Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest()
2025-04-03T04:10:24.0666356Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:408 +0x5750
2025-04-03T04:10:24.0667690Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.(*TestClient).QueryRangeHandler()
2025-04-03T04:10:24.0668737Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/client_test.go:378 +0x1f1
2025-04-03T04:10:24.0669465Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.TestDeltaProxyCacheRequestRangeMissChunks()
2025-04-03T04:10:24.0670500Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache_chunk_test.go:673 +0x1455
2025-04-03T04:10:24.0670974Z   testing.tRunner()
2025-04-03T04:10:24.0671405Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0671775Z   testing.(*T).Run.gowrap1()
2025-04-03T04:10:24.0672211Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x44
2025-04-03T04:10:24.0672466Z 
2025-04-03T04:10:24.0672571Z Goroutine 1313 (running) created at:
2025-04-03T04:10:24.0672813Z   testing.(*T).Run()
2025-04-03T04:10:24.0673225Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x8f2
2025-04-03T04:10:24.0673789Z   testing.runTests.func1()
2025-04-03T04:10:24.0674235Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2279 +0x85
2025-04-03T04:10:24.0674767Z   testing.tRunner()
2025-04-03T04:10:24.0675171Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0675516Z   testing.runTests()
2025-04-03T04:10:24.0675932Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2277 +0x96c
2025-04-03T04:10:24.0676269Z   testing.(*M).Run()
2025-04-03T04:10:24.0676669Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2142 +0xeea
2025-04-03T04:10:24.0676993Z   main.main()
2025-04-03T04:10:24.0677240Z       _testmain.go:389 +0x164
2025-04-03T04:10:24.0677456Z ==================
2025-04-03T04:10:24.0677634Z ==================
2025-04-03T04:10:24.0677812Z WARNING: DATA RACE
2025-04-03T04:10:24.0678022Z Read at 0x00c0005e0028 by goroutine 1361:
2025-04-03T04:10:24.0678437Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.WriteCache()
2025-04-03T04:10:24.0679052Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/cache.go:435 +0x6d2
2025-04-03T04:10:24.0679665Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest.func2()
2025-04-03T04:10:24.0680397Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:422 +0x5aa
2025-04-03T04:10:24.0680725Z 
2025-04-03T04:10:24.0680861Z Previous write at 0x00c0005e0028 by goroutine 1313:
2025-04-03T04:10:24.0681374Z   github.com/trickstercache/trickster/v2/pkg/timeseries.(*TimeRangeQuery).NormalizeExtent()
2025-04-03T04:10:24.0682067Z       /home/runner/work/trickster/trickster/pkg/timeseries/timerangequery.go:96 +0x269
2025-04-03T04:10:24.0682665Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest()
2025-04-03T04:10:24.0683359Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:95 +0x937
2025-04-03T04:10:24.0684349Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.(*TestClient).QueryRangeHandler()
2025-04-03T04:10:24.0685061Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/client_test.go:378 +0x1f1
2025-04-03T04:10:24.0685755Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.TestDeltaProxyCacheRequestRangeMissChunks()
2025-04-03T04:10:24.0686596Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache_chunk_test.go:720 +0x247d
2025-04-03T04:10:24.0687062Z   testing.tRunner()
2025-04-03T04:10:24.0687478Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0687843Z   testing.(*T).Run.gowrap1()
2025-04-03T04:10:24.0688274Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x44
2025-04-03T04:10:24.0688529Z 
2025-04-03T04:10:24.0688631Z Goroutine 1361 (running) created at:
2025-04-03T04:10:24.0689072Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.DeltaProxyCacheRequest()
2025-04-03T04:10:24.0689784Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache.go:408 +0x5750
2025-04-03T04:10:24.0690423Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.(*TestClient).QueryRangeHandler()
2025-04-03T04:10:24.0691121Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/client_test.go:378 +0x1f1
2025-04-03T04:10:24.0691805Z   github.com/trickstercache/trickster/v2/pkg/proxy/engines.TestDeltaProxyCacheRequestRangeMissChunks()
2025-04-03T04:10:24.0692646Z       /home/runner/work/trickster/trickster/pkg/proxy/engines/deltaproxycache_chunk_test.go:673 +0x1455
2025-04-03T04:10:24.0693104Z   testing.tRunner()
2025-04-03T04:10:24.0693638Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0694005Z   testing.(*T).Run.gowrap1()
2025-04-03T04:10:24.0694431Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x44
2025-04-03T04:10:24.0694682Z 
2025-04-03T04:10:24.0694784Z Goroutine 1313 (running) created at:
2025-04-03T04:10:24.0695031Z   testing.(*T).Run()
2025-04-03T04:10:24.0695437Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1851 +0x8f2
2025-04-03T04:10:24.0695937Z   testing.runTests.func1()
2025-04-03T04:10:24.0696361Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2279 +0x85
2025-04-03T04:10:24.0696697Z   testing.tRunner()
2025-04-03T04:10:24.0697095Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:1792 +0x225
2025-04-03T04:10:24.0697426Z   testing.runTests()
2025-04-03T04:10:24.0697830Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2277 +0x96c
2025-04-03T04:10:24.0698165Z   testing.(*M).Run()
2025-04-03T04:10:24.0698562Z       /opt/hostedtoolcache/go/1.24.2/x64/src/testing/testing.go:2142 +0xeea
2025-04-03T04:10:24.0698891Z   main.main()
2025-04-03T04:10:24.0699130Z       _testmain.go:389 +0x164
2025-04-03T04:10:24.0699338Z ==================

logs_36621665699.zip

crandles avatar Apr 03 '25 14:04 crandles

Hi @crandles @jranson I’d like to ask whether this issue is still available.

From time to time, I also encounter additional data races during tests, again within the ObjectProxy and DeltaProxy components. Because of this, I’m very interested in contributing if the issue is still open, I’d be happy to help.

Thanks!

Elia-Renzoni avatar Nov 18 '25 15:11 Elia-Renzoni

I have not resolved this (or observed this again), would welcome the help.

Feel free to assign this issue to yourself.

crandles avatar Nov 18 '25 15:11 crandles