Add more verbose logging to realm blocking process

This commit is contained in:
Dean Herbert 2022-07-02 12:35:29 +09:00
parent 3b1842a2c2
commit 4fd47b5fa0
7 changed files with 23 additions and 18 deletions

View File

@ -30,7 +30,7 @@ namespace osu.Game.Tests.Database
{
RunTestWithRealm((realm, _) =>
{
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
}
});
@ -56,7 +56,7 @@ namespace osu.Game.Tests.Database
{
Task writeTask;
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
writeTask = realm.WriteAsync(r => r.Add(TestResources.CreateTestBeatmapSetInfo()));
Thread.Sleep(100);
@ -169,7 +169,7 @@ namespace osu.Game.Tests.Database
Assert.Throws<TimeoutException>(() =>
{
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
}
});
@ -177,7 +177,7 @@ namespace osu.Game.Tests.Database
stopThreadedUsage.Set();
// Ensure we can block a second time after the usage has ended.
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
}
});

View File

@ -49,7 +49,7 @@ namespace osu.Game.Tests.Database
{
migratedStorage.DeleteDirectory(string.Empty);
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
storage.Migrate(migratedStorage);
}

View File

@ -136,7 +136,7 @@ namespace osu.Game.Tests.Database
resolvedItems = null;
lastChanges = null;
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
Assert.That(resolvedItems, Is.Empty);
realm.Write(r => r.Add(TestResources.CreateTestBeatmapSetInfo()));
@ -154,7 +154,7 @@ namespace osu.Game.Tests.Database
testEventsArriving(false);
// And make sure even after another context loss we don't get firings.
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
Assert.That(resolvedItems, Is.Null);
realm.Write(r => r.Add(TestResources.CreateTestBeatmapSetInfo()));
@ -212,7 +212,7 @@ namespace osu.Game.Tests.Database
Assert.That(beatmapSetInfo, Is.Not.Null);
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
// custom disposal action fired when context lost.
Assert.That(beatmapSetInfo, Is.Null);
@ -226,7 +226,7 @@ namespace osu.Game.Tests.Database
Assert.That(beatmapSetInfo, Is.Null);
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
Assert.That(beatmapSetInfo, Is.Null);
realm.Run(r => r.Refresh());
@ -251,7 +251,7 @@ namespace osu.Game.Tests.Database
Assert.That(receivedValue, Is.Not.Null);
receivedValue = null;
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
{
}
@ -262,7 +262,7 @@ namespace osu.Game.Tests.Database
subscription.Dispose();
receivedValue = null;
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("testing"))
Assert.That(receivedValue, Is.Null);
realm.Run(r => r.Refresh());

View File

@ -126,7 +126,7 @@ namespace osu.Game.Database
string backupSuffix = $"before_final_migration_{DateTimeOffset.UtcNow.ToUnixTimeSeconds()}";
// required for initial backup.
var realmBlockOperations = realm.BlockAllOperations();
var realmBlockOperations = realm.BlockAllOperations("EF migration");
Task.Factory.StartNew(() =>
{

View File

@ -780,7 +780,7 @@ namespace osu.Game.Database
public void CreateBackup(string backupFilename, IDisposable? blockAllOperations = null)
{
using (blockAllOperations ?? BlockAllOperations())
using (blockAllOperations ?? BlockAllOperations("creating backup"))
{
Logger.Log($"Creating full realm database backup at {backupFilename}", LoggingTarget.Database);
@ -811,9 +811,12 @@ namespace osu.Game.Database
/// This should be used in places we need to ensure no ongoing reads/writes are occurring with realm.
/// ie. to move the realm backing file to a new location.
/// </remarks>
/// <param name="reason">The reason for blocking. Used for logging purposes.</param>
/// <returns>An <see cref="IDisposable"/> which should be disposed to end the blocking section.</returns>
public IDisposable BlockAllOperations()
public IDisposable BlockAllOperations(string reason)
{
Logger.Log($@"Attempting to block all realm operations for {reason}.", LoggingTarget.Database);
if (!ThreadSafety.IsUpdateThread)
throw new InvalidOperationException(@$"{nameof(BlockAllOperations)} must be called from the update thread.");
@ -843,7 +846,7 @@ namespace osu.Game.Database
updateRealm = null;
}
Logger.Log(@"Blocking realm operations.", LoggingTarget.Database);
Logger.Log(@"Lock acquired for blocking operations", LoggingTarget.Database);
const int sleep_length = 200;
int timeout = 5000;
@ -867,6 +870,8 @@ namespace osu.Game.Database
Logger.Log($"Realm compact failed with error {e}", LoggingTarget.Database);
}
Logger.Log(@"Realm usage isolated via compact", LoggingTarget.Database);
// In order to ensure events arrive in the correct order, these *must* be fired post disposal of the update realm,
// and must be posted to the synchronization context.
// This is because realm may fire event callbacks between the `unregisterAllSubscriptions` and `updateRealm.Dispose`

View File

@ -446,7 +446,7 @@ namespace osu.Game
Scheduler.Add(() =>
{
realmBlocker = realm.BlockAllOperations();
realmBlocker = realm.BlockAllOperations("migration");
readyToRun.Set();
}, false);

View File

@ -39,7 +39,7 @@ namespace osu.Game.Overlays.Settings.Sections.DebugSettings
Action = () =>
{
// Blocking operations implicitly causes a Compact().
using (realm.BlockAllOperations())
using (realm.BlockAllOperations("compact"))
{
}
}
@ -58,7 +58,7 @@ namespace osu.Game.Overlays.Settings.Sections.DebugSettings
{
try
{
var token = realm.BlockAllOperations();
var token = realm.BlockAllOperations("maintenance");
blockAction.Enabled.Value = false;