Cant do _resync while db is offline

[thezluf]

after chnaging sync gateway to the latest version i have tried to do _resync and got this error “503 Database must be _offline before calling /_resync”

I took the db offline using _offline command and got time out
running the command again resulted in 200 OK
but _resync didn’t work

I have attached the logs

LOGS:
11:47:52.748641 2016-02-25T11:47:52.748Z HTTP: #5690: POST /db/_resync (ADMIN)
11:47:52.748703 2016-02-25T11:47:52.748Z HTTP: #5690: --> 503 Database must be _offline before calling /_resync (0.1 ms)
11:47:55.155120 2016-02-25T11:47:55.155Z HTTP: #5691: POST /db/_offline (ADMIN)
11:47:55.155146 2016-02-25T11:47:55.155Z CRUD: Taking Database : db, offline
11:47:55.155163 2016-02-25T11:47:55.155Z HTTP+: #5691: --> 200 (0.1 ms)
11:47:58.286254 2016-02-25T11:47:58.286Z HTTP: #5692: POST /db/_resync (ADMIN)
11:47:58.286316 2016-02-25T11:47:58.286Z HTTP: #5692: --> 503 Database must be _offline before calling /_resync (0.1 ms)
11:48:06.108094 2016-02-25T11:48:06.108Z HTTP: #5693: POST /db/_resync (ADMIN)
11:48:06.108155 2016-02-25T11:48:06.108Z HTTP: #5693: --> 503 Database must be _offline before calling /_resync (0.1 ms)
11:48:08.859966 2016-02-25T11:48:08.859Z HTTP: #5694: POST /db/_offline (ADMIN)
11:48:08.859993 2016-02-25T11:48:08.859Z CRUD: Taking Database : db, offline
11:48:08.860011 2016-02-25T11:48:08.860Z HTTP+: #5694: --> 200 (0.1 ms)
11:48:18.621788 2016-02-25T11:48:18.621Z HTTP: #5695: POST /db/_online (ADMIN)
11:48:18.621836 2016-02-25T11:48:18.621Z CRUD: Taking Database : db, online in 0 seconds
11:48:18.621867 2016-02-25T11:48:18.621Z HTTP+: #5695: --> 200 (0.2 ms)
11:48:23.757153 2016-02-25T11:48:23.757Z HTTP: #5696: POST /db/_resync (ADMIN)
11:48:23.757213 2016-02-25T11:48:23.757Z HTTP: #5696: --> 503 Database must be _offline before calling /_resync (0.1 ms)
11:48:31.989631 2016-02-25T11:48:31.989Z HTTP: #5697: POST /db/_offline (ADMIN)
11:48:31.989658 2016-02-25T11:48:31.989Z CRUD: Taking Database : db, offline
11:48:31.989675 2016-02-25T11:48:31.989Z HTTP+: #5697: --> 200 (0.1 ms)
11:48:34.758439 2016-02-25T11:48:34.758Z HTTP: #5698: POST /db/_resync (ADMIN)
11:48:34.758512 2016-02-25T11:48:34.758Z HTTP: #5698: --> 503 Database must be _offline before calling /_resync (0.1 ms)
11:48:40.214986 2016-02-25T11:48:40.214Z HTTP: #5699: POST /db/_online (ADMIN)
11:48:40.215020 2016-02-25T11:48:40.215Z CRUD: Taking Database : db, online in 0 seconds
11:48:40.215051 2016-02-25T11:48:40.215Z HTTP+: #5699: --> 200 (0.1 ms)

[andy]

@thezluf

The log provided shows each _resync request returning with a 503 status, does the log align with the failure scenario you describe?

Can you run the following curl command and paste the results here:

curl -X GET http://host:4985/_expvar

If you look at the stat “syncGateway_rest”, if there are no other active users on Sync Gateway, “requests_active” should be ‘1’ (your _expvar request). If there are other blocked requests then this number will be greater.

e.g. for an SG instance with no active users:

"syncGateway_rest": {"requests_0000ms": 3, "requests_active": 1, "requests_total": 2}

[thezluf]

@andy

curl -X GET http://host:4985/_expvar

look completely different tough I have restarted sync gateway since then

