Performance overhead of subscriptions

[peppy]

As we begin to introduce more usage of SubscribeForNotifications into our game, we are noticing Realm.Refresh calls are getting slower and slower. This seems dependent on the number of subscriptions active.

Calling Realm.Refresh from the main thread is basically a requirement of using realm, so we have the expectation that the overhead of calling it is low enough to not impede performance (unless obviously expensive operations were queued up since the last run). What we're seeing is a large overhead from a single realm update.

• To cause the overhead, the SubscribeForNotifications needs to be on a model being updated
• Threading doesn't matter - the update can be done on the main or an async thread and the same overhead is observed

Even when there's a lot of objects in a realm, my expectation is that since realm is aware of all ongoing operations, reporting said operations to a subscription should be of negligible cost, else it renders subscriptions useless for a large number of use cases.

Real world implications

With no subscriptions, this is how deleting items from realm looks. Realm.Refresh calls do have an overhead, but it is low enough that I think we can potentially deal with it (0-5ms). As an aside, the rate of deletions here is only limited by the fact we are deleting over item per transaction, I am aware we can greatly improve this but it is out of scope of this report:

20220120.185136.osu.mp4

To show the overhead of a single deletion operation, I added a sleep between deletions (else the game basically comes to a halt). With one subscription and deleting a single object from our realm, we see spikes of around 500ms:

20220119.181237_osu.mp4.mov

With five subscriptions (some are only subscribed on the song select screen, which explains the increased overhead compared to the menu above):

20220119.181442_osu.mp4.mov

The overhead looks to be native, as checked on macOS, then windows to confirm:

From the profiling output, I'd say this is likely a realm-core issue, but posting it here seems amicable to begin further investigation as usage and examples is in dotnet projects.

Reproduction

I've written a barebones repro of this taking away the complexities of our project:

using System;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Threading;
using NUnit.Framework;
using Realms;

namespace RealmPerformanceTest
{
    [TestFixture]
    public class RealmScratch
    {
        private readonly Stopwatch timer = new Stopwatch();

        [TestCase(1000)]
        [TestCase(10000)]
        [TestCase(100000)]
        [TestCase(1000000)]
        public void TestNestedContexts(int count)
        {
            ManualResetEventSlim gotInitialCallback = new ManualResetEventSlim();

            timer.Restart();

            string realmFilename = Path.Combine(Environment.CurrentDirectory, "test.realm");

            File.Delete(realmFilename);

            var configuration = new RealmConfiguration(realmFilename);

            using (var realm = Realm.GetInstance(configuration))
            {
                using (var transaction = realm.BeginWrite())
                {
                    for (int i = 0; i < count; i++)
                        realm.Add(new PersistedObject());

                    transaction.Commit();
                }
            }

            Console.WriteLine($"Running with realm size {new FileInfo(realmFilename).Length:g} ({count} objects)");

            using (var realm = Realm.GetInstance(configuration))
            {
                realm
                    .All<PersistedObject>()
                    .SubscribeForNotifications(NotifyCallback);

                while (!gotInitialCallback.IsSet)
                    TimedOp(realm.Refresh, "refresh");

                for (int i = 0; i < 10; i++)
                {
                    using (var transaction = realm.BeginWrite())
                    {
                        // make an arbitrary change to one object
                        realm.All<PersistedObject>().First(s => !s.ArbitraryBool).ArbitraryBool = true;
                        TimedOp(transaction.Commit, "commit");
                    }

                    TimedOp(realm.Refresh, "refresh");
                }
            }


            void NotifyCallback(IRealmCollection<PersistedObject> sender, ChangeSet changes, Exception error)
            {
                if (changes == null)
                    gotInitialCallback.Set();
            }
        }

        private void TimedOp(Func<bool> op, string name)
        {
            long before = timer.ElapsedMilliseconds;
            op();
            Console.WriteLine($"{name} took {timer.ElapsedMilliseconds - before} ms");
        }

        private void TimedOp(Action op, string name)
        {
            long before = timer.ElapsedMilliseconds;
            op();
            Console.WriteLine($"{name} took {timer.ElapsedMilliseconds - before} ms");
        }

        public class PersistedObject : RealmObject
        {
            public bool ArbitraryBool { get; set; }
        }
    }
}

Results for these runs are as follows:

