milvus
milvus copied to clipboard
[Bug]: Num entities are wrong after some pod kill chaos test
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
/assign @soothing-rain /unassign
[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
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
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)
/assign @wayblink /unassign
@wayblink any progress? This issue has happened for a long time
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
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) ===================
@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.
/assign @sunby please take a investigation on it
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.
Prefer to use count(*) instead of num_entities to get accurate record num.
/assign @zhuwenxing