milvus: [Bug]: [benchmark][standalone] search、query、load raise error: _MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded

Is there an existing issue for this?

I have searched the existing issues

Environment

- Milvus version: master-20220610-36ad9895
- Deployment mode(standalone or cluster): standalone
- SDK version(e.g. pymilvus v2.0.0rc2): 2.1.0.dev70
- OS(Ubuntu or CentOS): 
- CPU/Memory: 
- GPU: 
- Others:

Current Behavior

argo task: benchmark-backup-q258f

test yaml: client-configmap:client-random-locust-insert-delete server-configmap:server-single-32c128m-compaction

server:

NAME                                                          READY   STATUS      RESTARTS   AGE   IP             NODE                      NOMINATED NODE   READINESS GATES
benchmark-backup-q258f-1-etcd-0                               1/1     Running     0          35m   10.97.16.148   qa-node013.zilliz.local   <none>           <none>
benchmark-backup-q258f-1-milvus-standalone-7d9fb4bd8c-dlln7   1/1     Running     0          35m   10.97.17.14    qa-node014.zilliz.local   <none>           <none>
benchmark-backup-q258f-1-minio-864bd5df4-8gbgw                1/1     Running     0          35m   10.97.19.209   qa-node016.zilliz.local   <none>           <none>

client pod: benchmark-backup-q258f-341429661

client log:

[2022-06-13 03:26:58,926] [    INFO] -  (locust.stats_logger:733)
[2022-06-13 03:26:58,927] [   DEBUG] - Milvus get run in 194.6004s (milvus_benchmark.client:54)
[2022-06-13 03:26:58,928] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.085524', 'gRPC error': '2022-06-13 03:26:58.928661'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,929] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:43.992488', 'gRPC error': '2022-06-13 03:26:58.929541'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,930] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.085991', 'gRPC error': '2022-06-13 03:26:58.930694'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,931] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:43.992607', 'gRPC error': '2022-06-13 03:26:58.931458'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,933] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.086275', 'gRPC error': '2022-06-13 03:26:58.933148'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,934] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:43.992774', 'gRPC error': '2022-06-13 03:26:58.934021'}> (pymilvus.decorators:86)
[2022-06-13 03:26:58,936] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090003', 'gRPC error': '2022-06-13 03:26:58.936440'}> (pymilvus.decorators:86)
[2022-06-13 03:31:58,919] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090244', 'gRPC error': '2022-06-13 03:31:58.919293'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,001] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090323', 'gRPC error': '2022-06-13 03:31:59.001228'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,002] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090468', 'gRPC error': '2022-06-13 03:31:59.002465'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,003] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090718', 'gRPC error': '2022-06-13 03:31:59.003459'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,005] [   DEBUG] - Milvus load_collection run in 494.6779s (milvus_benchmark.client:54)
[2022-06-13 03:31:59,007] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.916830', 'gRPC error': '2022-06-13 03:31:59.007012'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,007] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.019903', 'gRPC error': '2022-06-13 03:31:59.007747'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,008] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.917169', 'gRPC error': '2022-06-13 03:31:59.008632'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,009] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.020039', 'gRPC error': '2022-06-13 03:31:59.009511'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,010] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.917442', 'gRPC error': '2022-06-13 03:31:59.010396'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,011] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.020156', 'gRPC error': '2022-06-13 03:31:59.011019'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,011] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.917740', 'gRPC error': '2022-06-13 03:31:59.011951'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,012] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.020264', 'gRPC error': '2022-06-13 03:31:59.012766'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,013] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.918033', 'gRPC error': '2022-06-13 03:31:59.013696'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,014] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.020443', 'gRPC error': '2022-06-13 03:31:59.014345'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,015] [   ERROR] - grpc RpcError: [query], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.327738', 'gRPC error': '2022-06-13 03:31:59.015259'}> (pymilvus.decorators:86)
[2022-06-13 03:31:59,017] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.935811', 'gRPC error': '2022-06-13 03:31:59.017381'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,007] [   ERROR] - grpc RpcError: [describe_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.936096', 'gRPC error': '2022-06-13 03:36:59.007089'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,008] [   ERROR] - RPC error: [bulk_insert], <MilvusException: (code=1, message=rpc timeout)>, <Time:{'RPC start': '2022-06-13 03:26:58.936075', 'RPC error': '2022-06-13 03:36:59.008732'}> (pymilvus.decorators:78)
[2022-06-13 03:36:59,009] [   ERROR] - <MilvusException: (code=1, message=rpc timeout)> (milvus_benchmark.client:167)
[2022-06-13 03:36:59,010] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.936269', 'gRPC error': '2022-06-13 03:36:59.010585'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,011] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:26:58.936346', 'gRPC error': '2022-06-13 03:36:59.011346'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,012] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.005090', 'gRPC error': '2022-06-13 03:36:59.012577'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,013] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.327482', 'gRPC error': '2022-06-13 03:36:59.013134'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,013] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.005470', 'gRPC error': '2022-06-13 03:36:59.013947'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,014] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.327621', 'gRPC error': '2022-06-13 03:36:59.014436'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,016] [   ERROR] - grpc RpcError: [_execute_search_requests], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.006886', 'gRPC error': '2022-06-13 03:36:59.016344'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,016] [   ERROR] - grpc RpcError: [search], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:44.327914', 'gRPC error': '2022-06-13 03:36:59.016918'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,017] [   ERROR] - grpc RpcError: [query], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:23:45.090552', 'gRPC error': '2022-06-13 03:36:59.017449'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,018] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2022-06-13 03:36:59,019] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2022-06-13 03:36:59,019] [    INFO] -  grpc delete                                                                         1573     0(0.00%)  |      97       3    1861      40  |    0.00    0.00 (locust.stats_logger:730)
[2022-06-13 03:36:59,019] [    INFO] -  grpc get                                                                            7639     2(0.03%)  |     348       3  793927      74  |    0.00    0.00 (locust.stats_logger:730)
[2022-06-13 03:36:59,020] [    INFO] -  grpc insert                                                                         1521     0(0.00%)  |     573      18  600074      98  |    0.00    0.00 (locust.stats_logger:730)
[2022-06-13 03:36:59,020] [    INFO] -  grpc load_collection                                                                2976     3(0.10%)  |     746       3  600075      72  |    0.00    0.00 (locust.stats_logger:730)
[2022-06-13 03:36:59,021] [    INFO] -  grpc query                                                                         15079    11(0.07%)  |     570       6  794689     110  |    0.00    0.00 (locust.stats_logger:730)
[2022-06-13 03:36:59,021] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2022-06-13 03:36:59,021] [    INFO] -  Aggregated                                                                         28788    16(0.06%)  |     503       3  794689      95  |    0.00    0.00 (locust.stats_logger:732)
[2022-06-13 03:36:59,021] [    INFO] -  (locust.stats_logger:733)
[2022-06-13 03:36:59,024] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.016139', 'gRPC error': '2022-06-13 03:36:59.024911'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,027] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.016376', 'gRPC error': '2022-06-13 03:36:59.027859'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,028] [   ERROR] - grpc RpcError: [describe_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.016485', 'gRPC error': '2022-06-13 03:36:59.028309'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,028] [   ERROR] - grpc RpcError: [describe_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.016781', 'gRPC error': '2022-06-13 03:36:59.028702'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,029] [   ERROR] - RPC error: [bulk_insert], <MilvusException: (code=1, message=rpc timeout)>, <Time:{'RPC start': '2022-06-13 03:31:59.016766', 'RPC error': '2022-06-13 03:36:59.029031'}> (pymilvus.decorators:78)
[2022-06-13 03:36:59,029] [   ERROR] - <MilvusException: (code=1, message=rpc timeout)> (milvus_benchmark.client:167)
[2022-06-13 03:36:59,029] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.016968', 'gRPC error': '2022-06-13 03:36:59.029634'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,030] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.017074', 'gRPC error': '2022-06-13 03:36:59.029973'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,030] [   ERROR] - grpc RpcError: [load_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.017143', 'gRPC error': '2022-06-13 03:36:59.030333'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,030] [   ERROR] - grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2022-06-13 03:31:59.017292', 'gRPC error': '2022-06-13 03:36:59.030724'}> (pymilvus.decorators:86)
[2022-06-13 03:36:59,085] [   DEBUG] - Milvus query run in 300.1662s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,109] [   DEBUG] - Milvus load_collection run in 0.0763s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,110] [   DEBUG] - Milvus load_collection run in 0.0868s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,113] [   DEBUG] - Milvus get run in 0.0854s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,114] [   DEBUG] - Milvus query run in 794.0245s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,148] [   DEBUG] - Milvus load_collection run in 0.1152s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,149] [   DEBUG] - Milvus query run in 600.2135s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,150] [   DEBUG] - Milvus query run in 0.1256s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,150] [   DEBUG] - Milvus query run in 794.0605s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,151] [   DEBUG] - Milvus query run in 0.127s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,163] [   DEBUG] - Milvus query run in 0.139s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,166] [   DEBUG] - Milvus query run in 0.1413s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,175] [   DEBUG] - Milvus query run in 794.0845s (milvus_benchmark.client:54)
[2022-06-13 03:36:59,202] [   DEBUG] - Milvus get run in 0.0871s (milvus_benchmark.client:54)

