few memcachec .get/.set calls take up to 3 seconds during rebalancing 25 node cluster with 170M items

Farshid Ghods added a comment - 15/Oct/11 10:30 PM after 10 mins ops/sec jumped back to 8k some statst o look at Get operations:      #of ops. min max avg max90th max95th max99th          6640 150 us 52 ms 1905 us 2357 us 2854 us 14 ms Set operations:      #of ops. min max avg max90th max95th max99th          3360 167 us 37 ms 1822 us 2375 us 2821 us 9307 us Average with 4 threads Get operations:      #of ops. min max avg max90th max95th max99th          6732 153 us 222 ms 2251 us 3116 us 4081 us 20 ms Set operations:      #of ops. min max avg max90th max95th max99th          3268 164 us 34 ms 2144 us 3050 us 4052 us 19 ms

Farshid Ghods added a comment - 15/Oct/11 10:32 PM attached screenshot also moxi receiving too many configuration changes 2011-10-16 03:31:06: (agent_config.c.397) configuration received 2011-10-16 03:31:07: (agent_config.c.397) configuration received 2011-10-16 03:31:08: (agent_config.c.397) configuration received 2011-10-16 03:31:09: (agent_config.c.397) configuration received 2011-10-16 03:31:10: (agent_config.c.397) configuration received 2011-10-16 03:31:11: (agent_config.c.397) configuration received 2011-10-16 03:31:12: (agent_config.c.397) configuration received 2011-10-16 03:31:13: (agent_config.c.397) configuration received 2011-10-16 03:31:14: (agent_config.c.397) configuration received 2011-10-16 03:31:15: (agent_config.c.397) configuration received 2011-10-16 03:31:16: (agent_config.c.397) configuration received 2011-10-16 03:31:17: (agent_config.c.397) configuration received 2011-10-16 03:31:18: (agent_config.c.397) configuration received 2011-10-16 03:31:20: (agent_config.c.397) configuration received 2011-10-16 03:31:21: (agent_config.c.397) configuration received 2011-10-16 03:31:22: (agent_config.c.397) configuration received 2011-10-16 03:31:23: (agent_config.c.397) configuration received 2011-10-16 03:31:25: (agent_config.c.397) configuration received 2011-10-16 03:31:26: (agent_config.c.397) configuration received 2011-10-16 03:31:27: (agent_config.c.397) configuration received 2011-10-16 03:31:28: (agent_config.c.397) configuration received 2011-10-16 03:31:29: (agent_config.c.397) configuration received 2011-10-16 03:31:30: (agent_config.c.397) configuration received 2011-10-16 03:31:31: (agent_config.c.397) configuration received 2011-10-16 03:31:33: (agent_config.c.397) configuration received 2011-10-16 03:31:34: (agent_config.c.397) configuration received 2011-10-16 03:31:35: (agent_config.c.397) configuration received 2011-10-16 03:31:36: (agent_config.c.397) configuration received 2011-10-16 03:31:37: (agent_config.c.397) configuration received 2011-10-16 03:31:38: (agent_config.c.397) configuration received 2011-10-16 03:31:39: (agent_config.c.397) configuration received 2011-10-16 03:31:40: (agent_config.c.397) configuration received 2011-10-16 03:31:42: (agent_config.c.397) configuration received 2011-10-16 03:31:43: (agent_config.c.397) configuration received 2011-10-16 03:31:44: (agent_config.c.397) configuration received 2011-10-16 03:31:45: (agent_config.c.397) configuration received 2011-10-16 03:31:46: (agent_config.c.397) configuration received 2011-10-16 03:31:47: (agent_config.c.397) configuration received 2011-10-16 03:31:48: (agent_config.c.397) configuration received 2011-10-16 03:31:49: (agent_config.c.397) configuration received 2011-10-16 03:31:50: (agent_config.c.397) configuration received 2011-10-16 03:31:51: (agent_config.c.397) configuration received 2011-10-16 03:31:52: (agent_config.c.397) configuration received 2011-10-16 03:31:54: (agent_config.c.397) configuration received 2011-10-16 03:31:55: (agent_config.c.397) configuration received 2011-10-16 03:31:56: (agent_config.c.397) configuration received 2011-10-16 03:31:57: (agent_config.c.397) configuration received 2011-10-16 03:31:58: (agent_config.c.397) configuration received 2011-10-16 03:32:00: (agent_config.c.397) configuration received 2011-10-16 03:32:01: (agent_config.c.397) configuration received 2011-10-16 03:32:02: (agent_config.c.397) configuration received 2011-10-16 03:32:03: (agent_config.c.397) configuration received 2011-10-16 03:32:04: (agent_config.c.397) configuration received 2011-10-16 03:32:06: (agent_config.c.397) configuration received 2011-10-16 03:32:08: (agent_config.c.397) configuration received 2011-10-16 03:32:09: (agent_config.c.397) configuration received 2011-10-16 03:32:10: (agent_config.c.397) configuration received 2011-10-16 03:32:11: (agent_config.c.397) configuration received 2011-10-16 03:32:12: (agent_config.c.397) configuration received 2011-10-16 03:32:13: (agent_config.c.397) configuration received 2011-10-16 03:32:14: (agent_config.c.397) configuration received 2011-10-16 03:32:15: (agent_config.c.397) configuration received 2011-10-16 03:32:16: (agent_config.c.397) configuration received 2011-10-16 03:32:18: (agent_config.c.397) configuration received 2011-10-16 03:32:19: (agent_config.c.397) configuration received 2011-10-16 03:32:20: (agent_config.c.397) configuration received 2011-10-16 03:32:21: (agent_config.c.397) configuration received 2011-10-16 03:32:22: (agent_config.c.397) configuration received 2011-10-16 03:32:23: (agent_config.c.397) configuration received 2011-10-16 03:32:24: (agent_config.c.397) configuration received 2011-10-16 03:32:25: (agent_config.c.397) configuration received 2011-10-16 03:32:26: (agent_config.c.397) configuration received 2011-10-16 03:32:27: (agent_config.c.397) configuration received 2011-10-16 03:32:28: (agent_config.c.397) configuration received 2

