milvus icon indicating copy to clipboard operation
milvus copied to clipboard

[Bug]: Num entities are wrong after some pod kill chaos test

Open zhuwenxing opened this issue 2 years ago • 7 comments

Is there an existing issue for this?

  • [X] I have searched the existing issues

Environment

- Milvus version: 2.2.0-20221213-437e4430
- Deployment mode(standalone or cluster): cluster
- SDK version(e.g. pymilvus v2.0.0rc2): pymilvus==2.3.0.dev21
- OS(Ubuntu or CentOS): 
- CPU/Memory: 
- GPU: 
- Others:

Current Behavior

2022-12-13T23:19:00.499Z] collection_name = 'Checker__1YhLOntA'

[2022-12-13T23:19:00.499Z] 

[2022-12-13T23:19:00.499Z]     @pytest.mark.tags(CaseLabel.L1)

[2022-12-13T23:19:00.499Z]     def test_milvus_default(self, collection_name):

[2022-12-13T23:19:00.499Z]         # create

[2022-12-13T23:19:00.499Z]         name = collection_name if collection_name else cf.gen_unique_str("Checker_")

[2022-12-13T23:19:00.499Z]         t0 = time.time()

[2022-12-13T23:19:00.499Z]         collection_w = self.init_collection_wrap(name=name, active_trace=True)

[2022-12-13T23:19:00.499Z]         tt = time.time() - t0

[2022-12-13T23:19:00.499Z]         assert collection_w.name == name

[2022-12-13T23:19:00.499Z]         # compact collection before getting num_entities

[2022-12-13T23:19:00.499Z]         collection_w.compact()

[2022-12-13T23:19:00.499Z]         collection_w.wait_for_compaction_completed()

[2022-12-13T23:19:00.499Z]     

[2022-12-13T23:19:00.500Z]         entities = collection_w.num_entities

[2022-12-13T23:19:00.500Z]         log.info(f"assert create collection: {tt}, init_entities: {entities}")

[2022-12-13T23:19:00.500Z]     

[2022-12-13T23:19:00.500Z]         # insert

[2022-12-13T23:19:00.500Z]         data = cf.gen_default_list_data()

[2022-12-13T23:19:00.500Z]         t0 = time.time()

[2022-12-13T23:19:00.500Z]         _, res = collection_w.insert(data)

[2022-12-13T23:19:00.500Z]         tt = time.time() - t0

[2022-12-13T23:19:00.500Z]         log.info(f"assert insert: {tt}")

[2022-12-13T23:19:00.500Z]         assert res

[2022-12-13T23:19:00.500Z]     

[2022-12-13T23:19:00.500Z]         # flush

[2022-12-13T23:19:00.500Z]         t0 = time.time()

[2022-12-13T23:19:00.500Z]         _, check_result = collection_w.flush(timeout=180)

[2022-12-13T23:19:00.500Z]         assert check_result

[2022-12-13T23:19:00.500Z] >       assert collection_w.num_entities == len(data[0]) + entities

[2022-12-13T23:19:00.500Z] E       assert 11526 == (3000 + 16585)

[2022-12-13T23:19:00.500Z] E        +  where 11526 = <base.collection_wrapper.ApiCollectionWrapper object at 0x7f5696819d30>.num_entities

[2022-12-13T23:19:00.500Z] E        +  and   3000 = len([0, 1, 2, 3, 4, 5, ...])

Expected Behavior

No response

Steps To Reproduce

No response

Milvus Log

chaos type: pod-kill image tag: 2.2.0-20221213-437e4430 target pod: etcd failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-kafka-for-release-cron/detail/chaos-test-kafka-for-release-cron/435/pipeline

log: artifacts-etcd-pod-kill-435-server-logs.tar.gz artifacts-etcd-pod-kill-435-pytest-logs.tar.gz

Anything else?

No response

zhuwenxing avatar Dec 14 '22 07:12 zhuwenxing

/assign @soothing-rain /unassign

yanliang567 avatar Dec 14 '22 11:12 yanliang567

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:35 - INFO - ci_test]: [test][2023-01-18T21:48:34Z] [0.43387900s] Checker__wprey9nE insert -> (insert count: 3000, delete count: 0, upsert count: 0, timestamp: 438849638266044417, success count: 3000, err count: 0) (wrapper.py:30)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:35 - INFO - ci_test]: assert insert: 0.4341561794281006 (test_all_collections_after_chaos.py:46)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:35 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:56)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:37 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:37 - INFO - ci_test]: [test][2023-01-18T21:48:35Z] [2.51903168s] Checker__wprey9nE flush -> None (wrapper.py:30)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:37 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 120} (api_request.py:56)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:37 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-18T21:50:54.483Z] [2023-01-18 21:48:37 - INFO - ci_test]: [test][2023-01-18T21:48:37Z] [0.00502164s] Checker__wprey9nE flush -> None (wrapper.py:30)

