Uploaded image for project: 'Couchbase Lite'
  1. Couchbase Lite
  2. CBL-222

CBL push replication is not replicating doc updates with delta sync after CBL upgrade

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Not a Bug
    • Affects Version/s: 2.6.0, 2.5.0
    • Fix Version/s: 2.6.0
    • Component/s: iOS
    • Security Level: Public
    • Labels:
      None
    • Environment:
      CBL iOS - 2.6.0-141
      SG - 2.5.1-11
      CBS - 6.0.1-2037
      iPhone-8-plus emulator

      Description

      CBL push replication is not replicating doc updates with delta sync after CBL upgrade.

      This is what I'm trying to do in CBL upgrade test -
      1. Migrate older-pre-built db to a provided cbl apps
      2. Start the replication and replicate db to cluster
      3. Running all query tests
      4. Perform mutation operations
      a. Add new docs and replicate to cluster
      b. Update docs for migrated db and replicate to cluster <-- Failing here
      c. Delete docs from migrated db and replicate to cluster

      ERROR:
      > assert "new_field" in sg_data, "Updated docs failed to get replicated"
      E AssertionError: Updated docs failed to get replicated
      E assert 'new_field' in {'_id': 'route_57637', '_rev': '1-53c9a41c517273c178023f50d4c22d82b2abca09', '_revisions':

      {'ids': ['53c9a41c517273c178023f50d4c22d82b2abca09'], 'start': 1}

      , 'airline': 'UA', ...}

      Code Snippet:

      # updating old docs
          repl_config = replicator.configure(cbl_db, sg_blip_url, replication_type="push", 
                                                               continuous=True, replicator_authenticator=replicator_authenticator)
          repl = replicator.create(repl_config)
          doc_ids_to_update = random.sample(cbl_doc_ids, 5)
          docs = db.getDocuments(cbl_db, doc_ids_to_update)
          for doc_id in docs:
              log_info("Updating CBL Doc - {}".format(doc_id))
              data = docs[doc_id]
              data["new_field"] = "test_string_for_{}".format(doc_id)
              db.updateDocument(cbl_db, doc_id=doc_id, data=data)
       
          replicator.start(repl)
          replicator.wait_until_replicator_idle(repl)
          replicator.stop(repl)
       
          cbs_docs = sg_client.get_all_docs(sg_admin_url, sg_db, session)["rows"]
          cbs_doc_ids = [doc["id"] for doc in cbs_docs]
       
          for doc_id in doc_ids_to_update:
              log_info("Checking for updates in doc on CBS: {}".format(doc_id))
              sg_data = sg_client.get_doc(url=sg_admin_url, db=sg_db, doc_id=doc_id, auth=session)
              assert "new_field" in sg_data, "Updated docs failed to get replicated"
          new_cbl_doc_ids = db.getDocIds(cbl_db, limit=40000)
      

      Command to run test -
      pytest -s --timeout 3600 --base-liteserv-version=2.5.0 --upgraded-liteserv-version=2.6.0-141 --liteserv-host=10.100.174.204 --liteserv-port=8080 --liteserv-platform=ios --xattrs --skip-provisioning --no-conflicts --enable-file-logging --encrypted-db --delta-sync --encrypted-db-password=password --sync-gateway-version=2.5.1-11 --mode=cc --server-version=6.0.1-2037 testsuites/CBLTester/upgrade_tests/test_cbl_upgrade.py -k test_upgrade_cbl

      Test is passing without --delta-sync.

      Jenkins job for this test will give a detailed look into the test flow - http://uberjenkins.sc.couchbase.com:8080/view/03%20CBL-2.x/job/CBL_upgrade/42/console

      PS: Tested only on iOS, will update status about other platform later.

        Attachments

        1. cbcollect_info.zip
          11.94 MB
        2. logs1565086375.916285.zip
          11.48 MB
        3. python_client.log
          141 kB
        4. route_5164.png
          route_5164.png
          197 kB
        5. sgcollect_info.zip
          17.74 MB
        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

          Hide
          ben.brooks Ben Brooks added a comment - - edited

          I think this is a channel/authentication issue on the autotest user, but can't immediately think of an explanation as to why it works when delta sync is turned off.

           

          A quick glance through the SG logs show we never recieve a rev for the second revision of the doc specified in the description[1] ... but there are quite a few instances of "404 Document revision is not accessible" for other docs being updated.

          I can see these docs belong in the "*" channel at rev 1, and it doesn't look like the test is removing or modifying any channels on docs. The "autotest" user only has access to channel "!".

          2019-08-06T03:13:49.598-07:00 [INF] HTTP:  #001: POST /db/_user/ (as ADMIN)
          2019-08-06T03:13:49.603-07:00 [INF] Access: Computed channels for "autotest": !:1
          2019-08-06T03:13:49.607-07:00 [INF] Access: Computed roles for "autotest":  

          2019-08-06T03:21:10.965-07:00 [DBG] WS+: c:[45b26621] Received frame: MSG#7~ (flags=    1000, length=33)
          2019-08-06T03:21:10.965-07:00 [DBG] WSFrame+: c:[45b26621] Incoming BLIP Request: MSG#7~
          2019-08-06T03:21:10.965-07:00 [DBG] SyncMsg+: c:[45b26621] #7: Type:rev Id:route_50214 Rev:2-150ff12292a580563c55974d531d5095af740de5 DeltaSrc:1-812acd0757f13d741547b575a697d99086c9c880 Sequence:31601  User:autotest
          2019-08-06T03:21:10.966-07:00 [DBG] CRUD+: c:[45b26621] Did not update document "route_50214" w/ xattr: 404 Document revision is not accessible
          2019-08-06T03:21:10.966-07:00 [INF] SyncMsg: c:[45b26621] #7: Type:rev   --> 404 Document revision is not accessible Time:1.381134ms User:autotest
          2019-08-06T03:21:10.966-07:00 [DBG] WS+: c:[45b26621] Push ERR#7
          2019-08-06T03:21:10.966-07:00 [DBG] WS+: c:[45b26621] Sending frame: ERR#7 (flags=      10, size=   69) 

          273963:2019-08-06T03:15:21.468-07:00 [DBG] SyncMsg+: c:[66d4a38a] #19629: Type:rev Id:route_50214 Rev:1-812acd0757f13d741547b575a697d99086c9c880 Sequence:19505  User:autotest
          273971:2019-08-06T03:15:21.469-07:00 [DBG] CRUD+: c:[66d4a38a] Invoking sync on doc "route_50214" rev 1-812acd0757f13d741547b575a697d99086c9c880
          273976:2019-08-06T03:15:21.469-07:00 [DBG] CRUD+: Backed up revision body "route_50214"/"1-812acd0757f13d741547b575a697d99086c9c880" (1351 bytes, ttl:86400)
          274013:2019-08-06T03:15:21.473-07:00 [DBG] CRUD+: c:[66d4a38a] Saving doc (seq: #19507, id: route_50214 rev: 1-812acd0757f13d741547b575a697d99086c9c880)
          274014:2019-08-06T03:15:21.474-07:00 [INF] CRUD: c:[66d4a38a] Stored doc "route_50214" / "1-812acd0757f13d741547b575a697d99086c9c880" as #19507
          ...
          2019-08-06T03:15:21.475-07:00 [INF] Cache: Received #19507 after   1ms ("route_50214" / "1-812acd0757f13d741547b575a697d99086c9c880")
          ...
          2019-08-06T03:15:21.475-07:00 [INF] Cache: #19507 ==> channels {*}
          ...
          443817:2019-08-06T03:21:10.965-07:00 [DBG] SyncMsg+: c:[45b26621] #7: Type:rev Id:route_50214 Rev:2-150ff12292a580563c55974d531d5095af740de5 DeltaSrc:1-812acd0757f13d741547b575a697d99086c9c880 Sequence:31601  User:autotest
          443818:2019-08-06T03:21:10.966-07:00 [DBG] CRUD+: c:[45b26621] Did not update document "route_50214" w/ xattr: 404 Document revision is not accessible 

           

           

          [1]

          $ rg 'route_57637' sg_debug.log
          350050:2019-08-06T03:15:43.852-07:00 [DBG] SyncMsg+: c:[66d4a38a] #25076: Type:rev Id:route_57637 Rev:1-53c9a41c517273c178023f50d4c22d82b2abca09 Sequence:24925  User:autotest
          350053:2019-08-06T03:15:43.852-07:00 [DBG] CRUD+: c:[66d4a38a] Invoking sync on doc "route_57637" rev 1-53c9a41c517273c178023f50d4c22d82b2abca09
          350056:2019-08-06T03:15:43.852-07:00 [DBG] CRUD+: Backed up revision body "route_57637"/"1-53c9a41c517273c178023f50d4c22d82b2abca09" (865 bytes, ttl:86400)
          350059:2019-08-06T03:15:43.853-07:00 [DBG] CRUD+: c:[66d4a38a] Saving doc (seq: #24924, id: route_57637 rev: 1-53c9a41c517273c178023f50d4c22d82b2abca09)
          350060:2019-08-06T03:15:43.853-07:00 [INF] CRUD: c:[66d4a38a] Stored doc "route_57637" / "1-53c9a41c517273c178023f50d4c22d82b2abca09" as #24924
          350065:2019-08-06T03:15:43.854-07:00 [INF] Cache: Received #24924 after   1ms ("route_57637" / "1-53c9a41c517273c178023f50d4c22d82b2abca09")

          Show
          ben.brooks Ben Brooks added a comment - - edited I think this is a channel/authentication issue on the autotest user, but can't immediately think of an explanation as to why it works when delta sync is turned off.   A quick glance through the SG logs show we never recieve a rev for the second revision of the doc specified in the description [1] ... but there are quite a few instances of " 404 Document revision is not accessible " for other docs being updated. I can see these docs belong in the " * " channel at rev 1, and it doesn't look like the test is removing or modifying any channels on docs. The " autotest " user only has access to channel " ! ". 2019 - 08 -06T03: 13 : 49.598 - 07 : 00 [INF] HTTP: # 001 : POST /db/_user/ (as ADMIN) 2019 - 08 -06T03: 13 : 49.603 - 07 : 00 [INF] Access: Computed channels for "autotest" : !: 1 2019 - 08 -06T03: 13 : 49.607 - 07 : 00 [INF] Access: Computed roles for "autotest" : 2019 - 08 -06T03: 21 : 10.965 - 07 : 00 [DBG] WS+: c:[45b26621] Received frame: MSG# 7 ~ (flags= 1000 , length= 33 ) 2019 - 08 -06T03: 21 : 10.965 - 07 : 00 [DBG] WSFrame+: c:[45b26621] Incoming BLIP Request: MSG# 7 ~ 2019 - 08 -06T03: 21 : 10.965 - 07 : 00 [DBG] SyncMsg+: c:[45b26621] # 7 : Type:rev Id:route_50214 Rev: 2 -150ff12292a580563c55974d531d5095af740de5 DeltaSrc: 1 -812acd0757f13d741547b575a697d99086c9c880 Sequence: 31601 User:autotest 2019 - 08 -06T03: 21 : 10.966 - 07 : 00 [DBG] CRUD+: c:[45b26621] Did not update document "route_50214" w/ xattr: 404 Document revision is not accessible 2019 - 08 -06T03: 21 : 10.966 - 07 : 00 [INF] SyncMsg: c:[45b26621] # 7 : Type:rev --> 404 Document revision is not accessible Time: 1 .381134ms User:autotest 2019 - 08 -06T03: 21 : 10.966 - 07 : 00 [DBG] WS+: c:[45b26621] Push ERR# 7 2019 - 08 -06T03: 21 : 10.966 - 07 : 00 [DBG] WS+: c:[45b26621] Sending frame: ERR# 7 (flags= 10 , size= 69 ) 273963 : 2019 - 08 -06T03: 15 : 21.468 - 07 : 00 [DBG] SyncMsg+: c:[66d4a38a] # 19629 : Type:rev Id:route_50214 Rev: 1 -812acd0757f13d741547b575a697d99086c9c880 Sequence: 19505 User:autotest 273971 : 2019 - 08 -06T03: 15 : 21.469 - 07 : 00 [DBG] CRUD+: c:[66d4a38a] Invoking sync on doc "route_50214" rev 1 -812acd0757f13d741547b575a697d99086c9c880 273976 : 2019 - 08 -06T03: 15 : 21.469 - 07 : 00 [DBG] CRUD+: Backed up revision body "route_50214" / "1-812acd0757f13d741547b575a697d99086c9c880" ( 1351 bytes, ttl: 86400 ) 274013 : 2019 - 08 -06T03: 15 : 21.473 - 07 : 00 [DBG] CRUD+: c:[66d4a38a] Saving doc (seq: # 19507 , id: route_50214 rev: 1 -812acd0757f13d741547b575a697d99086c9c880) 274014 : 2019 - 08 -06T03: 15 : 21.474 - 07 : 00 [INF] CRUD: c:[66d4a38a] Stored doc "route_50214" / "1-812acd0757f13d741547b575a697d99086c9c880" as # 19507 ... 2019 - 08 -06T03: 15 : 21.475 - 07 : 00 [INF] Cache: Received # 19507 after 1ms ( "route_50214" / "1-812acd0757f13d741547b575a697d99086c9c880" ) ... 2019 - 08 -06T03: 15 : 21.475 - 07 : 00 [INF] Cache: # 19507 ==> channels {*} ... 443817 : 2019 - 08 -06T03: 21 : 10.965 - 07 : 00 [DBG] SyncMsg+: c:[45b26621] # 7 : Type:rev Id:route_50214 Rev: 2 -150ff12292a580563c55974d531d5095af740de5 DeltaSrc: 1 -812acd0757f13d741547b575a697d99086c9c880 Sequence: 31601 User:autotest 443818 : 2019 - 08 -06T03: 21 : 10.966 - 07 : 00 [DBG] CRUD+: c:[45b26621] Did not update document "route_50214" w/ xattr: 404 Document revision is not accessible     [1] $ rg 'route_57637' sg_debug.log 350050 : 2019 - 08 -06T03: 15 : 43.852 - 07 : 00 [DBG] SyncMsg+: c:[66d4a38a] # 25076 : Type:rev Id:route_57637 Rev: 1 -53c9a41c517273c178023f50d4c22d82b2abca09 Sequence: 24925 User:autotest 350053 : 2019 - 08 -06T03: 15 : 43.852 - 07 : 00 [DBG] CRUD+: c:[66d4a38a] Invoking sync on doc "route_57637" rev 1 -53c9a41c517273c178023f50d4c22d82b2abca09 350056 : 2019 - 08 -06T03: 15 : 43.852 - 07 : 00 [DBG] CRUD+: Backed up revision body "route_57637" / "1-53c9a41c517273c178023f50d4c22d82b2abca09" ( 865 bytes, ttl: 86400 ) 350059 : 2019 - 08 -06T03: 15 : 43.853 - 07 : 00 [DBG] CRUD+: c:[66d4a38a] Saving doc (seq: # 24924 , id: route_57637 rev: 1 -53c9a41c517273c178023f50d4c22d82b2abca09) 350060 : 2019 - 08 -06T03: 15 : 43.853 - 07 : 00 [INF] CRUD: c:[66d4a38a] Stored doc "route_57637" / "1-53c9a41c517273c178023f50d4c22d82b2abca09" as # 24924 350065 : 2019 - 08 -06T03: 15 : 43.854 - 07 : 00 [INF] Cache: Received # 24924 after 1ms ( "route_57637" / "1-53c9a41c517273c178023f50d4c22d82b2abca09" )
          Hide
          hemant.rajput Hemant Rajput added a comment -

          So, I've re-ran the test after discussing with Ben Brooks, adding channel [*] to the user and the test passed

          http://uberjenkins.sc.couchbase.com:8080/view/03%20CBL-2.x/job/CBL_upgrade/47/console

          Although, both Ben Brooks and I think that there is an underlying issue, as why the test passed without delta-sync and failed with it. Let me know if anything is required from me.

          Show
          hemant.rajput Hemant Rajput added a comment - So, I've re-ran the test after discussing with Ben Brooks , adding channel [*] to the user and the test passed http://uberjenkins.sc.couchbase.com:8080/view/03%20CBL-2.x/job/CBL_upgrade/47/console Although, both Ben Brooks and I think that there is an underlying issue, as why the test passed without delta-sync and failed with it. Let me know if anything is required from me.
          Hide
          sridevi.saragadam Sridevi Saragadam added a comment -

          looks like this is tested against SGW 2.5.1-11 . We have last delta sync fix on 2.5.1-12. Not sure if the fix on 2.5.1-12 matters, can you test with latest build of 2.5.1?

           

          Show
          sridevi.saragadam Sridevi Saragadam added a comment - looks like this is tested against SGW 2.5.1-11 . We have last delta sync fix on 2.5.1-12. Not sure if the fix on 2.5.1-12 matters, can you test with latest build of 2.5.1?  
          Hide
          hemant.rajput Hemant Rajput added a comment -

          Tested agains SGW-2.5.1-12 as well, seeing the same behaviour.

           

          http://uberjenkins.sc.couchbase.com:8080/view/03%20CBL-2.x/job/CBL_upgrade/48/console

          Show
          hemant.rajput Hemant Rajput added a comment - Tested agains SGW-2.5.1-12 as well, seeing the same behaviour.   http://uberjenkins.sc.couchbase.com:8080/view/03%20CBL-2.x/job/CBL_upgrade/48/console
          Hide
          Jayahari.Vavachan Jayahari Vavachan added a comment - - edited

          Couldn't find anything useful information from the logs, we are getting a `HTTP 404 'Document revision is not accessible` when sending revision.

          Assigning to Adam, to further investigate from SG side.

          Show
          Jayahari.Vavachan Jayahari Vavachan added a comment - - edited Couldn't find anything useful information from the logs, we are getting a `HTTP 404 'Document revision is not accessible` when sending revision. Assigning to Adam, to further investigate from SG side.
          Hide
          adamf Adam Fraser added a comment - - edited

          Hemant Rajput In Ben's update above, he mentions that revision 2 is being written as a user that doesn't have read access to revision 1. That sounds to me like the underlying test failure here, but SG is working as intended. When delta sync is enabled, SG doesn't accept deltas when the client doesn't have access to the source revision for the delta, to prevent leaking data about previous revisions in the scenario where the user has write and not read access (i.e. this case).

          It's expected that this would pass with delta sync disabled, as Sync Gateway will allow users to write full documents when they don't have access to the ancestor, as there's no information leak in that scenario.

          For this test in particular, it looks to me like you should be writing revision 1 to the public channel [!], so that user autotest can successfully write rev 2 when delta sync is enabled.

          Show
          adamf Adam Fraser added a comment - - edited Hemant Rajput In Ben's update above, he mentions that revision 2 is being written as a user that doesn't have read access to revision 1. That sounds to me like the underlying test failure here, but SG is working as intended. When delta sync is enabled, SG doesn't accept deltas when the client doesn't have access to the source revision for the delta, to prevent leaking data about previous revisions in the scenario where the user has write and not read access (i.e. this case). It's expected that this would pass with delta sync disabled, as Sync Gateway will allow users to write full documents when they don't have access to the ancestor, as there's no information leak in that scenario. For this test in particular, it looks to me like you should be writing revision 1 to the public channel [!] , so that user autotest can successfully write rev 2 when delta sync is enabled.
          Hide
          ben.brooks Ben Brooks added a comment - - edited

          Ah yeah, that explanation above makes sense regarding the difference between deltas on and off.

          I didn't know a doc could be written to an ancestor that the user didn't have access to.
          Sidenote: I guess this can be locked down via the sync function if that behaviour is desired?

          Show
          ben.brooks Ben Brooks added a comment - - edited Ah yeah, that explanation above makes sense regarding the difference between deltas on and off. I didn't know a doc could be written to an ancestor that the user didn't have access to. Sidenote: I guess this can be locked down via the sync function if that behaviour is desired?
          Hide
          hemant.rajput Hemant Rajput added a comment -

          The explanation above make sense. Hence closing the ticket.

           

          PS: I've already added the channel access to SG user for our test.

          Show
          hemant.rajput Hemant Rajput added a comment - The explanation above make sense. Hence closing the ticket.   PS: I've already added the channel access to SG user for our test.

            People

            • Assignee:
              hemant.rajput Hemant Rajput
              Reporter:
              hemant.rajput Hemant Rajput
            • Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Gerrit Reviews

                There are no open Gerrit changes

                  PagerDuty

                  Error rendering 'com.pagerduty.jira-server-plugin:PagerDuty'. Please contact your Jira administrators.