Understanding in sync gateway logging

Mobile
1

Hi All,

I was analyzing the logs and following log timings I want to understand :-

2017-09-19T15:55:35.243Z HTTP: #50826: GET /database/_changes?feed=longpoll&heartbeat=30000&style=all_docs&since=0 (as user1)

2017-09-19T15:55:49.565Z HTTP+: #50826: --> 200 OK (0.0 ms)

Does it says that request number 50826 is sent in 0.0 ms but if I subtract timing then it will be around 19 seconds.

Am I understanding it correctly if yes then which log I should use to trace timings ?

Regards
Pankaj Sharma

2

_changes requests don’t report timing in HTTP+ logging, since they may block or be long-running by design (longpoll, continuous).

3

Hey @adamf

Thanks for the quick reply, but question again, what is the best way to monitor it?

I am getting a lot of socket time out errors when there is load. Want to understand is it sync gateway or the network.

4

@pankaj.sharma ,

Sometimes you need to understand whats going on on SG. Here is a basic set of tools to use to understand whats going on in SG logs.
Note this is NOT a real time tool. Its a more of a post analysis tool to figure out how long different HTTP ops took

07 AM
07 AM1404Ă—1680 351 KB

2 Likes
5

@househippo

Thanks a lot I was looking for it.

6

I need more understanding about it like what is the meaning of value on Y axix. what these two numbers mean.
Following is the graph. Machine is running on AWS with 8 Cores ,16 GB RAM , 9 buckets out of which 8 are handled by the sync gateway. with no accelerator. Its a dev envioment where the number of connection are very less netstat -tup gives 711 lines.

SGGraph
SGGraph.png1872Ă—760 60.4 KB

7

looks like your _changes feed is return very slow.
EXAMPLE
your first datapoint on September 23 @10:08:25 … (the blue graph = POST _changes) you did 8 _changes request that second and the longest one took 40.007 seconds to respond. Which is slow. I normally see a _bulk_get after the _changes feed.
Is this a logs of _changes POST coming from CBL
or
browser / backend script looking at _changes?

as you can see the above image attached is a normal CBL feed with …

  1. GET _local/checkpoint with the old seq it processed.
  2. POST _changes?since=seq_from_checkpoint
  3. POST _bulk_get of docs and revs that CBL wants from the _changes feed.
  4. PUT _local/checkpoint with the newest seq it processed.
8

I’m guessing CBL never gets to the _bulk_get b/c it times out. Can you verify in the CBL logs.

9

It looks like channel_cache_max_length has improved things drastically. What logging I should now have to get good logs and required graph. I will try to create a web solution so copy pasting of json wont required and it will be able to give almost real time graph. Then I would love to share it.

10

For the sg-log-reader-demo tool you need to have at least.
“log”:[“HTTP”,“HTTP+”]

Here is a list of all the logs events you can use.

30 PM
30 PM1714Ă—1148 132 KB

source: Couchbase Capella for Mobile Developers

It be great to get more tools for SG.

11

This is the Master Branch with the newest and most stable build