search

milvus-io / milvus

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

[Bug]: After Milvus recovered from a pod kill chaos in the querynode, there was a timeout issue with load/release in the test. #37466

Open zhuwenxing opened 2 days ago

zhuwenxing commented 2 days ago

Is there an existing issue for this?

Environment

- Milvus version:master-20241104-f54cf418-amd64
- Deployment mode(standalone or 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

load timeout

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: [initialize_milvus] Log cleaned up, start testing... (conftest.py:233)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: [setup_class] Start setup class... (client_base.py:41)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: *********************************** setup *********************************** (client_base.py:47)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: pymilvus version: 2.5.0rc106 (client_base.py:48)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: [setup_method] Start setup test case test_milvus_default. (client_base.py:49)

[2024-11-04T08:39:12.379Z] ------------------------------ Captured log call -------------------------------

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [Connections.connect] args: ['default', '', '', 'default', ''], kwargs: {'host': '10.255.62.25', 'port': 19530} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: server version: f54cf41 (client_base.py:166)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [list_database] args: ['default', None], kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : ['default', 'prod']  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: all database: ['default', 'prod'] (test_data_persistence.py:26)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [using_database] args: ['default', 'default'], kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['int64', <DataType.INT64: 5>, ''], kwargs: {'is_primary': False, 'is_partition_key': False, 'nullable': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['varchar', <DataType.VARCHAR: 21>, ''], kwargs: {'max_length': 65535, 'is_primary': False, 'is_partition_key': False, 'nullable': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float_vector', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'name': 'float_vector', 'description': '', 'type': <DataType.FLOAT_VECTOR: 101>, 'params': {'dim': 128}}  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float', <DataType.FLOAT: 10>, ''], kwargs: {'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['json_field', <DataType.JSON: 23>, ''], kwargs: {'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'name': 'json_field', 'description': '', 'type': <DataType.JSON: 23>}  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [CollectionSchema] args: [[{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}, {'name': 'json_field', 'description': '', 'type': <DataTyp......, kwargs: {'primary_field': 'int64', 'auto_id': False, 'enable_dynamic_field': False} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params......  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [Connections.has_connection] args: ['default'], kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : True  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Hello_Milvus', {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARC......, kwargs: {'consistency_level': 'Strong'} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : <Collection>:

[2024-11-04T08:39:12.379Z] -------------

[2024-11-04T08:39:12.379Z] <name>: Hello_Milvus

[2024-11-04T08:39:12.379Z] <description>: 

[2024-11-04T08:39:12.379Z] <schema>: {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'n......  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.379Z] [2024-11-04 08:30:32 - INFO - ci_test]: [test][2024-11-04T08:30:32Z] [0.55438854s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:32 - INFO - ci_test]: assert create collection: 0.06269669532775879, init_entities: 4000 (test_data_persistence.py:38)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:33 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[0          0

[2024-11-04T08:39:12.380Z] 1          1

[2024-11-04T08:39:12.380Z] 2          2

[2024-11-04T08:39:12.380Z] 3          3

[2024-11-04T08:39:12.380Z] 4          4

[2024-11-04T08:39:12.380Z]         ... 

[2024-11-04T08:39:12.380Z] 1995    1995

[2024-11-04T08:39:12.380Z] 1996    1996

[2024-11-04T08:39:12.380Z] 1997    1997

[2024-11-04T08:39:12.380Z] 1998    1998

[2024-11-04T08:39:12.380Z] 1999    1999

[2024-11-04T08:39:12.380Z] Length: 2000, dtype: int64, 0          0.0

[2024-11-04T08:39:12.380Z] 1          1.0

[2024-11-04T08:39:12.380Z] 2          2.0

[2024-11-04T08:39:12.380Z] 3          3.0

[2024-11-04T08:39:12.380Z] 4          4.0

[2024-11-04T08:39:12.380Z]          ...  

[2024-11-04T08:39:12.380Z] 1995    1995.0

[2024-11-04T08:39:12.380Z] 1996    1996.0

[2024-11-04T08:39:12.380Z] 1997   ......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:33 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453694988847415302, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:33 - INFO - ci_test]: [test][2024-11-04T08:30:33Z] [0.44906064s] Hello_Milvus insert -> (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453694988847415302, success count: 2000, err count: 0 (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:33 - INFO - ci_test]: assert insert: 0.44932007789611816 (test_data_persistence.py:45)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:33 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:44 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:44 - INFO - ci_test]: [test][2024-11-04T08:30:33Z] [10.79816395s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:44 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:54 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:54 - INFO - ci_test]: [test][2024-11-04T08:30:44Z] [10.28998629s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:30:54 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:04 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:04 - INFO - ci_test]: [test][2024-11-04T08:30:54Z] [10.36346526s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:04 - INFO - ci_test]: assert flush: 21.1387357711792, entities: 6000 (test_data_persistence.py:55)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - INFO - ci_test]: index info: [{'collection': 'Hello_Milvus', 'field': 'float_vector', 'index_name': 'test_UZwgVnCl', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Hello_Milvus', 'field': 'varchar', 'index_name': 'test_iJygBltn', 'index_param': {}}] (test_data_persistence.py:74)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - INFO - ci_test]: [test][2024-11-04T08:31:05Z] [0.05531953s] Hello_Milvus load -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_request)  : [Collection.search] args: [[[0.13762567019612615, 0.09812831146932842, 0.10553818672911264, 0.05135825942101038, 0.002457778534642566, 0.07402827253421998, 0.12595026878000393, 0.10520446227366506, 0.06752785669946733, 0.0700777847919367, 0.02027106608734192, 0.0913139639179615, 0.14394231498180546, 0.016736850998097106, 0.0......, kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_response) : data: ["['id: 1314, distance: 0.31922557950019836, entity: {}']"]  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - INFO - ci_test]: [test][2024-11-04T08:31:05Z] [0.21494975s] Hello_Milvus search -> data: ["['id: 1314, distance: 0.31922557950019836, entity: {}']"] (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - INFO - ci_test]: assert search: 0.2155914306640625 (test_data_persistence.py:86)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_request)  : [Collection.release] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:05 - INFO - ci_test]: [test][2024-11-04T08:31:05Z] [0.61651183s] Hello_Milvus release -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:06 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[0          0

[2024-11-04T08:39:12.380Z] 1          1

[2024-11-04T08:39:12.380Z] 2          2

[2024-11-04T08:39:12.380Z] 3          3

[2024-11-04T08:39:12.380Z] 4          4

[2024-11-04T08:39:12.380Z]         ... 

[2024-11-04T08:39:12.380Z] 1995    1995

[2024-11-04T08:39:12.380Z] 1996    1996

[2024-11-04T08:39:12.380Z] 1997    1997

[2024-11-04T08:39:12.380Z] 1998    1998

[2024-11-04T08:39:12.380Z] 1999    1999

[2024-11-04T08:39:12.380Z] Length: 2000, dtype: int64, 0          0.0

[2024-11-04T08:39:12.380Z] 1          1.0

[2024-11-04T08:39:12.380Z] 2          2.0

[2024-11-04T08:39:12.380Z] 3          3.0

[2024-11-04T08:39:12.380Z] 4          4.0

[2024-11-04T08:39:12.380Z]          ...  

[2024-11-04T08:39:12.380Z] 1995    1995.0

[2024-11-04T08:39:12.380Z] 1996    1996.0

[2024-11-04T08:39:12.380Z] 1997   ......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:06 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453694997498429442, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:06 - INFO - ci_test]: [test][2024-11-04T08:31:06Z] [0.35240082s] Hello_Milvus insert -> (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453694997498429442, success count: 2000, err count: 0 (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:06 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:17 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:17 - INFO - ci_test]: [test][2024-11-04T08:31:06Z] [10.73845173s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:17 - INFO - ci_test]: assert entities: 8000 (test_data_persistence.py:93)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:31:17 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:34:17 - ERROR - pymilvus.decorators]: RPC error: [wait_for_loading_collection], <MilvusException: (code=1, message=wait for loading collection timeout, collection: Hello_Milvus)>, <Time:{'RPC start': '2024-11-04 08:31:17.258853', 'RPC error': '2024-11-04 08:34:17.320883'}> (decorators.py:140)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:34:17 - WARNING - pymilvus.decorators]: Retry timeout: 180s (decorators.py:106)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:34:17 - ERROR - pymilvus.decorators]: RPC error: [load_collection], <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)>, <Time:{'RPC start': '2024-11-04 08:31:17.218893', 'RPC error': '2024-11-04 08:34:17.321416'}> (decorators.py:140)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:34:17 - ERROR - ci_test]: Traceback (most recent call last):

[2024-11-04T08:39:12.380Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 32, in inner_wrapper

[2024-11-04T08:39:12.380Z]     res = func(*args, **_kwargs)

[2024-11-04T08:39:12.380Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 63, in api_request

[2024-11-04T08:39:12.380Z]     return func(*arg, **kwargs)

[2024-11-04T08:39:12.380Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/orm/collection.py", line 429, in load

[2024-11-04T08:39:12.380Z]     conn.load_collection(

[2024-11-04T08:39:12.380Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 141, in handler

[2024-11-04T08:39:12.380Z]     raise e from e

[2024-11-04T08:39:12.380Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 137, in handler

[2024-11-04T08:39:12.380Z]     return func(*args, **kwargs)

[2024-11-04T08:39:12.380Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 176, in handler

[2024-11-04T08:39:12.380Z]     return func(self, *args, **kwargs)

[2024-11-04T08:39:12.380Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 107, in handler

[2024-11-04T08:39:12.380Z]     raise MilvusException(

[2024-11-04T08:39:12.380Z] pymilvus.exceptions.MilvusException: <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)>

[2024-11-04T08:39:12.380Z]  (api_request.py:45)

[2024-11-04T08:39:12.380Z] [2024-11-04 08:34:17 - ERROR - ci_test]: (api_response) : <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)> (api_request.py:46)
[2024-11-04T08:44:51.710Z] [gw3] linux -- Python 3.8.10 /usr/bin/python3.8

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z] self = <test_all_collections_after_chaos.TestAllCollection object at 0x7f9898501e50>

[2024-11-04T08:44:51.710Z] collection_name = 'Checker__Pezmr05g'

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z]     @pytest.mark.tags(CaseLabel.L1)

[2024-11-04T08:44:51.710Z]     def test_milvus_default(self, collection_name):

[2024-11-04T08:44:51.710Z]         self._connect()

[2024-11-04T08:44:51.710Z]         # create

[2024-11-04T08:44:51.710Z]         name = collection_name if collection_name else cf.gen_unique_str("Checker_")

[2024-11-04T08:44:51.710Z]         t0 = time.time()

[2024-11-04T08:44:51.710Z]         schema = Collection(name=name).schema

[2024-11-04T08:44:51.710Z]         collection_w = self.init_collection_wrap(name=name, schema=schema)

[2024-11-04T08:44:51.710Z]         tt = time.time() - t0

[2024-11-04T08:44:51.710Z]         assert collection_w.name == name

[2024-11-04T08:44:51.710Z]         # get collection info

[2024-11-04T08:44:51.710Z]         schema = collection_w.schema

[2024-11-04T08:44:51.710Z]         dim = cf.get_dim_by_schema(schema=schema)

[2024-11-04T08:44:51.710Z]         int64_field_name = cf.get_int64_field_name(schema=schema)

[2024-11-04T08:44:51.710Z]         float_vector_field_name = cf.get_float_vec_field_name(schema=schema)

[2024-11-04T08:44:51.710Z]         float_vector_field_name_list = cf.get_float_vec_field_name_list(schema=schema)

[2024-11-04T08:44:51.710Z]         # compact collection before getting num_entities

[2024-11-04T08:44:51.710Z]         collection_w.flush(timeout=180)

[2024-11-04T08:44:51.710Z]         collection_w.compact()

[2024-11-04T08:44:51.710Z]         collection_w.wait_for_compaction_completed(timeout=720)

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         entities = collection_w.num_entities

[2024-11-04T08:44:51.710Z]         log.info(f"assert create collection: {tt}, init_entities: {entities}")

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # insert

[2024-11-04T08:44:51.710Z]         offset = -3000

[2024-11-04T08:44:51.710Z]         data = cf.gen_row_data_by_schema(nb=ct.default_nb, schema=schema, start=offset)

[2024-11-04T08:44:51.710Z]         t0 = time.time()

[2024-11-04T08:44:51.710Z]         _, res = collection_w.insert(data)

[2024-11-04T08:44:51.710Z]         tt = time.time() - t0

[2024-11-04T08:44:51.710Z]         log.info(f"assert insert: {tt}")

[2024-11-04T08:44:51.710Z]         assert res

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # flush

[2024-11-04T08:44:51.710Z]         t0 = time.time()

[2024-11-04T08:44:51.710Z]         _, check_result = collection_w.flush(timeout=180)

[2024-11-04T08:44:51.710Z]         assert check_result

[2024-11-04T08:44:51.710Z]         # assert collection_w.num_entities == len(data[0]) + entities

[2024-11-04T08:44:51.710Z]         tt = time.time() - t0

[2024-11-04T08:44:51.710Z]         entities = collection_w.num_entities

[2024-11-04T08:44:51.710Z]         log.info(f"assert flush: {tt}, entities: {entities}")

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # show index infos

[2024-11-04T08:44:51.710Z]         index_infos = [index.to_dict() for index in collection_w.indexes]

[2024-11-04T08:44:51.710Z]         log.info(f"index info: {index_infos}")

[2024-11-04T08:44:51.710Z]         fields_created_index = [index["field"] for index in index_infos]

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # create index if not have

[2024-11-04T08:44:51.710Z]         index_params = {"index_type": "HNSW", "metric_type": "L2", "params": {"M": 48, "efConstruction": 500}}

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         for f in float_vector_field_name_list:

[2024-11-04T08:44:51.710Z]             if f not in fields_created_index:

[2024-11-04T08:44:51.710Z]                 t0 = time.time()

[2024-11-04T08:44:51.710Z]                 index, _ = collection_w.create_index(field_name=float_vector_field_name,

[2024-11-04T08:44:51.710Z]                                                      index_params=index_params)

[2024-11-04T08:44:51.710Z]                 tt = time.time() - t0

[2024-11-04T08:44:51.710Z]                 log.info(f"create index for field {f} cost: {tt} seconds")

[2024-11-04T08:44:51.710Z]         # show index infos

[2024-11-04T08:44:51.710Z]         index_infos = [index.to_dict() for index in collection_w.indexes]

[2024-11-04T08:44:51.710Z]         log.info(f"index info: {index_infos}")

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # load

[2024-11-04T08:44:51.710Z]         collection_w.load()

[2024-11-04T08:44:51.710Z]     

[2024-11-04T08:44:51.710Z]         # search

[2024-11-04T08:44:51.710Z]         search_vectors = cf.gen_vectors(1, dim)

[2024-11-04T08:44:51.710Z]         search_params = {"metric_type": "L2", "params": {"ef": 64}}

[2024-11-04T08:44:51.710Z]         t0 = time.time()

[2024-11-04T08:44:51.710Z]         res_1, _ = collection_w.search(data=search_vectors,

[2024-11-04T08:44:51.710Z]                                        anns_field=float_vector_field_name,

[2024-11-04T08:44:51.710Z]                                        param=search_params, limit=1)

[2024-11-04T08:44:51.710Z]         tt = time.time() - t0

[2024-11-04T08:44:51.710Z]         log.info(f"assert search: {tt}")

[2024-11-04T08:44:51.710Z]         assert len(res_1) == 1

[2024-11-04T08:44:51.710Z]         # query

[2024-11-04T08:44:51.710Z]         term_expr = f'{int64_field_name} in {[i for i in range(offset, 0)]}'

[2024-11-04T08:44:51.710Z]         t0 = time.time()

[2024-11-04T08:44:51.710Z]         res, _ = collection_w.query(term_expr)

[2024-11-04T08:44:51.710Z]         tt = time.time() - t0

[2024-11-04T08:44:51.710Z]         log.info(f"assert query result {len(res)}: {tt}")

[2024-11-04T08:44:51.710Z]         assert len(res) >= len(data[0])

[2024-11-04T08:44:51.710Z] >       collection_w.release()

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z] testcases/test_all_collections_after_chaos.py:108: 

[2024-11-04T08:44:51.710Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-04T08:44:51.710Z] ../utils/wrapper.py:33: in inner_wrapper

[2024-11-04T08:44:51.710Z]     res, result = func(*args, **kwargs)

[2024-11-04T08:44:51.710Z] ../base/collection_wrapper.py:119: in release

[2024-11-04T08:44:51.710Z]     check_result = ResponseChecker(res, func_name, check_task,

[2024-11-04T08:44:51.710Z] ../check/func_check.py:34: in run

[2024-11-04T08:44:51.710Z]     result = self.assert_succ(self.succ, True)

[2024-11-04T08:44:51.710Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z] self = <check.func_check.ResponseChecker object at 0x7f9800491d30>

[2024-11-04T08:44:51.710Z] actual = False, expect = True

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z]     def assert_succ(self, actual, expect):

[2024-11-04T08:44:51.710Z] >       assert actual is expect, f"Response of API {self.func_name} expect {expect}, but got {actual}"

[2024-11-04T08:44:51.710Z] E       AssertionError: Response of API release expect True, but got False

[2024-11-04T08:44:51.710Z] 

[2024-11-04T08:44:51.710Z] ../check/func_check.py:116: AssertionError

[2024-11-04T08:44:51.710Z] ------------------------------ Captured log setup ------------------------------

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: ################################################################################ (conftest.py:232)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: [initialize_milvus] Log cleaned up, start testing... (conftest.py:233)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: [setup_class] Start setup class... (client_base.py:41)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: *********************************** setup *********************************** (client_base.py:47)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: pymilvus version: 2.5.0rc106 (client_base.py:48)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: [setup_method] Start setup test case test_milvus_default. (client_base.py:49)

[2024-11-04T08:44:51.710Z] ------------------------------ Captured log call -------------------------------

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_request)  : [Connections.connect] args: ['default', '', '', 'default', ''], kwargs: {'host': '10.255.62.25', 'port': 19530} (api_request.py:62)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - INFO - ci_test]: server version: f54cf41 (client_base.py:166)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_request)  : [Connections.has_connection] args: ['default'], kwargs: {} (api_request.py:62)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_response) : True  (api_request.py:37)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Checker__Pezmr05g', {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType......, kwargs: {'consistency_level': 'Strong'} (api_request.py:62)

[2024-11-04T08:44:51.710Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_response) : <Collection>:

[2024-11-04T08:44:51.710Z] -------------

[2024-11-04T08:44:51.710Z] <name>: Checker__Pezmr05g

[2024-11-04T08:44:51.710Z] <description>: 

[2024-11-04T08:44:51.711Z] <schema>: {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}......  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:07 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:08 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:08 - DEBUG - ci_test]: (api_request)  : [Collection.compact] args: [False, 180], kwargs: {} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:08 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:08 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:19 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:19 - INFO - ci_test]: assert create collection: 0.021927595138549805, init_entities: 152037 (test_all_collections_after_chaos.py:49)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:25 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[{'int64': -3000, 'float': 0.6278791, 'varchar': 'byvlunlekajtayxsng', 'text': 'Produce not cut exist focus always. Who radio space you team all floor.\nDark entire second force trial rule time.', 'json_field': {'name': 'Christopher Fernandez', 'address': '0414 Lewis Square Suite 958\nKennethcheste......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:29 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453695003553955843, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:29 - INFO - ci_test]: assert insert: 4.800552606582642 (test_all_collections_after_chaos.py:57)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:29 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:39 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:39 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - INFO - ci_test]: assert flush: 10.240052938461304, entities: 154037 (test_all_collections_after_chaos.py:67)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - INFO - ci_test]: index info: [{'collection': 'Checker__Pezmr05g', 'field': 'float_vector', 'index_name': 'float_vector', 'index_param': {'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}, 'index_type': 'HNSW'}}, {'collection': 'Checker__Pezmr05g', 'field': 'image_emb', 'index_name': 'image_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pezmr05g', 'field': 'voice_emb', 'index_name': 'voice_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pezmr05g', 'field': 'text_sparse_emb', 'index_name': 'text_sparse_emb', 'index_param': {'index_type': 'SPARSE_INVERTED_INDEX', 'metric_type': 'BM25', 'params': {'bm25_k1': 1.5, 'bm25_b': 0.75}}}, {'collection': 'Checker__Pezmr05g', 'field': 'int64', 'index_name': 'int64', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'float', 'index_name': 'float', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'varchar', 'index_name': 'varchar', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'text', 'index_name': 'text', 'index_param': {'index_type': 'INVERTED'}}] (test_all_collections_after_chaos.py:71)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - INFO - ci_test]: index info: [{'collection': 'Checker__Pezmr05g', 'field': 'varchar', 'index_name': 'varchar', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'text', 'index_name': 'text', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'float_vector', 'index_name': 'float_vector', 'index_param': {'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}, 'index_type': 'HNSW'}}, {'collection': 'Checker__Pezmr05g', 'field': 'image_emb', 'index_name': 'image_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pezmr05g', 'field': 'voice_emb', 'index_name': 'voice_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pezmr05g', 'field': 'text_sparse_emb', 'index_name': 'text_sparse_emb', 'index_param': {'index_type': 'SPARSE_INVERTED_INDEX', 'metric_type': 'BM25', 'params': {'bm25_k1': 1.5, 'bm25_b': 0.75}}}, {'collection': 'Checker__Pezmr05g', 'field': 'int64', 'index_name': 'int64', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pezmr05g', 'field': 'float', 'index_name': 'float', 'index_param': {'index_type': 'INVERTED'}}] (test_all_collections_after_chaos.py:86)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:31:59 - DEBUG - ci_test]: (api_request)  : [Collection.search] args: [[[0.016461618205328488, 0.11684563101598885, 0.011476758734683594, 0.1551300737887587, 0.1609056080312071, 0.014115907302898424, 0.05048058245166518, 0.0360348978613695, 0.059719829545766996, 0.09129862467603699, 0.004458973354095027, 0.020415104612836313, 0.15253397442358851, 0.11377711246769018, ......, kwargs: {} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - DEBUG - ci_test]: (api_response) : data: ["['id: -1111, distance: 19.93882179260254, entity: {}']"]  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - INFO - ci_test]: assert search: 1.578230619430542 (test_all_collections_after_chaos.py:99)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - DEBUG - ci_test]: (api_request)  : [Collection.query] args: ['int64 in [-3000, -2999, -2998, -2997, -2996, -2995, -2994, -2993, -2992, -2991, -2990, -2989, -2988, -2987, -2986, -2985, -2984, -2983, -2982, -2981, -2980, -2979, -2978, -2977, -2976, -2975, -2974, -2973, -2972, -2971, -2970, -2969, -2968, -2967, -2966, -2965, -2964, -2963, -2962, -2961, -2960, -......, kwargs: {} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - DEBUG - ci_test]: (api_response) : data: ["{'int64': -3000}", "{'int64': -2999}", "{'int64': -2998}", "{'int64': -2997}", "{'int64': -2996}", "{'int64': -2995}", "{'int64': -2994}", "{'int64': -2993}", "{'int64': -2992}", "{'int64': -2991}"] ...  (api_request.py:37)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - INFO - ci_test]: assert query result 2000: 0.14196133613586426 (test_all_collections_after_chaos.py:106)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:32:00 - DEBUG - ci_test]: (api_request)  : [Collection.release] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:35:00 - ERROR - pymilvus.decorators]: grpc RpcError: [release_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2024-11-04 08:32:00.910638', 'gRPC error': '2024-11-04 08:35:00.911602'}> (decorators.py:151)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:35:00 - ERROR - ci_test]: Traceback (most recent call last):

