milvus icon indicating copy to clipboard operation
milvus copied to clipboard

Published 20 hours ago • verified publisher icon milvus-io

[Bug]: [benchmark][standalone]Milvus insert delete scene reported error"force to deny/milvus.proto.milvus.MilvusService/Delete."

Open jingkl opened this issue 2 years ago • 8 comments

Is there an existing issue for this?

  • [X] I have searched the existing issues

Environment

- Milvus version:2.2.0-20221108-2e78872b
- Deployment mode(standalone or cluster):standalone
- SDK version(e.g. pymilvus v2.0.0rc2):2.2.0dev70
- OS(Ubuntu or CentOS): 
- CPU/Memory: 
- GPU: 
- Others:

Current Behavior

server-instance fouram-mrc8s-1 server-configmap server-single-8c32m256d-diskann client-configmap client-random-locust-compaction-high-search-diskann image：2.2.0-20221108-2e78872b pymilvus 2.2.0dev70

server:


fouram-mrc8s-1-etcd-0                                            1/1     Running   0             140m    10.104.6.113   4am-node13   <none>           <none>
fouram-mrc8s-1-milvus-standalone-5fb6dd566f-zps2h                1/1     Running   1 (64m ago)   140m    10.104.9.142   4am-node14   <none>           <none>
fouram-mrc8s-1-minio-6bcd7b6c65-xxklq                            1/1     Running   0             140m    10.104.6.114   4am-node13   <none>           <none>

client pod：fouram-mrc8s-369167784 client log:

[2022-11-08 13:41:44,534] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.947610', 'RPC error': '2022-11-08 13:41:44.534820'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,534] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.948445', 'RPC error': '2022-11-08 13:41:44.534975'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,535] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.948073', 'RPC error': '2022-11-08 13:41:44.535134'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,535] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.948800', 'RPC error': '2022-11-08 13:41:44.535514'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,535] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.949162', 'RPC error': '2022-11-08 13:41:44.535754'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,536] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.949489', 'RPC error': '2022-11-08 13:41:44.535994'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,536] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.949835', 'RPC error': '2022-11-08 13:41:44.536171'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,536] [   DEBUG] - Milvus get_info run in 1.1865s (milvus_benchmark.client:57)
[2022-11-08 13:41:44,536] [   DEBUG] - [scene_insert_delete_flush] Start insert sift_10w_128_l2, len:1 (milvus_benchmark.client:675)
[2022-11-08 13:41:44,536] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.950298', 'RPC error': '2022-11-08 13:41:44.536667'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,536] [   ERROR] - RPC error: [delete], <MilvusException: (code=48, message=force to deny /milvus.proto.milvus.M
ilvusService/Delete.)>, <Time:{'RPC start': '2022-11-08 13:41:43.950581', 'RPC error': '2022-11-08 13:41:44.536830'}> (pymilvus.deco
rators:108)
[2022-11-08 13:41:44,537] [   DEBUG] - Milvus get_info run in 1.1875s (milvus_benchmark.client:57)
[2022-11-08 13:41:44,537] [   DEBUG] - [scene_insert_delete_flush] Start insert sift_10w_128_l2, len:1 (milvus_benchmark.client:675)

search failed ： 截屏2022-11-09 11 05 05

scene_insert_delete_flush sends about 22w requests and our server memory is given 32GB, which is more than enough memory：

20221109-172735

Expected Behavior

No response

Steps To Reproduce

1.create an collection
2.build diskann index
3.insert 10w data
4.build index again
6.load data
7.search ,query, load, scene_insert_delete_flush->raise error

Milvus Log

No response

Anything else?

data:
  config.yaml: |
    locust_random_performance:
      collections:
        -
          collection_name: sift_10w_128_l2
          ni_per: 50000
          other_fields: float1
          build_index: true
          index_type: diskann
          index_param: {}
          task:
            types:
              -
                type: query
                weight: 1
                params:
                  top_k: 10
                  nq: 10
                  search_param:
                    search_list: 30
                  filters:
                    -
                      range: "{'range': {'float1': {'GT': -1.0, 'LT': collection_size * 0.5}}}"
              -
                type: load
                weight: 1
              -
                type: get
                weight: 1
                params:
                  ids_length: 10
              -
                type: scene_insert_delete_flush
                weight: 20
                params:
                  insert_len: 1
                  del_len: 1
            connection_num: 1
            clients_num: 100
            spawn_rate: 2
            during_time: 72h

