Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: Latency spikes were observed when deleting 60% entities during concurrent searches #37413

Open
1 task done
ThreadDao opened this issue Nov 4, 2024 · 22 comments
Open
1 task done
Assignees
Labels
kind/bug Issues or changes related a bug severity/critical Critical, lead to crash, data missing, wrong result, function totally doesn't work. triage/accepted Indicates an issue or PR is ready to be actively worked on.
Milestone

Comments

@ThreadDao
Copy link
Contributor

Is there an existing issue for this?

  • I have searched the existing issues

Environment

- Milvus version: 2.4-20241101-ce7d4090-amd64
- Deployment mode(standalone or cluster): cluster
- MQ type(rocksmq, pulsar or kafka):    
- SDK version(e.g. pymilvus v2.0.0rc2):
- OS(Ubuntu or CentOS): 
- CPU/Memory: 
- GPU: 
- Others:

Current Behavior

server config

  config:
    dataCoord:
      compaction:
        globnal:
          interval: 1
        taskPrioritizer: level
      enableActiveStandby: true
      segment:
        expansionRate: 1.15
        maxSize: 2048
        sealProportion: 0.12
    indexCoord:
      enableActiveStandby: true
    log:
      level: debug
    minio:
      accessKeyID: xxx
      bucketName: bucket-zong
      rootPath: compact_2
      secretAccessKey: xx
    queryCoord:
      enableActiveStandby: true
    queryNode:
      levelZeroForwardPolicy: RemoteLoad
      streamingDeltaForwardPolicy: Direct
    quotaAndLimits:
      dml:
        deleteRate:
          max: 0.5
        enabled: true
        insertRate:
          max: 16
      limitWriting:
        deleteBufferRowCountProtection:
          enabled: true
          highWaterLevel: 6000000
          lowWaterLevel: 3000000
        deleteBufferSizeProtection:
          enabled: true
          highWaterLevel: 536870912
          lowWaterLevel: 134217728
        growingSegmentsSizeProtection:
          enabled: true
          highWaterLevel: 0.2
          lowWaterLevel: 0.1
          minRateRatio: 0.5
        l0SegmentsRowCountProtection:
          enabled: true
          highWaterLevel: 6000000
          lowWaterLevel: 5000000
        memProtection:
          dataNodeMemoryHighWaterLevel: 0.85
          dataNodeMemoryLowWaterLevel: 0.75
          queryNodeMemoryHighWaterLevel: 0.85
          queryNodeMemoryLowWaterLevel: 0.75
      limits:
        complexDeleteLimitEnable: true
    rootCoord:
      enableActiveStandby: true
    trace:
      exporter: jaeger

test steps

  1. delete 60m of 100m collection entities when concurrent search, concurrent user is 22
    concurrent_params:
      concurrent_number: 22
      during_time: '1h'
      interval: 20
    concurrent_tasks:
      -   
        type: search
        weight: 10
        params:
          nq: 10
          top_k: 100 
          #output_fields: ['int64_1']
          search_param:
            ef: 128 
          timeout: 600 
          random_data: false

results

  • proxy qps and avg, p99 search latency
    image
  • qn mem usage
    image
  • segcore search latency
    image

metrics of compact-opt-100m-2

Expected Behavior

No response

Steps To Reproduce

No response

Milvus Log

No response

Anything else?

No response

@ThreadDao ThreadDao added kind/bug Issues or changes related a bug needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. labels Nov 4, 2024
@ThreadDao ThreadDao added the severity/critical Critical, lead to crash, data missing, wrong result, function totally doesn't work. label Nov 4, 2024
@ThreadDao ThreadDao added this to the 2.4.15 milestone Nov 4, 2024
@yanliang567 yanliang567 added triage/accepted Indicates an issue or PR is ready to be actively worked on. and removed needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. labels Nov 4, 2024
@yanliang567 yanliang567 removed their assignment Nov 4, 2024
@xiaofan-luan
Copy link
Collaborator

/assign @zhagnlu
can you help on investigating on this?

@ThreadDao
Copy link
Contributor Author

  • image: 2.4-20241106-20534a3f-amd64
  • delete 60m 128dim entities of 100m
    metrics
    image

@chyezh
Copy link
Contributor

chyezh commented Nov 12, 2024

When the search latency increasing, the following search segments operation is applied on target querynode.
The following 8 search operation is blocked by the search segment 453736378046070459, and the concurrency of search task is 8.

b846da617afd4008e836914d991274a0
5d97d0063e9bb20616b0c9f4b1331e89
e2f307e841e0d78d62f8cc5236d54a30
3f4641c2d53a87f2ccb5aae6b2284972
e2cc4350f9ca3d34336165ddd6204e59
4892db4e944a6d661a3ba0f8b093a7b0
bc3d66e707f97e10e0955d04bde97c9b
0587ed6ea5131972f09871dec5d37b2b

The new incoming search operation 791406ad741e4c6045c36a982e25d15b is blocked by go scheduler.
So the major issue is that why all search operation on segment 453736378046070459 is blocked.

2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=b846da617afd4008e836914d991274a0] [msgID=453783998542298097] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=b846da617afd4008e836914d991274a0] [msgID=453783998542298097] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [msgID=453783998542298098] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [msgID=453783998542298098] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.771	[2024/11/08 07:37:40.771 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [msgID=453783998542298099] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [msgID=453783998542298099] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.772	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.772 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [msgID=453783998542298100] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [msgID=453783998542298100] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.773	[2024/11/08 07:37:40.773 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [msgID=453783998542298101] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [msgID=453783998542298101] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [msgID=453783998542298102] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [msgID=453783998542298102] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.774	[2024/11/08 07:37:40.774 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [msgID=453783998542298103] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [msgID=453783998542298103] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.775	[2024/11/08 07:37:40.775 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [msgID=453783998542298104] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [msgID=453783998542298104] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [querynodev2/services.go:676] ["start to search segments on worker"] [traceID=791406ad741e4c6045c36a982e25d15b] [msgID=453783998542298105] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2] [segmentIDs="[453736378046073577,453736378046067368,453736378046074578,453736378237606175,453736378046070459]"]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [querynodev2/services.go:683] ["search segments..."] [traceID=791406ad741e4c6045c36a982e25d15b] [msgID=453783998542298105] [collectionID=453628762668583828] [channel=compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0] [scope=Historical] [metric_type=L2]
2024-11-08 15:37:40.776	[2024/11/08 07:37:40.776 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:40.777	[2024/11/08 07:37:40.777 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.952	[2024/11/08 07:37:53.952 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.953	[2024/11/08 07:37:53.953 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=bc3d66e707f97e10e0955d04bde97c9b] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=13.178324185s]
2024-11-08 15:37:53.953	[2024/11/08 07:37:53.953 +00:00] [DEBUG] [segments/validate.go:50] ["read target partitions"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [partitionIDs="[453628762668583829]"]
2024-11-08 15:37:53.954	[2024/11/08 07:37:53.954 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.954	[2024/11/08 07:37:53.954 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.954	[2024/11/08 07:37:53.954 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.954	[2024/11/08 07:37:53.954 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.954	[2024/11/08 07:37:53.954 +00:00] [DEBUG] [segments/segment.go:575] ["search segment..."] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.979	[2024/11/08 07:37:53.979 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046074578] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.979	[2024/11/08 07:37:53.979 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.979	[2024/11/08 07:37:53.979 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378237606175] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.979	[2024/11/08 07:37:53.979 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046073577] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.982	[2024/11/08 07:37:53.982 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=791406ad741e4c6045c36a982e25d15b] [collectionID=453628762668583828] [segmentID=453736378046067368] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:53.983	[2024/11/08 07:37:53.982 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=791406ad741e4c6045c36a982e25d15b] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=13.206077267s]
2024-11-08 15:37:56.556	[2024/11/08 07:37:56.556 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:56.556	[2024/11/08 07:37:56.556 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=5d97d0063e9bb20616b0c9f4b1331e89] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=15.785497984s]
2024-11-08 15:37:57.450	[2024/11/08 07:37:57.450 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:57.450	[2024/11/08 07:37:57.450 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=e2f307e841e0d78d62f8cc5236d54a30] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=16.678506294s]
2024-11-08 15:37:57.748	[2024/11/08 07:37:57.748 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=b846da617afd4008e836914d991274a0] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:57.748	[2024/11/08 07:37:57.748 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=b846da617afd4008e836914d991274a0] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=16.97777758s]
2024-11-08 15:37:57.930	[2024/11/08 07:37:57.930 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:57.930	[2024/11/08 07:37:57.930 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=3f4641c2d53a87f2ccb5aae6b2284972] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=17.157274766s]
2024-11-08 15:37:57.979	[2024/11/08 07:37:57.979 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:57.980	[2024/11/08 07:37:57.979 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=e2cc4350f9ca3d34336165ddd6204e59] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=17.205798166s]
2024-11-08 15:37:58.070	[2024/11/08 07:37:58.070 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:58.070	[2024/11/08 07:37:58.070 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=4892db4e944a6d661a3ba0f8b093a7b0] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=17.295814341s]
2024-11-08 15:37:58.093	[2024/11/08 07:37:58.093 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=0587ed6ea5131972f09871dec5d37b2b] [collectionID=453628762668583828] [segmentID=453736378046070459] [segmentType=Sealed] [withIndex=true]
2024-11-08 15:37:58.093	[2024/11/08 07:37:58.093 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=0587ed6ea5131972f09871dec5d37b2b] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_1_453628762668583828v0, segmentIDs = [453736378046073577 453736378046067368 453736378046074578 453736378237606175 453736378046070459]"] [duration=17.317617989s]

@chyezh
Copy link
Contributor

chyezh commented Nov 12, 2024

By adding new log and attach trace_id into logs. Found that high time cost at delete.

2024-11-12 17:20:33.340	I20241112 09:20:33.339989   262 ExecPlanNodeVisitor.cpp:249] [SERVER][VectorVisitorImpl][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx search scalar cost:565.016, vector_cost:8297.627, get_active cost: 0.18, delete_cost: 354.756
2024-11-12 17:20:33.340	I20241112 09:20:33.340018   262 SegmentInterface.cpp:101] [SERVER][Search][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx visit done cost:8910.432 us, 8910.396us
2024-11-12 17:20:33.340	I20241112 09:20:33.340024   262 segment_c.cpp:121] [SERVER][operator()][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx search done cost, 9136.341us
2024-11-12 17:20:33.345	[2024/11/12 09:20:33.345 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543349412] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:33.349	[2024/11/12 09:20:33.349 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543345199] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:33.353	[2024/11/12 09:20:33.353 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543348115] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:33.353	[2024/11/12 09:20:33.353 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543348990] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:33.353	[2024/11/12 09:20:33.353 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543347896] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:33.354	[2024/11/12 09:20:33.353 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453876116819705802] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:40.672	I20241112 09:20:40.672757   255 ExecPlanNodeVisitor.cpp:249] [SERVER][VectorVisitorImpl][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx search scalar cost:7339881.75, vector_cost:1909.335, get_active cost: 0.143, delete_cost: 7339786.493
2024-11-12 17:20:40.672	I20241112 09:20:40.672828   255 SegmentInterface.cpp:101] [SERVER][Search][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx visit done cost:7341900.021 us, 7341899.981us
2024-11-12 17:20:40.672	I20241112 09:20:40.672838   255 segment_c.cpp:121] [SERVER][operator()][MILVUS_FUTURE_C][652d52ef3d7d73dcef3842aeac58069b]xxx search done cost, 7341941.737us
2024-11-12 17:20:40.673	[2024/11/12 09:20:40.673 +00:00] [DEBUG] [segments/segment.go:599] ["search segment done"] [traceID=652d52ef3d7d73dcef3842aeac58069b] [collectionID=453783998545273592] [segmentID=453783998543347140] [segmentType=Sealed] [withIndex=true]
2024-11-12 17:20:40.675	[2024/11/12 09:20:40.675 +00:00] [DEBUG] [querynodev2/services.go:713] [tr/searchSegments] [traceID=652d52ef3d7d73dcef3842aeac58069b] [msg="search segments done, channel = compact-opt-100m-2-rootcoord-dml_0_453783998545273592v0, segmentIDs = [453783998543348990 453783998543349412 453783998543345199 453783998543347140 453876116819706429 453783998543347896 453876116819705802 453783998543348115]"] [duration=7.345444755s]
2024-11-12 17:20:40.676	I20241112 09:20:40.675948 53585 segment_c.cpp:142] [SERVER][AsyncSearch][milvus][652d52ef3d7d73dcef3842aeac58069b]xxx cgo cost: 22.033us, 3a33399acb4e656fd04fa564a4f002ae
2024-11-12 17:20:40.689	I20241112 09:20:40.689484 53585 segment_c.cpp:142] [SERVER][AsyncSearch][milvus][652d52ef3d7d73dcef3842aeac58069b]xxx cgo cost: 22.991us, af0bfbc0a96dfd9e7b1645abea66ff1a
2024-11-12 17:20:40.696	I20241112 09:20:40.696331 53585 segment_c.cpp:142] [SERVER][AsyncSearch][milvus][652d52ef3d7d73dcef3842aeac58069b]xxx cgo cost: 14.962us, 38403758541202c972cc4daa8e3348ad
2024-11-12 17:20:40.823	I20241112 09:20:40.823050 53585 segment_c.cpp:142] [SERVER][AsyncSearch][milvus][652d52ef3d7d73dcef3842aeac58069b]xxx cgo cost: 16.512us, 5c775474bb691e0ca588315353a1a0e5

@xiaofan-luan
Copy link
Collaborator

scalar cost

That is a great find

@xiaofan-luan
Copy link
Collaborator

image

I thought the problem here.

When delete batch is large.
find primary takes too much time

SegmentSealedImpl::search_pk try to leverage inverted index or use sorted pk to check PK whcih could be much master.

A monitoring on all cgo call utilization could be great as well so we can no all cgo call performance

@xiaofan-luan
Copy link
Collaborator

or if the delete batch is really huge, a simple BF might be needed

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 13, 2024

image I thought the problem here.

When delete batch is large. find primary takes too much time

SegmentSealedImpl::search_pk try to leverage inverted index or use sorted pk to check PK whcih could be much master.

A monitoring on all cgo call utilization could be great as well so we can no all cgo call performance

For more details, add more log and analysis:
image

this situation mainly happen when a segment meet several requirement :

  1. a segment has big row number
  2. almost all insert record pk were unique for segment
  3. almost all pk were deleted for segment

the mainly cost from two part:
1.
image
firstly, this circle will reduce delete records. the cost = row_number * cost(insert hash map). because the row number and distinct(pk) is big, this circle will cost seconds.

image
secondly, this circle will set bits according deleted_records. because reduce result still big, the circle is not shrink, and search_pk interface is unstable because of internal is a binary-search. this part may cost seconds.

As why this happens once, because it need meeting requirements, and the mvcc bitmap is a snapshot, it only costs too much for the first time.

@congqixia
Copy link
Contributor

@zhagnlu If I got you correct, the delete request itself did NOT affect the search or hold any lock. The huge delete data DID?

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 13, 2024

@zhagnlu If I got you correct, the delete request itself did NOT affect the search or hold any lock. The huge delete data DID?

yes, not lock made it but just delted data itself

@yanliang567 yanliang567 modified the milestones: 2.4.15, 2.4.16 Nov 14, 2024
@xiaofan-luan
Copy link
Collaborator

image I thought the problem here. When delete batch is large. find primary takes too much time SegmentSealedImpl::search_pk try to leverage inverted index or use sorted pk to check PK whcih could be much master. A monitoring on all cgo call utilization could be great as well so we can no all cgo call performance

For more details, add more log and analysis: image

this situation mainly happen when a segment meet several requirement :

  1. a segment has big row number
  2. almost all insert record pk were unique for segment
  3. almost all pk were deleted for segment

the mainly cost from two part: 1. image firstly, this circle will reduce delete records. the cost = row_number * cost(insert hash map). because the row number and distinct(pk) is big, this circle will cost seconds.

image secondly, this circle will set bits according deleted_records. because reduce result still big, the circle is not shrink, and search_pk interface is unstable because of internal is a binary-search. this part may cost seconds.

As why this happens once, because it need meeting requirements, and the mvcc bitmap is a snapshot, it only costs too much for the first time.

  1. The current calculation seems to be wrong.
    std::unordered_map<PkType, Timestamp> delete_timestamps;
    for (auto del_index = start; del_index < end; ++del_index) {
    auto pk = delete_record.pks()[del_index];
    auto timestamp = delete_record.timestamps()[del_index];

     delete_timestamps[pk] = timestamp > delete_timestamps[pk]
                                 ? timestamp
                                 : delete_timestamps[pk];
    

    }

we always pick the latest delete timestamp

but what if
insert PK1 V1 at 50
delete PK1 at 100
insert PK1 V2 at 150
delete PK1 at 200

if query at 110, we should not see anything, but right now we can see both 100 and 150.

@xiaofan-luan
Copy link
Collaborator

What if we fully refactor the delete factor? instead of store PK, timestamp, we should store
SegmentOffset -> DeleteTs.
The conversion can be done when load delete, if there is a match Segment Offset, then convert PK into segmentOffset -> delete ts.

Good part:

  1. Save some memory, Varchar PK could be vey expensive
  2. Don't need to search pk when generate bitset
  3. For same SegmentOffset, if multiple delete applied, only the first count(becasue SegmentOffset will never update, but PK will)

@chyezh @zhagnlu @congqixia
thoughts?

@chyezh
Copy link
Contributor

chyezh commented Nov 15, 2024

I think that:

Why not generate the mask when insert/delete operation incoming.
Just store the timestamp/delete mask with different version (ts).
Then search or query operation just do a binary search to find which mask to use by ts.
We do not store the delete record at segment anymore.

@xiaofan-luan

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 15, 2024

image I thought the problem here. When delete batch is large. find primary takes too much time SegmentSealedImpl::search_pk try to leverage inverted index or use sorted pk to check PK whcih could be much master. A monitoring on all cgo call utilization could be great as well so we can no all cgo call performance

For more details, add more log and analysis: image
this situation mainly happen when a segment meet several requirement :

  1. a segment has big row number
  2. almost all insert record pk were unique for segment
  3. almost all pk were deleted for segment

the mainly cost from two part: 1. image firstly, this circle will reduce delete records. the cost = row_number * cost(insert hash map). because the row number and distinct(pk) is big, this circle will cost seconds.
image secondly, this circle will set bits according deleted_records. because reduce result still big, the circle is not shrink, and search_pk interface is unstable because of internal is a binary-search. this part may cost seconds.
As why this happens once, because it need meeting requirements, and the mvcc bitmap is a snapshot, it only costs too much for the first time.

  1. The current calculation seems to be wrong.
    std::unordered_map<PkType, Timestamp> delete_timestamps;
    for (auto del_index = start; del_index < end; ++del_index) {
    auto pk = delete_record.pks()[del_index];
    auto timestamp = delete_record.timestamps()[del_index];

     delete_timestamps[pk] = timestamp > delete_timestamps[pk]
                                 ? timestamp
                                 : delete_timestamps[pk];
    

    }

we always pick the latest delete timestamp

but what if insert PK1 V1 at 50 delete PK1 at 100 insert PK1 V2 at 150 delete PK1 at 200

if query at 110, we should not see anything, but right now we can see both 100 and 150.

for this situation: when mask_with_delete, firstly, set a insert_barrier which limit search range
image
so, you can not see at 150 and 200 for query_timestamp 110

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 15, 2024

I think that:

Why not generate the mask when insert/delete operation incoming. Just store the timestamp/delete mask with different version (ts). Then search or query operation just do a binary search to find which mask to use by ts. We do not store the delete record at segment anymore.

@xiaofan-luan

this solution will generate too much (ts,mask) pair, mask is cost memory object

@congqixia
Copy link
Contributor

congqixia commented Nov 15, 2024

@chyezh @zhagnlu @xiaofan-luan
pre generation of delete bitmap mask could be a good choice in cases. Say sealed segments could generate the delete mask after load delta logs.
Generate numerous mask could cost more memory than storing int pk it self.
Vote for offset->ts optimization(ONLY for sealed segment)

For growing segments, the When to convert pk to offset could be tricky to decide and become corner case:

Target, checkpoint t0
Growing segment G1 checkpoint = t0, and has more insert data pending in WAL
L0 segment has some delete data actually belongs to G1, after t0

Loading this growing segment could not convert deltalogs into bitmap NOR offset when loading deltalogs, 
since the insert data has not be insert into this G1 segment, which means delta data failed to apply

And another tricky scenario is for the incoming iterator:(for aggressive pre generation and DISCARD)

Iterator started at t0, the mvcc ts is set to t0 as definition

Loading a segments in target with checkpoint t1 (t1 > t0)
If the deltalog are converted into bitmap and discord original data, the iterator could not time travel back to t0 
since some data could be marked deleted.

IMHO, there are some possible way to optimize as fellows have suggested:

  1. use (offset, ts) tuple, keeping all records (growing segment corner case)
  2. use (mask, ts) tuple, could be too memory heavy
  3. add a safe timestamp(which is tricky to decide for now?) and generate a bitmap for all delta data before it, discarding the original data

for opt 1, sealed segment is safe to implement. growing segment is doable with opt3 ts
WDYGT?

@chyezh
Copy link
Contributor

chyezh commented Nov 15, 2024

for opt 1, sealed segment is safe to implement. growing segment is doable with opt3 ts WDYGT?

I think opt3 is good choice for both sealed and growing, (mask, ts) can be compacted fast. because our search operations are increasing the ts fast.
compact safets can be carried by any rpc between delegator and querynode.
once user stop the delete oepartion, sealed segment will only keep one mask.

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 15, 2024

for opt 1, sealed segment is safe to implement. growing segment is doable with opt3 ts WDYGT?

I think opt3 is good choice for both sealed and growing, (mask, ts) can be compacted fast. because our search operations are increasing the ts fast. compact safets can be carried by any rpc between delegator and querynode. once user stop the delete oepartion, sealed segment will only keep one mask.

Yes, opt3 is necessary for (offset, ts) solution.

@zhagnlu
Copy link
Contributor

zhagnlu commented Nov 15, 2024

But anyway, original solution now also has a cache solution that only process added (pk,ts) pairs, this issue mainly meet a case:

  1. load a segment with quite big row number,
  2. load delata log with big delete pairs.
  3. first search will build cache and cost a lot.

if the delta log is not big, or delete log apply with many times not once, this cache cost will shrink to many times not spikes.

for new (offset, ts) solution, the advantage is that it push some cost to load and apply delete record, at the same time, we need to implement a cache like opt3 upper.

@xiaofan-luan
Copy link
Collaborator

I think that:

Why not generate the mask when insert/delete operation incoming. Just store the timestamp/delete mask with different version (ts). Then search or query operation just do a binary search to find which mask to use by ts. We do not store the delete record at segment anymore.

@xiaofan-luan

the problem is about timetravel and mvcc.
There is no way we can handle query with an old ts

@xiaofan-luan
Copy link
Collaborator

I think for now we will just go for
offset ts rather than pk ts? because it's any way better.

To optimize, one thing we can do is to generate a snapshot bitset for every 10000 deletes, but again this is not the key challenege. With the offset ts optimization we should already be able to optimize the performance to 10X faster.

If this is still not fast enough, then we do

ts -> bitset
ts2 -> delete offset
ts3 -> delete offset
....
ts8 -> another bitset snapshot.

If we want check the delete bitset at t10,
it's always t8 + t9 + t10

@xiaofan-luan
Copy link
Collaborator

@chyezh @zhagnlu @xiaofan-luan pre generation of delete bitmap mask could be a good choice in cases. Say sealed segments could generate the delete mask after load delta logs. Generate numerous mask could cost more memory than storing int pk it self. Vote for offset->ts optimization(ONLY for sealed segment)

For growing segments, the When to convert pk to offset could be tricky to decide and become corner case:

Target, checkpoint t0
Growing segment G1 checkpoint = t0, and has more insert data pending in WAL
L0 segment has some delete data actually belongs to G1, after t0

Loading this growing segment could not convert deltalogs into bitmap NOR offset when loading deltalogs, 
since the insert data has not be insert into this G1 segment, which means delta data failed to apply

And another tricky scenario is for the incoming iterator:(for aggressive pre generation and DISCARD)

Iterator started at t0, the mvcc ts is set to t0 as definition

Loading a segments in target with checkpoint t1 (t1 > t0)
If the deltalog are converted into bitmap and discord original data, the iterator could not time travel back to t0 
since some data could be marked deleted.

IMHO, there are some possible way to optimize as fellows have suggested:

  1. use (offset, ts) tuple, keeping all records (growing segment corner case)
  2. use (mask, ts) tuple, could be too memory heavy
  3. add a safe timestamp(which is tricky to decide for now?) and generate a bitmap for all delta data before it, discarding the original data

for opt 1, sealed segment is safe to implement. growing segment is doable with opt3 ts WDYGT?

@chyezh @zhagnlu @xiaofan-luan pre generation of delete bitmap mask could be a good choice in cases. Say sealed segments could generate the delete mask after load delta logs. Generate numerous mask could cost more memory than storing int pk it self. Vote for offset->ts optimization(ONLY for sealed segment)

For growing segments, the When to convert pk to offset could be tricky to decide and become corner case:

Target, checkpoint t0
Growing segment G1 checkpoint = t0, and has more insert data pending in WAL
L0 segment has some delete data actually belongs to G1, after t0

Loading this growing segment could not convert deltalogs into bitmap NOR offset when loading deltalogs, 
since the insert data has not be insert into this G1 segment, which means delta data failed to apply

And another tricky scenario is for the incoming iterator:(for aggressive pre generation and DISCARD)

Iterator started at t0, the mvcc ts is set to t0 as definition

Loading a segments in target with checkpoint t1 (t1 > t0)
If the deltalog are converted into bitmap and discord original data, the iterator could not time travel back to t0 
since some data could be marked deleted.

IMHO, there are some possible way to optimize as fellows have suggested:

  1. use (offset, ts) tuple, keeping all records (growing segment corner case)
  2. use (mask, ts) tuple, could be too memory heavy
  3. add a safe timestamp(which is tricky to decide for now?) and generate a bitmap for all delta data before it, discarding the original data

for opt 1, sealed segment is safe to implement. growing segment is doable with opt3 ts WDYGT?

I don't thinks is a problem.
The insert with smaller ts has to be applied ealier to delete, this is the strong requiremnet we should never break.
otherwise the delete won't be work even for now, because we do an existing check before delete applied

@yanliang567 yanliang567 modified the milestones: 2.4.16, 2.4.17, 2.4.18 Nov 21, 2024
sre-ci-robot pushed a commit that referenced this issue Dec 15, 2024
#37413

Signed-off-by: luzhang <luzhang@zilliz.com>
Co-authored-by: luzhang <luzhang@zilliz.com>
@yanliang567 yanliang567 modified the milestones: 2.4.18, 2.4.19, 2.4.20 Dec 24, 2024
@yanliang567 yanliang567 modified the milestones: 2.4.20, 2.4.21 Jan 6, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Issues or changes related a bug severity/critical Critical, lead to crash, data missing, wrong result, function totally doesn't work. triage/accepted Indicates an issue or PR is ready to be actively worked on.
Projects
None yet
Development

No branches or pull requests

6 participants