Farshid Ghods added a comment - 18/Oct/11 2:39 AM this tme when removing two nodes from 15 node cluster SCII get error: SERVER_ERROR proxy downstream timeout <93660> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <95550> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <74314> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.70.153.65 ASCII get error: SERVER_ERROR proxy downstream timeout <44524> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <97907> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <77135> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <77135> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <4969> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <4969> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <15102> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <81448> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.70.153.65 ASCII get error: SERVER_ERROR proxy downstream timeout <90441> isn't there anymore Average with 16 threads Get operations:      #of ops. min max avg max90th max95th max99th          6645 149 us 203 ms 1696 us 2952 us 4055 us 6790 us Set operations:      #of ops. min max avg max90th max95th max99th          3343 162 us 5006 ms 4619 us 2879 us 3880 us 6416 us ASCII get error: SERVER_ERROR proxy downstream timeout <4969> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.82.143.243 ASCII get error: SERVER_ERROR proxy downstream timeout <41183> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.84.59.167 ASCII get error: SERVER_ERROR proxy downstream timeout <94872> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.84.59.167 ASCII get error: SERVER_ERROR proxy downstream timeout <94872> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <87778> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <24944> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <6118> isn't there anymore ASCII get error: SERVER_ERROR proxy downstream timeout <28446> isn't there anymore ASCII set failure: SERVER_ERROR proxy downstream timeout 10.82.143.243 ASCII set failure: SERVER_ERROR proxy downstream timeout 10.82.143.243 ASCII get error: SERVER_ERROR proxy downstream timeout <1878> isn't there anymore