[2023-01-18T21:50:54.483Z] ------------- generated html file: file:///tmp/ci_logs/report.html -------------

[2023-01-18T21:50:54.483Z] =========================== short test summary info ============================

[2023-01-18T21:50:54.483Z] FAILED testcases/test_all_collections_after_chaos.py::TestAllCollection::test_milvus_default[Checker__wprey9nE] - assert 19065 == (3000 + 16103)

[2023-01-18T21:50:54.483Z]  +  where 19065 = <base.collection_wrapper.ApiCollectionWrapper object at 0x7eff5ba80850>.num_entities

[2023-01-18T21:50:54.483Z]  +  and   3000 = len([0, 1, 2, 3, 4, 5, ...])

chaos type: pod-failure image tag: master-20230118-c82b5d15 target pod: rootcoord failed job:https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-cron/detail/chaos-test-cron/1392/pipeline log:

artifacts-rootcoord-pod-failure-1392-server-logs.tar.gz artifacts-rootcoord-pod-failure-1392-pytest-logs.tar.gz

zhuwenxing avatar Jan 19 '23 03:01 zhuwenxing

chaos type: pod-failure image tag: master-20230118-c82b5d15 target pod: minio failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-kafka-cron/detail/chaos-test-kafka-cron/1298/pipeline log:

artifacts-minio-pod-failure-1298-server-logs.tar.gz artifacts-minio-pod-failure-1298-pytest-logs.tar.gz

zhuwenxing avatar Jan 19 '23 03:01 zhuwenxing

chaos type: pod-failure image tag: 2.2.0-20230129-a4a20ee3 target pod: querynode failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-for-release-cron/detail/chaos-test-for-release-cron/1564/pipeline log: artifacts-querynode-pod-failure-1564-server-logs.tar.gz artifacts-querynode-pod-failure-1564-pytest-logs.tar.gz

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:32 - DEBUG - ci_test]: (api_request)  : [Collection.compact] args: [120], kwargs: {} (api_request.py:56)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:33 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:33 - INFO - ci_test]: [test][2023-01-29T22:28:32Z] [0.01865888s] Checker__ZrHd0LSO compact -> None (wrapper.py:30)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:33 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 120} (api_request.py:56)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:34 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:34 - INFO - ci_test]: [test][2023-01-29T22:28:33Z] [0.52429688s] Checker__ZrHd0LSO flush -> None (wrapper.py:30)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:34 - INFO - ci_test]: assert create collection: 1.2105226516723633, init_entities: 16940 (test_all_collections_after_chaos.py:39)

[2023-01-29T22:31:39.357Z] [2023-01-29 22:28:34 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76,......, kwargs: {'timeout': 120} (api_request.py:56)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:34 - DEBUG - ci_test]: (api_response) : (insert count: 3000, delete count: 0, upsert count: 0, timestamp: 439099408903831554, success count: 3000, err count: 0)  (api_request.py:31)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:34 - INFO - ci_test]: [test][2023-01-29T22:28:34Z] [0.36153043s] Checker__ZrHd0LSO insert -> (insert count: 3000, delete count: 0, upsert count: 0, timestamp: 439099408903831554, success count: 3000, err count: 0) (wrapper.py:30)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:34 - INFO - ci_test]: assert insert: 0.3617832660675049 (test_all_collections_after_chaos.py:46)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:34 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:56)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:37 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:37 - INFO - ci_test]: [test][2023-01-29T22:28:34Z] [2.53874112s] Checker__ZrHd0LSO flush -> None (wrapper.py:30)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:37 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 120} (api_request.py:56)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:37 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-01-29T22:31:39.358Z] [2023-01-29 22:28:37 - INFO - ci_test]: [test][2023-01-29T22:28:37Z] [0.00383276s] Checker__ZrHd0LSO flush -> None (wrapper.py:30)

[2023-01-29T22:31:39.358Z] ------------- generated html file: file:///tmp/ci_logs/report.html -------------

[2023-01-29T22:31:39.358Z] =========================== short test summary info ============================