[2024-11-04T08:44:51.711Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 32, in inner_wrapper

[2024-11-04T08:44:51.711Z]     res = func(*args, **_kwargs)

[2024-11-04T08:44:51.711Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 63, in api_request

[2024-11-04T08:44:51.711Z]     return func(*arg, **kwargs)

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/orm/collection.py", line 458, in release

[2024-11-04T08:44:51.711Z]     conn.release_collection(self._name, timeout=timeout, **kwargs)

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 155, in handler

[2024-11-04T08:44:51.711Z]     raise e from e

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 137, in handler

[2024-11-04T08:44:51.711Z]     return func(*args, **kwargs)

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 176, in handler

[2024-11-04T08:44:51.711Z]     return func(self, *args, **kwargs)

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 90, in handler

[2024-11-04T08:44:51.711Z]     raise e from e

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 86, in handler

[2024-11-04T08:44:51.711Z]     return func(*args, **kwargs)

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/client/grpc_handler.py", line 1210, in release_collection

[2024-11-04T08:44:51.711Z]     response = rf.result()

[2024-11-04T08:44:51.711Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 881, in result

[2024-11-04T08:44:51.711Z]     raise self

[2024-11-04T08:44:51.711Z] grpc._channel._MultiThreadedRendezvous: <_MultiThreadedRendezvous of RPC that terminated with:

[2024-11-04T08:44:51.711Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-04T08:44:51.711Z]  details = "Deadline Exceeded"

[2024-11-04T08:44:51.711Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2024-11-04T08:35:00.911082563+00:00"}"

[2024-11-04T08:44:51.711Z] >

[2024-11-04T08:44:51.711Z]  (api_request.py:45)

[2024-11-04T08:44:51.711Z] [2024-11-04 08:35:00 - ERROR - ci_test]: (api_response) : <_MultiThreadedRendezvous of RPC that terminated with:

[2024-11-04T08:44:51.711Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-04T08:44:51.711Z]  details = "Deadline Exceeded"

[2024-11-04T08:44:51.711Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2024-11-04T08:35:00.911082563+00:00"}"

[2024-11-04T08:44:51.712Z] > (api_request.py:46)

Expected Behavior

No response

Steps To Reproduce

No response

Milvus Log

failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-cron/detail/chaos-test-cron/19341/pipeline

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

Anything else?

No response

zhuwenxing commented 2 days ago

also happened in indexnode pod failure, and it does not make sense. image tag master-20241105-b83b376c-amd64

failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-kafka-cron/detail/chaos-test-kafka-cron/18453/pipeline

log:

artifacts-indexnode-pod-failure-18453-server-logs.tar.gz


[2024-11-05T08:42:59.761Z] [2024-11-05 08:42:59 - INFO - ci_test]: server version: b83b376 (client_base.py:166)

[2024-11-05T08:42:59.761Z] [2024-11-05 08:42:59 - INFO - ci_test]: all database: ['default', 'prod'] (test_data_persistence.py:26)

[2024-11-05T08:43:00.015Z] [2024-11-05 08:42:59 - INFO - ci_test]: [test][2024-11-05T08:42:59Z] [0.51473958s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:43:00.016Z] [2024-11-05 08:42:59 - INFO - ci_test]: assert create collection: 0.004714250564575195, init_entities: 4000 (test_data_persistence.py:38)

[2024-11-05T08:43:00.271Z] [2024-11-05 08:43:00 - INFO - ci_test]: [test][2024-11-05T08:42:59Z] [0.19946044s] Hello_Milvus insert -> (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717833810182145, success count: 2000, err count: 0 (wrapper.py:30)

[2024-11-05T08:43:00.276Z] [2024-11-05 08:43:00 - INFO - ci_test]: assert insert: 0.19964003562927246 (test_data_persistence.py:45)

[2024-11-05T08:43:12.431Z] [2024-11-05 08:43:10 - INFO - ci_test]: [test][2024-11-05T08:43:00Z] [10.73666304s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:43:22.372Z] [2024-11-05 08:43:21 - INFO - ci_test]: [test][2024-11-05T08:43:10Z] [10.23698029s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:43:32.302Z] [2024-11-05 08:43:31 - INFO - ci_test]: [test][2024-11-05T08:43:21Z] [10.17178544s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:43:32.302Z] [2024-11-05 08:43:31 - INFO - ci_test]: assert flush: 20.976419687271118, entities: 6000 (test_data_persistence.py:55)

[2024-11-05T08:43:32.302Z] [2024-11-05 08:43:31 - INFO - ci_test]: index info: [{'collection': 'Hello_Milvus', 'field': 'varchar', 'index_name': 'test_fhWbUNck', 'index_param': {}}, {'collection': 'Hello_Milvus', 'field': 'float_vector', 'index_name': 'test_nmaIoQf4', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}] (test_data_persistence.py:74)

[2024-11-05T08:43:32.302Z] [2024-11-05 08:43:31 - INFO - ci_test]: [test][2024-11-05T08:43:31Z] [0.00996241s] Hello_Milvus load -> None (wrapper.py:30)

[2024-11-05T08:43:58.780Z] [2024-11-05 08:43:55 - INFO - ci_test]: [test][2024-11-05T08:43:31Z] [24.30654723s] Hello_Milvus search -> data: ["['id: 388, distance: 0.34526920318603516, entity: {}']"] (wrapper.py:30)

[2024-11-05T08:43:58.780Z] [2024-11-05 08:43:55 - INFO - ci_test]: assert search: 24.30670976638794 (test_data_persistence.py:86)

[2024-11-05T08:47:05.172Z] [2024-11-05 08:46:55 - ERROR - pymilvus.decorators]: grpc RpcError: [release_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2024-11-05 08:43:55.541302', 'gRPC error': '2024-11-05 08:46:55.543250'}> (decorators.py:151)

[2024-11-05T08:47:05.173Z] [2024-11-05 08:46:55 - ERROR - ci_test]: Traceback (most recent call last):

[2024-11-05T08:47:05.173Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 32, in inner_wrapper

[2024-11-05T08:47:05.173Z]     res = func(*args, **_kwargs)

[2024-11-05T08:47:05.173Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 63, in api_request

[2024-11-05T08:47:05.173Z]     return func(*arg, **kwargs)

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/orm/collection.py", line 458, in release

[2024-11-05T08:47:05.173Z]     conn.release_collection(self._name, timeout=timeout, **kwargs)

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 155, in handler

[2024-11-05T08:47:05.173Z]     raise e from e

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 137, in handler

[2024-11-05T08:47:05.173Z]     return func(*args, **kwargs)

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 176, in handler

[2024-11-05T08:47:05.173Z]     return func(self, *args, **kwargs)

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 90, in handler

[2024-11-05T08:47:05.173Z]     raise e from e

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 86, in handler

[2024-11-05T08:47:05.173Z]     return func(*args, **kwargs)

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/client/grpc_handler.py", line 1210, in release_collection

[2024-11-05T08:47:05.173Z]     response = rf.result()

[2024-11-05T08:47:05.173Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 881, in result

[2024-11-05T08:47:05.173Z]     raise self

[2024-11-05T08:47:05.173Z] grpc._channel._MultiThreadedRendezvous: <_MultiThreadedRendezvous of RPC that terminated with:

[2024-11-05T08:47:05.173Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-05T08:47:05.173Z]  details = "Deadline Exceeded"

[2024-11-05T08:47:05.173Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2024-11-05T08:46:55.54242492+00:00"}"

[2024-11-05T08:47:05.173Z] >

[2024-11-05T08:47:05.173Z]  (api_request.py:45)

[2024-11-05T08:47:05.173Z] [2024-11-05 08:46:55 - ERROR - ci_test]: (api_response) : <_MultiThreadedRendezvous of RPC that terminated with:

[2024-11-05T08:47:05.173Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-05T08:47:05.173Z]  details = "Deadline Exceeded"

[2024-11-05T08:47:05.173Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {grpc_status:4, created_time:"2024-11-05T08:46:55.54242492+00:00"}"

[2024-11-05T08:47:05.173Z] > (api_request.py:46)

[2024-11-05T08:47:05.173Z] FAILED
[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - INFO - ci_test]: *********************************** setup *********************************** (client_base.py:47)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - INFO - ci_test]: pymilvus version: 2.5.0rc106 (client_base.py:48)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - INFO - ci_test]: [setup_method] Start setup test case test_milvus_default. (client_base.py:49)

[2024-11-05T08:53:29.746Z] ------------------------------ Captured log call -------------------------------

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [Connections.connect] args: ['default', '', '', 'default', ''], kwargs: {'host': '10.255.42.221', 'port': 19530} (api_request.py:62)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - INFO - ci_test]: server version: b83b376 (client_base.py:166)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [list_database] args: ['default', None], kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : ['prod', 'default']  (api_request.py:37)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - INFO - ci_test]: all database: ['prod', 'default'] (test_data_persistence.py:26)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [using_database] args: ['prod', 'default'], kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['int64', <DataType.INT64: 5>, ''], kwargs: {'is_primary': False, 'is_partition_key': False, 'nullable': False} (api_request.py:62)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}  (api_request.py:37)

[2024-11-05T08:53:29.746Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['varchar', <DataType.VARCHAR: 21>, ''], kwargs: {'max_length': 65535, 'is_primary': False, 'is_partition_key': False, 'nullable': False} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float_vector', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'name': 'float_vector', 'description': '', 'type': <DataType.FLOAT_VECTOR: 101>, 'params': {'dim': 128}}  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float', <DataType.FLOAT: 10>, ''], kwargs: {'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['json_field', <DataType.JSON: 23>, ''], kwargs: {'is_primary': False, 'nullable': False} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'name': 'json_field', 'description': '', 'type': <DataType.JSON: 23>}  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [CollectionSchema] args: [[{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}, {'name': 'json_field', 'description': '', 'type': <DataTyp......, kwargs: {'primary_field': 'int64', 'auto_id': False, 'enable_dynamic_field': False} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params......  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [Connections.has_connection] args: ['default'], kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : True  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Hello_Milvus', {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARC......, kwargs: {'consistency_level': 'Strong'} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_response) : <Collection>:

[2024-11-05T08:53:29.747Z] -------------

[2024-11-05T08:53:29.747Z] <name>: Hello_Milvus

[2024-11-05T08:53:29.747Z] <description>: 

[2024-11-05T08:53:29.747Z] <schema>: {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'n......  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:55 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - INFO - ci_test]: [test][2024-11-05T08:46:55Z] [0.51421434s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - INFO - ci_test]: assert create collection: 0.0066106319427490234, init_entities: 4000 (test_data_persistence.py:38)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[0          0

[2024-11-05T08:53:29.747Z] 1          1

[2024-11-05T08:53:29.747Z] 2          2

[2024-11-05T08:53:29.747Z] 3          3

[2024-11-05T08:53:29.747Z] 4          4

[2024-11-05T08:53:29.747Z]         ... 

[2024-11-05T08:53:29.747Z] 1995    1995

[2024-11-05T08:53:29.747Z] 1996    1996

[2024-11-05T08:53:29.747Z] 1997    1997

[2024-11-05T08:53:29.747Z] 1998    1998

[2024-11-05T08:53:29.747Z] 1999    1999

[2024-11-05T08:53:29.747Z] Length: 2000, dtype: int64, 0          0.0

[2024-11-05T08:53:29.747Z] 1          1.0

[2024-11-05T08:53:29.747Z] 2          2.0

[2024-11-05T08:53:29.747Z] 3          3.0

[2024-11-05T08:53:29.747Z] 4          4.0

[2024-11-05T08:53:29.747Z]          ...  

[2024-11-05T08:53:29.747Z] 1995    1995.0

[2024-11-05T08:53:29.747Z] 1996    1996.0

[2024-11-05T08:53:29.747Z] 1997   ......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717895781023745, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - INFO - ci_test]: [test][2024-11-05T08:46:56Z] [0.18878228s] Hello_Milvus insert -> (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717895781023745, success count: 2000, err count: 0 (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - INFO - ci_test]: assert insert: 0.18897247314453125 (test_data_persistence.py:45)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:46:56 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:47:06 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:47:06 - INFO - ci_test]: [test][2024-11-05T08:46:56Z] [10.17662379s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:47:06 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:47:16 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:47:16 - INFO - ci_test]: [test][2024-11-05T08:47:06Z] [10.17038712s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - INFO - ci_test]: [test][2024-11-05T08:50:09Z] [0.51233274s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - INFO - ci_test]: assert flush: 192.95085406303406, entities: 6000 (test_data_persistence.py:55)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - INFO - ci_test]: index info: [{'collection': 'Hello_Milvus', 'field': 'varchar', 'index_name': 'test_dQ39ti0A', 'index_param': {}}, {'collection': 'Hello_Milvus', 'field': 'float_vector', 'index_name': 'test_gSLJlfh1', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}] (test_data_persistence.py:74)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - INFO - ci_test]: [test][2024-11-05T08:50:09Z] [0.00937892s] Hello_Milvus load -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:09 - DEBUG - ci_test]: (api_request)  : [Collection.search] args: [[[0.050541197856489535, 0.04297834468753657, 0.07692952372538671, 0.03807416894760198, 0.1590659275968698, 0.14672504608074, 0.09746071594677795, 0.04930868689179872, 0.026912923287030873, 0.11615310502222301, 0.05999914338585865, 0.1175727794990904, 0.030109210439919105, 0.007327967739902115, 0.15......, kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - DEBUG - ci_test]: (api_response) : data: ["['id: 1254, distance: 0.3486194312572479, entity: {}']"]  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - INFO - ci_test]: [test][2024-11-05T08:50:09Z] [0.45814290s] Hello_Milvus search -> data: ["['id: 1254, distance: 0.3486194312572479, entity: {}']"] (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - INFO - ci_test]: assert search: 0.4583137035369873 (test_data_persistence.py:86)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - DEBUG - ci_test]: (api_request)  : [Collection.release] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:10 - INFO - ci_test]: [test][2024-11-05T08:50:10Z] [0.61245549s] Hello_Milvus release -> None (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:11 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[0          0

[2024-11-05T08:53:29.747Z] 1          1

[2024-11-05T08:53:29.747Z] 2          2

[2024-11-05T08:53:29.747Z] 3          3

[2024-11-05T08:53:29.747Z] 4          4

[2024-11-05T08:53:29.747Z]         ... 

[2024-11-05T08:53:29.747Z] 1995    1995

[2024-11-05T08:53:29.747Z] 1996    1996

[2024-11-05T08:53:29.747Z] 1997    1997

[2024-11-05T08:53:29.747Z] 1998    1998

[2024-11-05T08:53:29.747Z] 1999    1999

[2024-11-05T08:53:29.747Z] Length: 2000, dtype: int64, 0          0.0

[2024-11-05T08:53:29.747Z] 1          1.0

[2024-11-05T08:53:29.747Z] 2          2.0

[2024-11-05T08:53:29.747Z] 3          3.0

[2024-11-05T08:53:29.747Z] 4          4.0

[2024-11-05T08:53:29.747Z]          ...  

[2024-11-05T08:53:29.747Z] 1995    1995.0

[2024-11-05T08:53:29.747Z] 1996    1996.0

[2024-11-05T08:53:29.747Z] 1997   ......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:11 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717946833305602, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:11 - INFO - ci_test]: [test][2024-11-05T08:50:11Z] [0.19357006s] Hello_Milvus insert -> (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717946833305602, success count: 2000, err count: 0 (wrapper.py:30)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:11 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:21 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:53:29.747Z] [2024-11-05 08:50:21 - INFO - ci_test]: [test][2024-11-05T08:50:11Z] [10.17305608s] Hello_Milvus flush -> None (wrapper.py:30)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:50:21 - INFO - ci_test]: assert entities: 8000 (test_data_persistence.py:93)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:50:21 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:53:21 - ERROR - pymilvus.decorators]: RPC error: [wait_for_loading_collection], <MilvusException: (code=1, message=wait for loading collection timeout, collection: Hello_Milvus)>, <Time:{'RPC start': '2024-11-05 08:50:21.428241', 'RPC error': '2024-11-05 08:53:21.564081'}> (decorators.py:140)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:53:21 - WARNING - pymilvus.decorators]: Retry timeout: 180s (decorators.py:106)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:53:21 - ERROR - pymilvus.decorators]: RPC error: [load_collection], <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)>, <Time:{'RPC start': '2024-11-05 08:50:21.408710', 'RPC error': '2024-11-05 08:53:21.565090'}> (decorators.py:140)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:53:21 - ERROR - ci_test]: Traceback (most recent call last):

[2024-11-05T08:53:29.748Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 32, in inner_wrapper

[2024-11-05T08:53:29.748Z]     res = func(*args, **_kwargs)

[2024-11-05T08:53:29.748Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 63, in api_request

[2024-11-05T08:53:29.748Z]     return func(*arg, **kwargs)

[2024-11-05T08:53:29.748Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/orm/collection.py", line 429, in load

[2024-11-05T08:53:29.748Z]     conn.load_collection(

[2024-11-05T08:53:29.748Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 141, in handler

[2024-11-05T08:53:29.748Z]     raise e from e

[2024-11-05T08:53:29.748Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 137, in handler

[2024-11-05T08:53:29.748Z]     return func(*args, **kwargs)

[2024-11-05T08:53:29.748Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 176, in handler

[2024-11-05T08:53:29.748Z]     return func(self, *args, **kwargs)

[2024-11-05T08:53:29.748Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 107, in handler

[2024-11-05T08:53:29.748Z]     raise MilvusException(

[2024-11-05T08:53:29.748Z] pymilvus.exceptions.MilvusException: <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)>

[2024-11-05T08:53:29.748Z]  (api_request.py:45)

[2024-11-05T08:53:29.748Z] [2024-11-05 08:53:21 - ERROR - ci_test]: (api_response) : <MilvusException: (code=1, message=Retry timeout: 180s, message=wait for loading collection timeout, collection: Hello_Milvus)> (api_request.py:46)

has collection api also failed 

[2024-11-05T08:49:48.241Z] [gw1] linux -- Python 3.8.10 /usr/bin/python3.8

[2024-11-05T08:49:48.241Z] 

[2024-11-05T08:49:48.241Z] self = <test_concurrent_operation.TestOperations object at 0x7ff6246ef910>

[2024-11-05T08:49:48.241Z] request_duration = '4m', is_check = True, collection_name = 'Checker__Ci28fQqb'

[2024-11-05T08:49:48.241Z] 

[2024-11-05T08:49:48.241Z]     @pytest.mark.tags(CaseLabel.L3)

[2024-11-05T08:49:48.241Z]     def test_operations(self, request_duration, is_check, collection_name):

[2024-11-05T08:49:48.241Z]         # start the monitor threads to check the milvus ops

[2024-11-05T08:49:48.241Z]         log.info("*********************Test Start**********************")

[2024-11-05T08:49:48.241Z]         log.info(connections.get_connection_addr('default'))

[2024-11-05T08:49:48.241Z]         # event_records = EventRecords()

[2024-11-05T08:49:48.241Z]         c_name = collection_name if collection_name else cf.gen_unique_str("Checker_")

[2024-11-05T08:49:48.241Z]         # event_records.insert("init_health_checkers", "start")

[2024-11-05T08:49:48.241Z] >       self.init_health_checkers(collection_name=c_name)

[2024-11-05T08:49:48.241Z] 

[2024-11-05T08:49:48.241Z] testcases/test_concurrent_operation.py:103: 

[2024-11-05T08:49:48.241Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-05T08:49:48.241Z] testcases/test_concurrent_operation.py:76: in init_health_checkers

[2024-11-05T08:49:48.241Z]     Op.insert: InsertChecker(collection_name=c_name),

[2024-11-05T08:49:48.241Z] checker.py:834: in __init__

[2024-11-05T08:49:48.241Z]     super().__init__(collection_name=collection_name, shards_num=shards_num, schema=schema)

[2024-11-05T08:49:48.241Z] checker.py:359: in __init__

[2024-11-05T08:49:48.241Z]     self.c_wrap.init_collection(name=c_name,

[2024-11-05T08:49:48.241Z] ../base/collection_wrapper.py:40: in init_collection

[2024-11-05T08:49:48.241Z]     check_result = ResponseChecker(res, func_name, check_task, check_items, is_succ,

[2024-11-05T08:49:48.241Z] ../check/func_check.py:34: in run

[2024-11-05T08:49:48.241Z]     result = self.assert_succ(self.succ, True)

[2024-11-05T08:49:48.241Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-05T08:49:48.241Z] 

[2024-11-05T08:49:48.242Z] self = <check.func_check.ResponseChecker object at 0x7ff624011340>

[2024-11-05T08:49:48.242Z] actual = False, expect = True

[2024-11-05T08:49:48.242Z] 

[2024-11-05T08:49:48.242Z]     def assert_succ(self, actual, expect):

[2024-11-05T08:49:48.242Z] >       assert actual is expect, f"Response of API {self.func_name} expect {expect}, but got {actual}"

[2024-11-05T08:49:48.242Z] E       AssertionError: Response of API init_collection expect True, but got False

[2024-11-05T08:49:48.242Z] 

[2024-11-05T08:49:48.242Z] ../check/func_check.py:116: AssertionError

[2024-11-05T08:49:48.242Z] ------------------------------ Captured log setup ------------------------------

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:16 - INFO - ci_test]: ################################################################################ (conftest.py:232)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:16 - INFO - ci_test]: [initialize_milvus] Log cleaned up, start testing... (conftest.py:233)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:16 - INFO - ci_test]: connect to milvus successfully (test_concurrent_operation.py:64)

[2024-11-05T08:49:48.242Z] ------------------------------ Captured log call -------------------------------

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - INFO - ci_test]: *********************Test Start********************** (test_concurrent_operation.py:98)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - INFO - ci_test]: {'address': '10.255.42.221:19530', 'user': ''} (test_concurrent_operation.py:99)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['int64', <DataType.INT64: 5>, ''], kwargs: {'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float', <DataType.FLOAT: 10>, ''], kwargs: {'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['varchar', <DataType.VARCHAR: 21>, ''], kwargs: {'max_length': 65535, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['text', <DataType.VARCHAR: 21>, ''], kwargs: {'max_length': 2000, 'is_primary': False, 'enable_tokenizer': True, 'enable_match': True, 'tokenizer_params': {'tokenizer': 'default'}} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'text', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 2000, 'enable_match': True, 'enable_tokenizer': True, 'tokenizer_params': {'tokenizer': 'default'}}}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['json_field', <DataType.JSON: 23>, ''], kwargs: {'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'json_field', 'description': '', 'type': <DataType.JSON: 23>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['array_int', <DataType.ARRAY: 22>, ''], kwargs: {'element_type': <DataType.INT64: 5>, 'max_capacity': 100, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'array_int', 'description': '', 'type': <DataType.ARRAY: 22>, 'params': {'max_capacity': 100}, 'element_type': <DataType.INT64: 5>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['array_float', <DataType.ARRAY: 22>, ''], kwargs: {'element_type': <DataType.FLOAT: 10>, 'max_capacity': 100, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'array_float', 'description': '', 'type': <DataType.ARRAY: 22>, 'params': {'max_capacity': 100}, 'element_type': <DataType.FLOAT: 10>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['array_varchar', <DataType.ARRAY: 22>, ''], kwargs: {'element_type': <DataType.VARCHAR: 21>, 'max_capacity': 100, 'is_primary': False, 'max_length': 200} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'array_varchar', 'description': '', 'type': <DataType.ARRAY: 22>, 'params': {'max_length': 200, 'max_capacity': 100}, 'element_type': <DataType.VARCHAR: 21>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['array_bool', <DataType.ARRAY: 22>, ''], kwargs: {'element_type': <DataType.BOOL: 1>, 'max_capacity': 100, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'array_bool', 'description': '', 'type': <DataType.ARRAY: 22>, 'params': {'max_capacity': 100}, 'element_type': <DataType.BOOL: 1>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float_vector', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'float_vector', 'description': '', 'type': <DataType.FLOAT_VECTOR: 101>, 'params': {'dim': 128}}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['image_emb', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'image_emb', 'description': '', 'type': <DataType.FLOAT_VECTOR: 101>, 'params': {'dim': 128}}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['text_sparse_emb', <DataType.SPARSE_FLOAT_VECTOR: 104>, ''], kwargs: {'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'text_sparse_emb', 'description': '', 'type': <DataType.SPARSE_FLOAT_VECTOR: 104>}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['voice_emb', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'name': 'voice_emb', 'description': '', 'type': <DataType.FLOAT_VECTOR: 101>, 'params': {'dim': 128}}  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [CollectionSchema] args: [[{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params': {'max_length': 65535}}, {'name': 'text', 'description': '', 'type': <DataType.VARC......, kwargs: {'primary_field': 'int64', 'auto_id': False, 'enable_dynamic_field': True} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_response) : {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType.VARCHAR: 21>, 'params......  (api_request.py:37)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:43:53 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Checker__Ci28fQqb', {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType......, kwargs: {'shards_num': 2, 'timeout': 120, 'consistency_level': 'Strong'} (api_request.py:62)

[2024-11-05T08:49:48.242Z] [2024-11-05 08:45:53 - ERROR - pymilvus.decorators]: grpc RpcError: [has_collection], <_MultiThreadedRendezvous: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2024-11-05 08:43:53.296890', 'gRPC error': '2024-11-05 08:45:53.298025'}> (decorators.py:151)

and some search also failed


[2024-11-05T08:54:17.461Z] ___________ TestAllCollection.test_milvus_default[Checker__Pc4ibVTc] ___________

[2024-11-05T08:54:17.461Z] [gw3] linux -- Python 3.8.10 /usr/bin/python3.8

[2024-11-05T08:54:17.461Z] 

[2024-11-05T08:54:17.461Z] self = <test_all_collections_after_chaos.TestAllCollection object at 0x7fe2c808f640>

[2024-11-05T08:54:17.461Z] collection_name = 'Checker__Pc4ibVTc'

[2024-11-05T08:54:17.461Z] 

[2024-11-05T08:54:17.461Z]     @pytest.mark.tags(CaseLabel.L1)

[2024-11-05T08:54:17.461Z]     def test_milvus_default(self, collection_name):

[2024-11-05T08:54:17.461Z]         self._connect()

[2024-11-05T08:54:17.461Z]         # create

[2024-11-05T08:54:17.461Z]         name = collection_name if collection_name else cf.gen_unique_str("Checker_")

[2024-11-05T08:54:17.461Z]         t0 = time.time()

[2024-11-05T08:54:17.461Z]         schema = Collection(name=name).schema

[2024-11-05T08:54:17.461Z]         collection_w = self.init_collection_wrap(name=name, schema=schema)

[2024-11-05T08:54:17.461Z]         tt = time.time() - t0

[2024-11-05T08:54:17.461Z]         assert collection_w.name == name

[2024-11-05T08:54:17.461Z]         # get collection info

[2024-11-05T08:54:17.461Z]         schema = collection_w.schema

[2024-11-05T08:54:17.461Z]         dim = cf.get_dim_by_schema(schema=schema)

[2024-11-05T08:54:17.461Z]         int64_field_name = cf.get_int64_field_name(schema=schema)

[2024-11-05T08:54:17.461Z]         float_vector_field_name = cf.get_float_vec_field_name(schema=schema)

[2024-11-05T08:54:17.461Z]         float_vector_field_name_list = cf.get_float_vec_field_name_list(schema=schema)

[2024-11-05T08:54:17.461Z]         # compact collection before getting num_entities

[2024-11-05T08:54:17.461Z]         collection_w.flush(timeout=180)

[2024-11-05T08:54:17.461Z]         collection_w.compact()

[2024-11-05T08:54:17.462Z]         collection_w.wait_for_compaction_completed(timeout=720)

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         entities = collection_w.num_entities

[2024-11-05T08:54:17.462Z]         log.info(f"assert create collection: {tt}, init_entities: {entities}")

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # insert

[2024-11-05T08:54:17.462Z]         offset = -3000

[2024-11-05T08:54:17.462Z]         data = cf.gen_row_data_by_schema(nb=ct.default_nb, schema=schema, start=offset)

[2024-11-05T08:54:17.462Z]         t0 = time.time()

[2024-11-05T08:54:17.462Z]         _, res = collection_w.insert(data)

[2024-11-05T08:54:17.462Z]         tt = time.time() - t0

[2024-11-05T08:54:17.462Z]         log.info(f"assert insert: {tt}")

[2024-11-05T08:54:17.462Z]         assert res

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # flush

[2024-11-05T08:54:17.462Z]         t0 = time.time()

[2024-11-05T08:54:17.462Z]         _, check_result = collection_w.flush(timeout=180)

[2024-11-05T08:54:17.462Z]         assert check_result

[2024-11-05T08:54:17.462Z]         # assert collection_w.num_entities == len(data[0]) + entities

[2024-11-05T08:54:17.462Z]         tt = time.time() - t0

[2024-11-05T08:54:17.462Z]         entities = collection_w.num_entities

[2024-11-05T08:54:17.462Z]         log.info(f"assert flush: {tt}, entities: {entities}")

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # show index infos

[2024-11-05T08:54:17.462Z]         index_infos = [index.to_dict() for index in collection_w.indexes]

[2024-11-05T08:54:17.462Z]         log.info(f"index info: {index_infos}")

[2024-11-05T08:54:17.462Z]         fields_created_index = [index["field"] for index in index_infos]

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # create index if not have

[2024-11-05T08:54:17.462Z]         index_params = {"index_type": "HNSW", "metric_type": "L2", "params": {"M": 48, "efConstruction": 500}}

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         for f in float_vector_field_name_list:

[2024-11-05T08:54:17.462Z]             if f not in fields_created_index:

[2024-11-05T08:54:17.462Z]                 t0 = time.time()

[2024-11-05T08:54:17.462Z]                 index, _ = collection_w.create_index(field_name=float_vector_field_name,

[2024-11-05T08:54:17.462Z]                                                      index_params=index_params)

[2024-11-05T08:54:17.462Z]                 tt = time.time() - t0

[2024-11-05T08:54:17.462Z]                 log.info(f"create index for field {f} cost: {tt} seconds")

[2024-11-05T08:54:17.462Z]         # show index infos

[2024-11-05T08:54:17.462Z]         index_infos = [index.to_dict() for index in collection_w.indexes]

[2024-11-05T08:54:17.462Z]         log.info(f"index info: {index_infos}")

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # load

[2024-11-05T08:54:17.462Z]         collection_w.load()

[2024-11-05T08:54:17.462Z]     

[2024-11-05T08:54:17.462Z]         # search

[2024-11-05T08:54:17.462Z]         search_vectors = cf.gen_vectors(1, dim)

[2024-11-05T08:54:17.462Z]         search_params = {"metric_type": "L2", "params": {"ef": 64}}

[2024-11-05T08:54:17.462Z]         t0 = time.time()

[2024-11-05T08:54:17.462Z] >       res_1, _ = collection_w.search(data=search_vectors,

[2024-11-05T08:54:17.462Z]                                        anns_field=float_vector_field_name,

[2024-11-05T08:54:17.462Z]                                        param=search_params, limit=1)

[2024-11-05T08:54:17.462Z] 

[2024-11-05T08:54:17.462Z] testcases/test_all_collections_after_chaos.py:95: 

[2024-11-05T08:54:17.462Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-05T08:54:17.462Z] ../utils/wrapper.py:33: in inner_wrapper

[2024-11-05T08:54:17.462Z]     res, result = func(*args, **kwargs)

[2024-11-05T08:54:17.462Z] ../base/collection_wrapper.py:172: in search

[2024-11-05T08:54:17.462Z]     check_result = ResponseChecker(res, func_name, check_task, check_items, check,

[2024-11-05T08:54:17.462Z] ../check/func_check.py:34: in run

[2024-11-05T08:54:17.462Z]     result = self.assert_succ(self.succ, True)

[2024-11-05T08:54:17.462Z] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

[2024-11-05T08:54:17.462Z] 

[2024-11-05T08:54:17.462Z] self = <check.func_check.ResponseChecker object at 0x7fe1f007fbe0>

[2024-11-05T08:54:17.462Z] actual = False, expect = True

[2024-11-05T08:54:17.462Z] 

[2024-11-05T08:54:17.462Z]     def assert_succ(self, actual, expect):

[2024-11-05T08:54:17.462Z] >       assert actual is expect, f"Response of API {self.func_name} expect {expect}, but got {actual}"

[2024-11-05T08:54:17.462Z] E       AssertionError: Response of API search expect True, but got False

[2024-11-05T08:54:17.462Z] 

[2024-11-05T08:54:17.462Z] ../check/func_check.py:116: AssertionError

[2024-11-05T08:54:17.462Z] ------------------------------ Captured log setup ------------------------------

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: ################################################################################ (conftest.py:232)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: [initialize_milvus] Log cleaned up, start testing... (conftest.py:233)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: [setup_class] Start setup class... (client_base.py:41)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: *********************************** setup *********************************** (client_base.py:47)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: pymilvus version: 2.5.0rc106 (client_base.py:48)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: [setup_method] Start setup test case test_milvus_default. (client_base.py:49)

[2024-11-05T08:54:17.462Z] ------------------------------ Captured log call -------------------------------

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_request)  : [Connections.connect] args: ['default', '', '', 'default', ''], kwargs: {'host': '10.255.42.221', 'port': 19530} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - INFO - ci_test]: server version: b83b376 (client_base.py:166)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_request)  : [Connections.has_connection] args: ['default'], kwargs: {} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_response) : True  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Checker__Pc4ibVTc', {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}, {'name': 'varchar', 'description': '', 'type': <DataType......, kwargs: {'consistency_level': 'Strong'} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_response) : <Collection>:

[2024-11-05T08:54:17.462Z] -------------

[2024-11-05T08:54:17.462Z] <name>: Checker__Pc4ibVTc

[2024-11-05T08:54:17.462Z] <description>: 

[2024-11-05T08:54:17.462Z] <schema>: {'auto_id': False, 'description': '', 'fields': [{'name': 'int64', 'description': '', 'type': <DataType.INT64: 5>, 'is_primary': True, 'auto_id': False}, {'name': 'float', 'description': '', 'type': <DataType.FLOAT: 10>}......  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:15 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:16 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:16 - DEBUG - ci_test]: (api_request)  : [Collection.compact] args: [False, 180], kwargs: {} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:16 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:17 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:27 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:27 - INFO - ci_test]: assert create collection: 0.00937962532043457, init_entities: 52772 (test_all_collections_after_chaos.py:49)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:29 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[{'int64': -3000, 'float': 0.2327729, 'varchar': 'yqeq', 'text': 'Eye need meeting continue eat so. Feel think surface page fast share rest.\nLine someone evening prepare daughter institution. Market what truth fight hard. Cover organization Mr wish.', 'json_field': {'name': 'Sarah Snyder', 'addres......, kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:30 - DEBUG - ci_test]: (api_response) : (insert count: 2000, delete count: 0, upsert count: 0, timestamp: 453717841752883203, success count: 2000, err count: 0  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:30 - INFO - ci_test]: assert insert: 0.9942841529846191 (test_all_collections_after_chaos.py:57)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:30 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:38 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:38 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:62)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:48 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:48 - INFO - ci_test]: assert flush: 7.674049377441406, entities: 54772 (test_all_collections_after_chaos.py:67)

[2024-11-05T08:54:17.462Z] [2024-11-05 08:43:48 - INFO - ci_test]: index info: [{'collection': 'Checker__Pc4ibVTc', 'field': 'image_emb', 'index_name': 'image_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'voice_emb', 'index_name': 'voice_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'text_sparse_emb', 'index_name': 'text_sparse_emb', 'index_param': {'index_type': 'SPARSE_INVERTED_INDEX', 'metric_type': 'BM25', 'params': {'bm25_k1': 1.5, 'bm25_b': 0.75}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'int64', 'index_name': 'int64', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'float', 'index_name': 'float', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'varchar', 'index_name': 'varchar', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'text', 'index_name': 'text', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'float_vector', 'index_name': 'float_vector', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}] (test_all_collections_after_chaos.py:71)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:43:48 - INFO - ci_test]: index info: [{'collection': 'Checker__Pc4ibVTc', 'field': 'text', 'index_name': 'text', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'float_vector', 'index_name': 'float_vector', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'image_emb', 'index_name': 'image_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'voice_emb', 'index_name': 'voice_emb', 'index_param': {'index_type': 'HNSW', 'metric_type': 'L2', 'params': {'M': 48, 'efConstruction': 500}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'text_sparse_emb', 'index_name': 'text_sparse_emb', 'index_param': {'index_type': 'SPARSE_INVERTED_INDEX', 'metric_type': 'BM25', 'params': {'bm25_k1': 1.5, 'bm25_b': 0.75}}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'int64', 'index_name': 'int64', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'float', 'index_name': 'float', 'index_param': {'index_type': 'INVERTED'}}, {'collection': 'Checker__Pc4ibVTc', 'field': 'varchar', 'index_name': 'varchar', 'index_param': {'index_type': 'INVERTED'}}] (test_all_collections_after_chaos.py:86)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:43:48 - DEBUG - ci_test]: (api_request)  : [Collection.load] args: [None, 1, 180], kwargs: {} (api_request.py:62)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:43:48 - DEBUG - ci_test]: (api_response) : None  (api_request.py:37)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:43:48 - DEBUG - ci_test]: (api_request)  : [Collection.search] args: [[[0.013030808526965974, 0.10718841989023736, 0.03417382039349491, 0.09521140916860753, 0.06132043363766172, 0.08183799153940584, 0.01955850273859794, 0.033040919703253006, 0.10559069670981394, 0.09317936219713097, 0.05001781411734439, 0.07244139544415529, 0.09747295402789208, 0.08300185005986091, 0......, kwargs: {} (api_request.py:62)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:46:48 - ERROR - pymilvus.decorators]: grpc RpcError: [search], <_InactiveRpcError: StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded>, <Time:{'RPC start': '2024-11-05 08:43:48.366804', 'gRPC error': '2024-11-05 08:46:48.367872'}> (decorators.py:151)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:46:48 - ERROR - ci_test]: Traceback (most recent call last):

[2024-11-05T08:54:17.463Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 32, in inner_wrapper

[2024-11-05T08:54:17.463Z]     res = func(*args, **_kwargs)

[2024-11-05T08:54:17.463Z]   File "/home/jenkins/agent/workspace/tests/python_client/utils/api_request.py", line 63, in api_request

[2024-11-05T08:54:17.463Z]     return func(*arg, **kwargs)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/orm/collection.py", line 801, in search

[2024-11-05T08:54:17.463Z]     resp = conn.search(

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 155, in handler

[2024-11-05T08:54:17.463Z]     raise e from e

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 137, in handler

[2024-11-05T08:54:17.463Z]     return func(*args, **kwargs)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 176, in handler

[2024-11-05T08:54:17.463Z]     return func(self, *args, **kwargs)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 90, in handler

[2024-11-05T08:54:17.463Z]     raise e from e

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/decorators.py", line 86, in handler

[2024-11-05T08:54:17.463Z]     return func(*args, **kwargs)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/client/grpc_handler.py", line 806, in search

[2024-11-05T08:54:17.463Z]     return self._execute_search(request, timeout, round_decimal=round_decimal, **kwargs)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/client/grpc_handler.py", line 747, in _execute_search

[2024-11-05T08:54:17.463Z]     raise e from e

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/pymilvus/client/grpc_handler.py", line 735, in _execute_search

[2024-11-05T08:54:17.463Z]     response = self._stub.Search(request, timeout=timeout)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 277, in __call__

[2024-11-05T08:54:17.463Z]     response, ignored_call = self._with_call(

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 332, in _with_call

[2024-11-05T08:54:17.463Z]     return call.result(), call

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 438, in result

[2024-11-05T08:54:17.463Z]     raise self

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 315, in continuation

[2024-11-05T08:54:17.463Z]     response, call = self._thunk(new_method).with_call(

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 343, in with_call

[2024-11-05T08:54:17.463Z]     return self._with_call(

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 332, in _with_call

[2024-11-05T08:54:17.463Z]     return call.result(), call

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 438, in result

[2024-11-05T08:54:17.463Z]     raise self

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_interceptor.py", line 315, in continuation

[2024-11-05T08:54:17.463Z]     response, call = self._thunk(new_method).with_call(

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 1178, in with_call

[2024-11-05T08:54:17.463Z]     return _end_unary_response_blocking(state, call, True, None)

[2024-11-05T08:54:17.463Z]   File "/usr/local/lib/python3.8/dist-packages/grpc/_channel.py", line 1004, in _end_unary_response_blocking

[2024-11-05T08:54:17.463Z]     raise _InactiveRpcError(state)  # pytype: disable=not-instantiable

[2024-11-05T08:54:17.463Z] grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:

[2024-11-05T08:54:17.463Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-05T08:54:17.463Z]  details = "Deadline Exceeded"

[2024-11-05T08:54:17.463Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {created_time:"2024-11-05T08:46:48.367450715+00:00", grpc_status:4}"

[2024-11-05T08:54:17.463Z] >

[2024-11-05T08:54:17.463Z]  (api_request.py:45)

[2024-11-05T08:54:17.463Z] [2024-11-05 08:46:48 - ERROR - ci_test]: (api_response) : <_InactiveRpcError of RPC that terminated with:

[2024-11-05T08:54:17.463Z]  status = StatusCode.DEADLINE_EXCEEDED

[2024-11-05T08:54:17.463Z]  details = "Deadline Exceeded"

[2024-11-05T08:54:17.463Z]  debug_error_string = "UNKNOWN:Deadline Exceeded {created_time:"2024-11-05T08:46:48.367450715+00:00", grpc_status:4}"

[2024-11-05T08:54:17.463Z] > (api_request.py:46)

cluster: 4am ns: chaos-testing pod info

 + kubectl get pods -o wide
 + grep indexnode-pod-failure-18453
 indexnode-pod-failure-18453-etcd-0                               1/1     Running       0                44m     10.104.16.70    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-etcd-1                               1/1     Running       0                44m     10.104.27.226   4am-node31   <none>           <none>
 indexnode-pod-failure-18453-etcd-2                               1/1     Running       0                44m     10.104.34.79    4am-node37   <none>           <none>
 indexnode-pod-failure-18453-kafka-0                              2/2     Running       0                44m     10.104.34.80    4am-node37   <none>           <none>
 indexnode-pod-failure-18453-kafka-1                              2/2     Running       0                44m     10.104.16.73    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-kafka-2                              2/2     Running       0                44m     10.104.19.33    4am-node28   <none>           <none>
 indexnode-pod-failure-18453-kafka-exporter-6f777db574-bvgm7      1/1     Running       4 (44m ago)      44m     10.104.19.27    4am-node28   <none>           <none>
 indexnode-pod-failure-18453-milvus-datanode-557c6cdb47-pwl2p     1/1     Running       2 (44m ago)      44m     10.104.27.222   4am-node31   <none>           <none>
 indexnode-pod-failure-18453-milvus-datanode-557c6cdb47-wl4v9     1/1     Running       2 (44m ago)      44m     10.104.16.62    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-milvus-indexnode-678dff974b-dvbzq    1/1     Running       5 (19m ago)      44m     10.104.23.119   4am-node27   <none>           <none>
 indexnode-pod-failure-18453-milvus-indexnode-678dff974b-hv84v    1/1     Running       5 (19m ago)      44m     10.104.19.26    4am-node28   <none>           <none>
 indexnode-pod-failure-18453-milvus-indexnode-678dff974b-lfxvk    1/1     Running       5 (19m ago)      44m     10.104.15.53    4am-node20   <none>           <none>
 indexnode-pod-failure-18453-milvus-mixcoord-7c4978bbc8-h94zd     1/1     Running       2 (44m ago)      44m     10.104.19.24    4am-node28   <none>           <none>
 indexnode-pod-failure-18453-milvus-proxy-6ff4d994b-jlg7k         1/1     Running       2 (44m ago)      44m     10.104.16.61    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-milvus-querynode-6cb76f6584-8cl89    1/1     Running       2 (44m ago)      44m     10.104.9.59     4am-node14   <none>           <none>
 indexnode-pod-failure-18453-milvus-querynode-6cb76f6584-sd5z4    1/1     Running       2 (44m ago)      44m     10.104.14.139   4am-node18   <none>           <none>
 indexnode-pod-failure-18453-milvus-querynode-6cb76f6584-tvx9h    1/1     Running       2 (44m ago)      44m     10.104.23.118   4am-node27   <none>           <none>
 indexnode-pod-failure-18453-minio-0                              1/1     Running       0                44m     10.104.34.78    4am-node37   <none>           <none>
 indexnode-pod-failure-18453-minio-1                              1/1     Running       0                44m     10.104.16.77    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-minio-2                              1/1     Running       0                44m     10.104.27.227   4am-node31   <none>           <none>
 indexnode-pod-failure-18453-minio-3                              1/1     Running       0                44m     10.104.15.59    4am-node20   <none>           <none>
 indexnode-pod-failure-18453-zookeeper-0                          1/1     Running       0                44m     10.104.16.74    4am-node21   <none>           <none>
 indexnode-pod-failure-18453-zookeeper-1                          1/1     Running       0                44m     10.104.15.58    4am-node20   <none>           <none>
 indexnode-pod-failure-18453-zookeeper-2                          1/1     Running       0                44m     10.104.19.32    4am-node28   <none>           <none>
yanliang567 commented 2 days ago

/assign @weiliu1031 /unassign