20:07:40.819255 Enabling logging: [CRUD CRUD+ HTTP HTTP+ Access Cache Shadow Shadow+ Changes Changes+ SG] 20:07:40.820256 ==== Couchbase Sync Gateway/1.0.3(81;fa9a6e7) ==== 20:07:40.820256 Configured Go to use all 8 CPUs; setenv GOMAXPROCS to override this 20:07:40.820256 WARNING: Error setting MaxFileDescriptors to 5000: Unsupported on Windows -- rest.setMaxFileDescriptors() at config.go:378 20:07:40.820256 Opening db /oliclinomel_sync as bucket "oliclinomel_sync", pool "default", server 20:07:40.820256 Opening Couchbase database oliclinomel_sync on 20:07:40.977271 Cache: Initialized changeCache with nextSequence=#1 20:07:40.977271 Shadow: Watching doc changes... 20:07:40.980272 Reset guest user to config 20:07:40.984272 Changes+: Notifying that "oliclinomel_sync" changed (keys="{_sync:user:}") count=2 20:07:40.984272 Cache: Received #1 ("_user/") 20:07:40.984272 Cache: #1 ==> channel "*" 2015/03/26 20:07:41 go-couchbase: call to ViewCustom("sync_gateway", "access") in github.com/couchbaselabs/sync_gateway/base.couchbaseBucket.ViewCustom took 679.0679ms 20:07:41.661340 Access: Computed channels for "oliclinomel": 20:07:41.782352 Access: Computed roles for "oliclinomel": 20:07:41.890363 Created user "oliclinomel" 20:07:41.890363 Opening Couchbase database oliclinomel on 20:07:42.086382 Database "oliclinomel_sync" shadowing remote bucket "oliclinomel", pool "default", server 20:07:42.086382 Starting admin server on :5985 20:07:42.088382 Starting server on :5984 ... 20:07:42.131387 Shadow: Reading history of external bucket 20:07:42.211395 Shadow+: Pulling "product_02", CAS=13cf21cf4ecdc5b8 ... have UpstreamRev="", UpstreamCAS=0 20:07:42.212395 Shadow: Pulling "product_02", CAS=13cf21cf4ecdc5b8 --> rev "1-ee048f8698c5ca6f77613e038a169d9a" 20:07:42.212395 CRUD+: Invoking sync on doc "product_02" rev 1-ee048f8698c5ca6f77613e038a169d9a 20:07:42.328406 Cache: SAVING #3 20:07:42.328406 CRUD: Stored doc "product_02" / "1-ee048f8698c5ca6f77613e038a169d9a" 20:07:42.328406 Shadow+: Pulling "product_01", CAS=13cf21cf4de8de1c ... have UpstreamRev="", UpstreamCAS=0 20:07:42.329406 Shadow: Pulling "product_01", CAS=13cf21cf4de8de1c --> rev "1-da76424ff9ed7912c049b721457d04c2" 20:07:42.329406 CRUD+: Invoking sync on doc "product_01" rev 1-da76424ff9ed7912c049b721457d04c2 20:07:42.329406 Cache: SAVING #4 20:07:42.329406 CRUD: Stored doc "product_01" / "1-da76424ff9ed7912c049b721457d04c2" 20:07:42.336407 Shadow+: Pulling "Document-Oliclinomel_N4-550_E-pi-in-en_US", CAS=13cf21d94e60c274 ... have UpstreamRev="", UpstreamCAS=0 20:07:42.338407 Shadow: Pulling "Document-Oliclinomel_N4-550_E-pi-in-en_US", CAS=13cf21d94e60c274 --> rev "1-0825adeba68d336ae35319c4ad2e3e78" 20:07:42.338407 CRUD+: Invoking sync on doc "Document-Oliclinomel_N4-550_E-pi-in-en_US" rev 1-0825adeba68d336ae35319c4ad2e3e78 20:07:42.344408 Cache: SAVING #5 20:07:42.358409 CRUD: Stored doc "Document-Oliclinomel_N4-550_E-pi-in-en_US" / "1-0825adeba68d336ae35319c4ad2e3e78" 20:07:42.359409 Shadow+: Pulling "product_03", CAS=13cf21cf4efb8da4 ... have UpstreamRev="", UpstreamCAS=0 20:07:42.359409 Shadow: Pulling "product_03", CAS=13cf21cf4efb8da4 --> rev "1-59fb8f45f64fb5dda6acf7a4dc22e40b" 20:07:42.359409 CRUD+: Invoking sync on doc "product_03" rev 1-59fb8f45f64fb5dda6acf7a4dc22e40b 20:07:42.359409 Cache: SAVING #6 20:07:42.360410 CRUD: Stored doc "product_03" / "1-59fb8f45f64fb5dda6acf7a4dc22e40b" 20:07:42.368410 Shadow: Caught up with history of external bucket 20:07:42.724446 Changes+: Notifying that "oliclinomel_sync" changed (keys="{_sync:user:oliclinomel}") count=3 20:07:42.724446 Cache: Received #2 ("_user/oliclinomel") 20:07:42.724446 Cache: #2 ==> channel "*" 20:07:42.724446 Cache: Received #3 after 397ms ("product_02" / "1-ee048f8698c5ca6f77613e038a169d9a") 20:07:42.724446 Cache: #3 ==> channel "*" 20:07:42.724446 Changes+: Notifying that "oliclinomel_sync" changed (keys="{*}") count=4 20:07:42.724446 Cache: Received #4 after 395ms ("product_01" / "1-da76424ff9ed7912c049b721457d04c2") 20:07:42.724446 Cache: #4 ==> channel "*" 20:07:42.724446 Changes+: Notifying that "oliclinomel_sync" changed (keys="{*}") count=5 20:07:42.726446 Cache: Received #6 after 367ms ("product_03" / "1-59fb8f45f64fb5dda6acf7a4dc22e40b") 20:07:42.726446 Cache: Deferring #6 (1 now waiting for #5...#5) 20:07:42.731447 Cache: Received #5 after 388ms ("Document-Oliclinomel_N4-550_E-pi-in-en_US" / "1-0825adeba68d336ae35319c4ad2e3e78") 20:07:42.731447 Cache: #5 ==> channel "*" 20:07:42.731447 Cache: #6 ==> channel "*" 20:07:42.731447 Changes+: Notifying that "oliclinomel_sync" changed (keys="{*}") count=6 FIRST REPLICATION 2015/03/26 20:26:12 go-couchbase: call to ViewCustom("sync_gateway", "access") in github.com/couchbaselabs/sync_gateway/base.couchbaseBucket.ViewCustom took 329.5659ms 20:26:12.208919 Access: Computed channels for "": *:1 20:26:12.366450 Access: Computed roles for "": 20:26:12.366450 HTTP: #001: GET /oliclinomel_sync/_local/01202cb351fa162c38927bbcbf7ee22354f91089 20:26:12.366950 HTTP: #001: --> 404 missing (488.6 ms) 20:26:12.382953 HTTP: #002: POST /oliclinomel_sync/_changes 20:26:12.383954 Changes: MultiChangesFeed({*}, {Since:0 Limit:0 Conflicts:true IncludeDocs:false Wait:false Continuous:false Terminator:0xc084429720}) ... 20:26:12.384454 Changes+: MultiChangesFeed: channels expand to channels.TimedSet{"*":0x1} ... 20:26:12.384954 Cache: getCachedChanges("*", {0 0}) --> 6 changes valid from #1 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:1 ID:_user/ Deleted:false Removed:{} Doc:map[] Changes:[map[rev:]] branched:false} 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:2 ID:_user/oliclinomel Deleted:false Removed:{} Doc:map[] Changes:[map[rev:]] branched:false} 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:3 ID:product_02 Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-ee048f8698c5ca6f77613e038a169d9a]] branched:false} 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:4 ID:product_01 Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-da76424ff9ed7912c049b721457d04c2]] branched:false} 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:5 ID:Document-Oliclinomel_N4-550_E-pi-in-en_US Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-e6c7dd76d48b3b234aeac2ec7cca1f42]] branched:false} 20:26:12.384954 Changes+: MultiChangesFeed sending &{Seq:6 ID:product_03 Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-59fb8f45f64fb5dda6acf7a4dc22e40b]] branched:false} 20:26:12.384954 Changes: MultiChangesFeed done 20:26:12.384954 HTTP+: #002: --> 200 OK (0.0 ms) 20:26:12.394456 Changes+: Notifying that "oliclinomel_sync" changed (keys="{_sync:user:}") count=7 20:26:12.394456 Cache: Received #1 ("_user/") 20:26:12.416960 HTTP: #003: POST /oliclinomel_sync/_bulk_get?revs=true&attachments=true 20:26:12.420461 HTTP+: #003: --> 200 (4.0 ms) 20:26:12.510479 HTTP: #004: PUT /oliclinomel_sync/_local/01202cb351fa162c38927bbcbf7ee22354f91089 20:26:12.510979 HTTP+: #004: --> 201 (1.0 ms) SECOND REPLICATION 20:36:13.231099 HTTP: #008: GET /oliclinomel_sync/_local/01202cb351fa162c38927bbcbf7ee22354f91089 20:36:13.231099 HTTP+: #008: --> 200 (0.5 ms) 20:36:13.239101 HTTP: #009: POST /oliclinomel_sync/_changes 20:36:13.239101 Changes: MultiChangesFeed({*}, {Since:4 Limit:0 Conflicts:true IncludeDocs:false Wait:false Continuous:false Terminator:0xc08437d420}) ... 20:36:13.239101 Changes+: MultiChangesFeed: channels expand to channels.TimedSet{"*":0x1} ... 20:36:13.239101 Cache: getCachedChanges("*", {0 4}) --> 2 changes valid from #5 20:36:13.239101 Changes+: MultiChangesFeed sending &{Seq:5 ID:Document-Oliclinomel_N4-550_E-pi-in-en_US Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-e6c7dd76d48b3b234aeac2ec7cca1f42]] branched:false} 20:36:13.239101 Changes+: MultiChangesFeed sending &{Seq:6 ID:product_03 Deleted:false Removed:{} Doc:map[] Changes:[map[rev:1-59fb8f45f64fb5dda6acf7a4dc22e40b]] branched:false} 20:36:13.239101 Changes: MultiChangesFeed done 20:36:13.239101 HTTP+: #009: --> 200 OK (0.0 ms) 20:36:13.253103 HTTP: #010: GET /oliclinomel_sync/Document-Oliclinomel_N4-550_E-pi-in-en_US?rev=1-e6c7dd76d48b3b234aeac2ec7cca1f42&revs=true&attachments=true 20:36:13.256604 HTTP+: #010: --> 200 (4.0 ms)