[2023-01-29T22:31:39.358Z] FAILED testcases/test_all_collections_after_chaos.py::TestAllCollection::test_milvus_default[Checker__ZrHd0LSO] - assert 19685 == (3000 + 16940)

zhuwenxing avatar Jan 31 '23 03:01 zhuwenxing

/assign @wayblink /unassign

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

@wayblink any progress? This issue has happened for a long time

zhuwenxing avatar Feb 23 '23 06:02 zhuwenxing

chaos type: pod-kill image tag: master-20230222-7e19a924 target pod: rootcoord failed job: https://qa-jenkins.milvus.io/blue/organizations/jenkins/chaos-test-kafka-cron/detail/chaos-test-kafka-cron/2157/pipeline/286

log: artifacts-rootcoord-pod-kill-2157-server-logs.tar.gz artifacts-rootcoord-pod-kill-2157-pytest-logs.tar.gz

zhuwenxing avatar Feb 23 '23 06:02 zhuwenxing

chaos type: pod-kill image tag: 2.2.0-20230515-08fe2786 target pod: indexnode

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

[2023-05-15T23:03:01.303Z] ___________ TestAllCollection.test_milvus_default[Checker__Ob5SUeG7] ___________

[2023-05-15T23:03:01.303Z] [gw2] linux -- Python 3.8.10 /usr/bin/python3.8

[2023-05-15T23:03:01.303Z] 

[2023-05-15T23:03:01.303Z] self = <test_all_collections_after_chaos.TestAllCollection object at 0x7fad5af8e430>

[2023-05-15T23:03:01.303Z] collection_name = 'Checker__Ob5SUeG7'

[2023-05-15T23:03:01.303Z] 

[2023-05-15T23:03:01.303Z]     @pytest.mark.tags(CaseLabel.L1)

[2023-05-15T23:03:01.303Z]     def test_milvus_default(self, collection_name):

[2023-05-15T23:03:01.303Z]         # create

[2023-05-15T23:03:01.303Z]         name = collection_name if collection_name else cf.gen_unique_str("Checker_")

[2023-05-15T23:03:01.303Z]         t0 = time.time()

[2023-05-15T23:03:01.303Z]         collection_w = self.init_collection_wrap(name=name, active_trace=True)

[2023-05-15T23:03:01.303Z]         tt = time.time() - t0

[2023-05-15T23:03:01.303Z]         assert collection_w.name == name

[2023-05-15T23:03:01.303Z]         # compact collection before getting num_entities

[2023-05-15T23:03:01.303Z]         collection_w.flush(timeout=180)

[2023-05-15T23:03:01.303Z]         collection_w.compact()

[2023-05-15T23:03:01.303Z]         collection_w.wait_for_compaction_completed(timeout=720)

[2023-05-15T23:03:01.303Z]     

[2023-05-15T23:03:01.303Z]         entities = collection_w.num_entities

[2023-05-15T23:03:01.303Z]         log.info(f"assert create collection: {tt}, init_entities: {entities}")

[2023-05-15T23:03:01.303Z]     

[2023-05-15T23:03:01.303Z]         # insert

[2023-05-15T23:03:01.303Z]         data = cf.gen_default_list_data()

[2023-05-15T23:03:01.303Z]         t0 = time.time()

[2023-05-15T23:03:01.303Z]         _, res = collection_w.insert(data)

[2023-05-15T23:03:01.303Z]         tt = time.time() - t0

[2023-05-15T23:03:01.303Z]         log.info(f"assert insert: {tt}")

[2023-05-15T23:03:01.303Z]         assert res

[2023-05-15T23:03:01.303Z]     

[2023-05-15T23:03:01.303Z]         # flush

[2023-05-15T23:03:01.303Z]         t0 = time.time()

[2023-05-15T23:03:01.303Z]         _, check_result = collection_w.flush(timeout=180)

[2023-05-15T23:03:01.303Z]         assert check_result

[2023-05-15T23:03:01.303Z] >       assert collection_w.num_entities == len(data[0]) + entities

[2023-05-15T23:03:01.303Z] E       assert 22850 == (3000 + 20510)

[2023-05-15T23:03:01.303Z] E        +  where 22850 = <base.collection_wrapper.ApiCollectionWrapper object at 0x7fad5af1e5e0>.num_entities

[2023-05-15T23:03:01.303Z] E        +  and   3000 = len([0, 1, 2, 3, 4, 5, ...])

[2023-05-15T23:03:01.303Z] 

[2023-05-15T23:03:01.303Z] testcases/test_all_collections_after_chaos.py:55: AssertionError