@time_wrapper
    def scene_insert_delete_flush(self, collection_name=None, vectors=None, ids=None, del_len=30000):
        if collection_name is None:
            collection_name = self._collection_name

        logger.debug("[scene_insert_delete_flush] Start scene_insert_delete_flush : %s" % collection_name)
        collection_info = self.get_info(collection_name)

        entities = utils.generate_entities(collection_info, vectors, ids)
        logger.debug("[scene_insert_delete_flush] Start insert {0}, len:{1}".format(collection_name, len(ids)))
        self.insert(entities, collection_name=collection_name)

        logger.debug("[scene_insert_delete_flush] Start delete {0}, len:{1}".format(collection_name, del_len))
        self.delete(expr="id in {}".format(ids[:del_len]), collection_name=collection_name, timeout=300)

        logger.debug("[scene_insert_delete_flush] Start flush : %s" % collection_name)
        self.flush(collection_name=collection_name)
        logger.debug("[scene_insert_delete_flush] Finished scene_insert_delete_flush : %s" % collection_name)

jingkl avatar Nov 08 '22 13:11 jingkl

@jingkl does this issue reproduce ?

yanliang567 avatar Nov 23 '22 02:11 yanliang567

This problem still exists server-instance fouram-nhkrp-1 server-configmap server-single-8c32m256d-diskann client-configmap client-random-locust-compaction-high-search-diskann

image：2.2.2-20221219-ae5259ca pymilvus :2.2.1dev4

fouram-nhkrp-1-etcd-0                                             1/1     Running     0               18m     10.104.5.113   4am-node12   <none>           <none>
fouram-nhkrp-1-milvus-standalone-85dfbb4464-cpnlk                 1/1     Running     2 (3m44s ago)   18m     10.104.4.51    4am-node11   <none>           <none>
fouram-nhkrp-1-minio-69c4dc7c85-tn47k                             1/1     Running     0               18m     10.104.4.52    4am-node11   <none>           <none>

client log: 截屏2022-12-20 10 20 12

jingkl avatar Dec 20 '22 02:12 jingkl

This problem should be associated with diskann load：#20358

jingkl avatar Dec 20 '22 02:12 jingkl

/assign MrPresent-Han I will handle this

MrPresent-Han avatar Jan 04 '23 09:01 MrPresent-Han

/unassign

soothing-rain avatar Feb 03 '23 07:02 soothing-rain

This issue still exists. And OOM when milvus gave 8c64g

argo task: fouram-tag-no-clean-lpxx7

server-instance fouram-tag-no-clean-lpxx7-1 server-configmap server-single-8c64m256d-diskann client-configmap client-random-locust-compaction-high-search-diskann

image: 2.2.0-20230213-9c306b0d

server

fouram-tag-no-clean-lpxx7-1-etcd-0                                1/1     Running     0               19h     10.104.4.45    4am-node11   <none>           <none>
fouram-tag-no-clean-lpxx7-1-milvus-standalone-678bbbdb8b-rrx5c    1/1     Running     11 (18h ago)    19h     10.104.1.108   4am-node10   <none>           <none>
fouram-tag-no-clean-lpxx7-1-minio-84bf878bcc-qjk85                1/1     Running     0               19h     10.104.1.107   4am-node10   <none>           <none>

client pod: fouram-tag-no-clean-lpxx7-3323611136 client log image

milvus log image

Anything else?

client-random-locust-compaction-high-search-diskann

		  collections:
		    -
		      collection_name: sift_10w_128_l2
		      ni_per: 50000
		      # other_fields: int1,int2,float1,double1
		      other_fields: float1
		      build_index: true
		      index_type: diskann
		      index_param: {}
		      task:
		        types:
		          -
		            type: query
		            weight: 1
		            params:
		              top_k: 10
		              nq: 10
		              search_param:
		                search_list: 30
		              filters:
		                -
		                  range: \"{'range': {'float1': {'GT': -1.0, 'LT': collection_size * 0.5}}}\"
		          -
		            type: load
		            weight: 1
		          -
		            type: get
		            weight: 1
		            params:
		              ids_length: 10
		          -
		            type: scene_insert_delete_flush
		            weight: 20
		            params:
		              insert_len: 1
		              del_len: 1
		        connection_num: 1
		        clients_num: 100
		        spawn_rate: 2
		        # during_time: 84h
		        during_time: 12h

elstic avatar Feb 14 '23 06:02 elstic

@xige-16 @MrPresent-Han Recorded yesterday, can you look at this question

elstic avatar Feb 15 '23 02:02 elstic

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

stale[bot] avatar Mar 18 '23 22:03 stale[bot]

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

stale[bot] avatar Aug 02 '23 05:08 stale[bot]

this issue may be related to #23621 and probably has been fixed. Does the same problem reproduce now?

MrPresent-Han avatar Aug 07 '23 02:08 MrPresent-Han

Verified, no recent issues with change. Verified version: 2.2.0-20230804-13f69bfc

elstic avatar Aug 07 '23 08:08 elstic