{
“cb”: {“ops”: {“GetsRaw”: {“count”:3282,“sum”:549217303,“min”:52362,“max”:12040202,“mean”:167342.26173065204,“p25”:103239,“p50”:128232,“p75”:151749,“p90”:174871,“p99”:1821339}, “Incr”: {“count”:25,“sum”:29666851,“min”:165230,“max”:5443458,“mean”:1.18667404e+06,“p25”:262391,“p50”:554787,“p75”:1825160,“p90”:3255511,“p99”:5443458}, “Write(0x0)”: {“count”:7,“sum”:11469507,“min”:230574,“max”:5973724,“mean”:1.638501e+06,“p25”:256800,“p50”:938127,“p75”:2352845,“p90”:5973724,“p99”:5973724}, “Write(raw)”: {“count”:13,“sum”:7873853,“min”:161537,“max”:1232528,“mean”:605681,“p25”:232299,“p50”:375627,“p75”:1112096,“p90”:1217682,“p99”:1232528}, “casNext”: {“count”:848,“sum”:132489013,“min”:49681,“max”:5787112,“mean”:156237.04363207548,“p25”:83130,“p50”:92355,“p75”:111359,“p90”:170090,“p99”:2037860}}, “pools”: {“127.0.0.1:11210”: {“count”:4176,“sum”:21054754,“min”:588,“max”:4502301,“mean”:5041.847222222223,“p25”:803,“p50”:1159,“p75”:2475,“p90”:2713,“p99”:10885}}},
“cmdline”: ["/opt/couchbase-sync-gateway/bin/sync_gateway","-logFilePath=/home/sync_gateway/logs/spartkup.log","/home/ubuntu/sync_function/basic-sync-function-sparkup.json"],
“goroutine_stats”: {“HighWaterMark”:36,“Snapshots”:[36]}
,
“mc”: {“recv”: {“bytes”:{“ADD”:288,“GET”:30704302,“INCREMENT”:800,“SASL_AUTH”:72,“SASL_LIST_MECHS”:114,“SET”:833,“total”:30706409},“errs”:{},“ops”:{“ADD”:12,“GET”:4104,“INCREMENT”:25,“SASL_AUTH”:3,“SASL_LIST_MECHS”:3,“SET”:34,“total”:4181}}, “tap”: {“bytes”:{“NOOP”:2664,“TAP_DELETE”:1464,“TAP_MUTATION”:43960,“total”:48088},“errs”:{},“ops”:{“NOOP”:111,“TAP_DELETE”:11,“TAP_MUTATION”:68,“total”:190}}, “xmit”: {“bytes”:{“ADD”:11648,“GET”:259624,“INCREMENT”:1325,“SASL_AUTH”:114,“SASL_LIST_MECHS”:72,“SET”:30338,“TAP_CONNECT”:36,“total”:303157},“errs”:{},“ops”:{“ADD”:12,“GET”:4104,“INCREMENT”:25,“SASL_AUTH”:3,“SASL_LIST_MECHS”:3,“SET”:34,“TAP_CONNECT”:1,“total”:4182}}},
“memstats”: {“Alloc”:24434936,“TotalAlloc”:568201016,“Sys”:45848824,“Lookups”:1403,“Mallocs”:5328034,“Frees”:5061386,“HeapAlloc”:24434936,“HeapSys”:41254912,“HeapIdle”:13664256,“HeapInuse”:27590656,“HeapReleased”:0,“HeapObjects”:266648,“StackInuse”:688128,“StackSys”:688128,“MSpanInuse”:295344,“MSpanSys”:344064,“MCacheInuse”:2416,“MCacheSys”:16384,“BuckHashSys”:1557263,“GCSys”:1349888,“OtherSys”:638185,“NextGC”:27341293,“LastGC”:1456404899405413265,“PauseTotalNs”:45978058,“PauseNs”:[1553766,396883,355790,140554,286204,635350,540406,212242,541422,346266,1511889,5759046,397539,413110,399145,566270,324866,455803,510527,391067,511089,592680,544012,329865,253131,254079,627259,441386,472991,502391,484440,429746,454287,562466,415483,463268,485594,360824,415430,668644,6790069,383292,208670,742995,341233,427227,340131,415025,740414,266056,1383430,466914,499840,427984,475669,404264,765076,578901,479414,506687,391525,449943,656057,605300,226970,461019,478611,240532,817600,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],“PauseEnd”:[1456401822217924966,1456401822234418557,1456401822245627055,1456401822256718866,1456401822267182970,1456401943827588368,1456401948718716183,1456401951578542422,1456401952952392472,1456401956219758191,1456401959508749764,1456401962190138418,1456401966173350156,1456401967828300093,1456401968568453021,1456401974220296898,1456401977325173936,1456401979600940128,1456401985455906927,1456401990578553190,1456401995409607275,1456401999829717747,1456402003478821532,1456402005632263791,1456402012130739295,1456402017444411793,1456402024309716215,1456402034873179133,1456402053715989939,1456402087108018019,1456402170795275213,1456402291199314907,1456402411378055268,1456402426517655654,1456402446648649658,1456402463109880713,1456402486971018519,1456402608906360038,1456402731197972789,1456402851410335194,1456402973930114517,1456403096198868166,1456403216436811064,1456403336454424643,1456403458965066133,1456403581198749245,1456403701489071171,1456403823726926398,1456403853064414442,1456403864303298475,1456403882163786265,1456403898591167356,1456403924259926479,1456404046198592292,1456404166517842143,1456404286535675619,1456404348722090362,1456404355753203351,1456404369272462354,1456404382849684103,1456404415734781162,1456404536204449795,1456404656562381179,1456404746471652868,1456404757112385118,1456404769059372364,1456404783639056947,1456404815411439580,1456404899405413265,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],“NumGC”:69,“GCCPUFraction”:0.00014410986417160858,“EnableGC”:true,“DebugGC”:false,“BySize”:[{“Size”:0,“Mallocs”:0,“Frees”:0},{“Size”:8,“Mallocs”:491411,“Frees”:480868},{“Size”:16,“Mallocs”:2715888,“Frees”:2557171},{“Size”:32,“Mallocs”:712218,“Frees”:683646},{“Size”:48,“Mallocs”:328676,“Frees”:296091},{“Size”:64,“Mallocs”:78112,“Frees”:75434},{“Size”:80,“Mallocs”:215982,“Frees”:213485},{“Size”:96,“Mallocs”:230289,“Frees”:224882},{“Size”:112,“Mallocs”:151518,“Frees”:150192},{“Size”:128,“Mallocs”:6342,“Frees”:6134},{“Size”:144,“Mallocs”:30081,“Frees”:28104},{“Size”:160,“Mallocs”:10557,“Frees”:10169},{“Size”:176,“Mallocs”:45163,“Frees”:44373},{“Size”:192,“Mallocs”:2900,“Frees”:2876},{“Size”:208,“Mallocs”:67640,“Frees”:67562},{“Size”:224,“Mallocs”:1556,“Frees”:1521},{“Size”:240,“Mallocs”:22572,“Frees”:21936},{“Size”:256,“Mallocs”:5389,“Frees”:5251},{“Size”:288,“Mallocs”:96850,“Frees”:85827},{“Size”:320,“Mallocs”:5889,“Frees”:5665},{“Size”:352,“Mallocs”:30630,“Frees”:28656},{“Size”:384,“Mallocs”:2488,“Frees”:2313},{“Size”:416,“Mallocs”:14580,“Frees”:14165},{“Size”:448,“Mallocs”:2914,“Frees”:2833},{“Size”:480,“Mallocs”:162,“Frees”:150},{“Size”:512,“Mallocs”:3890,“Frees”:3396},{“Size”:576,“Mallocs”:8802,“Frees”:7167},{“Size”:640,“Mallocs”:6649,“Frees”:6465},{“Size”:704,“Mallocs”:6821,“Frees”:6593},{“Size”:768,“Mallocs”:77,“Frees”:65},{“Size”:896,“Mallocs”:722,“Frees”:697},{“Size”:1024,“Mallocs”:480,“Frees”:452},{“Size”:1152,“Mallocs”:6118,“Frees”:5040},{“Size”:1280,“Mallocs”:4100,“Frees”:3814},{“Size”:1408,“Mallocs”:2254,“Frees”:2164},{“Size”:1536,“Mallocs”:613,“Frees”:594},{“Size”:1664,“Mallocs”:74,“Frees”:61},{“Size”:2048,“Mallocs”:652,“Frees”:558},{“Size”:2304,“Mallocs”:6118,“Frees”:4534},{“Size”:2560,“Mallocs”:1096,“Frees”:1060},{“Size”:2816,“Mallocs”:1329,“Frees”:1321},{“Size”:3072,“Mallocs”:77,“Frees”:75},{“Size”:3328,“Mallocs”:55,“Frees”:47},{“Size”:4096,“Mallocs”:1400,“Frees”:1313},{“Size”:4608,“Mallocs”:556,“Frees”:534},{“Size”:5376,“Mallocs”:215,“Frees”:205},{“Size”:6144,“Mallocs”:1081,“Frees”:1018},{“Size”:6400,“Mallocs”:76,“Frees”:73},{“Size”:6656,“Mallocs”:31,“Frees”:30},{“Size”:6912,“Mallocs”:37,“Frees”:36},{“Size”:8192,“Mallocs”:403,“Frees”:390},{“Size”:8448,“Mallocs”:9,“Frees”:7},{“Size”:8704,“Mallocs”:33,“Frees”:33},{“Size”:9472,“Mallocs”:126,“Frees”:126},{“Size”:10496,“Mallocs”:37,“Frees”:36},{“Size”:12288,“Mallocs”:136,“Frees”:130},{“Size”:13568,“Mallocs”:103,“Frees”:103},{“Size”:14080,“Mallocs”:24,“Frees”:23},{“Size”:16384,“Mallocs”:159,“Frees”:156},{“Size”:16640,“Mallocs”:12,“Frees”:12},{“Size”:17664,“Mallocs”:71,“Frees”:69}]},
“syncGateway_changeCache”: {“lag-queue-0000ms”: 25, “lag-tap-0100ms”: 1, “lag-tap-0200ms”: 2, “lag-tap-0400ms”: 4, “lag-tap-0600ms”: 1, “lag-tap-0700ms”: 2, “lag-tap-0800ms”: 2, “lag-tap-1500ms”: 1, “lag-tap-1600ms”: 3, “lag-tap-1700ms”: 2, “lag-tap-1800ms”: 1, “lag-tap-2600ms”: 1, “lag-tap-3200ms”: 1, “lag-tap-3400ms”: 1, “lag-tap-4000ms”: 1, “lag-tap-5200ms”: 2, “lag-total-0100ms”: 1, “lag-total-0200ms”: 2, “lag-total-0400ms”: 4, “lag-total-0600ms”: 1, “lag-total-0700ms”: 2, “lag-total-0800ms”: 2, “lag-total-1500ms”: 1, “lag-total-1600ms”: 3, “lag-total-1700ms”: 2, “lag-total-1800ms”: 1, “lag-total-2600ms”: 1, “lag-total-3200ms”: 1, “lag-total-3400ms”: 1, “lag-total-4000ms”: 1, “lag-total-5200ms”: 2, “maxPending”: 1, “view_queries”: 60},
“syncGateway_db”: {“channelChangesFeeds”: 315, “document_gets”: 1530, “revisionCache_adds”: 25, “revisionCache_hits”: 7568, “revisionCache_misses”: 1506, “revs_added”: 25, “sequence_gets”: 1, “sequence_reserves”: 24},
“syncGateway_gocb”: {},
“syncGateway_httpListener”: {“max_active”: 0, “max_wait”: 0},
“syncGateway_index”: {“latest_write_batch”: 0},
“syncGateway_index_clocks”: {},
“syncGateway_rest”: {“changesFeeds_active”: 1, “changesFeeds_total”: 86, “requests_0000ms”: 216, “requests_0100ms”: 3, “requests_0200ms”: 78, “requests_0300ms”: 172, “requests_0400ms”: 42, “requests_0500ms”: 17, “requests_0600ms”: 5, “requests_0700ms”: 1, “requests_0800ms”: 1, “requests_0900ms”: 6, “requests_1000ms”: 6, “requests_10700ms”: 1, “requests_1100ms”: 2, “requests_1200ms”: 4, “requests_1300ms”: 3, “requests_13400ms”: 1, “requests_1400ms”: 1, “requests_1500ms”: 5, “requests_1600ms”: 2, “requests_17000ms”: 1, “requests_1800ms”: 2, “requests_19200ms”: 1, “requests_2200ms”: 1, “requests_22300ms”: 2, “requests_2300ms”: 2, “requests_23300ms”: 1, “requests_2400ms”: 2, “requests_2500ms”: 1, “requests_25900ms”: 1, “requests_2700ms”: 2, “requests_3000ms”: 1, “requests_3100ms”: 1, “requests_31900ms”: 1, “requests_34400ms”: 1, “requests_3600ms”: 1, “requests_3800ms”: 1, “requests_3900ms”: 4, “requests_40000ms”: 1, “requests_4000ms”: 2, “requests_42200ms”: 1, “requests_4300ms”: 1, “requests_49700ms”: 1, “requests_5500ms”: 2, “requests_55700ms”: 1, “requests_56700ms”: 1, “requests_64000ms”: 1, “requests_8200ms”: 1, “requests_8400ms”: 1, “requests_active”: 2, “requests_total”: 692}
}

