Details
-
Bug
-
Resolution: Fixed
-
Critical
-
6.5.0
-
Untriaged
-
Unknown
Description
Build: 6.5.0-3748
Test :
- Deploy handler
- Load data
- Pause handler
- rebalance in node
- resume handler
Seeing backlog never processed
./testrunner -i /tmp/testexec.14267.ini -p get-cbcollect-info=True,GROUP=bucket_op_curl -t eventing.eventing_rebalance.EventingRebalance.test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mutations,nodes_init=4,services_init=kv-eventing-index-n1ql,dataset=default,groups=simple,reset_services=True,doc-per-day=20,handler_code=bucket_op_curl_jenkins,curl=True,GROUP=bucket_op_curl,pause_resume=True,host=http://qa.sc.couchbase.com/
|
|
Exception: Bucket operations from handler code took lot of time to complete or didn't go through. Current : 23188 Expected : 40320 dcp_backlog : 19042 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.105.72': {}, '172.23.105.8': {}}
|
2019-07-15 00:33:03 | INFO | MainProcess | test_thread | [eventing_base.verify_eventing_results] Stats for Node 172.23.105.72 is
|
[
|
{
|
"dcp_feed_boundary": "from_prior",
|
"event_processing_stats": {
|
"adhoc_timer_response_received": 99,
|
"agg_messages_sent_to_worker": 34797,
|
"agg_queue_memory": 0,
|
"agg_queue_memory_cap": 132120576,
|
"agg_queue_size": 0,
|
"agg_queue_size_cap": 300000,
|
"agg_timer_feedback_queue_cap": 1500,
|
"agg_timer_feedback_queue_size": 0,
|
"dcp_mutation": 18572,
|
"dcp_mutation_sent_to_worker": 18572,
|
"dcp_snapshot": 512,
|
"dcp_stream_req_counter": 512,
|
"dcp_streamreq": 512,
|
"execution_stats": 3139,
|
"failure_stats": 3139,
|
"latency_stats": 3139,
|
"lcb_exception_stats": 3139,
|
"log_level": 6,
|
"thr_count": 3,
|
"thr_map": 3,
|
"v8_init": 3,
|
"v8_load": 3
|
},
|
"events_remaining": {
|
"dcp_backlog": 0
|
},
|
"execution_stats": {
|
"agg_queue_memory": 0,
|
"agg_queue_size": 0,
|
"dcp_delete_msg_counter": 0,
|
"dcp_delete_parse_failure": 0,
|
"dcp_mutation_msg_counter": 18572,
|
"dcp_mutation_parse_failure": 0,
|
"enqueued_dcp_delete_msg_counter": 0,
|
"enqueued_dcp_mutation_msg_counter": 18572,
|
"enqueued_timer_msg_counter": 0,
|
"feedback_queue_size": 0,
|
"filtered_dcp_delete_counter": 0,
|
"filtered_dcp_mutation_counter": 0,
|
"lcb_retry_failure": 0,
|
"messages_parsed": 34785,
|
"on_delete_failure": 0,
|
"on_delete_success": 0,
|
"on_update_failure": 0,
|
"on_update_success": 18572,
|
"timer_create_failure": 0,
|
"timer_msg_counter": 0,
|
"timer_responses_sent": 0,
|
"timestamp": {
|
"7694": "2019-07-15T07:33:02Z",
|
"7699": "2019-07-15T07:33:02Z",
|
"7707": "2019-07-15T07:33:02Z"
|
},
|
"uv_try_write_failure_counter": 0
|
},
|
"failure_stats": {
|
"app_worker_setting_events_lost": 0,
|
"bucket_op_exception_count": 0,
|
"checkpoint_failure_count": 0,
|
"dcp_events_lost": 0,
|
"debugger_events_lost": 0,
|
"delete_events_lost": 0,
|
"mutation_events_lost": 0,
|
"n1ql_op_exception_count": 0,
|
"timeout_count": 0,
|
"timer_callback_missing_counter": 0,
|
"timer_context_size_exceeded_counter": 0,
|
"timer_events_lost": 0,
|
"timestamp": {
|
"7694": "2019-07-15T07:33:02Z",
|
"7699": "2019-07-15T07:33:02Z",
|
"7707": "2019-07-15T07:33:02Z"
|
},
|
"v8worker_events_lost": 0
|
},
|
"function_id": 2610724135,
|
"function_name": "Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut",
|
"gocb_creds_request_counter": 16,
|
"internal_vb_distribution_stats": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[0-170]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[171-341]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[342-511]"
|
},
|
"latency_percentile_stats": {
|
"100": 839600,
|
"50": 106900,
|
"80": 122700,
|
"90": 130900,
|
"95": 139400,
|
"99": 186600
|
},
|
"lcb_creds_request_counter": 12,
|
"lcb_exception_stats": {},
|
"metastore_stats": {},
|
"planner_stats": [
|
{
|
"host_name": "172.23.105.72:8096",
|
"start_vb": 0,
|
"vb_count": 512
|
},
|
{
|
"host_name": "172.23.105.8:8096",
|
"start_vb": 512,
|
"vb_count": 512
|
}
|
],
|
"vb_distribution_stats_from_metadata": {
|
"172.23.105.72:8096": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[0-170]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[171-341]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[342-511]"
|
},
|
"172.23.105.8:8096": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[524, 527, 532, 538, 545, 565, 627, 636, 659, 661, 676-677]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[713, 720, 739, 809, 816, 828, 831, 847]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[877, 885, 904-905, 958, 977, 979]"
|
}
|
},
|
"worker_pids": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": 7694,
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": 7699,
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": 7707
|
}
|
}
|
]
|
2019-07-15 00:33:04 | INFO | MainProcess | test_thread | [eventing_base.verify_eventing_results] Stats for Node 172.23.105.8 is
|
[
|
{
|
"dcp_feed_boundary": "from_prior",
|
"event_processing_stats": {
|
"adhoc_timer_response_received": 10,
|
"agg_messages_sent_to_worker": 23021,
|
"agg_queue_memory": 0,
|
"agg_queue_memory_cap": 132120576,
|
"agg_queue_size": 0,
|
"agg_queue_size_cap": 300000,
|
"agg_timer_feedback_queue_cap": 1500,
|
"agg_timer_feedback_queue_size": 0,
|
"dcp_mutation": 1081,
|
"dcp_mutation_sent_to_worker": 1081,
|
"dcp_snapshot": 27,
|
"dcp_stream_req_counter": 27,
|
"dcp_streamreq": 27,
|
"execution_stats": 4379,
|
"failure_stats": 4379,
|
"latency_stats": 4379,
|
"lcb_exception_stats": 4379,
|
"log_level": 6,
|
"reb_vb_remaining_to_own": 485,
|
"reb_vb_remaining_to_stream_req": 485,
|
"thr_count": 3,
|
"thr_map": 3,
|
"v8_init": 3,
|
"v8_load": 3
|
},
|
"events_remaining": {
|
"dcp_backlog": 19042
|
},
|
"execution_stats": {
|
"agg_queue_memory": 0,
|
"agg_queue_size": 0,
|
"dcp_delete_msg_counter": 0,
|
"dcp_delete_parse_failure": 0,
|
"dcp_mutation_msg_counter": 1081,
|
"dcp_mutation_parse_failure": 0,
|
"enqueued_dcp_delete_msg_counter": 0,
|
"enqueued_dcp_mutation_msg_counter": 1081,
|
"enqueued_timer_msg_counter": 0,
|
"feedback_queue_size": 0,
|
"filtered_dcp_delete_counter": 0,
|
"filtered_dcp_mutation_counter": 0,
|
"lcb_retry_failure": 0,
|
"messages_parsed": 23009,
|
"on_delete_failure": 0,
|
"on_delete_success": 0,
|
"on_update_failure": 0,
|
"on_update_success": 1081,
|
"timer_create_failure": 0,
|
"timer_msg_counter": 0,
|
"timer_responses_sent": 0,
|
"timestamp": {
|
"2010": "2019-07-15T07:33:02Z",
|
"2016": "2019-07-15T07:33:02Z",
|
"2025": "2019-07-15T07:33:02Z"
|
},
|
"uv_try_write_failure_counter": 0
|
},
|
"failure_stats": {
|
"app_worker_setting_events_lost": 0,
|
"bucket_op_exception_count": 0,
|
"checkpoint_failure_count": 0,
|
"dcp_events_lost": 0,
|
"debugger_events_lost": 0,
|
"delete_events_lost": 0,
|
"mutation_events_lost": 0,
|
"n1ql_op_exception_count": 0,
|
"timeout_count": 0,
|
"timer_callback_missing_counter": 0,
|
"timer_context_size_exceeded_counter": 0,
|
"timer_events_lost": 0,
|
"timestamp": {
|
"2010": "2019-07-15T07:33:02Z",
|
"2016": "2019-07-15T07:33:02Z",
|
"2025": "2019-07-15T07:33:02Z"
|
},
|
"v8worker_events_lost": 0
|
},
|
"function_id": 2610724135,
|
"function_name": "Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut",
|
"gocb_creds_request_counter": 8,
|
"internal_vb_distribution_stats": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[524, 527, 532, 538, 545, 565, 627, 636, 659, 661, 676-677]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[713, 720, 739, 809, 816, 828, 831, 847]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[877, 885, 904-905, 958, 977, 979]"
|
},
|
"latency_percentile_stats": {
|
"100": 294600,
|
"50": 160500,
|
"80": 192000,
|
"90": 205700,
|
"95": 220000,
|
"99": 261100
|
},
|
"lcb_creds_request_counter": 6,
|
"lcb_exception_stats": {},
|
"metastore_stats": {},
|
"planner_stats": [
|
{
|
"host_name": "172.23.105.72:8096",
|
"start_vb": 0,
|
"vb_count": 512
|
},
|
{
|
"host_name": "172.23.105.8:8096",
|
"start_vb": 512,
|
"vb_count": 512
|
}
|
],
|
"vb_distribution_stats_from_metadata": {
|
"172.23.105.72:8096": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[0-170]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[171-341]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[342-511]"
|
},
|
"172.23.105.8:8096": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": "[524, 527, 532, 538, 545, 565, 627, 636, 659, 661, 676-677]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": "[713, 720, 739, 809, 816, 828, 831, 847]",
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": "[877, 885, 904-905, 958, 977, 979]"
|
}
|
},
|
"worker_pids": {
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_0": 2010,
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_1": 2016,
|
"worker_Function_17393222_test_eventing_rebalance_in_when_existing_eventing_node_is_processing_mut_2": 2025
|
}
|
}
|
]
|
Attachments
For Gerrit Dashboard: MB-35097 | ||||||
---|---|---|---|---|---|---|
# | Subject | Branch | Project | Status | CR | V |
112094,5 | MB-35097: Retry startDcp in case previous node hasn't closed vbs yet | unstable | eventing | Status: ABANDONED | 0 | 0 |
112160,4 | MB-35097: Handling of pausing/paused eventing apps | unstable | eventing | Status: MERGED | +2 | +1 |
112238,2 | MB-35097: Disable resume and undeploy button during pausing of handler | unstable | eventing | Status: MERGED | +2 | +1 |