Methods to troubleshoot UnobservedPromiseException about protopromise HOT 24 CLOSED

Aha, looks like it was fixed in #306! To confirm, I added a try/catch:

try
{
    await Promise.SwitchToForeground();
}
catch (Exception e)
{
    Debug.LogException(e);
}

And that actually logs
InvalidOperationException: SynchronizationOption.Foreground was provided, but Promise.Config.ForegroundContext was null. You should set Promise.Config.ForegroundContext at the start of your application (which may be as simple as 'Promise.Config.ForegroundContext = SynchronizationContext.Current;').

@drew-512 If you try latest master, it should be fixed. Thank you very much for the bug report, and please let me know if you hit any other issues!

from protopromise.

Hi Drew,

UnobservedPromiseException means a promise was not awaited or forgotten. If a deferred was left pending, it would instead be a UnhandledDeferredException.

The exception message should explain how to enable causality traces to find the culprit. You need to be in DEBUG mode and set Promise.Config.DebugCausalityTracer = Promise.TraceLevel.All.

from protopromise.

Ah, ok thanks for the correction there.

I did have Promise.TraceLevel.All set, however it's unclear what I need to look at for help. There are a ton of fields and the ones that are interesting like the stack trace are truncated by VSCode.

What and where should I look for more information?

from protopromise.

