search

milvus-io / milvus

A cloud-native vector database, storage for next generation AI applications
https://milvus.io
Apache License 2.0
30.09k stars 2.89k forks source link

[Bug]: TestLoadWithMmap failed due to data race #31249

Closed zhengbuqian closed 5 months ago

zhengbuqian commented 7 months ago

Is there an existing issue for this?

Environment

No response

Current Behavior

see those UT runs:

those 2 runs failed due to TestLoadWithMmap.

code location where the race happened:

this code location was recently changed by @sunby and I left a comment there. maybe @sunby can look at the possible data race.

note that the above linked segment_loader.go doesn't include @sunby 's latest change.

full log of TestLoadWithMmap:

2024-03-13T20:06:42.7958549Z === RUN   TestSegmentLoader/TestLoadWithMmap
2024-03-13T20:06:42.7988466Z [2024/03/13 20:06:42.798 +00:00] [INFO] [storage/minio_chunk_manager.go:74] ["minio chunk manager init success."] [bucketname=a-bucket] [root=TestSegmentLoader]
2024-03-13T20:06:42.7991205Z [2024/03/13 20:06:42.798 +00:00] [INFO] [segments/segment_loader.go:495] ["SegmentLoader created"] [ioPoolSize=32]
2024-03-13T20:06:42.8002454Z I20240313 20:06:42.799786 25669 Collection.cpp:64] [SERVER][parseIndexMeta][segments.test] index meta info: maxRowCount : {80732} FieldId : {107 IndexParams : { index_type : IVF_FLAT, metric_type : L2, nlist : 128,  }TypeParams : {dim : 128, }}FieldId : {108 IndexParams : { index_type : BIN_IVF_FLAT, metric_type : JACCARD, nlist : 128,  }TypeParams : {dim : 128, }}
2024-03-13T20:06:42.8007315Z [2024/03/13 20:06:42.799 +00:00] [INFO] [segments/collection.go:163] ["add partitions"] [collection=1829489970218378507] [partitions="[4453250523664703059]"]
2024-03-13T20:06:42.8009738Z [2024/03/13 20:06:42.800 +00:00] [DEBUG] [segments/collection.go:179] ["collection ref increment"] [collectionID=1829489970218378507] [refCount=1]
2024-03-13T20:06:42.9866692Z [2024/03/13 20:06:42.986 +00:00] [DEBUG] [segments/mock_data.go:752] [".. [query node unittest] Saving bin logs to MinIO .."] [number=13]
2024-03-13T20:06:42.9871743Z [2024/03/13 20:06:42.986 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=100]
2024-03-13T20:06:42.9874152Z [2024/03/13 20:06:42.986 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=101]
2024-03-13T20:06:42.9876635Z [2024/03/13 20:06:42.987 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=102]
2024-03-13T20:06:42.9879866Z [2024/03/13 20:06:42.987 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=103]
2024-03-13T20:06:42.9882958Z [2024/03/13 20:06:42.987 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=104]
2024-03-13T20:06:42.9885904Z [2024/03/13 20:06:42.988 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=105]
2024-03-13T20:06:42.9888963Z [2024/03/13 20:06:42.988 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=106]
2024-03-13T20:06:42.9891720Z [2024/03/13 20:06:42.988 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=107]
2024-03-13T20:06:42.9894727Z [2024/03/13 20:06:42.989 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=108]
2024-03-13T20:06:42.9897598Z [2024/03/13 20:06:42.989 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=109]
2024-03-13T20:06:42.9900722Z [2024/03/13 20:06:42.989 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=110]
2024-03-13T20:06:42.9903771Z [2024/03/13 20:06:42.989 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=0]
2024-03-13T20:06:42.9906809Z [2024/03/13 20:06:42.990 +00:00] [DEBUG] [segments/mock_data.go:759] ["[query node unittest] save binlog"] [fieldID=1]
2024-03-13T20:06:42.9909493Z [2024/03/13 20:06:42.990 +00:00] [DEBUG] [segments/mock_data.go:775] ["[query node unittest] save binlog file to MinIO/S3"]
2024-03-13T20:06:42.9912684Z [2024/03/13 20:06:42.990 +00:00] [DEBUG] [segments/mock_data.go:781] ["[query node unittest] save statLog"] [fieldID=109]
2024-03-13T20:06:42.9915370Z [2024/03/13 20:06:42.991 +00:00] [DEBUG] [segments/mock_data.go:794] ["[query node unittest] save statsLog file to MinIO/S3"]
2024-03-13T20:06:43.1018659Z [2024/03/13 20:06:43.101 +00:00] [INFO] [segments/segment_loader_test.go:504] ["start loading..."] [collectionID=1829489970218378507] [segmentType=Sealed] [requestSegments="[3823443440717593305]"] [preparedSegments="[3823443440717593305]"] [segmentNum=1] [afterFilter=1]
2024-03-13T20:06:43.1061275Z [2024/03/13 20:06:43.105 +00:00] [DEBUG] [segments/segment_loader.go:781] ["segment resource for loading"] [collectionID=1829489970218378507] [segmentID=3823443440717593305] [memoryUsage(MB)=0] [diskUsage(MB)=0] [memoryLoadFactor=1]
2024-03-13T20:06:43.1078699Z [2024/03/13 20:06:43.105 +00:00] [INFO] [segments/segment_loader.go:781] ["predict memory and disk usage while loading (in MiB)"] [collectionID=1829489970218378507] [maxSegmentSize(MB)=0] [committedMemSize(MB)=0] [memLimit(MB)=7888.27734375] [memUsage(MB)=365.1015625] [committedDiskSize(MB)=0] [diskUsage(MB)=0] [predictMemUsage(MB)=365.1015625] [predictDiskUsage(MB)=0] [mmapFieldCount=13]
2024-03-13T20:06:43.1084692Z [2024/03/13 20:06:43.107 +00:00] [INFO] [segments/segment_loader.go:574] ["request resource for loading segments (unit in MiB)"] [segmentIDs="[3823443440717593305]"] [memory=0] [committedMemory=0] [disk=0] [committedDisk=0]
2024-03-13T20:06:43.1090081Z [2024/03/13 20:06:43.108 +00:00] [INFO] [segments/segment_loader.go:608] ["create segment"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [segmentType=Sealed] [level=Legacy]
2024-03-13T20:06:43.1093489Z [2024/03/13 20:06:43.108 +00:00] [INFO] [segments/segment_loader_test.go:504] ["start to load segments in parallel"] [collectionID=1829489970218378507] [segmentType=Sealed] [requestSegments="[3823443440717593305]"] [preparedSegments="[3823443440717593305]"] [segmentNum=1] [concurrencyLevel=1]
2024-03-13T20:06:43.1099337Z [2024/03/13 20:06:43.108 +00:00] [INFO] [segments/segment_loader.go:648] ["start loading segment files"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [shard=] [segmentID=3823443440717593305] [rowNum=100] [segmentType=Sealed]
2024-03-13T20:06:43.1111113Z [2024/03/13 20:06:43.110 +00:00] [INFO] [segments/segment_loader.go:981] ["add field data info done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] ["row count"=100]
2024-03-13T20:06:43.1121093Z [2024/03/13 20:06:43.110 +00:00] [INFO] [segments/segment_loader.go:648] ["load fields..."] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [shard=] [segmentID=3823443440717593305] [indexedFields="[]"]
2024-03-13T20:06:43.1123042Z ==================
2024-03-13T20:06:43.1123442Z WARNING: DATA RACE
2024-03-13T20:06:43.1123917Z Write at 0x00c0014694b8 by goroutine 3590:
2024-03-13T20:06:43.1183972Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields()
2024-03-13T20:06:43.1184888Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1078 +0x752
2024-03-13T20:06:43.1185775Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).loadSegment()
2024-03-13T20:06:43.1186777Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1011 +0x3ad5
2024-03-13T20:06:43.1187637Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load.func4()
2024-03-13T20:06:43.1188511Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:648 +0x604
2024-03-13T20:06:43.1189361Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func3()
2024-03-13T20:06:43.1190155Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:86 +0x201
2024-03-13T20:06:43.1190868Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func4()
2024-03-13T20:06:43.1191572Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:104 +0x47
2024-03-13T20:06:43.1191972Z 
2024-03-13T20:06:43.1192122Z Previous read at 0x00c0014694b8 by goroutine 3591:
2024-03-13T20:06:43.1192814Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields.func1()
2024-03-13T20:06:43.1193710Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1081 +0x92
2024-03-13T20:06:43.1194330Z   golang.org/x/sync/errgroup.(*Group).Go.func1()
2024-03-13T20:06:43.1194820Z       /go/pkg/mod/golang.org/x/sync@v0.5.0/errgroup/errgroup.go:75 +0x82
2024-03-13T20:06:43.1195244Z 
2024-03-13T20:06:43.1195351Z Goroutine 3590 (running) created at:
2024-03-13T20:06:43.1195866Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel()
2024-03-13T20:06:43.1196592Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:73 +0x2af
2024-03-13T20:06:43.1197330Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load()
2024-03-13T20:06:43.1198167Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:674 +0x2144
2024-03-13T20:06:43.1199077Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*SegmentLoaderSuite).TestLoadWithMmap()
2024-03-13T20:06:43.1200010Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader_test.go:504 +0xa6a
2024-03-13T20:06:43.1200591Z   runtime.call16()
2024-03-13T20:06:43.1200894Z       /usr/local/go/src/runtime/asm_amd64.s:728 +0x48
2024-03-13T20:06:43.1201257Z   reflect.Value.Call()
2024-03-13T20:06:43.1201559Z       /usr/local/go/src/reflect/value.go:370 +0xc7
2024-03-13T20:06:43.1201940Z   github.com/stretchr/testify/suite.Run.func1()
2024-03-13T20:06:43.1202445Z       /go/pkg/mod/github.com/stretchr/testify@v1.8.4/suite/suite.go:197 +0x70d
2024-03-13T20:06:43.1202902Z   testing.tRunner()
2024-03-13T20:06:43.1203203Z       /usr/local/go/src/testing/testing.go:1576 +0x216
2024-03-13T20:06:43.1203560Z   testing.(*T).Run.func1()
2024-03-13T20:06:43.1203864Z       /usr/local/go/src/testing/testing.go:1629 +0x47
2024-03-13T20:06:43.1204130Z 
2024-03-13T20:06:43.1204234Z Goroutine 3591 (running) created at:
2024-03-13T20:06:43.1204574Z   golang.org/x/sync/errgroup.(*Group).Go()
2024-03-13T20:06:43.1205040Z       /go/pkg/mod/golang.org/x/sync@v0.5.0/errgroup/errgroup.go:72 +0x12e
2024-03-13T20:06:43.1205763Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields()
2024-03-13T20:06:43.1206626Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1080 +0x285
2024-03-13T20:06:43.1207486Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).loadSegment()
2024-03-13T20:06:43.1208581Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1011 +0x3ad5
2024-03-13T20:06:43.1209446Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load.func4()
2024-03-13T20:06:43.1210310Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:648 +0x604
2024-03-13T20:06:43.1211260Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func3()
2024-03-13T20:06:43.1211972Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:86 +0x201
2024-03-13T20:06:43.1212739Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func4()
2024-03-13T20:06:43.1213534Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:104 +0x47
2024-03-13T20:06:43.1214000Z ==================
2024-03-13T20:06:43.1214460Z ==================
2024-03-13T20:06:43.1242204Z WARNING: DATA RACE
2024-03-13T20:06:43.1242904Z Read at 0x00c000f47368 by goroutine 3599:
2024-03-13T20:06:43.1244075Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*LocalSegment).LoadFieldData()
2024-03-13T20:06:43.1245242Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment.go:814 +0x173
2024-03-13T20:06:43.1246377Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields.func1()
2024-03-13T20:06:43.1256343Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1081 +0xc8
2024-03-13T20:06:43.1258165Z   golang.org/x/sync/errgroup.(*Group).Go.func1()
2024-03-13T20:06:43.1259035Z       /go/pkg/mod/golang.org/x/sync@v0.5.0/errgroup/errgroup.go:75 +0x82
2024-03-13T20:06:43.1259660Z 
2024-03-13T20:06:43.1259932Z Previous write at 0x00c000f47368 by goroutine 3590:
2024-03-13T20:06:43.1261143Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields()
2024-03-13T20:06:43.1263098Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1078 +0x70c
2024-03-13T20:06:43.1264771Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).loadSegment()
2024-03-13T20:06:43.1266348Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1011 +0x3ad5
2024-03-13T20:06:43.1267859Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load.func4()
2024-03-13T20:06:43.1269399Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:648 +0x604
2024-03-13T20:06:43.1270862Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func3()
2024-03-13T20:06:43.1272176Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:86 +0x201
2024-03-13T20:06:43.1273268Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func4()
2024-03-13T20:06:43.1274444Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:104 +0x47
2024-03-13T20:06:43.1275098Z 
2024-03-13T20:06:43.1275268Z Goroutine 3599 (running) created at:
2024-03-13T20:06:43.1275833Z   golang.org/x/sync/errgroup.(*Group).Go()
2024-03-13T20:06:43.1276604Z       /go/pkg/mod/golang.org/x/sync@v0.5.0/errgroup/errgroup.go:72 +0x12e
2024-03-13T20:06:43.1277951Z   github.com/milvus-io/milvus/internal/querynodev2/segments.loadSealedSegmentFields()
2024-03-13T20:06:43.1279542Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1080 +0x285
2024-03-13T20:06:43.1281150Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).loadSegment()
2024-03-13T20:06:43.1282638Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:1011 +0x3ad5
2024-03-13T20:06:43.1284076Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load.func4()
2024-03-13T20:06:43.1285548Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:648 +0x604
2024-03-13T20:06:43.1287007Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func3()
2024-03-13T20:06:43.1288285Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:86 +0x201
2024-03-13T20:06:43.1289642Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel.func4()
2024-03-13T20:06:43.1290869Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:104 +0x47
2024-03-13T20:06:43.1291512Z 
2024-03-13T20:06:43.1291704Z Goroutine 3590 (running) created at:
2024-03-13T20:06:43.1292672Z   github.com/milvus-io/milvus/pkg/util/funcutil.ProcessFuncParallel()
2024-03-13T20:06:43.1294036Z       /go/src/github.com/milvus-io/milvus/pkg/util/funcutil/parallel.go:73 +0x2af
2024-03-13T20:06:43.1295354Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*segmentLoader).Load()
2024-03-13T20:06:43.1296810Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader.go:674 +0x2144
2024-03-13T20:06:43.1298518Z   github.com/milvus-io/milvus/internal/querynodev2/segments.(*SegmentLoaderSuite).TestLoadWithMmap()
2024-03-13T20:06:43.1300404Z       /go/src/github.com/milvus-io/milvus/internal/querynodev2/segments/segment_loader_test.go:504 +0xa6a
2024-03-13T20:06:43.1301359Z   runtime.call16()
2024-03-13T20:06:43.1301861Z       /usr/local/go/src/runtime/asm_amd64.s:728 +0x48
2024-03-13T20:06:43.1302647Z   reflect.Value.Call()
2024-03-13T20:06:43.1303074Z       /usr/local/go/src/reflect/value.go:370 +0xc7
2024-03-13T20:06:43.1303623Z   github.com/stretchr/testify/suite.Run.func1()
2024-03-13T20:06:43.1304362Z       /go/pkg/mod/github.com/stretchr/testify@v1.8.4/suite/suite.go:197 +0x70d
2024-03-13T20:06:43.1312681Z   testing.tRunner()
2024-03-13T20:06:43.1313205Z       /usr/local/go/src/testing/testing.go:1576 +0x216
2024-03-13T20:06:43.1313863Z   testing.(*T).Run.func1()
2024-03-13T20:06:43.1314396Z       /usr/local/go/src/testing/testing.go:1629 +0x47
2024-03-13T20:06:43.1315216Z ==================
2024-03-13T20:06:43.1317010Z [2024/03/13 20:06:43.112 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=100] [rowCount=100]
2024-03-13T20:06:43.1320215Z [2024/03/13 20:06:43.112 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=108] [rowCount=100]
2024-03-13T20:06:43.1323456Z [2024/03/13 20:06:43.113 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=101] [rowCount=100]
2024-03-13T20:06:43.1327423Z [2024/03/13 20:06:43.113 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=100] [rowCount=100]
2024-03-13T20:06:43.1330069Z I20240313 20:06:43.113639 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 100 with num_rows 100
2024-03-13T20:06:43.1332278Z I20240313 20:06:43.113695 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 100 task to thread pool
2024-03-13T20:06:43.1336570Z [2024/03/13 20:06:43.113 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=103] [rowCount=100]
2024-03-13T20:06:43.1339038Z I20240313 20:06:43.118108 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 100 done
2024-03-13T20:06:43.1341556Z [2024/03/13 20:06:43.113 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=102] [rowCount=100]
2024-03-13T20:06:43.1344861Z [2024/03/13 20:06:43.121 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=100] [rowCount=100]
2024-03-13T20:06:43.1347920Z [2024/03/13 20:06:43.122 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=104] [rowCount=100]
2024-03-13T20:06:43.1351154Z [2024/03/13 20:06:43.122 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=0] [rowCount=100]
2024-03-13T20:06:43.1353926Z [2024/03/13 20:06:43.122 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=1] [rowCount=100]
2024-03-13T20:06:43.1361766Z [2024/03/13 20:06:43.122 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=106] [rowCount=100]
2024-03-13T20:06:43.1365888Z [2024/03/13 20:06:43.123 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=107] [rowCount=100]
2024-03-13T20:06:43.1369103Z [2024/03/13 20:06:43.123 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=110] [rowCount=100]
2024-03-13T20:06:43.1372188Z [2024/03/13 20:06:43.123 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=105] [rowCount=100]
2024-03-13T20:06:43.1376295Z [2024/03/13 20:06:43.123 +00:00] [INFO] [segments/segment_loader.go:1081] ["start loading field data for field"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=109] [rowCount=100]
2024-03-13T20:06:43.1379165Z [2024/03/13 20:06:43.125 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=0] [rowCount=100]
2024-03-13T20:06:43.1381931Z I20240313 20:06:43.125208 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 0 with num_rows 100
2024-03-13T20:06:43.1384229Z I20240313 20:06:43.125249 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 0 task to thread pool
2024-03-13T20:06:43.1386731Z [2024/03/13 20:06:43.125 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=1] [rowCount=100]
2024-03-13T20:06:43.1389446Z I20240313 20:06:43.125370 25632 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 1 with num_rows 100
2024-03-13T20:06:43.1391514Z I20240313 20:06:43.125394 25632 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 1 task to thread pool
2024-03-13T20:06:43.1394209Z I20240313 20:06:43.130503 25632 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 1 done
2024-03-13T20:06:43.1404929Z I20240313 20:06:43.130683 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 0 done
2024-03-13T20:06:43.1407339Z [2024/03/13 20:06:43.130 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=1] [rowCount=100]
2024-03-13T20:06:43.1410127Z [2024/03/13 20:06:43.130 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=0] [rowCount=100]
2024-03-13T20:06:43.1413050Z [2024/03/13 20:06:43.131 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=108] [rowCount=100]
2024-03-13T20:06:43.1415580Z I20240313 20:06:43.131296 25666 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 108 with num_rows 100
2024-03-13T20:06:43.1418073Z I20240313 20:06:43.131331 25666 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 108 task to thread pool
2024-03-13T20:06:43.1420583Z [2024/03/13 20:06:43.130 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=103] [rowCount=100]
2024-03-13T20:06:43.1423147Z I20240313 20:06:43.133293 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 103 with num_rows 100
2024-03-13T20:06:43.1425269Z I20240313 20:06:43.133371 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 103 task to thread pool
2024-03-13T20:06:43.1433993Z I20240313 20:06:43.135378 25666 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 108 done
2024-03-13T20:06:43.1447650Z [2024/03/13 20:06:43.135 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=108] [rowCount=100]
2024-03-13T20:06:43.1451127Z [2024/03/13 20:06:43.136 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=107] [rowCount=100]
2024-03-13T20:06:43.1453778Z I20240313 20:06:43.137169 25666 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 107 with num_rows 100
2024-03-13T20:06:43.1456110Z I20240313 20:06:43.137202 25666 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 107 task to thread pool
2024-03-13T20:06:43.1458769Z I20240313 20:06:43.139523 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 103 done
2024-03-13T20:06:43.1461237Z [2024/03/13 20:06:43.139 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=103] [rowCount=100]
2024-03-13T20:06:43.1464321Z [2024/03/13 20:06:43.139 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=104] [rowCount=100]
2024-03-13T20:06:43.1466744Z I20240313 20:06:43.140020 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 104 with num_rows 100
2024-03-13T20:06:43.1468885Z I20240313 20:06:43.140053 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 104 task to thread pool
2024-03-13T20:06:43.1471117Z I20240313 20:06:43.142549 25666 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 107 done
2024-03-13T20:06:43.1473413Z [2024/03/13 20:06:43.142 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=107] [rowCount=100]
2024-03-13T20:06:43.1476399Z [2024/03/13 20:06:43.142 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=109] [rowCount=100]
2024-03-13T20:06:43.1479108Z I20240313 20:06:43.143043 25666 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 109 with num_rows 100
2024-03-13T20:06:43.1481298Z I20240313 20:06:43.143075 25666 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 109 task to thread pool
2024-03-13T20:06:43.1483630Z I20240313 20:06:43.143496 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 104 done
2024-03-13T20:06:43.1486267Z [2024/03/13 20:06:43.143 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=104] [rowCount=100]
2024-03-13T20:06:43.1494138Z [2024/03/13 20:06:43.144 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=102] [rowCount=100]
2024-03-13T20:06:43.1502079Z I20240313 20:06:43.144277 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 102 with num_rows 100
2024-03-13T20:06:43.1504578Z I20240313 20:06:43.144309 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 102 task to thread pool
2024-03-13T20:06:43.1507552Z I20240313 20:06:43.148809 25666 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 109 done
2024-03-13T20:06:43.1511412Z [2024/03/13 20:06:43.148 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=109] [rowCount=100]
2024-03-13T20:06:43.1514396Z [2024/03/13 20:06:43.149 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=101] [rowCount=100]
2024-03-13T20:06:43.1516821Z I20240313 20:06:43.149448 25632 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 101 with num_rows 100
2024-03-13T20:06:43.1518954Z I20240313 20:06:43.149482 25632 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 101 task to thread pool
2024-03-13T20:06:43.1521105Z I20240313 20:06:43.149670 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 102 done
2024-03-13T20:06:43.1524119Z [2024/03/13 20:06:43.149 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=106] [rowCount=100]
2024-03-13T20:06:43.1526780Z I20240313 20:06:43.149911 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 106 with num_rows 100
2024-03-13T20:06:43.1529083Z I20240313 20:06:43.149937 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 106 task to thread pool
2024-03-13T20:06:43.1541368Z I20240313 20:06:43.153319 25632 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 101 done
2024-03-13T20:06:43.1544208Z [2024/03/13 20:06:43.153 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=101] [rowCount=100]
2024-03-13T20:06:43.1547768Z [2024/03/13 20:06:43.153 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=105] [rowCount=100]
2024-03-13T20:06:43.1550670Z I20240313 20:06:43.153908 25666 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 105 with num_rows 100
2024-03-13T20:06:43.1552735Z I20240313 20:06:43.153959 25666 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 105 task to thread pool
2024-03-13T20:06:43.1577095Z I20240313 20:06:43.156627 25666 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 105 done
2024-03-13T20:06:43.1578231Z I20240313 20:06:43.156831 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 106 done
2024-03-13T20:06:43.1579591Z [2024/03/13 20:06:43.156 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=106] [rowCount=100]
2024-03-13T20:06:43.1581137Z [2024/03/13 20:06:43.156 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=105] [rowCount=100]
2024-03-13T20:06:43.1582894Z [2024/03/13 20:06:43.157 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=102] [rowCount=100]
2024-03-13T20:06:43.1584546Z [2024/03/13 20:06:43.157 +00:00] [INFO] [conc/pool.go:81] ["submitted loadFieldData task to load pool"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=110] [rowCount=100]
2024-03-13T20:06:43.1585999Z I20240313 20:06:43.157286 25667 SegmentSealedImpl.cpp:246] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 110 with num_rows 100
2024-03-13T20:06:43.1587223Z I20240313 20:06:43.157311 25667 SegmentSealedImpl.cpp:259] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 submits load field 110 task to thread pool
2024-03-13T20:06:43.1611542Z I20240313 20:06:43.160815 25667 SegmentSealedImpl.cpp:268] [SERVER][LoadFieldData][segments.test] segment 3823443440717593305 loads field 110 done
2024-03-13T20:06:43.1616054Z [2024/03/13 20:06:43.160 +00:00] [INFO] [segments/segment_loader.go:1081] ["load field done"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [fieldID=110] [rowCount=100]
2024-03-13T20:06:43.1663531Z [2024/03/13 20:06:43.161 +00:00] [INFO] [segments/segment_loader.go:1011] ["load field binlogs done for sealed segment"] [collection=1829489970218378507] [segment=3823443440717593305] [len(field)=13] [segmentType=Sealed]
2024-03-13T20:06:43.1665152Z [2024/03/13 20:06:43.161 +00:00] [INFO] [segments/segment_loader.go:648] ["loading delta..."] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [shard=] [segmentID=3823443440717593305]
2024-03-13T20:06:43.1666614Z [2024/03/13 20:06:43.161 +00:00] [INFO] [segments/segment_loader.go:1044] ["there are no delta logs saved with segment, skip loading delete record"] [segmentID=3823443440717593305]
2024-03-13T20:06:43.1696465Z [2024/03/13 20:06:43.169 +00:00] [INFO] [funcutil/parallel.go:86] ["load segment done"] [collectionID=1829489970218378507] [segmentType=Sealed] [requestSegments="[3823443440717593305]"] [preparedSegments="[3823443440717593305]"] [segmentID=3823443440717593305]
2024-03-13T20:06:43.1701866Z [2024/03/13 20:06:43.169 +00:00] [DEBUG] [funcutil/parallel.go:54] [loadSegmentFunc] [total=1] ["time cost"=61.253379ms]
2024-03-13T20:06:43.1706929Z [2024/03/13 20:06:43.170 +00:00] [INFO] [segments/segment_loader_test.go:504] ["all segment load done"] [collectionID=1829489970218378507] [segmentType=Sealed] [requestSegments="[3823443440717593305]"] [preparedSegments="[3823443440717593305]"]
2024-03-13T20:06:43.1760818Z [2024/03/13 20:06:43.175 +00:00] [INFO] [segments/segment.go:1370] ["delete segment from memory"] [collectionID=1829489970218378507] [partitionID=4453250523664703059] [segmentID=3823443440717593305] [segmentType=Sealed] [insertCount=100]
2024-03-13T20:06:43.1967459Z     testing.go:1446: race detected during execution of test

Expected Behavior

No response

Steps To Reproduce

No response

Milvus Log

No response

Anything else?

No response

zhengbuqian commented 7 months ago

fixed by https://github.com/milvus-io/milvus/pull/31230

zhengbuqian commented 7 months ago

/assign @sunby

to fix this comment https://github.com/milvus-io/milvus/commit/7b7187b4657e7526e54f737f811c3871050f5dd2#r139751182

stale[bot] commented 6 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions. Rotten issues close after 30d of inactivity. Reopen the issue with /reopen.