Expected Behavior

No response

Steps To Reproduce

1、create collection
2、create index of ivf_sq8
3、insert 10w million vectors
4、flush collection
5、build index with the same params
6、load collection
7、locust concurrent: query<-search, load, get<-query, delete, insert 《- raise error

Milvus Log

No response

Anything else?

client-random-locust-insert-delete:

    locust_random_performance:
      collections:
        -
          collection_name: sift_10w_128_l2
          ni_per: 50000
          other_fields: float1
          build_index: true
          index_type: ivf_sq8
          index_param:
            nlist: 2048
          task:
            types:
              -
                type: query
                weight: 10
                params:
                  top_k: 10
                  nq: 10
                  search_param:
                    nprobe: 16
                  filters:
                    -
                      range: "{'range': {'float1': {'GT': collection_size * 0.5, 'LT': collection_size * 1}}}"
              -
                type: load
                weight: 2
              -
                type: get
                weight: 5
                params:
                  ids_length: 10
              -
                type: insert
                weight: 1
                params:
                  ni_per: 1000
              -
                type: delete
                weight: 1
                params:
                  ni_per: 100
            connection_num: 1
            clients_num: 20
            spawn_rate: 2
            during_time: 30m

About this issue

Original URL
State: closed
Created 2 years ago
Comments: 29 (29 by maintainers)

Commits related to this issue

