How can I debug invalid_json?

Mobile
1

When I first create a document on my mobile device it is sync’ed to my App Service no problem. I am using Capella and the .Net SDK.

If I update the object on the mobile device the changes cause a sync issue with invalid_json in the metadata.

Each subsequent update causes a new one of these records to show up in the server side data.

Eventually these records seem to get processed and go away and the final state of the item that has been updated is reflected correctly on the server.

This is a slow process, maybe a minute or more for it to reconcile.

How can I debug this? See screenshot.

Screenshot 2025-01-03 at 2.16.10 PM
Screenshot 2025-01-03 at 2.16.10 PM1920×1487 123 KB

2

Would a DateTimeOffset property on an object I am serializing cause me issues at all?

3

Can you show us the error?

4

That’s all I get, these records show up in couchbase, nothing in the logs on the device and I have it set to Verbose.

Once this happens changes on the server are not reflected on the device. For instance if I delete the document on the server it remains on the device.

I have my Channels configured correctly, I also have PushAndPull configured properly on the device.

Here is a section of logs that are triggered on the device when I change a property on the server of an object, the change is not reflected in the app:

2025-01-06 11:04:06.741865-0500 MyApp[16409:565192] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (629)] <<< received 137 bytes [now 137 pending]
2025-01-06 11:04:06.744558-0500 MyApp[16409:565193] [.NET Long Running Task]| VERBOSE)  [Network] {C4SocketImpl#26} Received 133-byte message
2025-01-06 11:04:06.745936-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} Received frame: REQ #25 ---C, length   131
2025-01-06 11:04:06.746714-0500 MyApp[16409:565193] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (630)] c4Socket received.
2025-01-06 11:04:06.747531-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {Connection#14} Receiving 'changes' REQ #25 Z
2025-01-06 11:04:06.747797-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {Connection#14} Finished receiving 'changes' REQ #25 Z
2025-01-06 11:04:06.748998-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=idle: connectionState=2, savingChkpt=0
2025-01-06 11:04:06.750667-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {RevFinder#59} {Coll#4} Handling 'changes' REQ#25
2025-01-06 11:04:06.751079-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {RevFinder#59} {Coll#4} Received 1 changes (seq '280436'..'280436')
2025-01-06 11:04:06.751822-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {RevFinder#59} {Coll#4} Responded to 'changes' REQ#25 w/request for 1 revs in 0.000518 sec
2025-01-06 11:04:06.752060-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} Now waiting for 1 'rev' messages; 1 known sequences pending
2025-01-06 11:04:06.752272-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} Sending RES #25 Z
2025-01-06 11:04:06.752599-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} Requeuing RES #25...
2025-01-06 11:04:06.755149-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} Starting writeToWebSocket loop...
2025-01-06 11:04:06.755402-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} (collection: 4) progress +0/+1, 0 docs -- now 1 / 2, 1 docs
2025-01-06 11:04:06.755592-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Puller#31} {Coll#4} activityLevel=busy: pendingResponseCount=0, _caughtUp=1, _pendingRevMessages=1, _activeIncomingRevs=0, _waitingRevMessages=0, _unfinishedIncomingRevs=0
2025-01-06 11:04:06.755812-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} now busy
2025-01-06 11:04:06.756041-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27}     Sending frame: RES #25 ---C, bytes 0--13
2025-01-06 11:04:06.756187-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {C4SocketImpl#26} Sending 16-byte message
2025-01-06 11:04:06.756412-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} pushStatus=idle, pullStatus=busy, progress=6190/6191/13
2025-01-06 11:04:06.757493-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} Finished sending RES #25 Z
2025-01-06 11:04:06.757600-0500 MyApp[16409:565197] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (634)] c4Socket completed Write.
2025-01-06 11:04:06.758345-0500 MyApp[16409:564783] [581]| VERBOSE)  [Network] {BLIPIO#27} ...Wrote 16 bytes to WebSocket (writeable=1)
2025-01-06 11:04:06.758666-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} Replicator status collection-wise: pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=1/1, docCount=1|pushStatus=idle, pullStatus=busy, progress=4839/4840, docCount=5|pushStatus=idle, pullStatus=idle, progress=1350/1350, docCount=7|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0
2025-01-06 11:04:06.758822-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} (collection: 4294967295) progress +0/+1, 0 docs -- now 6190 / 6191, 13 docs
2025-01-06 11:04:06.759109-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=0
2025-01-06 11:04:06.759275-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} now busy
2025-01-06 11:04:06.759482-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {C4Replicator#25} State: busy, progress=99.98%
2025-01-06 11:04:06.759681-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] (Replicator) [293] Replicator[<*> wss://myednpoint.apps.cloud.couchbase.com:4984/test] is Busy, progress 6190/6191
2025-01-06 11:04:06.760639-0500 MyApp[16409:565198] Replicator status :: Busy
2025-01-06 11:04:06.800960-0500 MyApp[16409:565199] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (636)] <<< received 858 bytes [now 858 pending]
2025-01-06 11:04:06.802346-0500 MyApp[16409:565200] [.NET Long Running Task]| VERBOSE)  [Network] {C4SocketImpl#26} Received 854-byte message
2025-01-06 11:04:06.803489-0500 MyApp[16409:565200] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (637)] c4Socket received.
2025-01-06 11:04:06.804110-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {BLIPIO#27} Received frame: REQ #26 --NC, length   852
2025-01-06 11:04:06.804319-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {Connection#14} Receiving 'rev' REQ #26 NZ
2025-01-06 11:04:06.804546-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {Connection#14} Finished receiving 'rev' REQ #26 NZ
2025-01-06 11:04:06.804789-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=0
2025-01-06 11:04:06.806029-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {IncomingRev#150}==> litecore::repl::IncomingRev {Repl#15} @0x31dfceff0
2025-01-06 11:04:06.806242-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {IncomingRev#150} {Coll#4} Received revision 'd8wD1C8Y8Ws' #7-771c55576ea9660a1c60d683bef17602 (seq '280436')
2025-01-06 11:04:06.806491-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {IncomingRev#150} {Coll#4} _mayContainBlobChanges=0
2025-01-06 11:04:06.806712-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {IncomingRev#150} {Coll#4} _mayContainEncryptedProperties=0
2025-01-06 11:04:06.807002-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Puller#31} {Coll#4} activityLevel=busy: pendingResponseCount=0, _caughtUp=1, _pendingRevMessages=0, _activeIncomingRevs=1, _waitingRevMessages=0, _unfinishedIncomingRevs=1
2025-01-06 11:04:06.828068-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {Inserter#141} {Coll#4} Inserting 1 revs:
2025-01-06 11:04:06.828388-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#82} begin transaction
2025-01-06 11:04:06.829750-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#82} KeyStore(.ShoppingCarts) update d8wD1C8Y8Ws
2025-01-06 11:04:06.829976-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] Saved doc 'd8wD1C8Y8Ws' #7-771c55576ea9660a1c60d683bef17602; body=1018, extra=210
2025-01-06 11:04:06.830277-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#82} Saved 'd8wD1C8Y8Ws' rev #7-771c55576ea9660a1c60d683bef17602 as seq 14
2025-01-06 11:04:06.830544-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {Inserter#141} {Coll#4}     {'d8wD1C8Y8Ws (ShoppingCarts)' #7-771c55576ea9660a1c60d683bef17602 <- 6-df2e6becd0c90eb4c7c29475831d25d88b152f4d} seq 14
2025-01-06 11:04:06.830839-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#82} commit transaction
2025-01-06 11:04:06.831157-0500 MyApp[16409:564783] [581]| VERBOSE)  [Replicator] {Puller#31} 1 revs were provisionally handled; down to 0 active
2025-01-06 11:04:06.831403-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {Puller#31} {Coll#4} activityLevel=busy: pendingResponseCount=0, _caughtUp=1, _pendingRevMessages=0, _activeIncomingRevs=0, _waitingRevMessages=0, _unfinishedIncomingRevs=1
2025-01-06 11:04:06.831689-0500 MyApp[16409:565195] [633]| VERBOSE)  [Replicator] {ReplicatorChangesFeed#38} Database changed! [notify=1]
2025-01-06 11:04:06.831904-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Inserter#141} {Coll#4} Inserted   1 revs in   3.57ms (  280/sec) of which 99.9% was commit
2025-01-06 11:04:06.832099-0500 MyApp[16409:564783] [581]| VERBOSE)  [Replicator] {ReplicatorChangesFeed#38} Asking DB observer for 200 new changes since sequence #13 ...
2025-01-06 11:04:06.832384-0500 MyApp[16409:564783] [581]| VERBOSE)  [Replicator] {ReplicatorChangesFeed#38} Observed 1 db changes #14 ... #14
2025-01-06 11:04:06.832595-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} Checkpoint now at '280436' (collection: 4
2025-01-06 11:04:06.832806-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} (collection: 4) progress +1/+0, 1 docs -- now 2 / 2, 2 docs
2025-01-06 11:04:06.833026-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Puller#31} {Coll#4} activityLevel=idle: pendingResponseCount=0, _caughtUp=1, _pendingRevMessages=0, _activeIncomingRevs=0, _waitingRevMessages=0, _unfinishedIncomingRevs=0
2025-01-06 11:04:06.833199-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Puller#31} {Coll#4} now idle
2025-01-06 11:04:06.833443-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} pushStatus=idle, pullStatus=idle, progress=6191/6191/14
2025-01-06 11:04:06.833680-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {ReplicatorChangesFeed#38} No new observed changes...
2025-01-06 11:04:06.833852-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {Pusher#37} {Coll#4} Found 0 changes up to #14
2025-01-06 11:04:06.834154-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} Replicator status collection-wise: pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=1/1, docCount=1|pushStatus=idle, pullStatus=idle, progress=4840/4840, docCount=6|pushStatus=idle, pullStatus=idle, progress=1350/1350, docCount=7|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0
2025-01-06 11:04:06.834362-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} (collection: 4294967295) progress +1/+0, 1 docs -- now 6191 / 6191, 14 docs
2025-01-06 11:04:06.834565-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.834772-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} Coll=4 CorrID=cf74f08 Saving remote checkpoint 'cp-cFqeq2LD5sA//dcLyJ8L5BI4aX0P/BN39ylAmQzV+C8=' over rev='0-20': {"time":1736179446,"local":14,"remote":280436} ...
2025-01-06 11:04:06.834973-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.835186-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {Pusher#37} {Coll#4} activityLevel=busy: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pushingDocs=0, pendingSequences=0
2025-01-06 11:04:06.835353-0500 MyApp[16409:564783] [581]| VERBOSE)  [Replicator] {Pusher#37} {Coll#4} now busy
2025-01-06 11:04:06.835574-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Sending 'proposeChanges' REQ #0 UN
2025-01-06 11:04:06.835765-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Requeuing REQ #0...
2025-01-06 11:04:06.835966-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Starting writeToWebSocket loop...
2025-01-06 11:04:06.836163-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27}     Sending frame: REQ #96 -UN-, bytes 0--67
2025-01-06 11:04:06.836341-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {C4SocketImpl#26} Sending 70-byte message
2025-01-06 11:04:06.836601-0500 MyApp[16409:564783] [581]| INFO)  [Replicator] {Pusher#37} {Coll#4} activityLevel=idle: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pushingDocs=0, pendingSequences=0
2025-01-06 11:04:06.837592-0500 MyApp[16409:564783] [581]| VERBOSE)  [Replicator] {Pusher#37} {Coll#4} now idle
2025-01-06 11:04:06.837730-0500 MyApp[16409:565204] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (640)] c4Socket completed Write.
2025-01-06 11:04:06.838398-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Finished sending REQ #96 UN
2025-01-06 11:04:06.838612-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} pushStatus=busy, pullStatus=idle, progress=6191/6191/14
2025-01-06 11:04:06.838844-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} ...Wrote 70 bytes to WebSocket (writeable=1)
2025-01-06 11:04:06.839106-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Sending 'setCheckpoint' REQ #0
2025-01-06 11:04:06.839316-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Requeuing REQ #0...
2025-01-06 11:04:06.839504-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Starting writeToWebSocket loop...
2025-01-06 11:04:06.839688-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27}     Sending frame: REQ #97 ----, bytes 0--149
2025-01-06 11:04:06.839858-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {C4SocketImpl#26} Sending 152-byte message
2025-01-06 11:04:06.840185-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} Replicator status collection-wise: pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=1/1, docCount=1|pushStatus=busy, pullStatus=idle, progress=4840/4840, docCount=6|pushStatus=idle, pullStatus=idle, progress=1350/1350, docCount=7|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0
2025-01-06 11:04:06.841024-0500 MyApp[16409:565205] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (641)] c4Socket completed Write.
2025-01-06 11:04:06.842193-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.842402-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} pushStatus=idle, pullStatus=idle, progress=6191/6191/14
2025-01-06 11:04:06.842780-0500 MyApp[16409:561554] [293]| VERBOSE)  [Replicator] {Repl#15} {Coll#-1} Replicator status collection-wise: pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=1/1, docCount=1|pushStatus=idle, pullStatus=idle, progress=4840/4840, docCount=6|pushStatus=idle, pullStatus=idle, progress=1350/1350, docCount=7|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0|pushStatus=idle, pullStatus=idle, progress=0/0, docCount=0
2025-01-06 11:04:06.842975-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.843180-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.843417-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} Finished sending REQ #97
2025-01-06 11:04:06.843598-0500 MyApp[16409:565195] [633]| VERBOSE)  [Network] {BLIPIO#27} ...Wrote 152 bytes to WebSocket (writeable=1)
2025-01-06 11:04:06.969565-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {C4Replicator#25} State: busy, progress=100.00%
2025-01-06 11:04:06.971087-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] (Replicator) [293] Replicator[<*> wss://myednpoint.apps.cloud.couchbase.com:4984/test] is Busy, progress 6191/6191
2025-01-06 11:04:06.973332-0500 MyApp[16409:565208] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (642)] <<< received 18 bytes [now 18 pending]
2025-01-06 11:04:06.974401-0500 MyApp[16409:565209] Replicator status :: Busy
2025-01-06 11:04:06.976395-0500 MyApp[16409:561554] [293]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=busy: connectionState=2, savingChkpt=1
2025-01-06 11:04:06.976695-0500 MyApp[16409:565210] [.NET Long Running Task]| VERBOSE)  [Network] {C4SocketImpl#26} Received 16-byte message
2025-01-06 11:04:06.977926-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {BLIPIO#27} Received frame: RES #97 ----, length    14
2025-01-06 11:04:06.978654-0500 MyApp[16409:565210] [.NET Long Running Task]| VERBOSE)  [Replicator] (WebSocketWrapper) [.NET Long Running Task (644)] c4Socket received.
2025-01-06 11:04:06.979366-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {BLIPIO#27} RES #97 has reached the end of its frames
2025-01-06 11:04:06.979569-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {Connection#14} Receiving RES #97
2025-01-06 11:04:06.979843-0500 MyApp[16409:561554] [293]| VERBOSE)  [Network] {Connection#14} Finished receiving RES #97
2025-01-06 11:04:06.980073-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Repl#15} Coll=4 CorrID=cf74f08 Saved remote checkpoint 'cp-cFqeq2LD5sA//dcLyJ8L5BI4aX0P/BN39ylAmQzV+C8=' as rev='0-21'
2025-01-06 11:04:06.982200-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#12} begin transaction
2025-01-06 11:04:06.982522-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#12} KeyStore(checkpoints) set 'cp-cFqeq2LD5sA//dcLyJ8L5BI4aX0P/BN39ylAmQzV+C8='
2025-01-06 11:04:06.982766-0500 MyApp[16409:565195] [633]| VERBOSE)  [Database] {DB#12} commit transaction
2025-01-06 11:04:06.983101-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Repl#15} Coll=4 CorrID=cf74f08 Saved local checkpoint 'cp-cFqeq2LD5sA//dcLyJ8L5BI4aX0P/BN39ylAmQzV+C8=': {"time":1736179446,"local":14,"remote":280436}
2025-01-06 11:04:06.983323-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Repl#15} {Coll#-1} activityLevel=idle: connectionState=2, savingChkpt=0
2025-01-06 11:04:06.983505-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {Repl#15} {Coll#-1} now idle
2025-01-06 11:04:06.983736-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] {C4Replicator#25} State: idle, progress=100.00%
2025-01-06 11:04:06.983989-0500 MyApp[16409:565195] [633]| INFO)  [Replicator] (Replicator) [633] Replicator[<*> wss://myednpoint.apps.cloud.couchbase.com:4984/test] is Idle, progress 6191/6191
2025-01-06 11:04:06.985088-0500 MyApp[16409:565214] Replicator status :: Idle
5

This is weird. The document can’t actually have invalid JSON; you wouldn’t be able to save it on mobile, and even if you did the server would reject it during the sync.

It might be some kind of internal error in App Services.

(Also, those items whose keys start with _sync: aren’t your documents, they’re internal bookkeeping for revisions. You should leave them alone. I didn’t know they were even still visible, in Capella.)

6

The document you are showing in the screenshot is a temporary revision body backup (with key prefix _sync:rev: ) and is stored as a binary document. These get stored by Sync Gateway to support delta sync, among other things, and have a TTL so that they are automatically purged after some time.

The current revision of the document is not stored with this prefix.

I expect the ‘invalid JSON’ is expected and accurate because this is a binary document. You should not be manually attempting to modify the _sync:rev document and expecting that to be replicated - you’ll want to be making changes to the actual document.

7

Thanks for the clarity on why those documents exist, makes sense.

To be clear I have not modified the _sync:rev documents, I leave those alone., one appears for each edit I make on the device.

This was not happening in the previous months I have been working with Couchbase, I assumed it was something I was doing on my end.

Assuming this issue is also why deleted data on the server is not removed from the device.

What do I do at this point?

8

Hm. Could you clearly describe the steps that cause the problem?

In the client logs you gave above, it looks as though a document revision is being downloaded and saved by CBL:

Saved doc 'd8wD1C8Y8Ws' #7-771c55576ea9660a1c60d683bef17602; body=1018, extra=210

Is that not the document/revision you expected?

9

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.