[2023-05-15T23:03:01.303Z] ------------------------------ Captured log setup ------------------------------

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - INFO - ci_test]: *********************************** setup *********************************** (client_base.py:39)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - INFO - ci_test]: [setup_method] Start setup test case test_milvus_default. (client_base.py:40)

[2023-05-15T23:03:01.303Z] ------------------------------ Captured log call -------------------------------

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['int64', <DataType.INT64: 5>, ''], kwargs: {'is_primary': False} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : {

[2023-05-15T23:03:01.303Z]     name: int64

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 5

[2023-05-15T23:03:01.303Z]   }  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float', <DataType.FLOAT: 10>, ''], kwargs: {'is_primary': False} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : {

[2023-05-15T23:03:01.303Z]     name: float

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 10

[2023-05-15T23:03:01.303Z]   }  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['varchar', <DataType.VARCHAR: 21>, ''], kwargs: {'max_length': 65535, 'is_primary': False} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : {

[2023-05-15T23:03:01.303Z]     name: varchar

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 21

[2023-05-15T23:03:01.303Z]     params: {'max_length': 65535}

[2023-05-15T23:03:01.303Z]   }  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [FieldSchema] args: ['float_vector', <DataType.FLOAT_VECTOR: 101>, ''], kwargs: {'dim': 128, 'is_primary': False} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : {

[2023-05-15T23:03:01.303Z]     name: float_vector

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 101

[2023-05-15T23:03:01.303Z]     params: {'dim': 128}

[2023-05-15T23:03:01.303Z]   }  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [CollectionSchema] args: [[{

[2023-05-15T23:03:01.303Z]     name: int64

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 5

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 10

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: varchar

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 21

[2023-05-15T23:03:01.303Z]     params: {'max_length': 65535}

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float_vector

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 101

[2023-05-15T23:03:01.303Z]     params: {'dim': 128}

[2023-05-15T23:03:01.303Z]   }], ''], kwargs: {'primary_field': 'int64', 'auto_id': False} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : {

[2023-05-15T23:03:01.303Z]   auto_id: False

[2023-05-15T23:03:01.303Z]   description: 

[2023-05-15T23:03:01.303Z]   fields: [{

[2023-05-15T23:03:01.303Z]     name: int64

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 5

[2023-05-15T23:03:01.303Z]     is_primary: True

[2023-05-15T23:03:01.303Z]     auto_id: False

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 10

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: varchar

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 21

[2023-05-15T23:03:01.303Z]     params: {'max_length': 65535}

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float......  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [Connections.has_connection] args: ['default'], kwargs: {} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : True  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [Collection] args: ['Checker__Ob5SUeG7', {

[2023-05-15T23:03:01.303Z]   auto_id: False

[2023-05-15T23:03:01.303Z]   description: 

[2023-05-15T23:03:01.303Z]   fields: [{

[2023-05-15T23:03:01.303Z]     name: int64

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 5

[2023-05-15T23:03:01.303Z]     is_primary: True

[2023-05-15T23:03:01.303Z]     auto_id: False

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 10

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: varchar

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 21

[2023-05-15T23:03:01.303Z]     params: {'max_length': 65535}

[2023-05-15T23:03:01.303Z] ......, kwargs: {'consistency_level': 'Strong'} (api_request.py:56)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_response) : <Collection>:

[2023-05-15T23:03:01.303Z] -------------

[2023-05-15T23:03:01.303Z] <name>: Checker__Ob5SUeG7

[2023-05-15T23:03:01.303Z] <description>: 

[2023-05-15T23:03:01.303Z] <schema>: {

[2023-05-15T23:03:01.303Z]   auto_id: False

[2023-05-15T23:03:01.303Z]   description: 

[2023-05-15T23:03:01.303Z]   fields: [{

[2023-05-15T23:03:01.303Z]     name: int64

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 5

[2023-05-15T23:03:01.303Z]     is_primary: True

[2023-05-15T23:03:01.303Z]     auto_id: False

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: float

[2023-05-15T23:03:01.303Z]     description: 

[2023-05-15T23:03:01.303Z]     type: 10

[2023-05-15T23:03:01.303Z]   }, {

[2023-05-15T23:03:01.303Z]     name: varchar

[2023-05-15T23:03:01.303Z]     des......  (api_request.py:31)

[2023-05-15T23:03:01.303Z] [2023-05-15 22:59:24 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 22:59:25 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 22:59:25 - INFO - ci_test]: [test][2023-05-15T22:59:24Z] [0.50863940s] Checker__Ob5SUeG7 flush -> None (wrapper.py:30)

[2023-05-15T23:03:01.304Z] [2023-05-15 22:59:25 - DEBUG - ci_test]: (api_request)  : [Collection.compact] args: [120], kwargs: {} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 22:59:25 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 22:59:25 - INFO - ci_test]: [test][2023-05-15T22:59:25Z] [0.00942580s] Checker__Ob5SUeG7 compact -> None (wrapper.py:30)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:55 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 120} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:55 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:55 - INFO - ci_test]: [test][2023-05-15T23:00:55Z] [0.00832763s] Checker__Ob5SUeG7 flush -> None (wrapper.py:30)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:55 - INFO - ci_test]: assert create collection: 0.005415201187133789, init_entities: 20510 (test_all_collections_after_chaos.py:41)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:56 - DEBUG - ci_test]: (api_request)  : [Collection.insert] args: [[[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76,......, kwargs: {'timeout': 120} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:56 - DEBUG - ci_test]: (api_response) : (insert count: 3000, delete count: 0, upsert count: 0, timestamp: 441500737553301505, success count: 3000, err count: 0)  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:56 - INFO - ci_test]: [test][2023-05-15T23:00:56Z] [0.34802353s] Checker__Ob5SUeG7 insert -> (insert count: 3000, delete count: 0, upsert count: 0, timestamp: 441500737553301505, success count: 3000, err count: 0) (wrapper.py:30)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:56 - INFO - ci_test]: assert insert: 0.3483765125274658 (test_all_collections_after_chaos.py:48)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:56 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 180} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:59 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:59 - INFO - ci_test]: [test][2023-05-15T23:00:56Z] [3.54390780s] Checker__Ob5SUeG7 flush -> None (wrapper.py:30)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:00:59 - DEBUG - ci_test]: (api_request)  : [Collection.flush] args: [], kwargs: {'timeout': 120} (api_request.py:56)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:01:09 - DEBUG - ci_test]: (api_response) : None  (api_request.py:31)

[2023-05-15T23:03:01.304Z] [2023-05-15 23:01:09 - INFO - ci_test]: [test][2023-05-15T23:00:59Z] [9.64255467s] Checker__Ob5SUeG7 flush -> None (wrapper.py:30)

[2023-05-15T23:03:01.304Z] ------------- generated html file: file:///tmp/ci_logs/report.html -------------

[2023-05-15T23:03:01.304Z] =========================== short test summary info ============================

[2023-05-15T23:03:01.304Z] FAILED testcases/test_all_collections_after_chaos.py::TestAllCollection::test_milvus_default[Checker__Ob5SUeG7] - assert 22850 == (3000 + 20510)

[2023-05-15T23:03:01.304Z]  +  where 22850 = <base.collection_wrapper.ApiCollectionWrapper object at 0x7fad5af1e5e0>.num_entities

[2023-05-15T23:03:01.304Z]  +  and   3000 = len([0, 1, 2, 3, 4, 5, ...])

[2023-05-15T23:03:01.304Z] =================== 1 failed, 12 passed in 265.05s (0:04:25) ===================

log: artifacts-indexnode-pod-kill-4255-server-logs.tar.gz

artifacts-indexnode-pod-kill-4255-pytest-logs.tar.gz

zhuwenxing avatar May 16 '23 07:05 zhuwenxing

@soothing-rain @xiaofan-luan

The difference between the number entities obtained before and after Insert is not equal to the inserted number.

This issue has remained for a long time.

zhuwenxing avatar May 16 '23 07:05 zhuwenxing

/assign @sunby please take a investigation on it

xiaofan-luan avatar May 16 '23 11:05 xiaofan-luan

There was a compaction happed between the insert and num_entities. log: "generate a plan for small candidates"] ["plan segment IDs"="[441500485005239355,441500485005239492,441500485005240254]"] ["target segment row"=11525] ["target segment size"=5560410] ["meta update: prepare for complete compaction mutation - complete"] ["collection ID"=441500485005022006] ["partition ID"=441500485005022007] ["new segment ID"=441500485005240347] ["new segment num of rows"=10865] ["compacted from"="[441500485005239355,441500485005239492,441500485005240254]"]

And 660 enitites were deleted in this compaction which is the same as two num_entities calls' diff.

sunby avatar May 17 '23 07:05 sunby

Prefer to use count(*) instead of num_entities to get accurate record num.

sunby avatar May 17 '23 07:05 sunby

/assign @zhuwenxing

sunby avatar May 17 '23 08:05 sunby