Farshid Ghods added a comment - 20/Oct/11 1:56 AM debugged further and ran moxi with -vv seeing these errors : 2011-10-20 06:55:30: (agent_config.c.397) configuration received 2011-10-20 06:55:30: (cproxy.c.1911) 160: could not forward upstream to downstream 2011-10-20 06:55:30: (memcached.c.556) <181 connection closed. 2011-10-20 06:55:30: (memcached.c.556) <174 connection closed. 2011-10-20 06:55:30: (memcached.c.556) <160 connection closed. 2011-10-20 06:55:31: (cproxy.c.1911) 162: could not forward upstream to downstream 2011-10-20 06:55:31: (memcached.c.556) <180 connection closed. 2011-10-20 06:55:31: (memcached.c.556) <221 connection closed. 2011-10-20 06:55:31: (memcached.c.556) <162 connection closed. 2011-10-20 06:55:31: (agent_config.c.397) configuration received 2011-10-20 06:55:32: (agent_config.c.397) configuration received 2011-10-20 06:55:33: (agent_config.c.397) configuration received 2011-10-20 06:55:34: (cproxy.c.1911) 161: could not forward upstream to downstream 2011-10-20 06:55:34: (memcached.c.556) <251 connection closed. 2011-10-20 06:55:34: (memcached.c.556) <246 connection closed. 2011-10-20 06:55:34: (cproxy.c.1911) 235: could not forward upstream to downstream 2011-10-20 06:55:34: (memcached.c.556) <252 connection closed.

Farshid Ghods added a comment - 20/Oct/11 3:46 PM according to moxi historgram during rebalance as you can see there are 9 requests that are taking more than 3 seconds , one request that took 6 seconds and 13 requests that took 1.6 seconds STAT 11411:default:reserved 200+100 =266786 2.40% ** STAT 11411:default:reserved 300+100 =2049829 20.84% ********************** STAT 11411:default:reserved 400+100 =2149270 40.17% ************************ STAT 11411:default:reserved 500+100 =911981 48.37% ********** STAT 11411:default:reserved 600+100 =511158 52.97% ***** STAT 11411:default:reserved 700+100 =314520 55.80% *** STAT 11411:default:reserved 800+100 =200595 57.60% ** STAT 11411:default:reserved 900+100 =135042 58.82% * STAT 11411:default:reserved 1000+100 =96563 59.69% * STAT 11411:default:reserved 1100+100 =70240 60.32% STAT 11411:default:reserved 1200+100 =53051 60.80% STAT 11411:default:reserved 1300+100 =41026 61.16% STAT 11411:default:reserved 1400+100 =32318 61.46% STAT 11411:default:reserved 1500+100 =26347 61.69% STAT 11411:default:reserved 1600+100 =446476 65.71% **** STAT 11411:default:reserved 1700+100 =967941 74.41% ********** STAT 11411:default:reserved 1800+100 =801106 81.62% ******** STAT 11411:default:reserved 1900+100 =557752 86.64% ****** STAT 11411:default:reserved 2000+100 =464165 90.81% ***** STAT 11411:default:reserved 2100+200 =501547 95.32% ***** STAT 11411:default:reserved 2300+400 =263404 97.69% ** STAT 11411:default:reserved 2700+800 =106614 98.65% * STAT 11411:default:reserved 3500+1600 =48645 99.09% STAT 11411:default:reserved 5100+3200 =26557 99.33% STAT 11411:default:reserved 8300+6400 =24194 99.55% STAT 11411:default:reserved 14700+12800 =33564 99.85% STAT 11411:default:reserved 27500+25600 =15494 99.99% STAT 11411:default:reserved 53100+51200 =1136 100.00% STAT 11411:default:reserved 104300+102400 =201 100.00% STAT 11411:default:reserved 206700+204800 =67 100.00% STAT 11411:default:reserved 411500+409600 =30 100.00% STAT 11411:default:reserved 821100+819200 =18 100.00% STAT 11411:default:reserved 1640300+1638400=13 100.00% STAT 11411:default:reserved 3278700+3276800=9 100.00% STAT 11411:default:reserved 6555500+6553600=0 100.00%

Dipti Borkar added a comment - 16/Dec/11 2:02 PM Chiyoung: This is the DGM performance issue. Non-DGM case is fixed and seems to be working. Needs to be verified by QE.

Thuan Nguyen added a comment - 29/Dec/11 6:01 PM Integrated in github-ep-engine-2-0 #131 (See [ http://qa.hq.northscale.net/job/github-ep-engine-2-0/131/ ])     

Chiyoung Seo added a comment - 30/May/12 10:01 PM In DGM scenario, this is an expected behavior as the new master for a given vbucket has the different working set in memory compared with the old master. We will address this issue in post 2.0

Chiyoung Seo added a comment - 31/May/12 3:02 AM We already have the working set synchronization task for active / replica vbuckets: http://www.couchbase.com/issues/browse/CBD-27