Running with realm size 8192 (1000 objects)
refresh took 3 ms
commit took 0 ms
refresh took 6 ms
commit took 0 ms
refresh took 0 ms
commit took 1 ms
refresh took 0 ms
commit took 0 ms
refresh took 0 ms
commit took 0 ms
refresh took 0 ms
commit took 0 ms
refresh took 1 ms
commit took 0 ms
refresh took 0 ms
commit took 0 ms
refresh took 1 ms
commit took 0 ms
refresh took 0 ms
commit took 1 ms
refresh took 0 ms

Running with realm size 53248 (10000 objects)
refresh took 1 ms
commit took 0 ms
refresh took 2 ms
commit took 1 ms
refresh took 3 ms
commit took 0 ms
refresh took 3 ms
commit took 0 ms
refresh took 3 ms
commit took 0 ms
refresh took 2 ms
commit took 0 ms
refresh took 3 ms
commit took 0 ms
refresh took 2 ms
commit took 0 ms
refresh took 2 ms
commit took 0 ms
refresh took 2 ms
commit took 0 ms
refresh took 2 ms

Running with realm size 512000 (100000 objects)
refresh took 15 ms
commit took 0 ms
refresh took 21 ms
commit took 22 ms
refresh took 21 ms
commit took 0 ms
refresh took 22 ms
commit took 1 ms
refresh took 22 ms
commit took 0 ms
refresh took 19 ms
commit took 1 ms
refresh took 19 ms
commit took 0 ms
refresh took 25 ms
commit took 0 ms
refresh took 21 ms
commit took 1 ms
refresh took 22 ms
commit took 1 ms
refresh took 21 ms

Running with realm size 5603328 (1000000 objects)
refresh took 154 ms
commit took 1 ms
refresh took 207 ms
commit took 1 ms
refresh took 194 ms
commit took 1 ms
refresh took 192 ms
commit took 1 ms
refresh took 186 ms
commit took 2 ms
refresh took 196 ms
commit took 1 ms
refresh took 181 ms
commit took 1 ms
refresh took 187 ms
commit took 1 ms
refresh took 186 ms
commit took 1 ms
refresh took 187 ms
commit took 2 ms
refresh took 186 ms

[nirinchev]

This is because Refresh() will block until all subscription handlers have fired. Not only that, but it also forces the otherwise asynchronous changeset calculation to happen synchronously. This is to ensure correctness when notifications are delivered (i.e. they need to see the Realm in a state that is consistent with the changeset indices). I don't know how feasible this is, but the most obvious approach to alleviate this is to move away from calling Refresh manually and instead let Realm refresh itself. For this to work though, you'll need to install a synchronization context on your main thread, which may have unintended consequences for other parts of your code (e.g. async continuations being dispatched back on the main thread).

[peppy]

So one (hopefully) final thing: It looks like the same overhead is incurred when opening a new realm context - even if that request is on the main thread with an already open context. I believe either you or someone else on the realm team mentioned previously that opening extra contexts on the same thread will internally share the already open handle, but it seems this is also triggering a refresh/sync implicitly?

[nirinchev]

You're right on both counts - we do get a cached instance and we do refresh it:

realm-dotnet/wrappers/src/shared_realm_cs.cpp

Lines 133 to 144 in 5beb429

	inline SharedRealm* new_realm(SharedRealm realm)
	{
	// If a Realm is immutable, it can't be refreshed
	// If we can't refresh the Realm, make sure we begin a read transaction
	// as a lot of functionality expects an active read transaction and
	// ObjectStore doesn't always start one automatically.
	if (realm->config().immutable() || !realm->refresh()) {
	realm->read_group();
	}
	return new SharedRealm(realm);
	}

I understand the problem from your end, on the other hand, a lot of users have the expectation that when they call Realm.GetInstance, the resulting instance is fully up-to-date with whatever is on disk. For example,

await Task.Run(() =>
{
    using var bgRealm = Realm.GetInstance();
    bgRealm.Write(() => { ... });
});

var foregroundRealm = Realm.GetInstance();

// we expect to see whatever we wrote in the background here

The caching/refresh part is not necessarily well understood, so we had received bug reports that users are writing some data and not seeing it propagate correctly, which is why we added the forceful refresh. I'll consult with the team and get back to you.

[peppy]

I believe we can do something to work around it from our end, so it's not a deal-breaker either way.

[nirinchev]

Okay, so spoke with the team and we think that the current behavior better matches user expectations and providing an opt out would be more confusing than helpful. If it turns out more people hit perf issues with it, we'll revisit it.

[peppy]

Definitely agree (I checked after this thread and we do rely on said behaviour in a few places).

For anyone curious, we were able to work around the issue by abstracting realm operations one level further, where we can funnel all main thread requests into a single realm instance.