Details
-
Bug
-
Resolution: Fixed
-
Critical
-
5.5.0
-
5.5.0-2160
-
Untriaged
-
Centos 64-bit
-
Unknown
Description
Scripts to Repro
./testrunner -i /tmp/testexec.12561.ini get-cbcollect-info=True -t eventing.eventing_settings.EventingSettings.test_eventing_with_non_default_setting_values,nodes_init=4,services_init=kv-eventing-index-n1ql,dataset=default,groups=simple,reset_services=True,skip_cleanup=True,handler_code=bucket_op_with_timers
|
./testrunner -i /tmp/testexec.12561.ini get-cbcollect-info=True -t eventing.eventing_settings.EventingSettings.test_eventing_with_non_default_setting_values,nodes_init=4,services_init=kv-eventing-index-n1ql,dataset=default,groups=simple,reset_services=True,skip_cleanup=True,handler_code=n1ql_op_with_timers
|
Non default values are
sock_batch_size=8, worker_count=8, cpp_worker_thread_count=8,
|
checkpoint_interval=5000, tick_duration=2000
|
I think this bug was introduced in last 3-4 weeks. It was working fine before. This bug is not consistently reproducible. I have seen this 3 times in last 10 runs. A variation of the same bug was also seen by Abhishek Singh in Eventing CI. We had discussed about this couple of weeks back. I think its worth looking into this.
Results from test 1
Exception: Bucket operations from handler code took lot of time to complete or didn't go through. Current : 1019 Expected : 2016 dcp_backlog : 1596 TIMERS_IN_PAST : 0
|
[
|
{
|
"event_processing_stats": {
|
"ADHOC_DOC_TIMER_RESPONSES_RECEIVED": 61,
|
"AGG_MESSAGES_SENT_TO_WORKER": 7019,
|
"DCP_MUTATION": 4032,
|
"DCP_MUTATION_SENT_TO_WORKER": 2016,
|
"DCP_SNAPSHOT": 4004,
|
"DCP_STREAMREQ": 1024,
|
"DOC_TIMER_EVENTS": 1019,
|
"DOC_TIMER_RESPONSES_RECEIVED": 1019,
|
"EXECUTION_STATS": 982,
|
"FAILURE_STATS": 982,
|
"HANDLER_CODE": 8,
|
"LATENCY_STATS": 982,
|
"LCB_EXCEPTION_STATS": 982,
|
"LOG_LEVEL": 8,
|
"SOURCE_MAP": 8,
|
"THR_COUNT": 8,
|
"THR_MAP": 8,
|
"V8_INIT": 8,
|
"V8_LOAD": 8
|
},
|
"events_remaining": {
|
"dcp_backlog": 1596
|
},
|
"execution_stats": {
|
"agg_queue_size": 0,
|
"cron_timer_msg_counter": 0,
|
"dcp_delete_msg_counter": 0,
|
"dcp_mutation_msg_counter": 2016,
|
"doc_timer_create_failure": 0,
|
"doc_timer_msg_counter": 1019,
|
"doc_timer_responses_sent": 1019,
|
"enqueued_cron_timer_msg_counter": 0,
|
"enqueued_dcp_delete_msg_counter": 0,
|
"enqueued_dcp_mutation_msg_counter": 2016,
|
"enqueued_doc_timer_msg_counter": 1019,
|
"feedback_queue_size": 997,
|
"messages_parsed": 6995,
|
"on_delete_failure": 0,
|
"on_delete_success": 0,
|
"on_update_failure": 0,
|
"on_update_success": 2016
|
},
|
"failure_stats": {
|
"bucket_op_exception_count": 0,
|
"checkpoint_failure_count": 0,
|
"n1ql_op_exception_count": 0,
|
"timeout_count": 0
|
},
|
"function_name": "Function_859936519_test_eventing_with_non_default_setting_values",
|
"lcb_exception_stats": {},
|
"planner_stats": [
|
{
|
"host_name": "172.23.123.73:8096",
|
"start_vb": 0,
|
"vb_count": 1024
|
}
|
],
|
"vb_distribution_stats": {
|
"172.23.123.73:8096": {
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_0": "[0-127]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_1": "[128-255]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_2": "[256-383]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_3": "[384-511]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_4": "[512-639]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_5": "[640-767]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_6": "[768-895]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_7": "[896-1023]"
|
}
|
},
|
"worker_pids": {
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_0": 18721,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_1": 18727,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_2": 18733,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_3": 18736,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_4": 18765,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_5": 18763,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_6": 18779,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_7": 18823
|
}
|
}
|
]
|
Results from test 2
Exception: Bucket operations from handler code took lot of time to complete or didn't go through. Current : 1009 Expected : 2016 dcp_backlog : 1237 TIMERS_IN_PAST : 0
|
[
|
{
|
"event_processing_stats": {
|
"ADHOC_DOC_TIMER_RESPONSES_RECEIVED": 99,
|
"AGG_MESSAGES_SENT_TO_WORKER": 7201,
|
"DCP_MUTATION": 4032,
|
"DCP_MUTATION_SENT_TO_WORKER": 2016,
|
"DCP_SNAPSHOT": 3985,
|
"DCP_STREAMREQ": 1024,
|
"DOC_TIMER_EVENTS": 1009,
|
"DOC_TIMER_RESPONSES_RECEIVED": 1009,
|
"EXECUTION_STATS": 1030,
|
"FAILURE_STATS": 1030,
|
"HANDLER_CODE": 8,
|
"LATENCY_STATS": 1030,
|
"LCB_EXCEPTION_STATS": 1030,
|
"LOG_LEVEL": 8,
|
"SOURCE_MAP": 8,
|
"THR_COUNT": 8,
|
"THR_MAP": 8,
|
"V8_INIT": 8,
|
"V8_LOAD": 8
|
},
|
"events_remaining": {
|
"dcp_backlog": 1237
|
},
|
"execution_stats": {
|
"agg_queue_size": 0,
|
"cron_timer_msg_counter": 0,
|
"dcp_delete_msg_counter": 0,
|
"dcp_mutation_msg_counter": 2016,
|
"doc_timer_create_failure": 0,
|
"doc_timer_msg_counter": 1009,
|
"doc_timer_responses_sent": 1009,
|
"enqueued_cron_timer_msg_counter": 0,
|
"enqueued_dcp_delete_msg_counter": 0,
|
"enqueued_dcp_mutation_msg_counter": 2016,
|
"enqueued_doc_timer_msg_counter": 1009,
|
"feedback_queue_size": 1007,
|
"messages_parsed": 7177,
|
"on_delete_failure": 0,
|
"on_delete_success": 0,
|
"on_update_failure": 0,
|
"on_update_success": 2016
|
},
|
"failure_stats": {
|
"bucket_op_exception_count": 0,
|
"checkpoint_failure_count": 0,
|
"n1ql_op_exception_count": 0,
|
"timeout_count": 0
|
},
|
"function_name": "Function_859936519_test_eventing_with_non_default_setting_values",
|
"lcb_exception_stats": {},
|
"planner_stats": [
|
{
|
"host_name": "172.23.123.73:8096",
|
"start_vb": 0,
|
"vb_count": 1024
|
}
|
],
|
"vb_distribution_stats": {
|
"172.23.123.73:8096": {
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_0": "[0-127]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_1": "[128-255]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_2": "[256-383]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_3": "[384-511]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_4": "[512-639]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_5": "[640-767]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_6": "[768-895]",
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_7": "[896-1023]"
|
}
|
},
|
"worker_pids": {
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_0": 24130,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_1": 24125,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_2": 24158,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_3": 24136,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_4": 24147,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_5": 24191,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_6": 24168,
|
"worker_Function_859936519_test_eventing_with_non_default_setting_values_7": 24221
|
}
|
}
|
]
|
