Delayed response to clients from syncgateway


#1

can any one explain me in details please.
client is getting response with more delay. i am using webhooks,creating channel for each document. when a document is inserted, response to client (201) getting with more delay though doc saved in couchbase is in milliseconds. I would like to understand the what happens when a document inserted in syncgateway.

  1. which calls are asynchronous and synchronous
  2. what is the flow of doc operation like webhook trigger, couchbase insertion
  3. what are cache logs in sync gateway like cache received, deffered, saving etc

#2

Are you using the access() call in your sync gateway config function for the document type you are trying to save? Because I’ve found that call to be super slow and very expensive. Use it sparingly!


#3

yes @alexegli, we are using access() in sync gateway config. we done have other option to give access to channels for user. is there any change we need to do?


#4

We use it fine for documents that are not written frequently, it’s just if we use it for documents that are written often or are created often that we have issues. For something like a user document that I am assuming you are not writing or creating often it should be fine.

Do your webhook triggers return a response promptly? Maybe they’re slowing things down. I’m not entirely clear on how sync gateway would handle a non-200 response from a webhook though, only the sync gateway people can answer about those.


#5

It’s possible that the webhook invocation is contributing to your delay. Have you reviewed the documentation here, particularly the tuning section?
http://developer.couchbase.com/documentation/mobile/1.2/develop/guides/sync-gateway/server-integration/webhooks/index.html

As described there, there’s a potential for delays when doing a PUT operation if the webhook event processing queue is full - at that point the PUT operation will block waiting to write to the event queue. This can be tuned via the max_processes and wait_for_process properties.


#6

@adamf, currently we have configured the webhook but filter condition does not satisfy to pot to webhook so there is no question of webhook delay i think.

@alexegli, these documents are updating frequently . webhook is configured but filter condition not triggering webhook so no delay from webhook .

i just wanted to know when client will get response 201 from syncgateway. is it after doc inserted into couchbase or after webhook response. if i understood correctly response will be after doc inserted into couchbase, if so i should consider the couchbase response to couchbase.

also if using access() is causing delay, what is the alternative approach we can have?


#7

@adamf, i am receiving below log for each messages which uses access()
go-couchbase: call to ViewCustom(“sync_gateway”, “access”) in github.com/couchbase/sync_gateway/db.(*DatabaseContext).ComputeSequenceChannelsForPrincipal took 440.976536ms

i think this is related to call to view update at couchbase.
and this call response is only causing delayed response to client. what exactly happens , it updates the view and then gets the response. as per my knowledge , view updates are asynchrnous.

can you explain me in little bit dept.


#8

@arihant_rk That call will get executed at authentication time to determine the set of channels a user has been granted by an access call. The call will only be triggered if the access for that user has been changed (i.e. a document has made an access grant).


#9

Thanks @adamf, from log i could able to see , Invalidate of user and channels for user for each access() function.
is this user is getting created for each operation with new channels?
what is happeing when access() gets called.

09:33:41.138526 2016-04-20T09:33:41.138+05:30 HTTP: #33667: PUT /ptxdata/10006 (as guestuser5)
09:33:41.141153 2016-04-20T09:33:41.141+05:30 CRUD+: Invoking sync on doc “10006” rev 1-c65f9762d9ef3fef27757ede94969dc2
09:33:41.142885 2016-04-20T09:33:41.142+05:30 Access: Doc “10006” grants channel access: map[guestuser5:s918553899958_ptx101014042016064915-meta-CH:17145]
09:33:41.142914 2016-04-20T09:33:41.142+05:30 CRUD+: major = %!i(uint64=4), minor = %!i(uint64=0), micro = 0-4051
09:33:41.142937 2016-04-20T09:33:41.142+05:30 CRUD+: Optimizing write for Couchbase Server >= 3.0
09:33:41.143063 2016-04-20T09:33:41.143+05:30 Cache: SAVING #17145
09:33:41.143429 2016-04-20T09:33:41.143+05:30 CRUD: Stored doc “10006” / "1-c65f9762d9ef3fef27757ede94969dc2"
09:33:41.143452 2016-04-20T09:33:41.143+05:30 Access: Rev “10006”/“1-c65f9762d9ef3fef27757ede94969dc2” invalidates channels of [guestuser5]
09:33:41.143589 2016-04-20T09:33:41.143+05:30 Events+: Event queue worker sending event Document change event for doc id: 10006 to: Webhook handler [http://10.2.0.185:5000/echo]
09:33:41.143804 2016-04-20T09:33:41.143+05:30 Access: Invalidate access of "guestuser5"
09:33:41.144191 2016-04-20T09:33:41.144+05:30 Auth: Saved _sync:user:guestuser5: {“name”:“guestuser5”,“admin_channels”:{“public”:1},“all_channels”:null,“sequence”:1,“passwordhash_bcrypt”:“JDJhJDEwJG9DWEFrdXZ1SURxZFJYOGgyOXV4TGVmMkZ1OG9QbFZkWHVDbUMyRy5ORzlLWEVndC85Y1Rt”,“explicit_roles”:{“level-2”:1,“level-3”:1},“rolesSince”:{“level-2”:1,“level-3”:1}}
09:33:41.600649 2016-04-20T09:33:41.600+05:30 Access: Computed channels for “guestuser5”: !:1,public:1,s918553899958_ptx101014042016064915-meta-CH:2
09:33:41.601257 2016-04-20T09:33:41.601+05:30 HTTP+: #33667: --> 201 (463.6 ms)


#10

The set of channels available to the user is stored as part of the user document. When an access call is made, it invalidates that set of channels on the user doc. This triggers a recalculation of the channels the next time that user authenticates. That recalculation performs a view query to determine the access-granted channels, which is a (relatively) expensive operation.


#11

Thanks @adamf, can you please explain what exactly invalidates access and channel of user means. whats is authentication does?


#12

To be clearer - when an access call is made, it sets a flag on the user doc indicating that the channels need to be recalculated (since the current set of channels on the user doc are stale due to the new access grant). That’s what I mean by ‘invalidates’. If Sync Gateway sees that flag during user authentication, it’s the trigger to recalculate that user’s channel access.


#13

@arihant_rk , @adamf is right. the default behavior of the view engine is auto refresh the view index
every 5000 doc updates AND 5000 ms. Both conditions have to be meet. The access() call says refresh your index and waits for a response which can take extra time. So having X,000s of ,on low grade hardware for Couchbase Server, access() done per second is maybe not the best idea.


#14

Thanks @adamf and @househippo for info…