Performance problems when using channels with CBL (iOS) and Sync Gateway

Mobile
1

Hello,

according to your recommendations on my earlier question (see: http://www.couchbase.com/communities/q-and-a/how-partition-dataset-synced-couchbase-lite-sync-gateway ) we implemented the channels on the server and client.

The problem is that now the sync is taking much longer, even with very few channels selected. In fact, it seems it now takes longer than when we were previously transferring all documents to the clients.

See at the end of this post for an example output from the Sync Manager.

FYI, the original database has only around 3500 documents in it.

I understand that the “completed” value goes up as documents are transferred. But why is total going up and down? Is this normal? It just seems that an extra document gets created for every original document and channel combination and transferred to the client. Could this be?

I left the app running while writing this. Now the counter is already at 10095/19803

Looking forward to your replies.

Florian

2014-06-17 19:24:18.987 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19830; (null)
2014-06-17 19:24:19.485 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19786; (null)
2014-06-17 19:24:19.601 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19825; (null)
2014-06-17 19:24:19.643 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19803; (null)
2014-06-17 19:24:19.725 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19816; (null)
2014-06-17 19:24:19.855 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19858; (null)
2014-06-17 19:24:19.931 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19870; (null)
2014-06-17 19:24:20.434 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19786; (null)
2014-06-17 19:24:20.777 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19799; (null)
2014-06-17 19:24:20.842 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19809; (null)
2014-06-17 19:24:20.905 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19822; (null)
2014-06-17 19:24:20.997 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19825; (null)
2014-06-17 19:24:21.013 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19838; (null)
2014-06-17 19:24:21.196 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19864; (null)
2014-06-17 19:24:21.260 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19874; (null)
2014-06-17 19:24:21.768 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19786; (null)
2014-06-17 19:24:22.053 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19877; (null)
2014-06-17 19:24:22.087 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19803; (null)
2014-06-17 19:24:22.382 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19832; (null)
2014-06-17 19:24:22.535 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19858; (null)
2014-06-17 19:24:22.628 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19870; (null)
2014-06-17 19:24:23.116 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19786; (null)
2014-06-17 19:24:23.732 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19790; (null)
2014-06-17 19:24:23.852 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19819; (null)
2014-06-17 19:24:23.971 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19861; (null)
2014-06-17 19:24:24.362 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19884; (null)
2014-06-17 19:24:24.523 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19826; (null)
2014-06-17 19:24:24.661 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19845; (null)
2014-06-17 19:24:25.196 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19873; (null)
2014-06-17 19:24:25.397 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19803; (null)
2014-06-17 19:24:25.506 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19880; (null)
2014-06-17 19:24:25.547 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19806; (null)
2014-06-17 19:24:25.776 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19819; (null)
2014-06-17 19:24:25.797 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19833; (null)
2014-06-17 19:24:26.062 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19786; (null)
2014-06-17 19:24:26.217 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19809; (null)
2014-06-17 19:24:26.239 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19822; (null)
2014-06-17 19:24:26.315 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3945/19838; (null)
2014-06-17 19:24:28.630 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3995/19786; (null)
2014-06-17 19:24:29.127 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3995/19864; (null)
2014-06-17 19:24:29.311 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3995/19793; (null)
2014-06-17 19:24:29.400 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 3995/19829; (null)
2014-06-17 19:24:35.481 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19826; (null)
2014-06-17 19:24:35.977 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19786; (null)
2014-06-17 19:24:36.605 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19858; (null)
2014-06-17 19:24:36.835 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19803; (null)
2014-06-17 19:24:37.326 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19786; (null)
2014-06-17 19:24:39.183 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19883; (null)
2014-06-17 19:24:39.534 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19870; (null)
2014-06-17 19:24:39.949 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19793; (null)
2014-06-17 19:24:40.249 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19858; (null)
2014-06-17 19:24:40.727 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19786; (null)
2014-06-17 19:24:41.264 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19864; (null)
2014-06-17 19:24:41.320 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19877; (null)
2014-06-17 19:24:41.687 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19870; (null)
2014-06-17 19:24:41.744 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4095/19822; (null)
2014-06-17 19:24:44.989 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19786; (null)
2014-06-17 19:24:45.456 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19809; (null)
2014-06-17 19:24:45.571 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19838; (null)
2014-06-17 19:24:45.610 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19864; (null)
2014-06-17 19:24:45.703 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19874; (null)
2014-06-17 19:24:46.140 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19797; (null)
2014-06-17 19:24:46.227 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19826; (null)
2014-06-17 19:24:46.315 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19858; (null)
2014-06-17 19:24:46.812 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19786; (null)
2014-06-17 19:24:47.023 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19803; (null)
2014-06-17 19:24:47.128 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19806; (null)
2014-06-17 19:24:47.210 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19809; (null)
2014-06-17 19:24:47.241 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19835; (null)
2014-06-17 19:24:47.256 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19874; (null)
2014-06-17 19:24:47.682 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19797; (null)
2014-06-17 19:24:47.767 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19826; (null)
2014-06-17 19:24:47.902 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19858; (null)
2014-06-17 19:24:48.298 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19881; (null)
2014-06-17 19:24:48.503 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19846; (null)
2014-06-17 19:24:48.858 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19859; (null)
2014-06-17 19:24:48.918 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19869; (null)
2014-06-17 19:24:49.093 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19849; (null)
2014-06-17 19:24:49.180 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19830; (null)
2014-06-17 19:24:49.546 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19869; (null)
2014-06-17 19:24:49.638 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19875; (null)
2014-06-17 19:24:49.676 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19786; (null)
2014-06-17 19:24:49.815 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19854; (null)
2014-06-17 19:24:49.908 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19857; (null)
2014-06-17 19:24:49.973 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19796; (null)
2014-06-17 19:24:50.017 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19829; (null)
2014-06-17 19:24:50.379 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19852; (null)
2014-06-17 19:24:50.646 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19865; (null)
2014-06-17 19:24:50.721 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19881; (null)
2014-06-17 19:24:50.934 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4145/19813; (null)
2014-06-17 19:24:53.456 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19830; (null)
2014-06-17 19:24:54.017 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19832; (null)
2014-06-17 19:24:54.048 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19858; (null)
2014-06-17 19:24:54.222 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19884; (null)
2014-06-17 19:24:54.323 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19870; (null)
2014-06-17 19:24:54.813 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4195/19786; (null)
2014-06-17 19:24:57.657 appname[200:60b] SYNCMGR: active=1; status=3 (kCBLReplicationActive); 4245/19788; (null)

2

The total count will go up as the puller reads the incoming _changes feed from the server. It might then go down after the puller compares the revisions from the feed and ignores the ones that are already in the local database. So it might go up by 30 as it reads changes, then down by 18 when it turns out only 12 are new.

I’m wondering if you’ve got a loop somewhere, like something that’s indirectly responding to new revisions by making changes, creating new revisions. If you’ve only got 3000 docs in the server db, then the change count shouldn’t be going much over 3000 when pulling into an empty db.

The best thing to do is probably to run your app with ‘SyncVerbose’ logging enabled (http://docs.couchbase.com/couchbase-lite/cbl-ios/#enabling-logging), upload the logs to Gist or Pastebin or something, and submit an issue on Github with a link to the logs (https://github.com/couchbase/couchbase-lite-ios/issues).