[andy]

@thezluf

This shows “requests_active”: 2, but there is also a “changesFeeds_active”: 1. If you could run the curl command a few times over 10-30 minutes it would be useful to know if “requests_active” property fluctuates between 1 and >1 or stays at two, could you also note the value of “changesFeeds_active” for each call.

Your original issue could be related to ticket #1527, where a normal REST API call has blocked and this prevents the _offline REST API call from returning. If you experience the blocking _offline call again, it would be great if you can kill the Sync Gateway process with a SIGQUIT and post the stack trace to that ticket.

sudo kill -3 <sync_gateway_pid>

[thezluf]

I have another problem now while still not being able to take the sync gateway offline or running resync

,{“Size”:1664,“Mallocs”:26,“Frees”:16},{“Size”:2048,“Mallocs”:196,“Frees”:55},{“Size”:2304,“Mallocs”:2477,“Frees”:99},{“Size”:2560,“Mallocs”:22,“Frees”:13},{“Size”:2816,“Mallocs”:11,“Frees”:8},{“Size”:3072,“Mallocs”:6,“Frees”:3},{“Size”:3328,“Mallocs”:12,“Frees”:5},{“Size”:4096,“Mallocs”:178,“Frees”:39},{“Size”:4608,“Mallocs”:0,“Frees”:0},{“Size”:5376,“Mallocs”:25,“Frees”:13},{“Size”:6144,“Mallocs”:15,“Frees”:5},{“Size”:6400,“Mallocs”:3,“Frees”:0},{“Size”:6656,“Mallocs”:1,“Frees”:0},{“Size”:6912,“Mallocs”:0,“Frees”:0},{“Size”:8192,“Mallocs”:33,“Frees”:28},{“Size”:8448,“Mallocs”:0,“Frees”:0},{“Size”:8704,“Mallocs”:0,“Frees”:0},{“Size”:9472,“Mallocs”:4,“Frees”:2},{“Size”:10496,“Mallocs”:1,“Frees”:0},{“Size”:12288,“Mallocs”:6,“Frees”:6},{“Size”:13568,“Mallocs”:4,“Frees”:2},{“Size”:14080,“Mallocs”:4,“Frees”:2},{“Size”:16384,“Mallocs”:8,“Frees”:4},{“Size”:16640,“Mallocs”:0,“Frees”:0},{“Size”:17664,“Mallocs”:6,“Frees”:6}]},
“syncGateway_changeCache”: {“maxPending”: 0, “view_queries”: 4},
“syncGateway_db”: {“channelChangesFeeds”: 177, “document_gets”: 5, “revisionCache_hits”: 3, “revisionCache_misses”: 1, “sequence_gets”: 1, “sequence_reserves”: 1},
“syncGateway_gocb”: {},
“syncGateway_httpListener”: {“max_active”: 0, “max_wait”: 0},
“syncGateway_index”: {“latest_write_batch”: 0},
“syncGateway_index_clocks”: {},
“syncGateway_rest”: {“changesFeeds_active”: 55, “changesFeeds_total”: 59, “requests_0000ms”: 4, “requests_active”: 56, “requests_total”: 64}
}