Skip to content

Instantly share code, notes, and snippets.

@elevine

elevine/gist:a25cb722d701702e0f12

Created February 25, 2015 18:03
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save elevine/a25cb722d701702e0f12 to your computer and use it in GitHub Desktop.
Save elevine/a25cb722d701702e0f12 to your computer and use it in GitHub Desktop.
Download ZIP
Couchbase Sync Gateway log showing delays
Raw
gistfile1.txt
13:00:01.026023 Enabling logging: [CRUD CRUD+ HTTP HTTP+ Access Cache Shadow Shadow+ Changes Changes+]
13:00:01.028025 ==== Couchbase Sync Gateway/1.0.3(81;fa9a6e7) ====
13:00:01.029028 Configured Go to use all 8 CPUs; setenv GOMAXPROCS to override this
13:00:01.029028 WARNING: Error setting MaxFileDescriptors to 5000: Unsupported on Windows -- rest.setMaxFileDes
criptors() at config.go:378
13:00:01.030025 Opening db /db as bucket "eric_test", pool "default", server <http://localhost:8091>
13:00:01.031023 Opening Couchbase database eric_test on <http://localhost:8091> as user "eric_test"
13:00:01.216004 Cache: Initialized changeCache with nextSequence=#890
13:00:01.217004 Shadow: Watching doc changes...
2015/02/25 13:00:01 go-couchbase: call to ViewCustom("sync_gateway", "access") in github.com/couchbaselabs/sync
_gateway/base.couchbaseBucket.ViewCustom took 223.0177ms
13:00:01.442022 Access: Computed channels for "eric":
13:00:01.535027 Access: Computed roles for "eric":
13:00:01.624058 Created user "eric"
13:00:01.796640 Access: Computed channels for "eric2":
13:00:01.890651 Access: Computed roles for "eric2":
13:00:01.978655 Created user "eric2"
13:00:01.979654 Reset guest user to config
13:00:01.979654 Starting admin server on 127.0.0.1:4985
13:00:01.983673 Starting server on :4984 ...
13:00:03.279415 Changes+: Notifying that "eric_test" changed (keys="{_sync:user:eric}") count=2
13:00:03.280417 Changes+: Notifying that "eric_test" changed (keys="{_sync:user:eric2}") count=3
13:00:03.280417 Cache: Received #890 ("_user/eric")
13:00:03.281393 Cache: #890 ==> channel "*"
13:00:03.280417 Cache: Received #891 ("_user/eric2")
13:00:03.285390 Cache: #891 ==> channel "*"
13:01:08.384252 HTTP: #001: GET / (ADMIN)
13:01:08.384252 HTTP+: #001: --> 200 (1.0 ms)
13:01:08.389258 HTTP: #002: GET / (ADMIN)
13:01:08.390240 HTTP+: #002: --> 200 (1.0 ms)
13:01:08.409240 HTTP: #003: POST /db/ (ADMIN)
13:01:08.410255 CRUD+: Invoking sync on doc "3fa17471490a63aef45ecb1adb4e6592" rev 1-a7c4c54725612304cbfa0bc02b25edd8
13:01:08.502273 CRUD: Doc "3fa17471490a63aef45ecb1adb4e6592" in channels "{message}"
13:01:08.502273 Cache: SAVING #893
13:01:08.503250 CRUD: Stored doc "3fa17471490a63aef45ecb1adb4e6592" / "1-a7c4c54725612304cbfa0bc02b25edd8"
13:01:08.503250 HTTP+: #003: --> 200 (94.0 ms)
13:01:09.294145 Cache: Received #893 after 791ms ("3fa17471490a63aef45ecb1adb4e6592" / "1-a7c4c54725612304cbfa0bc02b25edd8")
13:01:09.294145 Cache: Deferring #893 (1 now waiting for #892...#892)
13:01:16.231435 WARNING: changeCache: Giving up, accepting #893 even though #892 is missing -- db.(*changeCache)._addPendingLogs() at change_cache.go:320
13:01:16.231435 Cache: #893 ==> channel "message"
13:01:16.231435 Cache: #893 ==> channel "*"
13:01:16.231435 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=4
13:01:17.687446 HTTP: #004: GET / (ADMIN)
13:01:17.688445 HTTP+: #004: --> 200 (1.0 ms)
13:01:17.691483 HTTP: #005: POST /db/ (ADMIN)
13:01:17.699455 CRUD+: Invoking sync on doc "310f9be9bb35e81344c1b42480133449" rev 1-dcab55859d4eb15de4f01c1812a59b41
13:01:17.711453 CRUD: Doc "310f9be9bb35e81344c1b42480133449" in channels "{message}"
13:01:17.718448 Cache: SAVING #894
13:01:17.724463 CRUD: Stored doc "310f9be9bb35e81344c1b42480133449" / "1-dcab55859d4eb15de4f01c1812a59b41"
13:01:17.729457 HTTP+: #005: --> 200 (38.0 ms)
13:01:18.739304 HTTP: #006: GET / (ADMIN)
13:01:18.740334 HTTP+: #006: --> 200 (1.0 ms)
13:01:18.747303 HTTP: #007: POST /db/ (ADMIN)
13:01:18.755305 CRUD+: Invoking sync on doc "9410620d8af066c3fd864a9512379e8e" rev 1-fba2bfb4862f666f3012b1abe2364270
13:01:18.759304 CRUD: Doc "9410620d8af066c3fd864a9512379e8e" in channels "{message}"
13:01:18.760312 Cache: SAVING #895
13:01:18.761317 CRUD: Stored doc "9410620d8af066c3fd864a9512379e8e" / "1-fba2bfb4862f666f3012b1abe2364270"
13:01:18.762335 HTTP+: #007: --> 200 (15.0 ms)
13:01:19.295679 Cache: Received #894 after 1577ms ("310f9be9bb35e81344c1b42480133449" / "1-dcab55859d4eb15de4f01c1812a59b41")
13:01:19.295679 Cache: Received #895 after 536ms ("9410620d8af066c3fd864a9512379e8e" / "1-fba2bfb4862f666f3012b1abe2364270")
13:01:19.295679 Cache: #894 ==> channel "message"
13:01:19.296655 Cache: #894 ==> channel "*"
13:01:19.296655 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=5
13:01:19.296655 Cache: #895 ==> channel "message"
13:01:19.297658 Cache: #895 ==> channel "*"
13:01:19.297658 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=6
13:01:19.764852 HTTP: #008: GET / (ADMIN)
13:01:19.765878 HTTP+: #008: --> 200 (1.9 ms)
13:01:19.769843 HTTP: #009: POST /db/ (ADMIN)
13:01:19.770839 CRUD+: Invoking sync on doc "00268776cc911c86cf90d67735b30f13" rev 1-8b9ff13e37b925a491badfab7a541453
13:01:19.771879 CRUD: Doc "00268776cc911c86cf90d67735b30f13" in channels "{message}"
13:01:19.772839 Cache: SAVING #896
13:01:19.773870 CRUD: Stored doc "00268776cc911c86cf90d67735b30f13" / "1-8b9ff13e37b925a491badfab7a541453"
13:01:19.773870 HTTP+: #009: --> 200 (4.0 ms)
13:01:20.776388 HTTP: #010: GET / (ADMIN)
13:01:20.776388 HTTP+: #010: --> 200 (0.0 ms)
13:01:20.777379 HTTP: #011: POST /db/ (ADMIN)
13:01:20.778389 CRUD+: Invoking sync on doc "2f2c9122d54cdefd797ebbbf29b291ba" rev 1-6d571288b2d4c84667c28a55c48e3cdd
13:01:20.778389 CRUD: Doc "2f2c9122d54cdefd797ebbbf29b291ba" in channels "{message}"
13:01:20.779363 Cache: SAVING #897
13:01:20.785364 CRUD: Stored doc "2f2c9122d54cdefd797ebbbf29b291ba" / "1-6d571288b2d4c84667c28a55c48e3cdd"
13:01:20.786364 HTTP+: #011: --> 200 (9.0 ms)
13:01:21.296403 Cache: Received #897 after 517ms ("2f2c9122d54cdefd797ebbbf29b291ba" / "1-6d571288b2d4c84667c28a55c48e3cdd")
13:01:21.296403 Cache: Deferring #897 (1 now waiting for #896...#896)
13:01:21.296403 Cache: Received #896 after 1523ms ("00268776cc911c86cf90d67735b30f13" / "1-8b9ff13e37b925a491badfab7a541453")
13:01:21.297402 Cache: #896 ==> channel "message"
13:01:21.297402 Cache: #896 ==> channel "*"
13:01:21.297402 Cache: #897 ==> channel "message"
13:01:21.298405 Cache: #897 ==> channel "*"
13:01:21.298405 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=7
13:01:21.787113 HTTP: #012: GET / (ADMIN)
13:01:21.788114 HTTP+: #012: --> 200 (1.0 ms)
13:01:21.790107 HTTP: #013: POST /db/ (ADMIN)
13:01:21.791138 CRUD+: Invoking sync on doc "0a883823c5b876a19650f4824fc37789" rev 1-a194b11583dbaea462eb5272fcb3060a
13:01:21.792115 CRUD: Doc "0a883823c5b876a19650f4824fc37789" in channels "{message}"
13:01:21.793140 Cache: SAVING #898
13:01:21.794108 CRUD: Stored doc "0a883823c5b876a19650f4824fc37789" / "1-a194b11583dbaea462eb5272fcb3060a"
13:01:21.794108 HTTP+: #013: --> 200 (4.0 ms)
13:01:22.796671 HTTP: #014: GET / (ADMIN)
13:01:22.797671 HTTP+: #014: --> 200 (1.0 ms)
13:01:22.801669 HTTP: #015: POST /db/ (ADMIN)
13:01:22.802702 CRUD+: Invoking sync on doc "6f0acc33766e21ce6b3e6440342ce45e" rev 1-4e31331be10c8cc289bd35e60cdb6287
13:01:22.803702 CRUD: Doc "6f0acc33766e21ce6b3e6440342ce45e" in channels "{message}"
13:01:22.804704 Cache: SAVING #899
13:01:22.805702 CRUD: Stored doc "6f0acc33766e21ce6b3e6440342ce45e" / "1-4e31331be10c8cc289bd35e60cdb6287"
13:01:22.805702 HTTP+: #015: --> 200 (4.0 ms)
13:01:23.300449 Cache: Received #898 after 1507ms ("0a883823c5b876a19650f4824fc37789" / "1-a194b11583dbaea462eb5272fcb3060a")
13:01:23.300449 Cache: Received #899 after 495ms ("6f0acc33766e21ce6b3e6440342ce45e" / "1-4e31331be10c8cc289bd35e60cdb6287")
13:01:23.300449 Cache: #898 ==> channel "message"
13:01:23.302480 Cache: #898 ==> channel "*"
13:01:23.303443 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=8
13:01:23.303443 Cache: #899 ==> channel "message"
13:01:23.305476 Cache: #899 ==> channel "*"
13:01:23.305476 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=9
13:01:23.808081 HTTP: #016: GET / (ADMIN)
13:01:23.808992 HTTP+: #016: --> 200 (0.9 ms)
13:01:23.810019 HTTP: #017: POST /db/ (ADMIN)
13:01:23.810992 CRUD+: Invoking sync on doc "cab33bbeb6d2a3600af72df23916cecc" rev 1-48c1628f8af9b29c25b4eb4de46a0dc0
13:01:23.812012 CRUD: Doc "cab33bbeb6d2a3600af72df23916cecc" in channels "{message}"
13:01:23.812012 Cache: SAVING #900
13:01:23.814992 CRUD: Stored doc "cab33bbeb6d2a3600af72df23916cecc" / "1-48c1628f8af9b29c25b4eb4de46a0dc0"
13:01:23.816008 HTTP+: #017: --> 200 (6.0 ms)
13:01:24.817805 HTTP: #018: GET / (ADMIN)
13:01:24.818757 HTTP+: #018: --> 200 (1.0 ms)
13:01:24.819776 HTTP: #019: POST /db/ (ADMIN)
13:01:24.820783 CRUD+: Invoking sync on doc "b801194eea7c665ae8adefec114f0ba2" rev 1-6f56659308fbb854f5568a42dec40fb5
13:01:24.820783 CRUD: Doc "b801194eea7c665ae8adefec114f0ba2" in channels "{message}"
13:01:24.821753 Cache: SAVING #901
13:01:24.821753 CRUD: Stored doc "b801194eea7c665ae8adefec114f0ba2" / "1-6f56659308fbb854f5568a42dec40fb5"
13:01:24.822753 HTTP+: #019: --> 200 (3.0 ms)
13:01:25.298565 Cache: Received #900 after 1486ms ("cab33bbeb6d2a3600af72df23916cecc" / "1-48c1628f8af9b29c25b4eb4de46a0dc0")
13:01:25.299565 Cache: #900 ==> channel "message"
13:01:25.299565 Cache: Received #901 after 476ms ("b801194eea7c665ae8adefec114f0ba2" / "1-6f56659308fbb854f5568a42dec40fb5")
13:01:25.299565 Cache: #900 ==> channel "*"
13:01:25.300567 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=10
13:01:25.300567 Cache: #901 ==> channel "message"
13:01:25.300567 Cache: #901 ==> channel "*"
13:01:25.301567 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=11
13:01:25.824629 HTTP: #020: GET / (ADMIN)
13:01:25.824629 HTTP+: #020: --> 200 (0.0 ms)
13:01:25.825622 HTTP: #021: POST /db/ (ADMIN)
13:01:25.826607 CRUD+: Invoking sync on doc "0a56a935965ccebeb27950b4a0ec5d01" rev 1-05571ddf8a8e91b3077c638743337c08
13:01:25.826607 CRUD: Doc "0a56a935965ccebeb27950b4a0ec5d01" in channels "{message}"
13:01:25.826607 Cache: SAVING #902
13:01:25.827606 CRUD: Stored doc "0a56a935965ccebeb27950b4a0ec5d01" / "1-05571ddf8a8e91b3077c638743337c08"
13:01:25.827606 HTTP+: #021: --> 200 (2.0 ms)
13:01:27.297571 Cache: Received #902 after 1470ms ("0a56a935965ccebeb27950b4a0ec5d01" / "1-05571ddf8a8e91b3077c638743337c08")
13:01:27.297571 Cache: #902 ==> channel "message"
13:01:27.298575 Cache: #902 ==> channel "*"
13:01:27.298575 Changes+: Notifying that "eric_test" changed (keys="{*, message}") count=12
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment