search

milvus-io / milvus

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

[Bug]: Search raise error with message `[UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:56` after standalone pod kill for 2.1 branch #19344

Closed zhuwenxing closed 1 year ago

zhuwenxing commented 1 year ago

Is there an existing issue for this?

Environment

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

Current Behavior

collection name: Checker__IEtjaysh

[2022-09-21T09:32:13.307Z] [2022-09-21 09:32:12 - ERROR - pymilvus.decorators]: RPC error: [search], <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=120, reason=Search 120 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:56
[2022-09-21T09:32:13.307Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>, <Time:{'RPC start': '2022-09-21 09:32:12.346867', 'RPC error': '2022-09-21 09:32:12.704574'}> (decorators.py:100)
[2022-09-21T09:32:13.307Z] [2022-09-21 09:32:12 - ERROR - ci_test]: Traceback (most recent call last):
[2022-09-21T09:32:13.307Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 26, in inner_wrapper
[2022-09-21T09:32:13.307Z]     res = func(*args, **_kwargs)
[2022-09-21T09:32:13.307Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 57, in api_request
[2022-09-21T09:32:13.307Z]     return func(*arg, **kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/orm/collection.py", line 718, in search
[2022-09-21T09:32:13.307Z]     partition_names, output_fields, round_decimal, timeout=timeout, schema=schema_dict, **kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 101, in handler
[2022-09-21T09:32:13.307Z]     raise e
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 97, in handler
[2022-09-21T09:32:13.307Z]     return func(*args, **kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 127, in handler
[2022-09-21T09:32:13.307Z]     ret = func(self, *args, **kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 79, in handler
[2022-09-21T09:32:13.307Z]     raise e
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 50, in handler
[2022-09-21T09:32:13.307Z]     return func(self, *args, **kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 472, in search
[2022-09-21T09:32:13.307Z]     return self._execute_search_requests(requests, timeout, **_kwargs)
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 436, in _execute_search_requests
[2022-09-21T09:32:13.307Z]     raise pre_err
[2022-09-21T09:32:13.307Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 427, in _execute_search_requests
[2022-09-21T09:32:13.307Z]     raise MilvusException(response.status.error_code, response.status.reason)
[2022-09-21T09:32:13.307Z] pymilvus.exceptions.MilvusException: <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=120, reason=Search 120 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:56
[2022-09-21T09:32:13.307Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>
[2022-09-21T09:32:13.307Z]  (api_request.py:39)

Expected Behavior

all test cases passed

Steps To Reproduce

No response

Milvus Log

failed job:https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-for-release/detail/chaos-test-for-release/737/pipeline/245

log: artifacts-standalone-pod-kill-737-server-logs.tar.gz

artifacts-standalone-pod-kill-737-pytest-logs.tar.gz

Anything else?

No response

yanliang567 commented 1 year ago

/assign @jiaoew1991 /unassign

jiaoew1991 commented 1 year ago

It's a parameter checker in Knowhere, if search params is wrong the error is reasonable

jiaoew1991 commented 1 year ago

@cydrain please take a look

zhuwenxing commented 1 year ago

It's a parameter checker in Knowhere, if search params is wrong the error is reasonable

The parameter should be correct because it works well before for the same test code.

zhuwenxing commented 1 year ago

chaos type: pod-kill image tag: 2.1.0-20220923-0375e802 target pod: standalone

failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-for-release-debug/detail/chaos-test-for-release-debug/8/pipeline

log: artifacts-standalone-pod-kill-8-server-logs.tar.gz artifacts-standalone-pod-kill-8-pytest-logs.tar.gz

zhuwenxing commented 1 year ago

The test script is: https://github.com/milvus-io/milvus/blob/master/tests/python_client/chaos/testcases/test_verify_all_collections.py

The code for search is 

    @trace()
    def search(self):
        res, result = self.c_wrap.search(
            data=cf.gen_vectors(5, ct.default_dim),
            anns_field=ct.default_float_vec_field_name,
            param={"nprobe": 32},
            limit=1,
            timeout=timeout,
            check_task=CheckTasks.check_nothing
        )
        return res, result
zhuwenxing commented 1 year ago

It also reproduced after querynode pod kill

failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-for-release-debug/detail/chaos-test-for-release-debug/10/pipeline

log: artifacts-querynode-pod-kill-10-server-logs.tar.gz

artifacts-querynode-pod-kill-10-pytest-logs.tar.gz

cydrain commented 1 year ago

hi @jiaoew1991 , I dump out the config before knowhere API is called, you can see "nprobe" setting is already missing. You need check what causes "nprobe" setting missing from config. artifacts-standalone-pod-kill-14-server-logs.tar.gz

CYD - Search config: {"k":1,"metric_type":"L2"}
[2022/09/24 05:25:54.766 +00:00] [DEBUG] [querynode/segment.go:333] ["do search on segment done"] [msgID=436206828880273991] [segmentID=436206691044818945] [segmentType=Sealed] [loadIndex=false]
[2022/09/24 05:25:54.766 +00:00] [DEBUG] [querynode/segment.go:316] ["start do search on segment"] [msgID=436206828880273991] [segmentID=436206684648505348] [segmentType=Sealed] [loadIndex=false]
Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
 => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist
[2022/09/24 05:25:54.766 +00:00] [DEBUG] [querynode/segment.go:316] ["start do search on segment"] [msgID=436206828880273991] [segmentID=436206716512108548] [segmentType=Sealed] [loadIndex=false]
[2022/09/24 05:25:54.766 +00:00] [WARN] [querynode/cgo_helper.go:57] ["Search failed, C Runtime Exception: [UnexpectedError] Assert \"false\" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59\n => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist\n"]
jiaoew1991 commented 1 year ago

@zhuwenxing the param is wrong, you should pass search_params like this

image

https://milvus.io/api-reference/pymilvus/v2.1.2/Collection/search().md

jiaoew1991 commented 1 year ago

/unassign /assign @zhuwenxing

zhuwenxing commented 1 year ago

I think it is not the root cause, because, with the param in my code, It works well at the beginning time, but after some time, then it raises the error.

[2022-09-24T05:06:13.288Z] testcases/test_verify_all_collections.py::TestOperations::test_operations[DeleteChecker__89VbCBJT] 
[2022-09-24T05:06:13.288Z] -------------------------------- live log setup --------------------------------
[2022-09-24T05:06:13.288Z] [2022-09-24 05:06:13 - INFO - ci_test]: ################################################################################ (conftest.py:189)
[2022-09-24T05:06:13.288Z] [2022-09-24 05:06:13 - INFO - ci_test]: [initialize_milvus] Log cleaned up, start testing... (conftest.py:190)
[2022-09-24T05:06:13.288Z] [2022-09-24 05:06:13 - INFO - ci_test]: connect to milvus successfully (test_verify_all_collections.py:66)
[2022-09-24T05:06:13.288Z] -------------------------------- live log call ---------------------------------
[2022-09-24T05:06:13.288Z] [2022-09-24 05:06:13 - INFO - ci_test]: *********************Test Start********************** (test_verify_all_collections.py:87)
[2022-09-24T05:06:13.288Z] [2022-09-24 05:06:13 - INFO - ci_test]: {'address': '10.101.118.11:19530', 'user': ''} (test_verify_all_collections.py:88)
[2022-09-24T05:06:39.805Z] [2022-09-24 05:06:36 - INFO - ci_test]: *********************Request Load Start********************** (test_verify_all_collections.py:92)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 012, average_time: 0.0115, max_time: 0.0197, min_time: 0.0082 (checker.py:126)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 003, average_time: 2.5340, max_time: 2.5384, min_time: 2.5259 (checker.py:126)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 002, average_time: 3.8509, max_time: 4.6118, min_time: 3.0901 (checker.py:126)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 010, average_time: 0.2106, max_time: 0.3726, min_time: 0.1578 (checker.py:126)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 010, average_time: 0.2091, max_time: 0.3166, min_time: 0.1649 (checker.py:126)
[2022-09-24T05:06:49.735Z] [2022-09-24 05:06:48 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 012, average_time: 0.0053, max_time: 0.0213, min_time: 0.0023 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 024, average_time: 0.0128, max_time: 0.0378, min_time: 0.0075 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 006, average_time: 2.7017, max_time: 3.0437, min_time: 2.5259 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 005, average_time: 3.3793, max_time: 4.6118, min_time: 3.0481 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 020, average_time: 0.2043, max_time: 0.3726, min_time: 0.1578 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 020, average_time: 0.2042, max_time: 0.3166, min_time: 0.1649 (checker.py:126)
[2022-09-24T05:07:01.893Z] [2022-09-24 05:07:00 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 024, average_time: 0.0046, max_time: 0.0213, min_time: 0.0022 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 036, average_time: 0.0138, max_time: 0.0378, min_time: 0.0075 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 010, average_time: 2.6861, max_time: 3.0437, min_time: 2.5220 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 008, average_time: 3.5776, max_time: 5.1134, min_time: 3.0481 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 030, average_time: 0.2137, max_time: 0.3989, min_time: 0.1578 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 030, average_time: 0.2052, max_time: 0.3166, min_time: 0.1649 (checker.py:126)
[2022-09-24T05:07:14.048Z] [2022-09-24 05:07:12 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 036, average_time: 0.0046, max_time: 0.0213, min_time: 0.0022 (checker.py:126)
[2022-09-24T05:07:26.205Z] [2022-09-24 05:07:24 - ERROR - pymilvus.decorators]: RPC error: [search], <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=124, reason=Search 124 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
[2022-09-24T05:07:26.205Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>, <Time:{'RPC start': '2022-09-24 05:07:24.217823', 'RPC error': '2022-09-24 05:07:24.412447'}> (decorators.py:100)
[2022-09-24T05:07:26.205Z] [2022-09-24 05:07:24 - ERROR - ci_test]: Traceback (most recent call last):
[2022-09-24T05:07:26.205Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 26, in inner_wrapper
[2022-09-24T05:07:26.205Z]     res = func(*args, **_kwargs)
[2022-09-24T05:07:26.205Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 57, in api_request
[2022-09-24T05:07:26.205Z]     return func(*arg, **kwargs)
[2022-09-24T05:07:26.205Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/orm/collection.py", line 718, in search
[2022-09-24T05:07:26.205Z]     partition_names, output_fields, round_decimal, timeout=timeout, schema=schema_dict, **kwargs)
[2022-09-24T05:07:26.205Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 101, in handler
[2022-09-24T05:07:26.205Z]     raise e
[2022-09-24T05:07:26.205Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 97, in handler
[2022-09-24T05:07:26.205Z]     return func(*args, **kwargs)
[2022-09-24T05:07:26.205Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 127, in handler
[2022-09-24T05:07:26.205Z]     ret = func(self, *args, **kwargs)
[2022-09-24T05:07:26.205Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 79, in handler
[2022-09-24T05:07:26.205Z]     raise e
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 50, in handler
[2022-09-24T05:07:26.206Z]     return func(self, *args, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 472, in search
[2022-09-24T05:07:26.206Z]     return self._execute_search_requests(requests, timeout, **_kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 436, in _execute_search_requests
[2022-09-24T05:07:26.206Z]     raise pre_err
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 427, in _execute_search_requests
[2022-09-24T05:07:26.206Z]     raise MilvusException(response.status.error_code, response.status.reason)
[2022-09-24T05:07:26.206Z] pymilvus.exceptions.MilvusException: <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=124, reason=Search 124 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
[2022-09-24T05:07:26.206Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>
[2022-09-24T05:07:26.206Z]  (api_request.py:39)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - ERROR - ci_test]: (api_response) : <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=124, reason=Search 124 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
[2022-09-24T05:07:26.206Z]  => Error in void knowhere::CheckIntege...... (api_request.py:40)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 048, average_time: 0.0129, max_time: 0.0378, min_time: 0.0075 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 013, average_time: 2.6496, max_time: 3.0437, min_time: 2.5198 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 010, average_time: 3.5819, max_time: 5.1134, min_time: 3.0481 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: SearchChecker, succ_rate: 0.97, total: 040, average_time: 0.2121, max_time: 0.3989, min_time: 0.1578 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 040, average_time: 0.2063, max_time: 0.3166, min_time: 0.1649 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:24 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 048, average_time: 0.0044, max_time: 0.0213, min_time: 0.0022 (checker.py:126)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:25 - ERROR - pymilvus.decorators]: RPC error: [search], <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=124, reason=Search 124 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
[2022-09-24T05:07:26.206Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>, <Time:{'RPC start': '2022-09-24 05:07:25.416948', 'RPC error': '2022-09-24 05:07:25.611036'}> (decorators.py:100)
[2022-09-24T05:07:26.206Z] [2022-09-24 05:07:25 - ERROR - ci_test]: Traceback (most recent call last):
[2022-09-24T05:07:26.206Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 26, in inner_wrapper
[2022-09-24T05:07:26.206Z]     res = func(*args, **_kwargs)
[2022-09-24T05:07:26.206Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 57, in api_request
[2022-09-24T05:07:26.206Z]     return func(*arg, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/orm/collection.py", line 718, in search
[2022-09-24T05:07:26.206Z]     partition_names, output_fields, round_decimal, timeout=timeout, schema=schema_dict, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 101, in handler
[2022-09-24T05:07:26.206Z]     raise e
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 97, in handler
[2022-09-24T05:07:26.206Z]     return func(*args, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 127, in handler
[2022-09-24T05:07:26.206Z]     ret = func(self, *args, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 79, in handler
[2022-09-24T05:07:26.206Z]     raise e
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/decorators.py", line 50, in handler
[2022-09-24T05:07:26.206Z]     return func(self, *args, **kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 472, in search
[2022-09-24T05:07:26.206Z]     return self._execute_search_requests(requests, timeout, **_kwargs)
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 436, in _execute_search_requests
[2022-09-24T05:07:26.206Z]     raise pre_err
[2022-09-24T05:07:26.206Z]   File "/usr/local/lib/python3.7/dist-packages/pymilvus/client/grpc_handler.py", line 427, in _execute_search_requests
[2022-09-24T05:07:26.206Z]     raise MilvusException(response.status.error_code, response.status.reason)
[2022-09-24T05:07:26.206Z] pymilvus.exceptions.MilvusException: <MilvusException: (code=1, message=fail to search on all shard leaders, err=fail to Search, QueryNode ID=124, reason=Search 124 failed, reason [UnexpectedError] Assert "false" at /go/src/github.com/milvus-io/milvus/internal/core/src/query/SearchOnSealed.cpp:59
[2022-09-24T05:07:26.206Z]  => Error in void knowhere::CheckIntegerRange(const Config&, const string&, int64_t, int64_t) at ConfAdapter.cpp:53: Param 'nprobe' not exist err %!w(<nil>))>
[2022-09-24T05:07:26.206Z]  (api_request.py:39)
zhuwenxing commented 1 year ago

When the search param is complete like {"metric_type": "L2", "params": {"nprobe": 16}}, this issue not reproduced.

[2022-09-26T09:22:53.312Z] testcases/test_verify_all_collections.py::TestOperations::test_operations[Checker__zhFxZeE7] 

[2022-09-26T09:22:53.312Z] -------------------------------- live log setup --------------------------------

[2022-09-26T09:22:53.312Z] [2022-09-26 09:22:52 - INFO - ci_test]: connect to milvus successfully (test_verify_all_collections.py:66)

[2022-09-26T09:22:53.312Z] -------------------------------- live log call ---------------------------------

[2022-09-26T09:22:53.312Z] [2022-09-26 09:22:52 - INFO - ci_test]: *********************Test Start********************** (test_verify_all_collections.py:87)

[2022-09-26T09:22:53.312Z] [2022-09-26 09:22:52 - INFO - ci_test]: {'address': '10.101.141.144:19530', 'user': ''} (test_verify_all_collections.py:88)

[2022-09-26T09:23:25.311Z] [2022-09-26 09:23:22 - INFO - ci_test]: *********************Request Load Start********************** (test_verify_all_collections.py:92)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 012, average_time: 0.0119, max_time: 0.0303, min_time: 0.0068 (checker.py:126)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 003, average_time: 2.8687, max_time: 3.0752, min_time: 2.5172 (checker.py:126)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 001, average_time: 6.6271, max_time: 6.6271, min_time: 6.6271 (checker.py:126)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 010, average_time: 0.2873, max_time: 0.4087, min_time: 0.1647 (checker.py:126)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 010, average_time: 0.2855, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:23:35.233Z] [2022-09-26 09:23:34 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 012, average_time: 0.0029, max_time: 0.0093, min_time: 0.0019 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 024, average_time: 0.0109, max_time: 0.0303, min_time: 0.0066 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 006, average_time: 2.8612, max_time: 3.0752, min_time: 2.5172 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 003, average_time: 6.0328, max_time: 6.6271, min_time: 5.7341 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 019, average_time: 0.2882, max_time: 0.4455, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 019, average_time: 0.2603, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:23:47.383Z] [2022-09-26 09:23:46 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 024, average_time: 0.0028, max_time: 0.0093, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 036, average_time: 0.0105, max_time: 0.0303, min_time: 0.0057 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 009, average_time: 2.8624, max_time: 3.0752, min_time: 2.5154 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 005, average_time: 5.8727, max_time: 6.6271, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 027, average_time: 0.3218, max_time: 0.4984, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 029, average_time: 0.2621, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:23:59.534Z] [2022-09-26 09:23:58 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 036, average_time: 0.0029, max_time: 0.0125, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 048, average_time: 0.0106, max_time: 0.0303, min_time: 0.0057 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 012, average_time: 2.8251, max_time: 3.0752, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 007, average_time: 5.8293, max_time: 6.6271, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 036, average_time: 0.3307, max_time: 0.4984, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 038, average_time: 0.2667, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:24:11.689Z] [2022-09-26 09:24:10 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 048, average_time: 0.0034, max_time: 0.0143, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 060, average_time: 0.0155, max_time: 0.2388, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 015, average_time: 2.8697, max_time: 3.1065, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 008, average_time: 5.8711, max_time: 6.6271, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 046, average_time: 0.3202, max_time: 0.4984, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 048, average_time: 0.2649, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:24:23.849Z] [2022-09-26 09:24:22 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 060, average_time: 0.0033, max_time: 0.0143, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 071, average_time: 0.0218, max_time: 0.2388, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 018, average_time: 2.9345, max_time: 4.2132, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 009, average_time: 5.9544, max_time: 6.6271, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 054, average_time: 0.3348, max_time: 0.5121, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 057, average_time: 0.2648, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:24:36.007Z] [2022-09-26 09:24:34 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 072, average_time: 0.0033, max_time: 0.0143, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 082, average_time: 0.0315, max_time: 0.3768, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 020, average_time: 3.1033, max_time: 6.1207, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 011, average_time: 6.5832, max_time: 9.8440, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 064, average_time: 0.3263, max_time: 0.5121, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 067, average_time: 0.2666, max_time: 0.4722, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:24:48.161Z] [2022-09-26 09:24:46 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 084, average_time: 0.0032, max_time: 0.0143, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 094, average_time: 0.0287, max_time: 0.3768, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 023, average_time: 3.1034, max_time: 6.1207, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 012, average_time: 6.5525, max_time: 9.8440, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 072, average_time: 0.3333, max_time: 0.5121, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 075, average_time: 0.2794, max_time: 0.4873, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:25:00.310Z] [2022-09-26 09:24:58 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 096, average_time: 0.0032, max_time: 0.0143, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 106, average_time: 0.0266, max_time: 0.3768, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 026, average_time: 3.0584, max_time: 6.1207, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 014, average_time: 6.4954, max_time: 9.8440, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 081, average_time: 0.3404, max_time: 0.5121, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 085, average_time: 0.2771, max_time: 0.4873, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:25:10.292Z] [2022-09-26 09:25:10 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 108, average_time: 0.0035, max_time: 0.0211, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: InsertChecker, succ_rate: 1.00, total: 118, average_time: 0.0251, max_time: 0.3768, min_time: 0.0056 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: FlushChecker, succ_rate: 1.00, total: 030, average_time: 2.9993, max_time: 6.1207, min_time: 2.5140 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: IndexChecker, succ_rate: 1.00, total: 016, average_time: 6.5224, max_time: 9.8440, min_time: 5.1134 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: SearchChecker, succ_rate: 1.00, total: 090, average_time: 0.3442, max_time: 0.5121, min_time: 0.1628 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: QueryChecker, succ_rate: 1.00, total: 094, average_time: 0.2846, max_time: 0.4873, min_time: 0.1345 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: DeleteChecker, succ_rate: 1.00, total: 120, average_time: 0.0034, max_time: 0.0211, min_time: 0.0015 (checker.py:126)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: ******assert after chaos deleted:  (test_verify_all_collections.py:102)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.insert succ rate 1.0, total: 118, average time: 0.0251 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.flush succ rate 1.0, total: 30, average time: 2.9993 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.index succ rate 1.0, total: 16, average time: 6.5224 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.search succ rate 1.0, total: 90, average time: 0.3442 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.query succ rate 1.0, total: 94, average time: 0.2846 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: Expect Succ: Op.delete succ rate 1.0, total: 120, average time: 0.0034 (chaos_commons.py:87)

[2022-09-26T09:25:22.447Z] [2022-09-26 09:25:22 - INFO - ci_test]: *********************Test Completed********************** (test_verify_all_collections.py:105)

[2022-09-26T09:25:22.447Z] PASSED