Oh, it looks you even enabled developer mode! That shouldn't be necessary for you, that's really for me to debug the internal promise code. You should disable that to get a cleaner causality trace (it strips internal promise frames if it's disabled).

The information you're looking for is in the Stacktrace of the UnhandledException, in this case the one that contains the UnobservedPromiseException as its InnerException.

from protopromise.

I think VS has options to view the entire stacktrace if you right-click it. Otherwise, you could try grabbing the ToString() of the entire exception, which should include all of the stacktrace information.

from protopromise.

Also, when it's printed to the console in Unity, it should include the full stacktrace there. If it's truncated in the console, you can view the full thing in the log file (the console can open it directly from the ... dropdown).

from protopromise.

I wasn't getting any info from Unity since the exception was happening when play mode was starting (when GC was likely happening from the last play). This means any exception msgs pushed to Unity were being cleared as play mode begins. Meanwhile, VSCode / C# is still highly unimpressive with strings in the debugger. I ended up just putting in some lines that print the stack trace to a Debug.Log message. Given this somewhat likely scenario (where GC occurring right before entering play mode), perhaps an enhancement here makes sense.

Anyway, the offender suprisingly is await Promise.SwitchToForeground(), made from an async void proc that exits during app shutdown (play mode exit):

async void sessionReader(NetworkStream stream) {
    await Promise.SwitchToBackground();
    string logMsg = null;
    try {
        var hdr = new byte[TxMsg.TxHeaderSz];
        int bytesRead;                     
        
        while ((bytesRead = stream.Read(hdr, 0, TxMsg.TxHeaderSz)) == TxMsg.TxHeaderSz) {
            var tx = TxMsg.Acquire(hdr);
            if ((bytesRead = stream.Read(tx.TxStore, TxMsg.TxBodyOfs, tx.TxBodyLen)) != tx.TxBodyLen) {
                throw new Exception($"Failed to read TxMsg body: {bytesRead} != {tx.TxBodyLen}");
            }
            handleIncomingTx(tx);
        }
    } catch (Exception ex) {
        logMsg = ex.ToString();
    }

    // Cancel the writer if the reader stops
    Cancel();
    
    await Promise.SwitchToForeground();
    if (logMsg != null) {
        Logger.Warn(logMsg);
    }
    
    // Tell controller we're fully disconnected
    _client.OnConnectionClosed();
}

from protopromise.

I wasn't getting any info from Unity since the exception was happening when play mode was starting (when GC was likely happening from the last play). This means any exception msgs pushed to Unity were being cleared as play mode begins.

You can fix that by disabling clear on play mode.

Anyway, the offender suprisingly is await Promise.SwitchToForeground(), made from an async void proc that exits during app shutdown (play mode exit):

I'm guessing that's because you have AppDomain reload disabled. The default exception handler ignores any further exceptions after OnApplicationQuit. Since it occurs when you start the game again, it no longer considers it to be in the quitting state, so it does log it.

I can't think of a nice way to handle that case, I'm open to suggestions.

from protopromise.

Hmm, is there any way to catch or prevent whatever is going on with that await Promise.SwitchToForeground()?

from protopromise.

Hmm, is there any way to catch or prevent whatever is going on with that await Promise.SwitchToForeground()?

Suffice to say, there's nothing wrong with your code, and you won't see this issue in production. This is purely a side effect of stopping and restarting code without resetting its run context (AppDomain reload here, process isolation in built player).

from protopromise.

Perhaps I could add an API like Promise.Manager.ResetRuntimeContext() that can be called from OnApplicationQuit or SubsystemRegistration. That would then ignore exceptions from every object created before ResetRuntimeContext was called.

from protopromise.

If it's interesting, Unity seems to be being mean to your exceptions.

from protopromise.

That looks like it's from throwing the exception on a ThreadPool thread after the default exception handler is removed from OnApplicationQuit. Kinda weird that they truncate the inner exceptions, but oh well. I guess their background thread exception handler just logs warning with the exception's message, rather than its full ToString.

from protopromise.

So I tried to repro that code in a test case, and it passes every time I run it. I debugged it and saw the promise was marked as awaited (as it should be). The only thing I can think of is the background thread is being aborted in the middle of the await. I'm unaware of Unity aborting background threads without the AppDomain being reloaded. Are you perhaps running your own background SynchronizationContext and aborting threads yourself?

private class StrongBox<T>
{
    public T value;
}

[MethodImpl(MethodImplOptions.NoInlining)]
private static async void RunAndSwitchContext(StrongBox<bool> box, SynchronizationContext context)
{
    await Promise.SwitchToBackground();
    box.value = true;
    await Promise.SwitchToContext(context);
    box.value = true;
}

[Test]
public void PromiseSwitchToContext_NeverExecuted_NoExceptions()
{
    // We're purposefully not completing the promise, to simulate Unity's enter/exit playmode.
    var box = new StrongBox<bool>();
    RunAndSwitchContext(box, new NeverExecutedSynchronizationContext());
    while (!box.value) { Thread.MemoryBarrier(); }
    box.value = false;
    Thread.Sleep(1000);
    Assert.False(box.value);

    TestHelper.GcCollectAndWaitForFinalizers();
}

from protopromise.

@drew-512 Can you confirm if aborting threads is the cause?

from protopromise.

Hi Tim,

Not aborting any threads. I start a reader and writer via await Promise.SwitchToBackground(); and only exit those threads (which I'm not regarding as aborting).

Can I test something specifically?

from protopromise.

So you're not setting anything in Promise.Config? Just using the default values? I'm trying to determine the root cause of the issue, and if it's not thread aborts, I can't think of what it might be.

from protopromise.

@drew-512 Could you possibly send me a repro project?

from protopromise.

If I'm hearing you right, you'd like a repro project of the shows a warning as in my Oct 18 post?

I have to sheepishly admit that I didn't event know about Promise.Config until your mention of it above (and so had not made any changes to that).

from protopromise.

If I'm hearing you right, you'd like a repro project of the shows a warning as in my Oct 18 post?

If possible, yes. I'm uncomfortable merging #303 without understanding the actual cause.

I have to sheepishly admit that I didn't event know about Promise.Config until your mention of it above (and so had not made any changes to that).

No worries, that's good to know. (Although if you had set Promise.TraceLevel.All, then you were using it. 😉)

from protopromise.

Sorry for the delay, been a tough go personally lately.

Ok, I'll use the latest release version (not branch)? What vars should I set exactly out of Promise.Config to give you the output or stack that you're looking for?

from protopromise.

You didn't change any defaults before so no need to do so now. I just need to be able to repro it like you had before, then I can start debugging it myself.

from protopromise.

Nevermind, I was able to reproduce it with this code in editor.

void Start()
{
    for (int i = 0; i < Environment.ProcessorCount; ++i)
    {
        Func().Forget();
    }
}

private async Promise Func()
{
    while (true)
    {
        await Promise.SwitchToBackground();
        Thread.Sleep(10);
        await Promise.SwitchToForeground();
    }
}

from protopromise.

Yay, nice work! Switching to main!

from protopromise.