Description
Data mismatch starts happening for timers after swap rebalance of multiple kv nodes
./testrunner -i /tmp/testexec.16358.ini -p get-cbcollect-info=True,GROUP=n1ql_op_with_timers -t eventing.eventing_rebalance.EventingRebalance.test_eventing_rebalance_with_multiple_kv_nodes,doc-per-day=5,dataset=default,nodes_init=5,services_init=kv-kv-kv-eventing-index:n1ql,groups=simple,reset_services=True,,handler_code=n1ql_op_with_timers,replicas=1,GROUP=n1ql_op_with_timers
|
|
|
Exception: Bucket operations from handler code took lot of time to complete or didn't go through. Current : 0 Expected : 10080 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.104.253': {}}
|
|
|
|
|
./testrunner -i /tmp/testexec.19911.ini -p get-cbcollect-info=True,GROUP=bucket_op_with_timers -t eventing.eventing_rebalance.EventingRebalance.test_eventing_rebalance_with_multiple_kv_nodes,doc-per-day=5,dataset=default,nodes_init=5,services_init=kv-kv-kv-eventing-index:n1ql,groups=simple,reset_services=True,,handler_code=bucket_op_with_timers,GROUP=bucket_op_with_timers
|
|
Exception: Bucket operations from handler code took lot of time to complete or didn't go through. Current : 0 Expected : 10080 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.105.235': {}}
|
In the test, documents loading is triggered asynchronously before swap rebalance of the kv node.
2019-11-13 03:24:55 | INFO | MainProcess | test_thread | [rest_client.add_node] adding remote node @172.23.106.69:8091 to this cluster @172.23.106.74:8091
|
2019-11-13 03:24:56 | INFO | MainProcess | test_thread | [rest_client.add_node] adding remote node @172.23.106.67:8091 to this cluster @172.23.106.74:8091
|
2019-11-13 03:24:58 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:58 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [data_helper.direct_client] creating direct client 172.23.106.75:11210 src_bucket
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [data_helper.direct_client] creating direct client 172.23.106.76:11210 src_bucket
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [data_helper.direct_client] creating direct client 172.23.106.77:11210 src_bucket
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.67 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | test_thread | [rest_client.get_nodes] Node 172.23.106.69 not part of cluster inactiveAdded
|
2019-11-13 03:24:59 | INFO | MainProcess | Cluster_Thread | [rest_client.rebalance] rebalance params : {'password': 'password', 'ejectedNodes': u'ns_1@172.23.106.76,ns_1@172.23.106.77', 'user': 'Administrator', 'knownNodes': u'ns_1@172.23.106.69,ns_1@172.23.106.74,ns_1@172.23.106.67,ns_1@172.23.106.76,ns_1@172.23.106.73,ns_1@172.23.106.75,ns_1@172.23.106.77'}
|
2019-11-13 03:24:59 | INFO | MainProcess | Cluster_Thread | [rest_client.rebalance] rebalance operation started
|
2019-11-13 03:24:59 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 0.00 %
|
2019-11-13 03:24:59 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 0.00%
|
2019-11-13 03:25:02 | INFO | MainProcess | test_thread | [rest_client.rebalance_reached] rebalance reached >100% in 3.01206994057 seconds
|
2019-11-13 03:25:09 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 11.12 %
|
2019-11-13 03:25:09 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 11.12%
|
2019-11-13 03:25:20 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 19.05 %
|
2019-11-13 03:25:20 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 19.05%
|
2019-11-13 03:25:30 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 26.66 %
|
2019-11-13 03:25:30 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 26.66%
|
2019-11-13 03:25:40 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 40.04 %
|
2019-11-13 03:25:40 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 40.04%
|
2019-11-13 03:25:50 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 42.86 %
|
2019-11-13 03:25:50 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 42.86%
|
2019-11-13 03:26:00 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 55.30 %
|
2019-11-13 03:26:00 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 55.30%
|
2019-11-13 03:26:10 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 66.67 %
|
2019-11-13 03:26:10 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 66.67%
|
2019-11-13 03:26:20 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 71.00 %
|
2019-11-13 03:26:20 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 71.00%
|
2019-11-13 03:26:30 | INFO | MainProcess | Cluster_Thread | [rest_client._rebalance_status_and_progress] rebalance percentage : 78.57 %
|
2019-11-13 03:26:30 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: running, progress: 78.57%
|
2019-11-13 03:26:40 | INFO | MainProcess | Cluster_Thread | [task.check] Rebalance - status: none, progress: 100.00%
|
2019-11-13 03:26:40 | ERROR | MainProcess | Cluster_Thread | [rest_client._http_request] GET http://172.23.106.76:8091/pools/default body: headers: {'Content-Type': 'application/json', 'Accept': '*/*', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpwYXNzd29yZA==\n'} error: 404 reason: unknown "unknown pool" auth: Administrator:password
|
In the eventing handler code, timer is suppose to trigger after 30 seconds but lcb authentication is failed due to which eventing is unable to set timer.
During that time, Eventing log is filled with LCB_AUTH_ERROR
86554:2019-11-13T03:25:01.855-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86558:2019-11-13T03:25:01.906-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86573:2019-11-13T03:25:01.915-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86595:2019-11-13T03:25:01.963-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86599:2019-11-13T03:25:01.982-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86612:2019-11-13T03:25:02.005-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86617:2019-11-13T03:25:02.010-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86619:2019-11-13T03:25:02.015-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86622:2019-11-13T03:25:02.021-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86643:2019-11-13T03:25:02.058-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86646:2019-11-13T03:25:02.060-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86647:2019-11-13T03:25:02.061-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86650:2019-11-13T03:25:02.063-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86678:2019-11-13T03:25:02.090-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86691:2019-11-13T03:25:02.128-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86695:2019-11-13T03:25:02.156-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86698:2019-11-13T03:25:02.161-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86718:2019-11-13T03:25:02.181-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86721:2019-11-13T03:25:02.195-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86732:2019-11-13T03:25:02.227-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86735:2019-11-13T03:25:02.238-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86746:2019-11-13T03:25:02.272-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86749:2019-11-13T03:25:02.276-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86760:2019-11-13T03:25:02.303-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86763:2019-11-13T03:25:02.305-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86774:2019-11-13T03:25:02.339-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86777:2019-11-13T03:25:02.341-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86788:2019-11-13T03:25:02.396-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86791:2019-11-13T03:25:02.399-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86810:2019-11-13T03:25:02.426-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86813:2019-11-13T03:25:02.428-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86824:2019-11-13T03:25:02.471-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86827:2019-11-13T03:25:02.479-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86838:2019-11-13T03:25:02.538-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86841:2019-11-13T03:25:02.541-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86860:2019-11-13T03:25:02.574-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86863:2019-11-13T03:25:02.580-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_0:/tmp/127.0.0.1:8091_0_955883421.sock:94849] [lcb,server L:777 I:2248989486] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f25c4077220,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86874:2019-11-13T03:25:02.619-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86882:2019-11-13T03:25:02.624-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_1:/tmp/127.0.0.1:8091_1_955883421.sock:94855] [lcb,server L:777 I:823726560] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7fdd8c0ff3f0,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
86903:2019-11-13T03:25:02.694-08:00 [Info] eventing-consumer [worker_Function_28066170_test_eventing_rebalance_with_multiple_kv_nodes_2:/tmp/127.0.0.1:8091_2_955883421.sock:94868] [lcb,server L:777 I:2767056025] <NOHOST:NOPORT> (CTX=(nil),,SRV=0x7f9c7c056620,IX=0) Connection attempt failed. Received LCB_AUTH_ERROR (0x02) from libcouchbase, received 0 from operating system
|
memcahced reported invalid password
memcached.log.000002.txt:2019-11-13T03:25:01.855076-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[0951d172-e444-4d52-1695-0da9d3a3b70a] memcached.log.000002.txt:2019-11-13T03:25:01.905298-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[a474b816-807f-4241-65b9-50204a4edbaf] memcached.log.000002.txt:2019-11-13T03:25:01.914388-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[8c84f2f7-427d-403f-8f77-6bab1ea8e515] memcached.log.000002.txt:2019-11-13T03:25:01.961682-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[e37cca2b-81b3-4c37-4ed9-73a0556badfd] memcached.log.000002.txt:2019-11-13T03:25:01.980954-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[56e6d40b-e8f9-43f2-b384-d0508c71ced8] memcached.log.000002.txt:2019-11-13T03:25:02.003642-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[055591f2-e4d2-4eab-929b-28d6c3233ed4] memcached.log.000002.txt:2019-11-13T03:25:02.010237-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[b1f70e06-1479-406a-39dc-96eafe195b33] memcached.log.000002.txt:2019-11-13T03:25:02.010752-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[f4caeff2-fe4d-4996-813a-f04aa283d857] memcached.log.000002.txt:2019-11-13T03:25:02.020544-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[6b3c3f47-d70e-45dd-7e9d-2a4eac9da8bc] memcached.log.000002.txt:2019-11-13T03:25:02.058054-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[03e50aa6-298c-4f19-8927-8a25217e39d7] memcached.log.000002.txt:2019-11-13T03:25:02.060075-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[f8722235-3730-43fc-f75b-62b6e088db87] memcached.log.000002.txt:2019-11-13T03:25:02.060274-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[7ba18171-f35d-44ea-c832-66e379cbc803] memcached.log.000002.txt:2019-11-13T03:25:02.062806-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[f9a03a45-1e2d-494d-71de-145248084b5c] memcached.log.000002.txt:2019-11-13T03:25:02.087241-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[6ce774f6-3334-4ff3-24f0-496b622db8db] memcached.log.000002.txt:2019-11-13T03:25:02.127632-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[cd99e289-df43-42a6-4f02-20497ad14340] memcached.log.000002.txt:2019-11-13T03:25:02.156452-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[0538c38f-c5fd-4050-bf41-a5379e847dbd] memcached.log.000002.txt:2019-11-13T03:25:02.160161-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[671f814f-0a0c-4d2a-a643-d6cd57cfc2bc] memcached.log.000002.txt:2019-11-13T03:25:02.180398-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[c37d6f8f-2fdb-41c2-04db-1e5f9d4666e8] memcached.log.000002.txt:2019-11-13T03:25:02.193727-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[dfbd800e-216c-49ff-976c-096239da68fe] memcached.log.000002.txt:2019-11-13T03:25:02.225690-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[c143d783-3dee-4279-73c0-47f721bede52] memcached.log.000002.txt:2019-11-13T03:25:02.233399-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[7327c9b2-814f-4749-ee2f-0315475c2877] memcached.log.000002.txt:2019-11-13T03:25:02.270654-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[7baa583b-29c1-4b0f-0219-3131d020d0bb] memcached.log.000002.txt:2019-11-13T03:25:02.276455-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[4e1987e3-2a21-4404-0871-36ca3ec63a36] memcached.log.000002.txt:2019-11-13T03:25:02.302918-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[01556332-ecfb-4950-60a6-33929aef899e] memcached.log.000002.txt:2019-11-13T03:25:02.304770-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[e99f4ec2-bafd-42c2-8ad3-cf1350e5eec9] memcached.log.000002.txt:2019-11-13T03:25:02.337058-08:00 WARNING 61: Invalid password specified for [<ud>@eventing</ud>] UUID:[473aecd7-0205-4c52-63f5-eb665e40f525] memcached.log.000002.txt:2019-11-13T03:25:02.341124-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[77dea468-9ccd-409c-7866-21801c727ca5] memcached.log.000002.txt:2019-11-13T03:25:02.396470-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[afc56437-86d1-491b-a4e6-bc0e6eba57c9] memcached.log.000002.txt:2019-11-13T03:25:02.398927-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[cb47e73c-4bf8-4610-1924-33cf7a62a0d7] memcached.log.000002.txt:2019-11-13T03:25:02.426198-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[766a8856-b2cd-4ef4-4046-e83165fe880a] memcached.log.000002.txt:2019-11-13T03:25:02.428360-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[ef06bf0d-debb-4156-cd8d-9a5490fb5e95] memcached.log.000002.txt:2019-11-13T03:25:02.471185-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[e15cc6d0-dfaf-4a9b-ede8-d64cd24e5d18] memcached.log.000002.txt:2019-11-13T03:25:02.478532-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[67675cec-eaac-46cb-8a6f-79930a740309] memcached.log.000002.txt:2019-11-13T03:25:02.538075-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[10ccf837-3fa2-404a-c8eb-7754a41fe7d4] memcached.log.000002.txt:2019-11-13T03:25:02.540548-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[a5e4a5f8-0e8a-4014-a4e8-5dd689be7f6c] memcached.log.000002.txt:2019-11-13T03:25:02.574465-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[ada1307f-7d50-4896-a7f6-99f1bff4969d] memcached.log.000002.txt:2019-11-13T03:25:02.580377-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[2c0df47a-92a2-48c8-8b29-eefe4b43f3f5] memcached.log.000002.txt:2019-11-13T03:25:02.611907-08:00 WARNING 61: Invalid password specified for [<ud>@eventing</ud>] UUID:[18ae8315-307b-4393-1079-5dba93604d2a] memcached.log.000002.txt:2019-11-13T03:25:02.623563-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[56752aab-3310-41c2-75f0-99dd3282c68f] memcached.log.000002.txt:2019-11-13T03:25:02.692173-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[0901389c-2ede-470a-b8cf-c031cac57427] memcached.log.000002.txt:2019-11-13T03:25:02.727378-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[2ac96a60-b6b4-471b-5888-84d225282df5] memcached.log.000002.txt:2019-11-13T03:25:02.729486-08:00 WARNING 54: Invalid password specified for [<ud>@eventing</ud>] UUID:[a21f4451-a4c5-47db-3313-002325445203] memcached.log.000002.txt:2019-11-13T03:25:02.779051-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[1d66f1d2-41bf-402a-b10b-e06733929f3a] memcached.log.000002.txt:2019-11-13T03:25:02.784393-08:00 WARNING 60: Invalid password specified for [<ud>@eventing</ud>] UUID:[977c98a5-5698-496c-e7ff-e6654e24a36b]
|
This issue starts happening from build 4712. There is no changes in eventing code from 4711 and 4712 build.
There is one change in libcouchbase which is related to caching credentials: http://review.couchbase.org/#/c/116958/
Attachments
Issue Links
- blocks
-
MB-36326 [System test]: Eventing rebalance hung since 9 hrs
-
- Closed
-
-
-
- Closed
-
- causes
-
-
- Closed
-
- relates to
-
CCBC-1260 Need way to boostrap using cluster mgmt port
-
- Resolved
-
Activity
See notes in MB-36793. I think we now understand why the config is not being updated, which would cause lcb to continue to try to connect to nodes from the config that aren't in cbauth.
Marking resolved as we believe the root cause here was the change to HTTP, while there is still an open question on why the long-polling didn't update the client. Regardless, Sergey Avseyev and I reviewed and have recommendations we hope will resolve this in the related MB.
I've logged CCBC-1260 to request providing a way to bootstrap libcouchbase using ns_server management port. We'd like to revert the fixes put into MB-36793 when this is provided. I do not believe "Not a Bug" is accurate disposition as the question as to why http bootstrap didn't work correctly was never resolved. Perhaps "Will Not Fix" is more suitable.
Vikas Chaudhary repro also has the same signature. libcouchbase is asking for credentials of already rebalanced out node.
Node .60 is ejected out.
2019-12-12 02:32:41 | INFO | MainProcess | Cluster_Thread | [rest_client.rebalance] rebalance params : {'password': 'password', 'ejectedNodes': u'ns_1@172.23.106.60', 'user': 'Administrator', 'knownNodes':Rebalance completed at 02:34:28
2019-12-12 02:34:28 | INFO | MainProcess | Cluster_Thread | [task.check] rebalancing was completed with progress: 100% in 107.180487156 sec2019-12-12 02:34:28 | INFO | MainProcess | test_thread | [basetestcase.get_nodes_from_services_map] list of eventing nodes in cluster: [ip:172.23.106.53 port:8091 ssh_username:root, ip:172.23.106.52 port:8091 ssh_username:root, ip:172.23.105.231 port:8091 ssh_username:root]Around that time libcouchbase continuously asking for credentials of node .60
60571:2019-12-12T02:35:10.970-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60575:2019-12-12T02:35:10.973-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60576:2019-12-12T02:35:10.974-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60579:2019-12-12T02:35:10.981-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60581:2019-12-12T02:35:10.981-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60586:2019-12-12T02:35:10.986-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60588:2019-12-12T02:35:10.986-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60589:2019-12-12T02:35:10.987-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60590:2019-12-12T02:35:10.987-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60595:2019-12-12T02:35:10.989-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'60596:2019-12-12T02:35:10.989-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48025 2019-12-12T02:35:11.259-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48026 2019-12-12T02:35:11.259-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48046 2019-12-12T02:35:11.259-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48047 2019-12-12T02:35:11.260-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48048 2019-12-12T02:35:11.260-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'48049 2019-12-12T02:35:11.260-08:00 [Error] ServiceMgr::getCreds Failed to get credentials for endpoint: 172.23.106.60:11210, err: Unable to find given hostport in cbauth database: `172.23.106.60:11210'This stopped after 2019-12-12T02:35:11 and also the LCB_AUTH_ERROR.
During that time libcouchbase detected that node .60 is removed from the cluster. But it detected that around 02:35:10 for 1st worker which is almost 30sec after the rebalance out of the node and it started detecting for other workers too. There are 8 worker and each has 8 cpp worker thread. Last worker closed its connection at 2019-12-12T02:35:15
Node53/eventing.log:59669:2019-12-12T02:35:10.086-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:2970348907] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59702:2019-12-12T02:35:10.094-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:2427882106] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59708:2019-12-12T02:35:10.095-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:2017628134] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59746:2019-12-12T02:35:10.120-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:3865357689] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59754:2019-12-12T02:35:10.122-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:849874182] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59770:2019-12-12T02:35:10.124-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:1996525270] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59779:2019-12-12T02:35:10.126-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:3276651883] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59788:2019-12-12T02:35:10.139-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_0:/tmp/127.0.0.1:8091_0_3146742372.sock:120432] [lcb,newconfig L:178 I:906463098] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59939:2019-12-12T02:35:10.309-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:2757363660] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59962:2019-12-12T02:35:10.319-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:1423024812] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:59974:2019-12-12T02:35:10.324-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:583636605] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60008:2019-12-12T02:35:10.349-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:289074711] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60031:2019-12-12T02:35:10.359-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:1059246787] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60060:2019-12-12T02:35:10.377-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:1963847587] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60077:2019-12-12T02:35:10.392-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:873955377] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60083:2019-12-12T02:35:10.392-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_1:/tmp/127.0.0.1:8091_1_3146742372.sock:120441] [lcb,newconfig L:178 I:2367975670] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60102:2019-12-12T02:35:10.430-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:2004420470] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60151:2019-12-12T02:35:10.502-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:3852044021] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60184:2019-12-12T02:35:10.535-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:414744423] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60196:2019-12-12T02:35:10.547-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:2919938948] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60242:2019-12-12T02:35:10.568-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:1461047975] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60250:2019-12-12T02:35:10.571-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:404554326] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60259:2019-12-12T02:35:10.578-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:819007663] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60268:2019-12-12T02:35:10.582-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_2:/tmp/127.0.0.1:8091_2_3146742372.sock:120446] [lcb,newconfig L:178 I:2914811298] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60311:2019-12-12T02:35:10.680-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:3730702953] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60344:2019-12-12T02:35:10.726-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:1791024843] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60361:2019-12-12T02:35:10.754-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:2408344560] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60381:2019-12-12T02:35:10.768-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:827963802] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60413:2019-12-12T02:35:10.795-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:2311987916] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60430:2019-12-12T02:35:10.816-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:3497262264] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60440:2019-12-12T02:35:10.837-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:3832177653] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60629:2019-12-12T02:35:11.032-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:325555734] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60655:2019-12-12T02:35:11.040-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:1963060550] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60663:2019-12-12T02:35:11.041-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:1739423958] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60678:2019-12-12T02:35:11.052-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:2534975915] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60718:2019-12-12T02:35:11.138-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:3921607530] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60727:2019-12-12T02:35:11.152-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:4009376487] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60750:2019-12-12T02:35:11.213-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:2255639193] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60759:2019-12-12T02:35:11.221-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_3:/tmp/127.0.0.1:8091_3_3146742372.sock:120465] [lcb,newconfig L:178 I:4211586985] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60794:2019-12-12T02:35:15.346-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_4:/tmp/127.0.0.1:8091_4_3146742372.sock:120455] [lcb,newconfig L:178 I:3964063974] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60813:2019-12-12T02:35:15.588-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:805358594] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60826:2019-12-12T02:35:15.592-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:767697159] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60832:2019-12-12T02:35:15.594-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:4114596483] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60838:2019-12-12T02:35:15.597-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:2224158362] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60847:2019-12-12T02:35:15.599-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:3502468914] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60854:2019-12-12T02:35:15.600-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:30346045] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60860:2019-12-12T02:35:15.613-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:3275868326] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60866:2019-12-12T02:35:15.616-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_5:/tmp/127.0.0.1:8091_5_3146742372.sock:120487] [lcb,newconfig L:178 I:3354657746] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60897:2019-12-12T02:35:15.636-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:2490629776] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60903:2019-12-12T02:35:15.637-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:1451407412] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60911:2019-12-12T02:35:15.639-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:3230835460] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60924:2019-12-12T02:35:15.642-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:533353985] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60927:2019-12-12T02:35:15.642-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:1912362609] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60936:2019-12-12T02:35:15.643-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:247974662] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60944:2019-12-12T02:35:15.643-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:3989845398] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60954:2019-12-12T02:35:15.647-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_6:/tmp/127.0.0.1:8091_6_3146742372.sock:120492] [lcb,newconfig L:178 I:1835199566] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60963:2019-12-12T02:35:15.647-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:3518838272] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60970:2019-12-12T02:35:15.648-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:775323449] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60978:2019-12-12T02:35:15.651-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:3719864427] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60985:2019-12-12T02:35:15.653-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:2678987733] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60991:2019-12-12T02:35:15.654-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:2499662027] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:60997:2019-12-12T02:35:15.656-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:882947994] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:61006:2019-12-12T02:35:15.657-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:3003034330] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removedNode53/eventing.log:61012:2019-12-12T02:35:15.662-08:00 [Info] eventing-consumer [worker_Function_184941835_test_kv_swap_rebalance_when_existing_eventing_node_is_processing_mutati_7:/tmp/127.0.0.1:8091_7_3146742372.sock:120490] [lcb,newconfig L:178 I:2959535368] Detected server 172.23.106.60:11210(Data=11210, Index=0, Query=0) removed