Sync-Gateway Bucket Shadowing Fails with High-Speed GET, DELETE, POST Sequence


#1

My server unit tests for Sync Gateway REST API produces a high-speed call sequence that seems to break bucket shadowing, requiring Sync Gateway to be restarted. Upon preliminary investigation, I am seeing the following WARNING buried in the Sync Gateway console, but unsure if it’s related or not.

WARNING

2015-12-03T05:22:48.732Z WARNING: Error pushing rev of "TESTKEY:1B" to external bucket: MCResponse status=KEY_ENOENT, opcode=DELETE, opaque=0, msg: Not found -- db.(*Shadower).PushRevision() at shadower.go:162

Pseudo Code / Sequence

Simulating the (approximate) sequence produced by go unit test that causes the anomaly is:

Loop high-speed for 50 - 100 cycles:

GET doc_id              // Get doc (and acquire latest _rev)
DELETE doc_id, _rev	// Use _rev returned by Get, above
POST doc_id             // Insert a doc with same key as just deleted

Question

Q1: What causes this error, how can it be avoided in a high-load situation, and should bucket shadowing recover?

Q2: Is it possible to DELETE or PUT a document without knowing the latest _rev ( for brute force doc deletes or overwrite situations where the _rev is not initially available )? In other words, force a doc delete or replace without first querying for the latest known _rev.

Note

Client vs. Server speed may be a factor, influencing cycles required to overload the server.

It appears the _rev may become stale ( behind the latest POST _rev ) as the Sync Gateway has not caught up resolving the cache / queue. The problem that concerns me is this approximate scenario could happen in a deployed high-load situation.

.
.
.
.

More from the console:

2015-12-03T05:22:48.622Z HTTP:  #4306: GET /test_store_sg/TESTKEY:1B  (ADMIN)
2015-12-03T05:22:48.653Z HTTP: #4306:     --> 404 deleted  (31.0 ms)
2015-12-03T05:22:48.658Z HTTP:  #4307: GET /test_store_sg/  (ADMIN)
2015-12-03T05:22:48.659Z HTTP+: #4307:     --> 200   (0.6 ms)
2015-12-03T05:22:48.661Z HTTP:  #4308: GET /test_store_sg/TESTKEY:1B  (ADMIN)
2015-12-03T05:22:48.711Z Cache: Received deduplicated #3245 for ("TESTKEY:1B" / "1762-bc72a185f288c31aee1176de268b518e")
2015-12-03T05:22:48.711Z Cache: Received deduplicated #3246 for ("TESTKEY:1B" / "1762-bc72a185f288c31aee1176de268b518e")
2015-12-03T05:22:48.711Z Cache: Received deduplicated #3247 for ("TESTKEY:1B" / "1762-bc72a185f288c31aee1176de268b518e")
2015-12-03T05:22:48.711Z Cache: Received #3248 after 414ms ("TESTKEY:1B" / "1762-bc72a185f288c31aee1176de268b518e")
2015-12-03T05:22:48.711Z Cache:     #3248 ==> channel "public"
2015-12-03T05:22:48.712Z Cache:     #3248 ==> channel "*"
2015-12-03T05:22:48.712Z Changes+: Notifying that "test_store_sync_gateway" changed (keys="{*, public}") count=141
2015-12-03T05:22:48.711Z HTTP: #4308:     --> 404 deleted  (49.7 ms)
2015-12-03T05:22:48.722Z Cache: Received #3248 after 391ms ("TESTKEY:1B" / "1762-bc72a185f288c31aee1176de268b518e")
2015-12-03T05:22:48.724Z HTTP:  #4309: GET /test_store_sg/  (ADMIN)
2015-12-03T05:22:48.725Z HTTP+: #4309:     --> 200   (1.2 ms)
2015-12-03T05:22:48.726Z Shadow: Pushing "TESTKEY:1B", rev "1762-bc72a185f288c31aee1176de268b518e" [deletion]
2015-12-03T05:22:48.732Z HTTP:  #4310: GET /test_store_sg/TESTKEY:1B  (ADMIN)
2015-12-03T05:22:48.732Z WARNING: Error pushing rev of "TESTKEY:1B" to external bucket: MCResponse status=KEY_ENOENT, opcode=DELETE, opaque=0, msg: Not found -- db.(*Shadower).PushRevision() at shadower.go:162
2015-12-03T05:22:48.772Z Shadow: Pushing "TESTKEY:1B", rev "1762-bc72a185f288c31aee1176de268b518e" [deletion]
2015-12-03T05:22:48.784Z WARNING: Error pushing rev of "TESTKEY:1B" to external bucket: MCResponse status=KEY_ENOENT, opcode=DELETE, opaque=0, msg: Not found -- db.(*Shadower).PushRevision() at shadower.go:162
2015-12-03T05:22:48.793Z HTTP: #4310:     --> 404 deleted  (61.0 ms)

#2

Hi,

Bucket Shadowing is not the most stable thing there is. It has actually been discontinued in favors of WebHooks.


#3

The particular push warning may or may not be a problem - it looks like a failure to push the delete. Can you tell whether the subsequent POST is successfully getting sent to the shadowed bucket?

To clarify, is the issue about what ends up in the shadowed bucket, or what you get back from the SG REST API after calling GET/DELETE/POST?

In general the point being made by @ldoguin is valid - bucket shadowing should be avoided when possible.


#4

I think the final POST in the sequence is being shadowed eventually, but need to write a more specific test to determine the timeline of the shadow state.

Based on your responses, I’ve spent the last few days rewriting my doc management layer to be purely Sync Gateway i/o where mobile replication is required, w/o any Couchbase shadowing dependencies.

I was a fan of bucket shadowing due to high speed native language access to the entire CB doc store via Golang, .Net, etc. Sad to see it not working and/or being discontinued.