Add msg id to log in search path. issue: #17513 Add msg id to log in search path, which should help us to trace a detailed request more easier. Signed-off-by: longjiquan <jiquan.long@zilliz.com> — committed to longjiquan/milvus by longjiquan 2 years ago
Add msg id to log in search path. (#17654) issue: #17513 Add msg id to log in search path, which should help us to trace a detailed request more easier. Signed-off-by: longjiquan <jiquan.long@zilliz... — committed to milvus-io/milvus by longjiquan 2 years ago
Fix msgstream close block. issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> — committed to sunby/milvus by deleted user 2 years ago
Fix msgstream close block. issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> — committed to sunby/milvus by deleted user 2 years ago
Fix msgstream close block. issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> — committed to sunby/milvus by deleted user 2 years ago
Fix msgstream close block. (#17880) issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> Co-authored-by: sunby <bingyi.sun@zilliz.com> — committed to milvus-io/milvus by sunby 2 years ago
Fix msgstream close block. (#17880) issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> Co-authored-by: sunby <bingyi.sun@zilliz.com> — committed to sunby/milvus by sunby 2 years ago
Fix msgstream close block. (#17880) (#17909) issue: #17513 Signed-off-by: sunby <bingyi.sun@zilliz.com> Co-authored-by: sunby <bingyi.sun@zilliz.com> Co-authored-by: sunby <bingyi.sun@zilliz.c... — committed to milvus-io/milvus by sunby 2 years ago

Most upvoted comments

argo test-etcd-no-clean-wggls server-configmap server-cluster-dn2c10m-in8c32m-qn8c64m-compaction client-configmap client-random-locust-insert-delete-60h 2.1.0-20220624-6c47ea2f pymilvus 2.1.0dev87

test-etcd-no-clean-wggls-1-0                                    1/1     Running     0          2d13h   10.97.16.226   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-1                                    1/1     Running     0          2d13h   10.97.17.51    qa-node014.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-2                                    1/1     Running     0          2d13h   10.97.16.231   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-datacoord-849b96865-5qhdc     1/1     Running     0          2d13h   10.97.20.28    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-datanode-6cbc5c47d8-h9cgl     1/1     Running     0          2d13h   10.97.20.31    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-indexcoord-7db95b96b6-tkk5k   1/1     Running     0          2d13h   10.97.20.29    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-indexnode-85ff6847-cj8zr      1/1     Running     0          2d13h   10.97.20.37    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-proxy-6db5455b-qh5zd          1/1     Running     0          2d13h   10.97.20.32    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-querycoord-68f87c54bf-2xtb2   1/1     Running     0          2d13h   10.97.20.35    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-querynode-6c9cb85685-hhmwc    1/1     Running     0          2d13h   10.97.20.38    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-milvus-rootcoord-58794b6d69-bd4cb    1/1     Running     0          2d13h   10.97.20.30    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-minio-0                              1/1     Running     0          2d13h   10.97.20.43    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-minio-1                              1/1     Running     0          2d13h   10.97.16.218   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-minio-2                              1/1     Running     0          2d13h   10.97.20.44    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-minio-3                              1/1     Running     0          2d13h   10.97.20.45    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-bookie-0                      1/1     Running     0          2d13h   10.97.16.228   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-bookie-1                      1/1     Running     0          2d13h   10.97.16.220   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-bookie-2                      1/1     Running     0          2d13h   10.97.16.230   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-bookie-init-tld7k             0/1     Completed   0          2d13h   10.97.20.34    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-broker-0                      1/1     Running     0          2d13h   10.97.20.36    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-proxy-0                       1/1     Running     0          2d13h   10.97.20.39    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-pulsar-init-hxdlj             0/1     Completed   0          2d13h   10.97.20.33    qa-node018.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-recovery-0                    1/1     Running     0          2d13h   10.97.16.203   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-zookeeper-0                   1/1     Running     0          2d13h   10.97.16.215   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-zookeeper-1                   1/1     Running     0          2d13h   10.97.16.233   qa-node013.zilliz.local   <none>           <none>
test-etcd-no-clean-wggls-1-pulsar-zookeeper-2                   1/1     Running     0          2d13h   10.97.20.48    qa-node018.zilliz.local   <none>           <none>

2022-06-26 07:08:56,900] [   ERROR] - RPC error: [query], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 300s)>, <Time:{'RPC start': '2022-06-26 07:03:56.877886', 'RPC error': '2022-06-26 07:08:56.900408'}> (pymilvus.decorators:94)
[2022-06-26 07:08:56,901] [   ERROR] - RPC error: [query], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 300s)>, <Time:{'RPC start': '2022-06-26 06:47:56.812773', 'RPC error': '2022-06-26 07:08:56.901111'}> (pymilvus.decorators:94)
[2022-06-26 07:08:56,902] [   ERROR] - RPC error: [describe_collection], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888285', 'RPC error': '2022-06-26 07:08:56.902565'}> (pymilvus.decorators:94)
[2022-06-26 07:08:56,904] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888230', 'RPC error': '2022-06-26 07:08:56.904700'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,894] [   ERROR] - RPC error: [describe_collection], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888508', 'RPC error': '2022-06-26 07:09:56.894811'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,895] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888467', 'RPC error': '2022-06-26 07:09:56.895521'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,896] [   ERROR] - RPC error: [describe_collection], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888717', 'RPC error': '2022-06-26 07:09:56.896142'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,896] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:03:56.888666', 'RPC error': '2022-06-26 07:09:56.896646'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,897] [   DEBUG] - Milvus load_collection run in 360.0187s (milvus_benchmark.client:54)
[2022-06-26 07:09:56,897] [   DEBUG] - Milvus load_collection run in 360.0185s (milvus_benchmark.client:54)
[2022-06-26 07:09:56,899] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.890929149","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.878234', 'RPC error': '2022-06-26 07:09:56.899038'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,899] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.891887736","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.878610', 'RPC error': '2022-06-26 07:09:56.899535'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,900] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.891915221","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.879221', 'RPC error': '2022-06-26 07:09:56.900125'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,900] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.892885121","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.879033', 'RPC error': '2022-06-26 07:09:56.900632'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,901] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.892904077","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.879491', 'RPC error': '2022-06-26 07:09:56.901198'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,901] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.892916989","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.878839', 'RPC error': '2022-06-26 07:09:56.901816'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,902] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.892949317","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.879687', 'RPC error': '2022-06-26 07:09:56.902477'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,906] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=<_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1656227396.893873898","description":"Error received from peer ipv4:10.96.53.65:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>)>, <Time:{'RPC start': '2022-06-26 07:03:56.883874', 'RPC error': '2022-06-26 07:09:56.906748'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,910] [   ERROR] - RPC error: [describe_collection], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:08:56.901961', 'RPC error': '2022-06-26 07:09:56.909996'}> (pymilvus.decorators:94)
[2022-06-26 07:09:56,910] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:08:56.901904', 'RPC error': '2022-06-26 07:09:56.910443'}> (pymilvus.decorators:94)
[2022-06-26 07:14:56,901] [   ERROR] - RPC error: [describe_collection], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:08:56.902170', 'RPC error': '2022-06-26 07:14:56.900911'}> (pymilvus.decorators:94)
[2022-06-26 07:14:56,901] [   ERROR] - RPC error: [search], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 60s)>, <Time:{'RPC start': '2022-06-26 07:08:56.902132', 'RPC error': '2022-06-26 07:14:56.901697'}> (pymilvus.decorators:94)
[2022-06-26 07:14:56,903] [   ERROR] - RPC error: [query], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 300s)>, <Time:{'RPC start': '2022-06-26 06:53:56.832131', 'RPC error': '2022-06-26 07:14:56.903029'}> (pymilvus.decorators:94)
[2022-06-26 07:14:56,903] [   ERROR] - RPC error: [query], <MilvusException: (code=1, message=rpc deadline exceeded: Retry timeout: 300s)>, <Time:{'RPC start': '2022-06-26 06:53:56.832366', 'RPC error': '2022-06-26 07:14:56.903938'}> (pymilvus.decorators:94)

