PopulateInitialSubscriptions doesn't work

Movsar_Bekaev · January 13, 2023, 4:25am

I have this code:

            _app = App.Create(new AppConfiguration(myRealmAppId) {
                BaseFilePath = FileService.AppDataDirectory,
            });
            _user = await _app.LogInAsync(Credentials.Anonymous());
            _config = new FlexibleSyncConfiguration(_user)
            {
                PopulateInitialSubscriptions = (realm) =>
                {
                    realm.Subscriptions.Add(realm.All<LanguageEntity>());
                }
            };
            var _realm = Realm.GetInstance(_config);
            await _realm.Subscriptions.WaitForSynchronizationAsync();

            var _localRealm = (new OfflineDataAccess()).GetRealmInstance();

            _realm.Write(() =>
            {
                var languages = _localRealm.All<LanguageEntity>();
                foreach (var language in languages)
                {
                    _realm.Add(new LanguageEntity() { Code = language.Code, _id = language._id });
                }
            });

            await _realm.Subscriptions.WaitForSynchronizationAsync();

And it throws

RealmException: Cannot write to class Language when no flexible sync subscription has been created.

If I change Realm.GetInstance() to await Realm.GetInstanceAsync() - it just hangs there indefinitely with these logs (after which it’s just ping-pong logs:

APP: Realm : 2023-01-13 04:19:35.526 Debug: WebSocket::initiate_client_handshake()
APP: Realm : 2023-01-13 04:19:35.758 Debug: WebSocket::handle_http_response_received()
APP: Realm : 2023-01-13 04:19:35.760 Detail: Connection[1]: Negotiated protocol version: 7
APP: Realm : 2023-01-13 04:19:35.761 Debug: Connection[1]: Will emit a ping in 12788 milliseconds
APP: Realm : 2023-01-13 04:19:35.763 Debug: Connection[1]: Session[1]: Sending: IDENT(client_file_ident=18, client_file_ident_salt=576499042362797227, scan_server_version=12, scan_client_version=5, latest_server_version=12, latest_server_version_salt=4481538362546054629, query_version: 0 query_size: 2, query: “{}”)
APP: Realm : 2023-01-13 04:19:35.765 Debug: Connection[1]: Session[1]: Sending: MARK(request_ident=2)
APP: Realm : 2023-01-13 04:19:36.140 Debug: Connection[1]: Session[1]: Received: MARK(request_ident=2)
APP: Realm : 2023-01-13 04:19:36.142 Debug: Connection[1]: Session[1]: Sending: UPLOAD(progress_client_version=13, progress_server_version=12, locked_server_version=12, num_changesets=0)
APP: Realm : 2023-01-13 04:19:49.259 Debug: Connection[1]: Sending: PING(timestamp=133122415, rtt=0)
APP: Realm : 2023-01-13 04:19:49.321 Debug: Connection[1]: Received: PONG(timestamp=133122415)
APP: Realm : 2023-01-13 04:19:49.326 Debug: Connection[1]: Round trip time was 67 milliseconds
APP: Realm : 2023-01-13 04:19:49.327 Debug: Connection[1]: Will emit a ping in 55078 milliseconds
The thread 0x759c has exited with code 0 (0x0).
The thread 0x7560 has exited with code 0 (0x0).
The thread 0x7004 has exited with code 0 (0x0).
The thread 0x29cc has exited with code 0 (0x0).
The thread 0x675c has exited with code 0 (0x0).
APP: Realm : 2023-01-13 04:20:44.900 Debug: Connection[1]: Sending: PING(timestamp=133178056, rtt=67)
APP: Realm : 2023-01-13 04:20:44.962 Debug: Connection[1]: Received: PONG(timestamp=133178056)
APP: Realm : 2023-01-13 04:20:44.964 Debug: Connection[1]: Round trip time was 64 milliseconds
APP: Realm : 2023-01-13 04:20:44.965 Debug: Connection[1]: Will emit a ping in 55907 milliseconds

Here’s my LanguageEntity:

namespace Data.Entities
{
    [MapTo("Language")]
    public class LanguageEntity : RealmObject
    {
        [PrimaryKey]
        public ObjectId _id { get; set; } = ObjectId.GenerateNewId();
        public string Code { get; set; } = string.Empty;
        public DateTimeOffset CreatedAt { get; set; } = DateTimeOffset.Now;
    }
}

I was starting with no local / remote data, so it’s a fresh start.
My Atlas App Id: “dosham-lxwuu”, please take a look.

nirinchev · January 13, 2023, 7:30am

Regarding the error you’re getting - considering you’re using PopulateInitialSubscriptions, my guess would be that you had opened the Realm before, which means that PopulateInitialSubscriptions wouldn’t have run - it may not be obvious but it runs only once for the lifetime of the Realm. You can try deleting the local realm file and running your app again. Might be worth also logging something inside PopulateInitialSubscriptions just to verify it actually runs.

Regarding GetInstanceAsync not completing, you increase the log level to Debug? You can do that by calling Logger.LogLevel = LogLevel.Debug before you call App.Create.

I tried plugging your code in a simple console application and it seemed to have worked for me - I didn’t do any writes as I don’t have the local realm with the language entities, but it could successfully synchronize and both GetInstance and GetInstanceAsync complete. Here are the debug logs from when I tried it:

2023-01-13 07:21:50.355 Debug: App: log_in_with_credentials: app_id: dosham-lxwuu
2023-01-13 07:21:50.359 Debug: App: version info: platform: Realm .NET  version: Realm .NET - sdk version: 10.19.0 - core version: 12.13.0
2023-01-13 07:21:50.639 Debug: App: update_hostname: https://westeurope.azure.realm.mongodb.com | wss://ws.westeurope.azure.realm.mongodb.com
2023-01-13 07:21:51.094 Debug: App: do_authenticated_request: GET https://westeurope.azure.realm.mongodb.com/api/client/v2.0/auth/profile
2023-01-13 07:21:51.178 Debug: Realm sync client ([realm-core-12.13.0])
2023-01-13 07:21:51.178 Debug: Supported protocol versions: 2-7
2023-01-13 07:21:51.178 Debug: Platform: macOS Darwin 21.6.0 Darwin Kernel Version 21.6.0: Sun Nov  6 23:31:13 PST 2022; root:xnu-8020.240.14~1/RELEASE_ARM64_T6000 arm64
2023-01-13 07:21:51.178 Debug: Build mode: Release
2023-01-13 07:21:51.178 Debug: Config param: one_connection_per_session = true
2023-01-13 07:21:51.178 Debug: Config param: connect_timeout = 120000 ms
2023-01-13 07:21:51.178 Debug: Config param: connection_linger_time = 30000 ms
2023-01-13 07:21:51.178 Debug: Config param: ping_keepalive_period = 60000 ms
2023-01-13 07:21:51.178 Debug: Config param: pong_keepalive_timeout = 120000 ms
2023-01-13 07:21:51.178 Debug: Config param: fast_reconnect_limit = 60000 ms
2023-01-13 07:21:51.178 Debug: Config param: disable_upload_compaction = false
2023-01-13 07:21:51.178 Debug: Config param: disable_sync_to_disk = false
2023-01-13 07:21:51.178 Debug: User agent string: 'RealmSync/12.13.0 (macOS Darwin 21.6.0 Darwin Kernel Version 21.6.0: Sun Nov  6 23:31:13 PST 2022; root:xnu-8020.240.14~1/RELEASE_ARM64_T6000 arm64)  '
2023-01-13 07:21:51.197 Detail: Connection[1]: Session[1]: Binding '/Users/nikola.irinchev/mongodb-realm/dosham-lxwuu/63c1068fc865975c79e72031/default.realm' to ''
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: Activating
2023-01-13 07:21:51.197 Info: Connection[1]: Session[1]: client_reset_config = false, Realm exists = true, client reset = false
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: client_file_ident = 0, client_file_ident_salt = 0
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: last_version_available  = 6
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: progress_server_version = 0
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: progress_client_version = 0
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 0, downloadable(total) = 0, uploaded = 0, uploadable = 57, reliable_download_progress = false, snapshot version = 6
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 0, downloadable(total) = 0, uploaded = 0, uploadable = 57, reliable_download_progress = false, snapshot version = 6
2023-01-13 07:21:51.197 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 0, downloadable(total) = 0, uploaded = 0, uploadable = 57, reliable_download_progress = false, snapshot version = 6
2023-01-13 07:21:51.198 Debug: WebSocket::Websocket()
2023-01-13 07:21:51.198 Detail: Resolving 'ws.westeurope.azure.realm.mongodb.com:443'
2023-01-13 07:21:51.244 Detail: Connecting to endpoint '40.74.36.35:443' (1/1)
2023-01-13 07:21:51.269 Info: Connected to endpoint '40.74.36.35:443' (from '10.46.0.5:58799')
2023-01-13 07:21:51.411 Debug: WebSocket::initiate_client_handshake()
2023-01-13 07:21:51.512 Debug: WebSocket::handle_http_response_received()
2023-01-13 07:21:51.513 Detail: Connection[1]: Negotiated protocol version: 7
2023-01-13 07:21:51.513 Debug: Connection[1]: Will emit a ping in 9396 milliseconds
2023-01-13 07:21:51.856 Debug: Connection[1]: Session[1]: Received: IDENT(client_file_ident=19, client_file_ident_salt=3673400305230201167)
2023-01-13 07:21:51.858 Debug: Connection[1]: Session[1]: Sending: IDENT(client_file_ident=19, client_file_ident_salt=3673400305230201167, scan_server_version=0, scan_client_version=0, latest_server_version=0, latest_server_version_salt=0, query_version: 0 query_size: 2, query: "{}")
2023-01-13 07:21:51.859 Debug: Connection[1]: Session[1]: Sending: MARK(request_ident=1)
2023-01-13 07:21:51.952 Debug: Connection[1]: Received: DOWNLOAD CHANGESET(server_version=18, client_version=0, origin_timestamp=253524112007, origin_file_ident=1, original_changeset_size=1113, changeset_size=1113)
2023-01-13 07:21:51.952 Debug: Connection[1]: Session[1]: Received: DOWNLOAD(download_server_version=18, download_client_version=0, latest_server_version=18, latest_server_version_salt=8495948514551732795, upload_client_version=0, upload_server_version=0, downloadable_bytes=0, last_in_batch=true, query_version=0, num_changesets=1, ...)
2023-01-13 07:21:51.957 Info: Connection[1]: Session[1]: Begin processing pending FLX bootstrap for query version 0. (changesets: 1, original total changeset size: 1113)
2023-01-13 07:21:51.957 Debug: Connection[1]: Session[1]: Finished changeset indexing (incoming: 1 changeset(s) / 95 instructions, local: 1 changeset(s) / 3 instructions, conflict group(s): 3)
2023-01-13 07:21:51.957 Debug: Connection[1]: Session[1]: Finished transforming 1 local changesets through 1 incoming changesets (3 vs 95 instructions, in 3 conflict groups)
2023-01-13 07:21:51.968 Debug: Connection[1]: Session[1]: Integrated 1 changesets out of 1
2023-01-13 07:21:51.968 Info: Connection[1]: Session[1]: Integrated 1 changesets from pending bootstrap for query version 0, producing client version 10 in 11 ms. 0 changesets remaining in bootstrap
2023-01-13 07:21:51.968 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 1113, downloadable(total) = 1113, uploaded = 0, uploadable = 57, reliable_download_progress = true, snapshot version = 10
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Received: MARK(request_ident=1)
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Sending: UPLOAD(progress_client_version=6, progress_server_version=0, locked_server_version=18, num_changesets=1)
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Fetching changeset for upload (client_version=5, server_version=0, changeset_size=57, origin_timestamp=253524111194, origin_file_ident=0)
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Sending: QUERY(query_version=1, query_size=30, query="{"Language":"(TRUEPREDICATE)"}"
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Sending: MARK(request_ident=2)
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Sending: UPLOAD(progress_client_version=10, progress_server_version=18, locked_server_version=18, num_changesets=0)
2023-01-13 07:21:51.970 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 1113, downloadable(total) = 1113, uploaded = 0, uploadable = 57, reliable_download_progress = true, snapshot version = 11
2023-01-13 07:21:52.104 Debug: Connection[1]: Session[1]: Received: DOWNLOAD(download_server_version=19, download_client_version=5, latest_server_version=19, latest_server_version_salt=8560354801592955379, upload_client_version=6, upload_server_version=0, downloadable_bytes=0, last_in_batch=true, query_version=0, num_changesets=0, ...)
2023-01-13 07:21:52.106 Debug: Connection[1]: Session[1]: Sending: UPLOAD(progress_client_version=12, progress_server_version=19, locked_server_version=19, num_changesets=0)
2023-01-13 07:21:52.106 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 1113, downloadable(total) = 1113, uploaded = 57, uploadable = 57, reliable_download_progress = true, snapshot version = 12
2023-01-13 07:21:52.170 Debug: Connection[1]: Received: DOWNLOAD CHANGESET(server_version=20, client_version=5, origin_timestamp=253524112215, origin_file_ident=1, original_changeset_size=0, changeset_size=0)
2023-01-13 07:21:52.170 Debug: Connection[1]: Session[1]: Received: DOWNLOAD(download_server_version=20, download_client_version=5, latest_server_version=20, latest_server_version_salt=0, upload_client_version=6, upload_server_version=0, downloadable_bytes=0, last_in_batch=true, query_version=1, num_changesets=1, ...)
2023-01-13 07:21:52.171 Info: Connection[1]: Session[1]: Begin processing pending FLX bootstrap for query version 1. (changesets: 1, original total changeset size: 0)
2023-01-13 07:21:52.172 Debug: Connection[1]: Session[1]: Integrated 1 changesets out of 1
2023-01-13 07:21:52.172 Info: Connection[1]: Session[1]: Integrated 1 changesets from pending bootstrap for query version 1, producing client version 14 in 1 ms. 0 changesets remaining in bootstrap
2023-01-13 07:21:52.172 Debug: Connection[1]: Session[1]: Sending: UPLOAD(progress_client_version=14, progress_server_version=20, locked_server_version=20, num_changesets=0)
2023-01-13 07:21:52.173 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 1113, downloadable(total) = 1113, uploaded = 57, uploadable = 57, reliable_download_progress = true, snapshot version = 14
2023-01-13 07:21:52.174 Debug: Connection[1]: Session[1]: Progress handler called, downloaded = 1113, downloadable(total) = 1113, uploaded = 57, uploadable = 57, reliable_download_progress = true, snapshot version = 15
2023-01-13 07:21:52.175 Debug: Connection[1]: Session[1]: Received: MARK(request_ident=2)
2023-01-13 07:21:52.175 Debug: Connection[1]: Session[1]: Marking query version 1 as complete after receiving MARK message

Movsar_Bekaev · January 13, 2023, 7:51am

It turns out that error was due to my class names, I got curious why the error mentions class “Language” - which didn’t exist and not the LanguageEntity, looks like MapTo() - doesn’t work with FlexibleSync, I renamed my entities to correspond to database schema and it doesn’t give me that error any more, and it looks like, this error only happens when using PopulateInitialSubscriptions, because yesterday I used with Subscriptions.Update the LanguageEntity class name and it didn’t produce that error.

I still have issues though, the app hangs after first couple of inserts, my hair are getting white with all these issues, but I hope you’ll make it stable one day

One of the other issues btw, is that I always have to run the app twice for it just to pass first GetInstance, i.e. when there is no .realm file, but still it’s like moving one line at a day.

nirinchev · January 13, 2023, 9:03am

MapTo should work with flexible sync. Just to be clear what it does is it configures the name of the class/property in the database. And it needs to match the schema on the server - i.e. if your Atlas collection is called Language, then MapTo("Language") is the right attribute to apply. The reason why the error is mentioning the database name rather than the C# class is because it’s being thrown by the database and it doesn’t know what the public name is (we have an issue to fix this though).

Regarding your other issues, if you come across unexpected behavior, the fastest way to get help would be to file a Github issue where one of the engineers will try and assist you. And of course, if you have feedback about how to make things more intuitive, we’d be more than happy to receive that as well.

Movsar_Bekaev · January 13, 2023, 9:21am

I understood that, but there was nothing wrong with database and server - both contained Language schema, but when I renamed the classes and removed the MapTo - everything started to work, first time in a week! Yes, I’ll file an issue on github, I think this is a bug, thank you