Unity LogAssert with async methods

Unity Engine
,
1

My goal is to implement a test, that can check if an error is logged, when it is happened in the async void method.

I have this sample class for editor mode auto-testing in Unity3d:

public class AsyncLogTest
{
   [Test]
   public void Test1()
   {
       ThrowException();
       LogAssert.Expect(LogType.Exception, new Regex(".*"));
   }
   
   [Test]
   public void Test2()
   {
       DirectLog();
       LogAssert.Expect(LogType.Exception, new Regex(".*"));
   }

   [UnityTest]
   public IEnumerator Test3()
   {
       LogAssert.ignoreFailingMessages = true;
       ThrowException();
       yield return null;
       LogAssert.Expect(LogType.Exception, new Regex(".*"));
   }

   [UnityTest]
   public IEnumerator Test4()
   {
       ThrowException();
       // Wait for 1 second
       var stopwatch = new Stopwatch();
       stopwatch.Start();
       while (stopwatch.ElapsedMilliseconds < 1000)
       {
           yield return null;
       }
       stopwatch.Stop();
       LogAssert.Expect(LogType.Exception, new Regex(".*"));
   }

   [UnityTest]
   public IEnumerator Test5()
   {
       LogAssert.ignoreFailingMessages = true;
       ThrowException();
       // Wait for 1 second
       var stopwatch = new Stopwatch();
       stopwatch.Start();
       while (stopwatch.ElapsedMilliseconds < 1000)
       {
           yield return null;
       }
       stopwatch.Stop();
       LogAssert.Expect(LogType.Exception, new Regex(".*"));
   }

   public async void ThrowException()
   {
       throw new Exception();
   }

   public async void DirectLog()
   {
       Debug.LogException(new Exception());
   }
}

The result of this tests is next:

  • Test1 - always fails due to Expected log did not appear: [Exception] Regex: .*.
  • Test2 - always success.
  • Test3 - sometimes fails, sometimes success. Fail reason - Expected log did not appear: [Exception] Regex: .*
  • Test4 - always fails due to Unhandled log message: '[Exception] Exception: Exception of type 'System.Exception' was thrown.'. Use UnityEngine.TestTools.LogAssert.Expect
  • Test 5 - always success.

Also I can see the correct exception log in Unity3d console for all of these tests. Even for those, that fails.

I can make some conclusions and raise some questions based on these results.

  • Firstly, looks like exceptions, that are thrown in async methods are not logged instantly, but written to some kind of buffer, and logged only when this buffer is purged. Also, this buffer purging does not depend on engine Update tick, or this dependency is not clear for me. I can say all of this because Test5, where I wait great amount of time success always, but Test3 where I wait only for one engine tick is unstable and looks like this exceptions buffer can either be purged while this tick elapsed or not.
  • Secondly, for some reason, I have to specify LogAssert.ignoreFailingMessages = true; for exceptions logs, that are logged from this buffer, but I don’t have to do it if exception logged explicitly. Test4 and Test5 results illustrate this well.

So the question is how to make a test, that assert exception, raised in async method, logged? And make it most efficient. I mean, the case when I should wait a second is not suitable for auto-tests, of course. I expect, I can do something like this:

[Test]
public void Test()
{
    ThrowException();
    UnityAPI.ForceLogAllAsyncExceptions(); // I imagine this method
    LogAssert.Expect(LogType.Exception, new Regex(".*"));
}

Or any other solutions.

2

Test1/3/4 is failed on throw exception. LogAssert is not executed.

If you want to test the thrown exception, the following code may be helpful.

3

What makes you think these tests fails due to exceptions? I thought I wrote reasons pretty clearly:

4

There’s no simple way to check/guarantee that an async void method has completed at any given time. In some of your cases, it’s completing after the test has finished. The common guideline would be to not use async void methods, but if you really have to, then I’d suggest looking for solutions on “how to wait for an async void method to complete”.

5

What do you mean by method completing?

6

sbergen I’m not sure what completing do you mean, but async methods without await always execute synchronously. I can add such kind of test to make you sure about it. This test does stably fail same way as Test1. And again I can see correct exception in editor log.

        [Test]
        public void Test6()
        {
            var t = new TaskCompletionSource<object>();
            ThrowException(t);
            t.Task.Wait();
            LogAssert.Expect(LogType.Exception, new Regex(".*"));
        }
    
        public async void ThrowException(TaskCompletionSource<object> t)
        {
            try
            {
                throw new Exception();
            }
            finally
            {
                t.SetResult(new object());
            }
        }
7

First off, I was assuming you actually have some async code in the method you’d actually want to test: why would you use async void otherwise?

Second, exception handling from async void methods gets dispatched to the synchronization context, which in Unity seems to happen asynchronously, even if you are already on the main thread. I’ve run into a few similar cases before, where certain async/await behaviours are slightly different in Unity than in .NET console applications at least.

“Completed” was perhaps not the clearest term to use. Let’s rather say that there’s no simple way to know when all the side effects of an async void method have been fully applied.