realm-dotnet: [Bug]: hang on async commit

What happened?

Sometimes, an async transaction hangs when the async callback completes. The application goes to sleep. The instruction after the await WriteAsync(realm => { … }) is never executed.

This seems to be a timing/synchronisation-related problem. When I add tracing Debug.WriteLine() calls to my code, it happens less frequently. 😦

It does not happen when the server is offline. (I tested this inadvertently just now because my WIFI connection dropped out for a while. No problems while it was down, no problems with the subsequent sync once online again. But when I ran it again while online, the hang happened again.)

Additionally, when I use the instructions at the bottom of this page to try to trace what else might be happening at the time, nothing changes. I get no logging output anywhere. Am I missing something? (Yes, my logging setup code is called before any other Realm code - AFAIK! I call it from Window_Loaded WPF callback before I call my Realm connection code.)

Repro steps

Write to Realm using WriteAsync from WPF UI thread in a DispatcherTimer callback. Keep doing this until one of the transactions hangs.

Version

10.7.1

What SDK flavour are you using?

MongoDB Realm (i.e. Sync, auth, functions)

What type of application is this?

WPF

Client OS and version

Microsoft Windows 10 Pro Version 10.0.19043 Build 19043

Code snippets

image

image

I can provide more code detail if you want it, just ask (but the whole program is pretty big!).

Stacktrace of the exception/crash you’re getting

Call Stack:
[Async] System.Private.CoreLib.dll!Task (bool) [Promise]
[Managed to Native Transition]
WindowsBase.dll!MS.Win32.UnsafeNativeMethods.GetMessageW(ref System.Windows.Interop.MSG msg, System.Runtime.InteropServices.HandleRef hWnd, int uMsgFilterMin, int uMsgFilterMax)
WindowsBase.dll!System.Windows.Threading.Dispatcher.GetMessage(ref System.Windows.Interop.MSG msg, System.IntPtr hwnd, int minMessage, int maxMessage)
WindowsBase.dll!System.Windows.Threading.Dispatcher.PushFrameImpl(System.Windows.Threading.DispatcherFrame frame)
WindowsBase.dll!System.Windows.Threading.Dispatcher.PushFrame(System.Windows.Threading.DispatcherFrame frame)
WindowsBase.dll!System.Windows.Threading.Dispatcher.Run()
PresentationFramework.dll!System.Windows.Application.RunDispatcher(object ignore)
PresentationFramework.dll!System.Windows.Application.RunInternal(System.Windows.Window window)
PresentationFramework.dll!System.Windows.Application.Run()
CarnivalSimulator.dll!CarnivalSimulator.App.Main()
[Async] CarnivalSimulator.dll!CarnivalSimulator.Simulators.RaceImporter.ActionAsync() Line 209
	at C:\Users\Ian\source\repos\Sports Carnival Pro\SportsCarnivalPro\CarnivalSimulator\Simulators\RaceImporter.cs(209)
[Async] CarnivalSimulator.dll!CarnivalSimulator.MainWindow.TryActivity(CarnivalSimulator.Simulators.ActivityBase activity, System.Func<System.Threading.Tasks.Task> action) Line 677
	at C:\Users\Ian\source\repos\Sports Carnival Pro\SportsCarnivalPro\CarnivalSimulator\MainWindow.xaml.cs(677)
[Async] CarnivalSimulator.dll!CarnivalSimulator.MainWindow.TickAsync() Line 745
	at C:\Users\Ian\source\repos\Sports Carnival Pro\SportsCarnivalPro\CarnivalSimulator\MainWindow.xaml.cs(745)
[Async] CarnivalSimulator.dll!CarnivalSimulator.MainWindow.LoadEvents.AnonymousMethod__21_1(object s, System.EventArgs a) Line 150
	at C:\Users\Ian\source\repos\Sports Carnival Pro\SportsCarnivalPro\CarnivalSimulator\MainWindow.xaml.cs(150)

Tasks:
Not Flagged		1298	Awaiting	CarnivalSimulator.MainWindow.LoadEvents.AnonymousMethod__21_1(s, a)	CarnivalSimulator.MainWindow.LoadEvents.AnonymousMethod__21_1(s, a)
Not Flagged		1297	Awaiting	CarnivalSimulator.MainWindow.TickAsync()	CarnivalSimulator.MainWindow.TickAsync()
Not Flagged		1296	Awaiting	CarnivalSimulator.MainWindow.TryActivity(activity, action)	CarnivalSimulator.MainWindow.TryActivity(activity, action)
Not Flagged		1295	Awaiting	CarnivalSimulator.Simulators.RaceImporter.ActionAsync()	CarnivalSimulator.Simulators.RaceImporter.ActionAsync()
Not Flagged		1294	Awaiting	Realms.Realm.WriteAsync<T>(function)	Realms.Realm.WriteAsync<T>(function)
Not Flagged	>	1301	Scheduled	[Scheduled and waiting to run]

Relevant log output

ActionAsync(4× 50m Relay Swim) @ 0/6 . 0/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.0.False
ActionAsync(4× 50m Relay Swim): adding 0.0 => 61a96398b266c38613d5b220
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4cf
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 1/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 1/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.1.False
ActionAsync(4× 50m Relay Swim): adding 0.1 => 61a96398b266c38613d5b221
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d0
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 2/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 2/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.2.False
ActionAsync(4× 50m Relay Swim): adding 0.2 => 61a96398b266c38613d5b222
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d1
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 3/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 3/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.3.False
ActionAsync(4× 50m Relay Swim): adding 0.3 => 61a96399b266c38613d5b223
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d2
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 4/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 4/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.4.False
ActionAsync(4× 50m Relay Swim): adding 0.4 => 61a96399b266c38613d5b224
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4cf
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 5/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 5/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.5.False
ActionAsync(4× 50m Relay Swim): adding 0.5 => 61a9639ab266c38613d5b225
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d0
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 6/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 6/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.6.False
ActionAsync(4× 50m Relay Swim): adding 0.6 => 61a9639ab266c38613d5b226
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d1
ActionAsync(4× 50m Relay Swim): committing
ActionAsync(4× 50m Relay Swim): committed
ActionAsync(4× 50m Relay Swim) complete @ 0/6 . 7/8 . Time==False
ActionAsync(4× 50m Relay Swim) @ 0/6 . 7/8 . Time==False
ActionAsync(4× 50m Relay Swim): writing 0.7.False
ActionAsync(4× 50m Relay Swim): adding 0.7 => 61a9639ab266c38613d5b227
ActionAsync(4× 50m Relay Swim): storing house 613b1002c8322e6d5a36a4d2
ActionAsync(4× 50m Relay Swim): committing

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 19 (13 by maintainers)

Most upvoted comments

@polymath74 disregard my previous message, I managed to reproduce the issue using the project you shared. I can see that the counting stops after some time (no “comitted” in the logs) and the code does not return after WriteAsync. I have also verified that it does not happen if Write is used instead, or if the code does not use Sync. I’m investigating why and I will keep you posted on the results. I will also try to understand what is happening with the logging.