Realm-java: Can object deletion affects insertions in a changesetObservable ?

[jrmybrault]

Hi,

I'm facing an issue regarding the usage of the _asChangesetObservable()_ method. I suspect the root cause has something to do with poor threading / synchronization management in my code but it might just be a misconception about the API behavior as well.

1. Goals

Given a RealmObject _Element_ with a _synchronizationState_ property, I want to detect when new elements match the specific state value "_UPLOADABLE"_. From there an upload procedure is launched for those new elements. Once the uploading completed, they are deleted from Realm.

2. Expected results

Whenever an element's state is set to the specific value, a change is triggered with the corresponding insertion.
Whenever an element is deleted, a change is triggered with the corresponding deletion.

3. Actual results

Whenever an element is deleted, a change is triggered with the corresponding deletion but sometimes the changeset also contains insertion(s) even though there is no new uploadable element, which seems unsettling to me. The edge effect is that, when this happens, an already uploaded element is being uploaded again (then its deletion fails because it has already been deleted after the first upload).

4. Steps to reproduce

1. Set a change listener on the RealmResult using _asChangesetObservable()_.
2. Update multiple elements states to _"UPLOADABLE"_ within a single transaction. The change listener is triggered with the matching insertions : all is fine thus far.
3. Delete elements that have been uploaded, each one in a dedicated transaction. The change listener is triggered multiple times with matching deletions but also, sometimes, with insertion(s).

Somehow the number of uploadable elements added in step 2 seems to matter : I've never observed the phenomenon with only a couple elements, but the more there is, the more the probability to observe it is high.

5. Code sample that highlights the issue

https://github.com/jrmybrault/realm-changeset-simple-test

The code has been reduced to the bare minimum. Notably, the upload procedure has been completely replaced by a simple delay simulation. The UI allows to see the list of elements, add new elements and mark them as uploadable. The issue can be observed in the logs.

6. Version of Realm/Android Studio/OS

Realm 5.4.1
Android Studio 3.1.4
Reproduced both on simulator running Nougat and a real device running Oreo

[Zhuinden]

https://github.com/realm/realm-java/issues/4262

Good question btw

[cmelchior]

Hi @jrmybrault Thank you very much for the project 👏
After adding a little more logging I can definitely see something that looks fishy that I need to investigate further:

This is the log when adding 1 element and removing it again

2018-12-20 13:06:19.584 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Copy results out due to change - size: 0
2018-12-20 13:06:35.661 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Copy results out due to change - size: 1
2018-12-20 13:06:39.293 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Will update elements: [2c435eeb-aa04-409c-ae24-9b7c13b7cb6e]
2018-12-20 13:06:39.308 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Copy results out due to change - size: 1
2018-12-20 13:06:39.311 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Change occurred in com.urgo.appolo.realmchangesetsimpletest.RealmNewResultsObserver@feae815 -> size: 1
2018-12-20 13:06:39.338 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Changes: Deletion Ranges: []
    Insertion Ranges: [startIndex: 0, length: 1]
    Change Ranges: []
2018-12-20 13:06:39.339 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: New result Element = proxy[{id:2c435eeb-aa04-409c-ae24-9b7c13b7cb6e},{creationDate:1545307595593},{path:fake/path},{synchronizationState:UPLOADABLE}]
2018-12-20 13:06:39.340 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Start sync of element 2c435eeb-aa04-409c-ae24-9b7c13b7cb6e at path /path
2018-12-20 13:06:40.537 8817-8854/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Will delete element: 2c435eeb-aa04-409c-ae24-9b7c13b7cb6e
2018-12-20 13:06:40.554 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Copy results out due to change - size: 0
2018-12-20 13:06:40.555 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Change occurred in com.urgo.appolo.realmchangesetsimpletest.RealmNewResultsObserver@feae815 -> size: 0
2018-12-20 13:06:40.555 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Changes: Deletion Ranges: [startIndex: 0, length: 1]
    Insertion Ranges: []
    Change Ranges: []
2018-12-20 13:06:40.555 8817-8817/com.urgo.appolo.realmchangesetsimpletest I/LogUtils: Deleted 1 results

[realm-probot[bot]]

Hey - looks like you forgot to add a T:* label - could you please add one?

[Zhuinden]

I think it's just that if an item at the end is moved back (for example in an unsorted results) then it is registered as a deletion at the end and an insertion at whatever index

[jrmybrault]

Oh good catch @Zhuinden, I didn't think of that for a second ! Sorting the results seems to do the trick indeed.

I guess _OrderedCollectionChangeSet_ documentation could benefit from a mention on this subtlety :)

Thanks guys for the lightening assistance !