Understanding why? (ERROR "Server permissions for this file ident have changed)

We are facing the following issue, why are we getting this?
Server permissions for this file ident have changed since the last time it was used (IDENT)

Setup:

  • Sync: flexible sync
  • Rules: some require user data, for example:
"document_filters": { "write":  { "_id": { "$in": "%%user.custom_data.owned_documents" } } }

Discussion:

The device would call a cloud function to create a brand new document for the user.
The cloud function would verify some things, create the document and then add it to
the user’s user.custom_data.owned_documents array. (which is a collection called UserCusomData)

After we receive a success call on the device, we register a new subscription to the UserDocuments’s object with condition _id == the newly added id.
So essentially If we have multiple documents, we would have a subscription for each. (why we are not using $in is another discussion and out of scope)

Expected:

So after that, we expect the realm to sync and any new documents to be downloaded, and also, any collection observations to be updated so that the UI updates.

Actual:

Nothing happens. We need to restart the app several times, and sometimes do a fresh install (or just clearing the state to remove the db) so that all of the documents get redownloaded.

Things we looked at:

  • maybe the user’e permissions are changing because the rules rely on custom data?
  • maybe the custom data is not being refreshed after adding the document (we tried refreshing the token by calling refresh custom data on device, since the function does both under the hood)
  • maybe its related to this issue trail? (8042, 7902, 5697)
  • tried on multiple devices, and restarting sync

Gathered logs:

### Just after a fresh launch (will download added document and perform reset):
Session[1]: Binding '<...clipped>/db.realm' to ''
Session[1]: client_reset_config = false, Realm exists = true, client reset = false
Connected to app services with request id: "6453afa84e2b82fb08ee51f8"
Session[1]: Begin processing pending FLX bootstrap for query version 0. (changesets: 1, original total changeset size: 4495)
Session[1]: Integrated 1 changesets from pending bootstrap for query version 0, producing client version 10 in 20 ms. 0 changesets remaining in bootstrap
Session[1]: Begin processing pending FLX bootstrap for query version 1. (changesets: 1, original total changeset size: 947)
Session[1]: Integrated 1 changesets from pending bootstrap for query version 1, producing client version 14 in 5 ms. 0 changesets remaining in bootstrap
Session[1]: Begin processing pending FLX bootstrap for query version 2. (changesets: 1, original total changeset size: 5103)
Session[1]: Integrated 1 changesets from pending bootstrap for query version 2, producing client version 19 in 4 ms. 0 changesets remaining in bootstrap
Disconnected
Session[2]: Binding '<...clipped>/db.realm' to ''
Session[2]: client_reset_config = false, Realm exists = true, client reset = false
Connected to app services with request id: "6453afaa1e186846b76f50d0"
Session[2]: Begin processing pending FLX bootstrap for query version 3. (changesets: 1, original total changeset size: 343)
Session[2]: Integrated 1 changesets from pending bootstrap for query version 3, producing client version 24 in 6 ms. 0 changesets remaining in bootstrap
Session[2]: Begin processing pending FLX bootstrap for query version 4. (changesets: 1, original total changeset size: 343)
<...clipped>
Session[2]: Begin processing pending FLX bootstrap for query version 10. (changesets: 1, original total changeset size: 343)
Session[2]: Integrated 1 changesets from pending bootstrap for query version 10, producing client version 59 in 6 ms. 0 changesets remaining in bootstrap
### Just after creating the document by calling the cloud function:
Session[2]: Begin processing pending FLX bootstrap for query version 11. (changesets: 1, original total changeset size: 0)
Session[2]: Integrated 1 changesets from pending bootstrap for query version 11, producing client version 65 in 13 ms. 0 changesets remaining in bootstrap
### Closed app, and relaunched:
Realm sync client ([realm-core-13.9.4])
Connection[1]: Session[1]: Binding '<...clipped>/db.realm' to ''
Connection[1]: Session[1]: client_reset_config = false, Realm exists = true, client reset = false
Connected to endpoint '<...clipped>:443' (from '<...clipped>:54823')
Connection[1]: Connected to app services with request id: "6453b14273a19bf390945f2c"
Connection[1]: Session[1]: Received: ERROR "Server permissions for this file ident have changed since the last time it was used (IDENT)" (error_code=228, try_again=true, error_action=ClientReset)
Connection[2]: Session[2]: Binding '<...clipped>/db.realm.fresh' to ''
Connection[2]: Session[2]: client_reset_config = false, Realm exists = true, client reset = false
Connection[1]: Disconnected
Connected to endpoint '54.81.24.155:443' (from '192.168.1.131:54836')
Connection[2]: Connected to app services with request id: "6453b1430f4949df9f90f3cf"
Connection[2]: Session[2]: Begin processing pending FLX bootstrap for query version 0. (changesets: 1, original total changeset size: 4495)
Connection[2]: Session[2]: Integrated 1 changesets from pending bootstrap for query version 0, producing client version 9 in 10 ms. 0 changesets remaining in bootstrap
Connection[2]: Session[2]: Begin processing pending FLX bootstrap for query version 1. (changesets: 1, original total changeset size: 8459)
Connection[2]: Session[2]: Integrated 1 changesets from pending bootstrap for query version 1, producing client version 12 in 8 ms. 0 changesets remaining in bootstrap
Connection[3]: Session[3]: Binding '<...clipped>/db.realm' to ''
Connection[3]: Session[3]: client_reset_config = true, Realm exists = true, client reset = true
Connection[2]: Disconnected
Connected to endpoint '<...clipped>:443' (from '<...clipped>:54838')
Connection[3]: Connected to app services with request id: "6453b1444e2b82fb08f98717"
Connection[3]: Session[3]: Client reset, path_local = <...clipped>/db.realm.fresh, mode = Recover, recovery_is_allowed = true
Connection[3]: Session[3]: Local changesets to recover: 2
Connection[3]: Session[3]: Recreated the active subscription set in the complete state (12 -> 12)
Connection[3]: Session[3]: perform_client_reset_diff is done, old_version.version = 67, old_version.index = 0, new_version.version = 70, new_version.index = 1
Connection[3]: Session[3]: Tracking pending client reset of type "Recover" from 2023-05-04 13:21:08

Hello @Georges_Jamous,

A few things to note here:

  1. Permissions are evaluated on a per-session, per-table-being-queried-on basis in flexible sync (at session start). In other words, when you register a new subscription on table T, the permissions for T are evaluated on the server, and that set of permissions is “locked in” for table T for the duration of the session.
  2. In a particular sync session, if the permissions have changed (for any of the tables referenced in the registered subscriptions) since the last session, then a client reset gets triggered. This is outlined in the docs here. Specifically, the server examines if the read permissions have changed. The reasoning being that the system has been designed assuming that the objects that are “in permissions view” for the client is consistent for the duration of a particular session.

The logs you have sent are suggesting that the following is happening:

  1. A flexible sync session is opened, permissions are evaluated for the tables corresponding to the registered subscriptions. Assuming that: "document_filters": { "write": { "_id": { "$in": "%%user.custom_data.owned_documents" } } } is defined on a rule that applies for one of the tables being queried on, the evaluated read permissions would be influenced by this expression since write permission implies read permission.
  2. The cloud function is being called, which is adding something to the owned_documents array in the user’s custom user data. Then, a new subscription is registered on UserDocuments. Recall that the permissions are not re-evaluated here for the tables that are not UserDocuments, as permissions have already been evaluated for those tables in (1.); the new subscription will simply cause permissions for UserDocuments to be evaluated on the server
  3. The next flexible sync session is opened on app relaunch, which causes permissions to be evaluated again. Because the owned_documents custom user data field has changed due to the cloud function in (2.), the value of %%user.custom_data.owned_documents has also changed; therefore, the evaluated read permissions have changed since the previous session opened in (1.), which explains the appearance of this log Connection[1]: Session[1]: Received: ERROR "Server permissions for this file ident have changed since the last time it was used (IDENT)" (error_code=228, try_again=true, error_action=ClientReset)

The team recognizes that the behavior surrounding handling permissions changes between sessions could be improved (ie, not have the end result be a client reset). In fact, we have a future project planned to have the server make handling this more graceful.

Let me know if you have any more questions,
Jonathan

Hey @Jonathan_Lee , thanks for this.

So taking what you said into account, we will try to find a way to re-initiate the sync session to force the new permissions to take effect.

Currently the only way (to my knowledge) to do it gracefully in the client (swift in my case) would be something like that:

user.allSessions.forEach { session in
    session.suspend()
}
try! await Task.sleep... // wait 1 second
user.allSessions.forEach { session in
    session.resume()
}

Any suggestions or a better way? also, do you foresee any downside of doing it?

thanks

Unfortunately, I don’t think there’s really a way of gracefully doing it at the moment - ultimately changing read permissions between sync sessions will result in a client reset error. I would suggest taking a look at the docs for handling client resets and identifying which strategy from there works best for your use case. I do want to reiterate though that this is something the team plans to improve and your feedback here is appreciated :slight_smile:.

Best,
Jonathan

1 Like

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