milvus: [Bug]: [benchmark][standalone] search and query timeout

Is there an existing issue for this?

I have searched the existing issues

Environment

- Milvus version: master-20211222-1dab9cc
- Deployment mode(standalone or cluster): standalone
- SDK version(e.g. pymilvus v2.0.0rc2): 2.0.0rc9.dev22
- OS(Ubuntu or CentOS): 
- CPU/Memory: 
- GPU: 
- Others:

Current Behavior

client pod: benchmark-tag-bc6ld-3487203131

client logs:

[2021-12-23 04:22:46,616] [   DEBUG] - [scene_test] Start scene test : scene_test_5264_689522 (milvus_benchmark.client:505)
[2021-12-23 04:23:32,409] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233366.604157093","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:17:46.603767', 'RPC start': '2021-12-23 04:17:46.603824', 'RPC error': '2021-12-23 04:23:32.409629'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:23:32,444] [   DEBUG] - Building index done, collection_name: scene_test_1802_167306, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 04:23:32,444] [   DEBUG] - Milvus create_index run in 612.8284s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,445] [   DEBUG] - Building index done, collection_name: scene_test_8011_102868, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 04:23:32,445] [   DEBUG] - Milvus create_index run in 612.8278s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,446] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233126.633154575","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:17:46.632618', 'RPC start': '2021-12-23 04:17:46.632624', 'RPC error': '2021-12-23 04:23:32.446040'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:23:32,446] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233126.633154575","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:13:24.925997', 'RPC start': '2021-12-23 04:13:24.926014', 'RPC error': '2021-12-23 04:23:32.446291'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:23:32,492] [   DEBUG] - Milvus load_collection run in 605.3294s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,499] [   DEBUG] - Row count: 3000 in collection: <scene_test_2642_262496> (milvus_benchmark.client:421)
[2021-12-23 04:23:32,499] [   DEBUG] - [scene_test] Start create index : scene_test_2642_262496 (milvus_benchmark.client:519)
[2021-12-23 04:23:32,504] [    INFO] - Building index start, collection_name: scene_test_2642_262496, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:23:32,504] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:23:32,505] [   DEBUG] - collection: scene_test_2642_262496 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:23:32,507] [   DEBUG] - Milvus get_info run in 45.8987s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,507] [   DEBUG] - [scene_test] Start insert : scene_test_1240_982971 (milvus_benchmark.client:512)
[2021-12-23 04:23:32,510] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:23:32,511] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:23:32,511] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:23:32,512] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:23:32,512] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:23:32,512] [    INFO] -  grpc scene_test                                                                    10112     0(0.00%)  |   82760   63128  386677   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:23:32,513] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:23:32,513] [    INFO] -  Aggregated                                                                         95321     0(0.00%)  |   11006       2  605335    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:23:32,513] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:23:32,513] [    INFO] - Create collection: <scene_test_5264_689522> successfully (milvus_benchmark.client:149)
[2021-12-23 04:23:32,514] [   DEBUG] - Milvus create_collection run in 45.8975s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,514] [   DEBUG] - Milvus insert run in 606.3567s (milvus_benchmark.client:53)
[2021-12-23 04:23:32,514] [   DEBUG] - [scene_test] Start flush : scene_test_3944_481886 (milvus_benchmark.client:514)
[2021-12-23 04:28:32,517] [   DEBUG] - Drop collection scene_test_6326_526193 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,518] [   DEBUG] - Milvus drop run in 345.907s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,519] [   DEBUG] - [scene_test]Scene test close : scene_test_6326_526193 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,519] [   DEBUG] - Milvus scene_test run in 990.1005s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,520] [   DEBUG] - Drop collection scene_test_4829_118527 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,520] [   DEBUG] - Milvus drop run in 345.9084s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,520] [   DEBUG] - [scene_test]Scene test close : scene_test_4829_118527 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,521] [   DEBUG] - Milvus scene_test run in 964.011s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,521] [   DEBUG] - Drop collection scene_test_9575_358882 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,521] [   DEBUG] - Milvus drop run in 345.9092s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,522] [   DEBUG] - [scene_test]Scene test close : scene_test_9575_358882 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,522] [   DEBUG] - Milvus scene_test run in 957.3892s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,522] [   DEBUG] - Drop collection scene_test_624_241587 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,522] [   DEBUG] - Milvus drop run in 345.9095s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,523] [   DEBUG] - [scene_test]Scene test close : scene_test_624_241587 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,523] [   DEBUG] - Milvus scene_test run in 957.3819s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,523] [   DEBUG] - Drop collection scene_test_919_115405 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,523] [   DEBUG] - Milvus drop run in 345.9099s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,523] [   DEBUG] - [scene_test]Scene test close : scene_test_919_115405 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,524] [   DEBUG] - Milvus scene_test run in 951.5586s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,524] [   DEBUG] - Drop collection scene_test_5555_628482 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,524] [   DEBUG] - Milvus drop run in 345.9103s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,524] [   DEBUG] - [scene_test]Scene test close : scene_test_5555_628482 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,525] [   DEBUG] - Milvus scene_test run in 948.5807s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,525] [   DEBUG] - Drop collection scene_test_5944_87763 done. (milvus_benchmark.client:447)
[2021-12-23 04:28:32,525] [   DEBUG] - Milvus drop run in 345.9105s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,525] [   DEBUG] - [scene_test]Scene test close : scene_test_5944_87763 (milvus_benchmark.client:526)
[2021-12-23 04:28:32,525] [   DEBUG] - Milvus scene_test run in 946.3246s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,529] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:28:32,529] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:28:32,530] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:28:32,530] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:28:32,530] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:28:32,531] [    INFO] -  grpc scene_test                                                                    10119     0(0.00%)  |   83367   63128  990100   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:28:32,531] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:28:32,531] [    INFO] -  Aggregated                                                                         95328     0(0.00%)  |   11075       2  990100    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:28:32,531] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:28:32,531] [   DEBUG] - [scene_test] Start drop : scene_test_1802_167306 (milvus_benchmark.client:524)
[2021-12-23 04:28:32,532] [    INFO] - Start Drop collection: scene_test_1802_167306 (milvus_benchmark.client:429)
[2021-12-23 04:28:32,533] [   DEBUG] - [scene_test] Start drop : scene_test_8011_102868 (milvus_benchmark.client:524)
[2021-12-23 04:28:32,534] [    INFO] - Start Drop collection: scene_test_8011_102868 (milvus_benchmark.client:429)
[2021-12-23 04:28:32,535] [   DEBUG] - Milvus insert run in 645.9051s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,535] [   DEBUG] - [scene_test] Start flush : scene_test_1953_10987 (milvus_benchmark.client:514)
[2021-12-23 04:28:32,536] [   DEBUG] - Milvus insert run in 645.9056s (milvus_benchmark.client:53)
[2021-12-23 04:28:32,537] [   DEBUG] - [scene_test] Start flush : scene_test_7844_178763 (milvus_benchmark.client:514)
[2021-12-23 04:28:32,538] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233712.516247870","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:23:32.515424', 'RPC start': '2021-12-23 04:23:32.515430', 'RPC error': '2021-12-23 04:28:32.538649'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:28:32,539] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233472.517144719","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:23:32.516545', 'RPC start': '2021-12-23 04:23:32.516551', 'RPC error': '2021-12-23 04:28:32.539309'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:28:32,539] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640233472.517144719","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:17:46.607235', 'RPC start': '2021-12-23 04:17:46.607286', 'RPC error': '2021-12-23 04:28:32.539595'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:28:32,540] [   DEBUG] - [scene_test] Start scene test : scene_test_2447_699884 (milvus_benchmark.client:505)
[2021-12-23 04:28:32,542] [   DEBUG] - [scene_test] Start scene test : scene_test_7943_758126 (milvus_benchmark.client:505)
[2021-12-23 04:33:32,556] [   DEBUG] - Building index done, collection_name: scene_test_3157_90113, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 04:33:32,557] [   DEBUG] - Milvus create_index run in 1208.8143s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,558] [   DEBUG] - Milvus get_info run in 300.0294s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,558] [   DEBUG] - [scene_test] Start insert : scene_test_5264_689522 (milvus_benchmark.client:512)
[2021-12-23 04:33:32,561] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:33:32,562] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:33:32,562] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:33:32,562] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:33:32,562] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:33:32,563] [    INFO] -  grpc scene_test                                                                    10119     0(0.00%)  |   83367   63128  990100   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:33:32,563] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:33:32,563] [    INFO] -  Aggregated                                                                         95328     0(0.00%)  |   11075       2  990100    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:33:32,563] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:33:32,564] [   DEBUG] - Milvus insert run in 600.0561s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,564] [   DEBUG] - [scene_test] Start flush : scene_test_1240_982971 (milvus_benchmark.client:514)
[2021-12-23 04:33:32,565] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234012.541176037","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:28:32.540134', 'RPC start': '2021-12-23 04:28:32.540140', 'RPC error': '2021-12-23 04:33:32.565906'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:33:32,566] [    INFO] - Create collection: <scene_test_2447_699884> successfully (milvus_benchmark.client:149)
[2021-12-23 04:33:32,566] [   DEBUG] - Milvus create_collection run in 300.0258s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,567] [    INFO] - Create collection: <scene_test_7943_758126> successfully (milvus_benchmark.client:149)
[2021-12-23 04:33:32,567] [   DEBUG] - Milvus create_collection run in 300.0249s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,567] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234012.556189569","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:28:32.555369', 'RPC start': '2021-12-23 04:28:32.555376', 'RPC error': '2021-12-23 04:33:32.567544'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:33:32,567] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234012.556153669","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:28:32.555869', 'RPC start': '2021-12-23 04:28:32.555875', 'RPC error': '2021-12-23 04:33:32.567798'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:33:32,577] [   DEBUG] - Drop collection scene_test_1802_167306 done. (milvus_benchmark.client:447)
[2021-12-23 04:33:32,577] [   DEBUG] - Milvus drop run in 300.0456s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,577] [   DEBUG] - [scene_test]Scene test close : scene_test_1802_167306 (milvus_benchmark.client:526)
[2021-12-23 04:33:32,578] [   DEBUG] - Milvus scene_test run in 1234.4197s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,578] [   DEBUG] - Drop collection scene_test_8011_102868 done. (milvus_benchmark.client:447)
[2021-12-23 04:33:32,578] [   DEBUG] - Milvus drop run in 300.0444s (milvus_benchmark.client:53)
[2021-12-23 04:33:32,578] [   DEBUG] - [scene_test]Scene test close : scene_test_8011_102868 (milvus_benchmark.client:526)
[2021-12-23 04:33:32,579] [   DEBUG] - Milvus scene_test run in 1232.126s (milvus_benchmark.client:53)
[2021-12-23 04:38:32,588] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234072.581164386","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:33:32.580376', 'RPC start': '2021-12-23 04:33:32.580382', 'RPC error': '2021-12-23 04:38:32.587933'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,591] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234072.581164386","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:28:32.541721', 'RPC start': '2021-12-23 04:28:32.541727', 'RPC error': '2021-12-23 04:38:32.590763'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,595] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234072.583784208","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:33:32.581334', 'RPC start': '2021-12-23 04:33:32.581339', 'RPC error': '2021-12-23 04:38:32.594916'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,596] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234072.583784208","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:28:32.556371', 'RPC start': '2021-12-23 04:28:32.556377', 'RPC error': '2021-12-23 04:38:32.596470'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,603] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234312.583377847","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:33:32.582058', 'RPC start': '2021-12-23 04:33:32.582082', 'RPC error': '2021-12-23 04:38:32.603365'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,607] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234312.586420084","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:33:32.585492', 'RPC start': '2021-12-23 04:33:32.585564', 'RPC error': '2021-12-23 04:38:32.607694'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:38:32,609] [   DEBUG] - Milvus insert run in 300.0503s (milvus_benchmark.client:53)
[2021-12-23 04:38:32,609] [   DEBUG] - [scene_test] Start flush : scene_test_5264_689522 (milvus_benchmark.client:514)
[2021-12-23 04:38:32,625] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:38:32,625] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:38:32,626] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:38:32,626] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:38:32,627] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:38:32,628] [    INFO] -  grpc scene_test                                                                    10121     0(0.00%)  |   83594   63128 1234419   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:38:32,628] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:38:32,629] [    INFO] -  Aggregated                                                                         95330     0(0.00%)  |   11101       2 1234419    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:38:32,629] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:38:32,629] [   DEBUG] - [scene_test] Start drop : scene_test_3157_90113 (milvus_benchmark.client:524)
[2021-12-23 04:38:32,630] [    INFO] - Start Drop collection: scene_test_3157_90113 (milvus_benchmark.client:429)
[2021-12-23 04:43:32,625] [   DEBUG] - Milvus flush run in 1200.1105s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,627] [   DEBUG] - Milvus flush run in 900.0919s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,628] [   DEBUG] - Milvus flush run in 900.0911s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,630] [   DEBUG] - Building index done, collection_name: scene_test_2642_262496, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 04:43:32,630] [   DEBUG] - Milvus create_index run in 1200.1265s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,630] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234612.619203565","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:38:32.618621', 'RPC start': '2021-12-23 04:38:32.618627', 'RPC error': '2021-12-23 04:43:32.630741'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:43:32,631] [   DEBUG] - Milvus get_info run in 300.0113s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,631] [   DEBUG] - [scene_test] Start insert : scene_test_2447_699884 (milvus_benchmark.client:512)
[2021-12-23 04:43:32,632] [   DEBUG] - Milvus get_info run in 300.0105s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,633] [   DEBUG] - [scene_test] Start insert : scene_test_7943_758126 (milvus_benchmark.client:512)
[2021-12-23 04:43:32,633] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234612.625121273","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:38:32.624148', 'RPC start': '2021-12-23 04:38:32.624154', 'RPC error': '2021-12-23 04:43:32.633784'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:43:32,647] [   DEBUG] - Row count: 3000 in collection: <scene_test_3944_481886> (milvus_benchmark.client:421)
[2021-12-23 04:43:32,648] [   DEBUG] - [scene_test] Start create index : scene_test_3944_481886 (milvus_benchmark.client:519)
[2021-12-23 04:43:32,648] [    INFO] - Building index start, collection_name: scene_test_3944_481886, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:43:32,648] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:43:32,649] [   DEBUG] - collection: scene_test_3944_481886 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:43:32,652] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:43:32,653] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:43:32,653] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:43:32,654] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:43:32,654] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:43:32,654] [    INFO] -  grpc scene_test                                                                    10121     0(0.00%)  |   83594   63128 1234419   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:43:32,654] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:43:32,655] [    INFO] -  Aggregated                                                                         95330     0(0.00%)  |   11101       2 1234419    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:43:32,655] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:43:32,656] [   DEBUG] - Row count: 3000 in collection: <scene_test_1953_10987> (milvus_benchmark.client:421)
[2021-12-23 04:43:32,656] [   DEBUG] - [scene_test] Start create index : scene_test_1953_10987 (milvus_benchmark.client:519)
[2021-12-23 04:43:32,656] [    INFO] - Building index start, collection_name: scene_test_1953_10987, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:43:32,656] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:43:32,656] [   DEBUG] - collection: scene_test_1953_10987 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:43:32,657] [   DEBUG] - Row count: 3000 in collection: <scene_test_7844_178763> (milvus_benchmark.client:421)
[2021-12-23 04:43:32,657] [   DEBUG] - [scene_test] Start create index : scene_test_7844_178763 (milvus_benchmark.client:519)
[2021-12-23 04:43:32,658] [    INFO] - Building index start, collection_name: scene_test_7844_178763, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:43:32,658] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:43:32,658] [   DEBUG] - collection: scene_test_7844_178763 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:43:32,661] [   DEBUG] - Drop collection scene_test_3157_90113 done. (milvus_benchmark.client:447)
[2021-12-23 04:43:32,661] [   DEBUG] - Milvus drop run in 300.0318s (milvus_benchmark.client:53)
[2021-12-23 04:43:32,662] [   DEBUG] - [scene_test]Scene test close : scene_test_3157_90113 (milvus_benchmark.client:526)
[2021-12-23 04:43:32,662] [   DEBUG] - Milvus scene_test run in 1831.4244s (milvus_benchmark.client:53)
[2021-12-23 04:44:32,663] [   DEBUG] - Milvus flush run in 660.0985s (milvus_benchmark.client:53)
[2021-12-23 04:44:32,680] [   DEBUG] - Milvus flush run in 360.0707s (milvus_benchmark.client:53)
[2021-12-23 04:44:32,683] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234672.661140664","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:43:32.660081', 'RPC start': '2021-12-23 04:43:32.660087', 'RPC error': '2021-12-23 04:44:32.683008'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:44:32,685] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234672.661140664","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:38:32.619297', 'RPC start': '2021-12-23 04:38:32.619303', 'RPC error': '2021-12-23 04:44:32.685060'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:44:32,739] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:44:32,739] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:44:32,740] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:44:32,740] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:44:32,740] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:44:32,741] [    INFO] -  grpc scene_test                                                                    10122     0(0.00%)  |   83767   63128 1831424   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:44:32,741] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:44:32,741] [    INFO] -  Aggregated                                                                         95331     0(0.00%)  |   11120       2 1831424    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:44:32,742] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:44:32,742] [   DEBUG] - [scene_test] Start drop : scene_test_2642_262496 (milvus_benchmark.client:524)
[2021-12-23 04:44:32,742] [    INFO] - Start Drop collection: scene_test_2642_262496 (milvus_benchmark.client:429)
[2021-12-23 04:44:32,773] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234672.662121014","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:43:32.661280', 'RPC start': '2021-12-23 04:43:32.661285', 'RPC error': '2021-12-23 04:44:32.773803'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:44:32,774] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234672.662121014","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:38:32.624805', 'RPC start': '2021-12-23 04:38:32.624813', 'RPC error': '2021-12-23 04:44:32.774240'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:49:32,739] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234972.663240341","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:44:32.662621', 'RPC start': '2021-12-23 04:44:32.662633', 'RPC error': '2021-12-23 04:49:32.739698'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:49:32,741] [   DEBUG] - Row count: 3000 in collection: <scene_test_1240_982971> (milvus_benchmark.client:421)
[2021-12-23 04:49:32,741] [   DEBUG] - [scene_test] Start create index : scene_test_1240_982971 (milvus_benchmark.client:519)
[2021-12-23 04:49:32,742] [    INFO] - Building index start, collection_name: scene_test_1240_982971, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:49:32,742] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:49:32,742] [   DEBUG] - collection: scene_test_1240_982971 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:49:32,743] [   DEBUG] - Row count: 3000 in collection: <scene_test_5264_689522> (milvus_benchmark.client:421)
[2021-12-23 04:49:32,744] [   DEBUG] - [scene_test] Start create index : scene_test_5264_689522 (milvus_benchmark.client:519)
[2021-12-23 04:49:32,744] [    INFO] - Building index start, collection_name: scene_test_5264_689522, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 04:49:32,744] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 04:49:32,744] [   DEBUG] - collection: scene_test_5264_689522 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 04:49:32,746] [   DEBUG] - Milvus insert run in 360.1141s (milvus_benchmark.client:53)
[2021-12-23 04:49:32,746] [   DEBUG] - [scene_test] Start flush : scene_test_2447_699884 (milvus_benchmark.client:514)
[2021-12-23 04:49:32,747] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234972.737200348","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:44:32.736810', 'RPC start': '2021-12-23 04:44:32.736817', 'RPC error': '2021-12-23 04:49:32.747271'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:49:32,747] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234972.738150497","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:44:32.737921', 'RPC start': '2021-12-23 04:44:32.737927', 'RPC error': '2021-12-23 04:49:32.747683'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:49:32,748] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640234972.739133486","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:44:32.738488', 'RPC start': '2021-12-23 04:44:32.738494', 'RPC error': '2021-12-23 04:49:32.747987'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:49:32,748] [   DEBUG] - Milvus insert run in 360.1154s (milvus_benchmark.client:53)
[2021-12-23 04:49:32,748] [   DEBUG] - [scene_test] Start flush : scene_test_7943_758126 (milvus_benchmark.client:514)
[2021-12-23 04:49:32,754] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:49:32,754] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:49:32,754] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:49:32,755] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:49:32,755] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:49:32,755] [    INFO] -  grpc scene_test                                                                    10122     0(0.00%)  |   83767   63128 1831424   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:49:32,756] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:49:32,756] [    INFO] -  Aggregated                                                                         95331     0(0.00%)  |   11120       2 1831424    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:49:32,756] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:54:32,755] [   DEBUG] - Drop collection scene_test_2642_262496 done. (milvus_benchmark.client:447)
[2021-12-23 04:54:32,780] [   DEBUG] - Milvus drop run in 600.038s (milvus_benchmark.client:53)
[2021-12-23 04:54:32,780] [   DEBUG] - [scene_test]Scene test close : scene_test_2642_262496 (milvus_benchmark.client:526)
[2021-12-23 04:54:32,781] [   DEBUG] - Milvus scene_test run in 2486.5033s (milvus_benchmark.client:53)
[2021-12-23 04:54:32,782] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235272.752310273","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:49:32.751326', 'RPC start': '2021-12-23 04:49:32.751332', 'RPC error': '2021-12-23 04:54:32.782828'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:54:32,784] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235272.752259133","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:49:32.751901', 'RPC start': '2021-12-23 04:49:32.751907', 'RPC error': '2021-12-23 04:54:32.783934'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:54:32,797] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:54:32,798] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:54:32,798] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:54:32,798] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:54:32,799] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:54:32,799] [    INFO] -  grpc scene_test                                                                    10123     0(0.00%)  |   84004   63128 2486503   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:54:32,799] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:54:32,799] [    INFO] -  Aggregated                                                                         95332     0(0.00%)  |   11146       2 2486503    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:54:32,799] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:59:32,803] [   DEBUG] - Milvus flush run in 600.0565s (milvus_benchmark.client:53)
[2021-12-23 04:59:32,819] [   DEBUG] - Milvus flush run in 600.0706s (milvus_benchmark.client:53)
[2021-12-23 04:59:32,823] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235572.790272391","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:54:32.789878', 'RPC start': '2021-12-23 04:54:32.789909', 'RPC error': '2021-12-23 04:59:32.823651'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:59:32,824] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235572.797319665","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:54:32.796845', 'RPC start': '2021-12-23 04:54:32.796852', 'RPC error': '2021-12-23 04:59:32.824283'} (pymilvus.client.grpc_handler:84)
[2021-12-23 04:59:32,827] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 04:59:32,828] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 04:59:32,828] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:59:32,828] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:59:32,829] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:59:32,829] [    INFO] -  grpc scene_test                                                                    10123     0(0.00%)  |   84004   63128 2486503   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 04:59:32,829] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 04:59:32,829] [    INFO] -  Aggregated                                                                         95332     0(0.00%)  |   11146       2 2486503    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 04:59:32,829] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 04:59:32,834] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235572.801308527","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:54:32.800971', 'RPC start': '2021-12-23 04:54:32.800977', 'RPC error': '2021-12-23 04:59:32.834235'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:00:32,825] [   DEBUG] - Row count: 3000 in collection: <scene_test_2447_699884> (milvus_benchmark.client:421)
[2021-12-23 05:00:33,200] [   DEBUG] - [scene_test] Start create index : scene_test_2447_699884 (milvus_benchmark.client:519)
[2021-12-23 05:00:33,202] [    INFO] - Building index start, collection_name: scene_test_2447_699884, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 05:00:33,204] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 05:00:33,206] [   DEBUG] - collection: scene_test_2447_699884 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 05:00:33,212] [   DEBUG] - Row count: 3000 in collection: <scene_test_7943_758126> (milvus_benchmark.client:421)
[2021-12-23 05:00:33,236] [   DEBUG] - [scene_test] Start create index : scene_test_7943_758126 (milvus_benchmark.client:519)
[2021-12-23 05:00:33,236] [    INFO] - Building index start, collection_name: scene_test_7943_758126, index_type: IVF_SQ8, metric_type: L2 (milvus_benchmark.client:274)
[2021-12-23 05:00:33,237] [    INFO] - {'nlist': 2048} (milvus_benchmark.client:276)
[2021-12-23 05:00:33,237] [   DEBUG] - collection: scene_test_7943_758126 Index params: {'index_type': 'IVF_SQ8', 'metric_type': 'L2', 'params': {'nlist': 2048}} (milvus_benchmark.client:282)
[2021-12-23 05:00:33,238] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235632.823167864","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:59:32.822533', 'RPC start': '2021-12-23 04:59:32.822540', 'RPC error': '2021-12-23 05:00:33.238521'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:00:33,238] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235632.823167864","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:49:32.750126', 'RPC start': '2021-12-23 04:49:32.750132', 'RPC error': '2021-12-23 05:00:33.238847'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:00:33,239] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235632.824134188","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:59:32.823354', 'RPC start': '2021-12-23 04:59:32.823359', 'RPC error': '2021-12-23 05:00:33.239193'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:00:33,239] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235632.824134188","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:49:32.750731', 'RPC start': '2021-12-23 04:49:32.750737', 'RPC error': '2021-12-23 05:00:33.239646'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:00:33,252] [    INFO] -  Name                                                                              # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s (locust.stats_logger:725)
[2021-12-23 05:00:33,253] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:727)
[2021-12-23 05:00:33,253] [    INFO] -  grpc get                                                                           39823     0(0.00%)  |    2044     981  259468    2000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 05:00:33,254] [    INFO] -  grpc load_collection                                                                5073     0(0.00%)  |    2044       2  605335    1500  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 05:00:33,254] [    INFO] -  grpc query                                                                         40313     0(0.00%)  |    2987     155   15437    2600  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 05:00:33,255] [    INFO] -  grpc scene_test                                                                    10123     0(0.00%)  |   84004   63128 2486503   82000  |    0.00    0.00 (locust.stats_logger:730)
[2021-12-23 05:00:33,255] [    INFO] - ---------------------------------------------------------------------------------------------------------------------------------------------------------------- (locust.stats_logger:731)
[2021-12-23 05:00:33,255] [    INFO] -  Aggregated                                                                         95332     0(0.00%)  |   11146       2 2486503    2200  |    0.00    0.00 (locust.stats_logger:732)
[2021-12-23 05:00:33,255] [    INFO] -  (locust.stats_logger:733)
[2021-12-23 05:05:33,251] [   DEBUG] - Building index done, collection_name: scene_test_3944_481886, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 05:05:33,252] [   DEBUG] - Milvus create_index run in 1320.6044s (milvus_benchmark.client:53)
[2021-12-23 05:05:33,253] [   DEBUG] - Building index done, collection_name: scene_test_1953_10987, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 05:05:33,254] [   DEBUG] - Milvus create_index run in 1320.5975s (milvus_benchmark.client:53)
[2021-12-23 05:05:33,254] [   DEBUG] - Building index done, collection_name: scene_test_7844_178763, response: Status(code=0, message='') (milvus_benchmark.client:284)
[2021-12-23 05:05:33,254] [   DEBUG] - Milvus create_index run in 1320.5968s (milvus_benchmark.client:53)
[2021-12-23 05:05:33,255] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235933.248149882","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 05:00:33.247536', 'RPC start': '2021-12-23 05:00:33.247543', 'RPC error': '2021-12-23 05:05:33.255242'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,255] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235933.250196955","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 05:00:33.249105', 'RPC start': '2021-12-23 05:00:33.249111', 'RPC error': '2021-12-23 05:05:33.255918'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,256] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235933.250155375","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 05:00:33.249672', 'RPC start': '2021-12-23 05:00:33.249678', 'RPC error': '2021-12-23 05:05:33.256503'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,256] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] query
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235933.251131414","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 05:00:33.250222', 'RPC start': '2021-12-23 05:00:33.250228', 'RPC error': '2021-12-23 05:05:33.256847'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,257] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] _execute_search_requests
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235693.258181166","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 05:00:33.257585', 'RPC start': '2021-12-23 05:00:33.257590', 'RPC error': '2021-12-23 05:05:33.257963'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,258] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19530] search
RPC error: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.DEADLINE_EXCEEDED
	details = "Deadline Exceeded"
	debug_error_string = "{"created":"@1640235693.258181166","description":"Error received from peer ipv4:10.96.42.187:19530","file":"src/core/lib/surface/call.cc","file_line":1068,"grpc_message":"Deadline Exceeded","grpc_status":4}"
