Details
-
Bug
-
Resolution: Fixed
-
Major
-
3.1.0, 3.1.1
-
Security Level: Public
-
None
-
Untriaged
-
No
-
KV: Sep 14 - Oct 2
Description
I have a two node cluster with a one-replica bucket. I send 100 mutations 20Mb each and observe the dcp queue size. It takes about 6 seconds to replicate each item.
With more logging I figured out that it takes the consumer 6 seconds to send the dcp_window_update message (measured since the moment when ns_server forwards a mutation to it). Immediately after that, the producer would send the next mutation:
[ns_server:debug,2015-08-25T18:23:06.065,n_0@kingstar.local:<0.551.0>:dcp_proxy:do_handle_mutations:226]=========================mutation request, body len 20971566
|
[ns_server:debug,2015-08-25T18:23:06.081,n_0@kingstar.local:<0.551.0>:dcp_proxy:pass_through_rest:241]=========================done sending mutation
|
[ns_server:debug,2015-08-25T18:23:12.066,n_0@kingstar.local:dcp_consumer_conn-default-n_1@kingstar.local<0.550.0>:dcp_proxy:handle_packet:117]Proxy packet: REQUEST: 0x5D (dcp_window_update) vbucket = 0 opaque = 0x6020000
|
80 5D 00 00
|
04 00 00 00
|
00 00 00 04
|
06 02 00 00
|
00 00 00 00
|
00 00 00 00
|
01 40 00 46
|
|
[ns_server:debug,2015-08-25T18:23:12.066,n_0@kingstar.local:<0.551.0>:dcp_proxy:do_handle_mutations:226]=========================mutation request, body len 20971559
|
[ns_server:debug,2015-08-25T18:23:12.076,n_0@kingstar.local:<0.551.0>:dcp_proxy:pass_through_rest:241]=========================done sending mutation
|
[ns_server:debug,2015-08-25T18:23:18.066,n_0@kingstar.local:dcp_consumer_conn-default-n_1@kingstar.local<0.550.0>:dcp_proxy:handle_packet:117]Proxy packet: REQUEST: 0x5D (dcp_window_update) vbucket = 0 opaque = 0x7020000
|
80 5D 00 00
|
04 00 00 00
|
00 00 00 04
|
07 02 00 00
|
00 00 00 00
|
00 00 00 00
|
01 40 00 97
|
|
I tested it on 3.1.1 only. But I'm guessing the behavior is similar in sherlock.