Continuous Replication, New Documents are not created


#1

Hello,

My colleque @thomas1983 and me are having this issue where new documents created on the mobile device are not replicated and inserted into couchbase server. Updating existing documents seems to work fine. When we change something on Device A the change is also visible on Device B. However Creating a new document on Device A won’t be visible on Device B. Sync Gateway log also does not show any activity of this event occuring.
I made sure the new document is in fact created locally. I know this question is very broad. I cannot pinpoint exactly where the issue might be situated. Everything seems to be configured correctly but here is a summary of the things that might be of importance here.

-Sync gateway version: 2.0.0-823
-Couchbase Server version: 5.5.0-2036
-Couhbase Lite version: 2.0.0.1
-Visual studio 2017 EE version: 15.6.6
-Mobile OS versions: Android KitKat 4.4.4 and Android Nougat 7.0

-We are working with continuous replication push/pull
-Our Sync gateway config uses an import-filter

Sync Gateway Config:

{
	 "ServerReadTimeout": 200,
     "ServerWriteTimeout": 200,
    "logging": {
    "default": {
      "logFilePath": "C:/***/Logs/sgw.log",
      "logKeys": ["*" ],
      "logLevel": "debug",
      "rotation": {
        "maxsize": 5,
        "maxage": 30,
        "maxbackups": 2,
        "localtime": true
      }
    }
	},

	"interface": ":4984",
	"adminInterface": ":4985",
	 "compressResponses":false,

	"databases": {
		"user": {
			"server": "http://*.*.*.*:8091",
			"username": "*****",
			"password": "*****",
			"bucket": "user",
			"enable_shared_bucket_access": true,
			"import_docs": "continuous",
			"import_filter": "\r\n\t\t\tfunction(doc) {\r\n\t\t\t\tif (doc.db != \"user\") {\r\n\t\t\t\t\treturn false\r\n\t\t\t\t}\r\n\t\t\t\treturn true\r\n\t\t\t}\r\n\t\t\t",
			"users": {
				"GUEST": {
					"disabled": true
				},
				"*****": {
					"password": "*****",
					"admin_channels": ["*"],
					"allow_empty_password": false
				}

			},
			"unsupported": {
				"replicator_2": true,
				"enable_extended_attributes": true
			}

		}

	}
}

logcat:

04-27 11:33:27.585: V/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.591+02:00 Sync {DBWorker#331} Notified of 1 db changes #29 ... #29
04-27 11:33:27.585: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.591+02:00 Sync {DBWorker#331} activityLevel=idle: pendingResponseCount=0, eventCount=1
04-27 11:33:27.585: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.592+02:00 Sync {Push#333} Read 1 local changes up to #29: sending 'proposeChanges' with sequences #29 - #29
04-27 11:33:27.585: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.595+02:00 Sync {Push#333} progress +0/+1194, 0 docs -- now 2 / 1196, 1 docs
04-27 11:33:27.585: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.596+02:00 Sync {Push#333} activityLevel=busy: pendingResponseCount=1, caughtUp=1, changeLists=1, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pendingSequences=1
04-27 11:33:27.585: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.597+02:00 Sync {Push#333} now busy
04-27 11:33:27.585: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.598+02:00 Sync {Repl#330} pushStatus=busy, pullStatus=idle, dbStatus=idle, progress=2/1196
04-27 11:33:27.585: V/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.599+02:00 Sync {Repl#330} progress +0/+1194, 0 docs -- now 2 / 1196, 1 docs
04-27 11:33:27.585: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.600+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.595: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.601+02:00 Sync {Repl#330} now busy
04-27 11:33:27.595: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.602+02:00 Sync (Replicator) [10] 2018-04-27T11:33:27.6023700+02:00 Replicator[<*> ws://10.10.10.46:4984/purchase] is Busy, progress 2/1196
04-27 11:33:27.595: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.604+02:00 Sync {Push#333} activityLevel=busy: pendingResponseCount=1, caughtUp=1, changeLists=1, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pendingSequences=1
04-27 11:33:27.605: V/CouchbaseLite(5881): [694] 2018-4-27 11:33:27.611+02:00 Sync (WebSocketWrapper) [694] 2018-04-27T11:33:27.6109460+02:00 <<< received 13 bytes [now 13 pending]
04-27 11:33:27.605: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.613+02:00 Sync {Push#333} Queueing rev '7b15db06-68f6-47e2-93d5-29c3840cc0bb' #1-f550694f6976045a6f7f83e6b8a3ccc52fe2cd5a (seq #29) [1 queued]
04-27 11:33:27.605: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.614+02:00 Sync {Push#333} Uploading rev 7b15db06-68f6-47e2-93d5-29c3840cc0bb 1-f550694f6976045a6f7f83e6b8a3ccc52fe2cd5a (seq #29) [1/5]
04-27 11:33:27.605: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.615+02:00 Sync {Push#333} activityLevel=busy: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=1, blobsInFlight=0, awaitingReply=0, revsToSend=0, pendingSequences=1
04-27 11:33:27.605: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.616+02:00 Sync {DBWorker#331} Sending revision '7b15db06-68f6-47e2-93d5-29c3840cc0bb' #1-f550694f6976045a6f7f83e6b8a3ccc52fe2cd5a
04-27 11:33:27.605: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.618+02:00 Sync {DBWorker#331} activityLevel=busy: pendingResponseCount=1, eventCount=1
04-27 11:33:27.605: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.619+02:00 Sync {DBWorker#331} now busy
04-27 11:33:27.615: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.621+02:00 Sync {Repl#330} pushStatus=busy, pullStatus=idle, dbStatus=busy, progress=2/1196
04-27 11:33:27.615: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.622+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.615: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.623+02:00 Sync {Push#333} activityLevel=busy: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=0, blobsInFlight=0, awaitingReply=2092, revsToSend=0, pendingSequences=1
04-27 11:33:27.615: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.624+02:00 Sync {DBWorker#331} activityLevel=busy: pendingResponseCount=1, eventCount=1
04-27 11:33:27.625: V/CouchbaseLite(5881): [697] 2018-4-27 11:33:27.631+02:00 Sync (WebSocketWrapper) [697] 2018-04-27T11:33:27.6316280+02:00 <<< received 9 bytes [now 9 pending]
04-27 11:33:27.625: V/CouchbaseLite(5881): [697] 2018-4-27 11:33:27.634+02:00 Sync (WebSocketWrapper) [697] 2018-04-27T11:33:27.6340230+02:00 <<< received 88 bytes [now 97 pending]
04-27 11:33:27.625: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.636+02:00 Sync {DBWorker#331} activityLevel=idle: pendingResponseCount=0, eventCount=1
04-27 11:33:27.625: V/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.637+02:00 Sync {DBWorker#331} now idle
04-27 11:33:27.625: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.638+02:00 Sync {Repl#330} pushStatus=busy, pullStatus=idle, dbStatus=idle, progress=2/1196
04-27 11:33:27.625: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.639+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.625: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.640+02:00 Sync {Push#333} Completed rev 7b15db06-68f6-47e2-93d5-29c3840cc0bb #1-f550694f6976045a6f7f83e6b8a3ccc52fe2cd5a (seq #29)
04-27 11:33:27.635: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.641+02:00 Sync {Pull#332} Received 'changes' REQ#3 (0 pending revs)
04-27 11:33:27.635: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.642+02:00 Sync {Pull#332} Handling 'changes' message REQ#3
04-27 11:33:27.635: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.642+02:00 Sync {Pull#332} activityLevel=busy: pendingResponseCount=0, _caughtUp=1, _waitingForChangesCallback=1, _pendingRevMessages=0, _activeIncomingRevs=0
04-27 11:33:27.635: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.643+02:00 Sync {Pull#332} now busy
04-27 11:33:27.635: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.643+02:00 Sync {Repl#330} pushStatus=busy, pullStatus=busy, dbStatus=idle, progress=2/1196
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.644+02:00 Sync {Push#333} Checkpoint now at #29
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.644+02:00 Sync {Push#333} progress +1194/+0, 1 docs -- now 1196 / 1196, 2 docs
04-27 11:33:27.635: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.645+02:00 Sync {Push#333} activityLevel=idle: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pendingSequences=0
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.645+02:00 Sync {Push#333} now idle
04-27 11:33:27.635: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.646+02:00 Sync {DBWorker#331} activityLevel=idle: pendingResponseCount=0, eventCount=1
04-27 11:33:27.635: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.646+02:00 Sync {DBWorker#331} Received 1 changes (seq '30'..'30')
04-27 11:33:27.635: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.647+02:00 Sync {DBWorker#331} Responding w/request for 0 revs
04-27 11:33:27.635: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.647+02:00 Sync {DBWorker#331} activityLevel=idle: pendingResponseCount=0, eventCount=1
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.648+02:00 Sync {Pull#332} Checkpoint now at 30
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.649+02:00 Sync {Pull#332} Now waiting for 0 'rev' messages; 0 known sequences pending
04-27 11:33:27.635: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.649+02:00 Sync {Pull#332} activityLevel=idle: pendingResponseCount=0, _caughtUp=1, _waitingForChangesCallback=0, _pendingRevMessages=0, _activeIncomingRevs=0
04-27 11:33:27.635: V/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.650+02:00 Sync {Pull#332} now idle
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.650+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.651+02:00 Sync {Repl#330} pushStatus=idle, pullStatus=busy, dbStatus=idle, progress=1196/1196
04-27 11:33:27.645: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.651+02:00 Sync {Repl#330} progress +1194/+0, 1 docs -- now 1196 / 1196, 2 docs
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.652+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.652+02:00 Sync {Repl#330} pushStatus=idle, pullStatus=idle, dbStatus=idle, progress=1196/1196
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.652+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.645: V/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.653+02:00 Sync {Repl#330} Saving remote checkpoint cp-oxlCrEWfeRlkJcQLISobmw+ndGI= with rev='0-4': {"local":29,"remote":30} ...
04-27 11:33:27.645: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.653+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.645: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.654+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.695: V/CouchbaseLite(5881): [702] 2018-4-27 11:33:27.705+02:00 Sync (WebSocketWrapper) [702] 2018-04-27T11:33:27.7053900+02:00 <<< received 17 bytes [now 17 pending]
04-27 11:33:27.695: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.707+02:00 Sync {Repl#330} Saved remote checkpoint cp-oxlCrEWfeRlkJcQLISobmw+ndGI= as rev='0-5'
04-27 11:33:27.695: I/CouchbaseLite(5881): [24] 2018-4-27 11:33:27.708+02:00 Sync {Repl#330} activityLevel=busy: connectionState=2
04-27 11:33:27.695: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.709+02:00 Sync {DBWorker#331} Saved local checkpoint cp-oxlCrEWfeRlkJcQLISobmw+ndGI= to db
04-27 11:33:27.695: I/CouchbaseLite(5881): [20] 2018-4-27 11:33:27.710+02:00 Sync {DBWorker#331} activityLevel=idle: pendingResponseCount=0, eventCount=1
04-27 11:33:27.705: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.711+02:00 Sync {Repl#330} activityLevel=idle: connectionState=2
04-27 11:33:27.705: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.711+02:00 Sync {Repl#330} now idle
04-27 11:33:27.705: I/CouchbaseLite(5881): [19] 2018-4-27 11:33:27.712+02:00 Sync (Replicator) [19] 2018-04-27T11:33:27.7123150+02:00 Replicator[<*> ws://10.10.10.46:4984/purchase] is Idle, progress 1196/1196
04-27 11:33:27.795: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.803+02:00 Sync (Replicator) [10] 2018-04-27T11:33:27.8027490+02:00 Replicator[<*> ws://10.10.10.46:4984/purchase] is Idle, progress 1196/1196
04-27 11:33:27.795: I/CouchbaseLite(5881): [10] 2018-4-27 11:33:27.804+02:00 Sync {Repl#330} activityLevel=idle: connectionState=2

If anybody has any suggestions on what to check let us know. All help is welcome.

Thanks in advance.

UPDATE:

After building our solution on the two devices from the same PC. Replication Does work for everything. Very strange. We had this before but were never able to reproduce this behavior.


#2

Yeah- that is indeed very strange. Maybe it has nothing to do with the the PC but just that you needed to do a clean rebuild and install ?


#3

Hi @priya.rajagopal,

No it does not actually. We’ve tried just everything. To make them sync we need to build the app from the same machine. Maybe it has once again to do with the merging part of the project. But I yet have to find out where that takes place.

We have the same build as in

[Couchbase]: (Startup) [1] 2018-05-02T16:21:06.3601980+02:00 CouchbaseLite/2.0.0 (.NET; Android 7.1.1 [API 25]; Honeywell CT60) Build/713 LiteCore/ (780) Commit/79870fb05-02