>
	{'API start': '2021-12-23 04:59:32.826820', 'RPC start': '2021-12-23 04:59:32.826826', 'RPC error': '2021-12-23 05:05:33.258438'} (pymilvus.client.grpc_handler:84)
[2021-12-23 05:05:33,259] [   ERROR] - 
Addr [benchmark-tag-bc6ld-1-milvus.qa-milvus.svc.cluster.local:19

Expected Behavior

argo task: benchmark-tag-bc6ld

test yaml: client-configmap:client-random-locust-100m-ddl-r8-w2 server-configmap:server-single-32c128m

server:

NAME                                                             READY   STATUS      RESTARTS   AGE    IP             NODE                      NOMINATED NODE   READINESS GATES
benchmark-tag-bc6ld-1-etcd-0                                     1/1     Running     0          20h    10.97.17.75    qa-node014.zilliz.local   <none>           <none>
benchmark-tag-bc6ld-1-milvus-standalone-59cbdc47bb-gs6xb         1/1     Running     0          20h    10.97.20.190   qa-node018.zilliz.local   <none>           <none>
benchmark-tag-bc6ld-1-minio-8486ccdd6d-m7zh2                     1/1     Running     0          20h    10.97.12.41    qa-node015.zilliz.local   <none>           <none>

Steps To Reproduce

1、create collation
2、build index of ivf_sq8
3、insert 100 million vectors
4、flush collection
5、build index with the same params
6、load collection
7、locust concurrent: query<-search, load, get<-query, scene_test

Anything else?

client-random-locust-100m-ddl-r8-w2:

locust_random_performance:
      collections:
        -
          collection_name: sift_100m_128_l2
          ni_per: 50000
          build_index: true
          index_type: ivf_sq8
          index_param:
            nlist: 2048
          task:
            types:
              -
                type: query
                weight: 8
                params:
                  top_k: 10
                  nq: 10
                  search_param:
                    nprobe: 16
              -
                type: load
                weight: 1
              -
                type: get
                weight: 8
                params:
                  ids_length: 10
              -
                type: scene_test
                weight: 2
            connection_num: 1
            clients_num: 20
            spawn_rate: 2
            during_time: 302400

scene_test:

    def scene_test(self, collection_name=None, vectors=None, ids=None):
        logger.debug("[scene_test] Start scene test : %s" % collection_name)
        self.create_collection(dimension=128, collection_name=collection_name)
        time.sleep(1)

        collection_info = self.get_info(collection_name)

        entities = utils.generate_entities(collection_info, vectors, ids)
        logger.debug("[scene_test] Start insert : %s" % collection_name)
        self.insert(entities, collection_name=collection_name)
        logger.debug("[scene_test] Start flush : %s" % collection_name)
        self.flush(collection_name=collection_name)

        self.count(collection_name=collection_name)

        logger.debug("[scene_test] Start create index : %s" % collection_name)
        self.create_index(field_name='float_vector', index_type="ivf_sq8", metric_type='l2',
                          collection_name=collection_name, index_param={'nlist': 2048})
        time.sleep(59)

        logger.debug("[scene_test] Start drop : %s" % collection_name)
        self.drop(collection_name=collection_name)
        logger.debug("[scene_test]Scene test close : %s" % collection_name)

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 34 (34 by maintainers)

Most upvoted comments

benchmark-no-clean-kxmp4-1-milvus-standalone-9fdc7b6dc-7qbp2

standalone restart, but querynode recovery failed. rootCoord set state to helthy before registe session to etcd, so when getRecoveryInfo call rootCoord’s describeCollection, rootCoord return error after two retries.

[2022/01/10 14:53:51.242 +00:00] [DEBUG] [cluster.go:617] ["stopNode: queryNode offline"] [nodeID=4]
[2022/01/10 14:53:51.243 +00:00] [DEBUG] [task_scheduler.go:466] ["EnQueue a triggerTask and save to etcd"] [taskID=430394936994824193]
[2022/01/10 14:53:51.242 +00:00] [DEBUG] [session_util.go:379] ["watch services"] ["delete kv"="key:\"by-dev/meta/session/querynode-4\" create_revision:15 mod_revision:15 version:1 value:\"{\\\"ServerID\\\":4,\\\"ServerName\\\":\\\"querynode\\\",\\\"Address\\\":\\\"10.97.16.218:21123\\\",\\\"TriggerKill\\\":true}\" lease:6232557765448952156 "]
[2022/01/10 14:53:51.242 +00:00] [DEBUG] [session_util.go:388] [WatchService] ["event type"=2]
[2022/01/10 14:53:51.242 +00:00] [DEBUG] [query_coord.go:368] ["get a del event after QueryNode down"] [nodeID=4]
[2022/01/10 14:53:51.243 +00:00] [DEBUG] [task_scheduler.go:624] ["scheduleLoop: pop a triggerTask from triggerTaskQueue"] [triggerTaskID=430394936994824193]
[2022/01/10 14:53:51.243 +00:00] [DEBUG] [query_coord.go:398] ["start a loadBalance task"] [task="base:<msg_type:LoadBalanceSegments sourceID:14 > source_nodeIDs:4 balance_reason:NodeDown "]
[2022/01/10 14:53:51.243 +00:00] [DEBUG] [task.go:1650] ["start do loadBalanceTask"] ["trigger type"=4] [sourceNodeIDs="[4]"] [balanceReason=NodeDown] [taskID=430394936994824193]
[2022/01/10 14:53:51.244 +00:00] [DEBUG] [root_coord.go:1551] [ShowPartitions] [role=rootcoord] ["collection name"=] [msgID=0]
[2022/01/10 14:53:51.244 +00:00] [DEBUG] [task.go:1710] ["loadBalanceTask: get collection's all partitionIDs"] [collectionID=430393496637476161] [partitionIDs="[430393496637476162]"]
[2022/01/10 14:53:51.244 +00:00] [DEBUG] [root_coord.go:1569] ["ShowPartitions success"] [role=rootcoord] ["collection name"=] ["num of partitions"=1] [msgID=0]
[2022/01/10 14:53:51.245 +00:00] [INFO] [services.go:487] ["receive get recovery info request"] [collectionID=430393496637476161] [partitionID=430393496637476162]
[2022/01/10 14:53:51.247 +00:00] [DEBUG] [client.go:94] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2022/01/10 14:53:51.247 +00:00] [DEBUG] [client.go:94] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2022/01/10 14:53:51.247 +00:00] [ERROR] [client.go:131] ["failed to get client address"] [error="number of RootCoord is incorrect, 0"] [stack="github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).connect\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:131\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).GetGrpcClient\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:103\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).callOnce\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:193\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:239\ngithub.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201\ngithub.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574\ngithub.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898\ngithub.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:934"]
[2022/01/10 14:53:51.247 +00:00] [WARN] [client.go:245] ["rootcoord ClientBase ReCall grpc first call get error "] [error="err: number of RootCoord is incorrect, 0\n, /go/src/github.com/milvus-io/milvus/internal/util/trace/stack_trace.go:51 github.com/milvus-io/milvus/internal/util/trace.StackTrace\n/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:244 github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201 github.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574 github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283 github.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38 github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286 google.golang.org/grpc.(*Server).processUnaryRPC\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609 google.golang.org/grpc.(*Server).handleStream\n"]
[2022/01/10 14:53:51.247 +00:00] [DEBUG] [client.go:91] ["RootCoordClient GetSessions success"]
[2022/01/10 14:53:51.247 +00:00] [ERROR] [client.go:131] ["failed to get client address"] [error="number of RootCoord is incorrect, 0"] [stack="github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).connect\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:131\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).GetGrpcClient\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:103\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).callOnce\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:193\ngithub.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:251\ngithub.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201\ngithub.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574\ngithub.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898\ngithub.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:934"]
[2022/01/10 14:53:51.247 +00:00] [DEBUG] [client.go:91] ["RootCoordClient GetSessions success"]
[2022/01/10 14:53:51.248 +00:00] [DEBUG] [cluster.go:606] ["removeNodeInfo: delete nodeInfo in cluster MetaReplica"] [nodeID=4]
[2022/01/10 14:53:51.248 +00:00] [DEBUG] [task.go:1975] ["loadBalanceTask postExecute done"] ["trigger type"=4] [sourceNodeIDs="[4]"] [balanceReason=NodeDown] [taskID=430394936994824193]
[2022/01/10 14:53:51.248 +00:00] [DEBUG] [task_scheduler.go:629] ["scheduleLoop: process triggerTask failed"] [triggerTaskID=430394936994824193] [error="err: number of RootCoord is incorrect, 0\n, /go/src/github.com/milvus-io/milvus/internal/util/trace/stack_trace.go:51 github.com/milvus-io/milvus/internal/util/trace.StackTrace\n/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:253 github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201 github.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574 github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283 github.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38 github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286 google.golang.org/grpc.(*Server).processUnaryRPC\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609 google.golang.org/grpc.(*Server).handleStream\n"]
[2022/01/10 14:53:51.248 +00:00] [ERROR] [services.go:582] ["get collection info from master failed"] [collectionID=430393496637476161] [error="err: number of RootCoord is incorrect, 0\n, /go/src/github.com/milvus-io/milvus/internal/util/trace/stack_trace.go:51 github.com/milvus-io/milvus/internal/util/trace.StackTrace\n/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:253 github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201 github.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574 github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283 github.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38 github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286 google.golang.org/grpc.(*Server).processUnaryRPC\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609 google.golang.org/grpc.(*Server).handleStream\n"] [stack="github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:582\ngithub.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898\ngithub.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:934"]
[2022/01/10 14:53:51.247 +00:00] [ERROR] [client.go:254] ["rootcoord ClientBase ReCall grpc second call get error "] [error="err: number of RootCoord is incorrect, 0\n, /go/src/github.com/milvus-io/milvus/internal/util/trace/stack_trace.go:51 github.com/milvus-io/milvus/internal/util/trace.StackTrace\n/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:253 github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201 github.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574 github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283 github.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38 github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286 google.golang.org/grpc.(*Server).processUnaryRPC\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609 google.golang.org/grpc.(*Server).handleStream\n"] [stack="github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n\t/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:254\ngithub.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201\ngithub.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574\ngithub.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n\t/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898\ngithub.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38\ngithub.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n\t/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:934"]
[2022/01/10 14:53:51.248 +00:00] [ERROR] [task.go:1715] ["loadBalanceTask: getRecoveryInfo failed"] [collectionID=430393496637476161] [partitionID=430393496637476162] [error="err: number of RootCoord is incorrect, 0\n, /go/src/github.com/milvus-io/milvus/internal/util/trace/stack_trace.go:51 github.com/milvus-io/milvus/internal/util/trace.StackTrace\n/go/src/github.com/milvus-io/milvus/internal/util/grpcclient/client.go:253 github.com/milvus-io/milvus/internal/util/grpcclient.(*ClientBase).ReCall\n/go/src/github.com/milvus-io/milvus/internal/distributed/rootcoord/client/client.go:201 github.com/milvus-io/milvus/internal/distributed/rootcoord/client.(*Client).DescribeCollection\n/go/src/github.com/milvus-io/milvus/internal/datacoord/services.go:574 github.com/milvus-io/milvus/internal/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/distributed/datacoord/service.go:283 github.com/milvus-io/milvus/internal/distributed/datacoord.(*Server).GetRecoveryInfo\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3898 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler.func1\n/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.3.0/tracing/opentracing/server_interceptors.go:38 github.com/grpc-ecosystem/go-grpc-middleware/tracing/opentracing.UnaryServerInterceptor.func1\n/go/src/github.com/milvus-io/milvus/internal/proto/datapb/data_coord.pb.go:3900 github.com/milvus-io/milvus/internal/proto/datapb._DataCoord_GetRecoveryInfo_Handler\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1286 google.golang.org/grpc.(*Server).processUnaryRPC\n/go/pkg/mod/google.golang.org/grpc@v1.38.0/server.go:1609 google.golang.org/grpc.(*Server).handleStream\n"] [stack="github.com/milvus-io/milvus/internal/querycoord.(*loadBalanceTask).execute\n\t/go/src/github.com/milvus-io/milvus/internal/querycoord/task.go:1715\ngithub.com/milvus-io/milvus/internal/querycoord.(*TaskScheduler).processTask\n\t/go/src/github.com/milvus-io/milvus/internal/querycoord/task_scheduler.go:550\ngithub.com/milvus-io/milvus/internal/querycoord.(*TaskScheduler).scheduleLoop\n\t/go/src/github.com/milvus-io/milvus/internal/querycoord/task_scheduler.go:627"]
[2022/01/10 14:53:51.249 +00:00] [DEBUG] [task_scheduler.go:686] ["scheduleLoop: trigger task done and delete from etcd"] [triggerTaskID=430394936994824193]
[2022/01/10 14:53:51.630 +00:00] [DEBUG] [session_util.go:236] ["Session register successfully"] [ServerID=9]
[2022/01/10 14:53:51.631 +00:00] [DEBUG] [service.go:146] ["RootCoord start done ..."]

xige-16 on Jan 11, 2022