querynode’s tsafe stopped advancing around 6-22 04:07

rootcoord stopped sending timetick due to backlog quota exceeded

time="2022-06-26T04:07:49Z" level=info msg="Broker notification of Closed producer: 2" local_addr="10.97.20.30:59148" remote_addr="pulsar://test-etcd-no-clean-wggls-1-pulsar-proxy:6650"

time="2022-06-26T04:07:49Z" level=warning msg="[Connection was closed]" cnx="10.97.20.30:59148 -> 10.96.88.79:6650" producerID=2 producer_name=test-etcd-no-clean-wggls-1-pulsar-0-1 topic="persistent://public/default/by-dev-rootcoord-dml_1"

time="2022-06-26T04:07:49Z" level=info msg="[Reconnecting to broker in  106.244432ms]" producerID=2 producer_name=test-etcd-no-clean-wggls-1-pulsar-0-1 topic="persistent://public/default/by-dev-rootcoord-dml_1"

time="2022-06-26T04:07:56Z" level=error msg="[Failed to create producer]" error="server error: ProducerBlockedQuotaExceededException: Cannot create producer on topic with backlog quota exceeded" producerID=2 producer_name=test-etcd-no-clean-wggls-1-pulsar-0-1 topic="persistent://public/default/by-dev-rootcoord-dml_1"

xige-16 on Jun 28, 2022