Validating Custom Logging in Unity

Unity has a few builtin methods to validate assertions in the UnityEngine.TestTools namespace, you can validate the message as well as the log level. Here are a couple of examples

LogAssert.Expect(LogType.Warning, new Regex(".*(?i)My logs message"));
LogAssert.Expect(LogType.Error, "My log message");

One gotcha I have found with these is that if the test completes before the log is triggered, unity log assertions will not wait implicitly for the log to appear, it also does not provide any await conditions.

In my case I am using custom logging using nlog. If I was to bypass unity logging completely the log assertions would not work, however I am using unity console as one of nlogs targets

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">

    <variable name="defaultLayout" value="${longdate} ${level:uppercase=true} [${threadid}] -- ${message} ${exception:format=tostring}" />
    <variable name="unityLayout" value="${timestampcolor} ${levelcolor} [${threadid}] -- ${message} ${exception:format=tostring}"/>

    <extensions>
        <add assembly="ExampleAssembly"/>
    </extensions>

    <targets async="true">
        <!-- File target -->
        <target xsi:type="File" name="fileTarget"
                fileName="${unityDataPath}/logs/${date:format=yyyy-MM-dd}_run-${run_id}.log"
                layout="${defaultLayout}"
                keepFileOpen="true"
                concurrentWrites="false"
                archiveNumbering="Date"
                archiveEvery="Day"
                maxArchiveFiles="10" />

        <!-- Unity console target -->
        <target xsi:type="UnityDebugLog" name="unityConsole"
                layout="${unityLayout}"
        />
    </targets>

    <rules>
        <!-- Write Info and higher levels to the Unity console -->
        <logger name="*" minlevel="Info" writeTo="unityConsole" />

        <!-- Write all log levels to the file -->
        <logger name="*" minlevel="Trace" writeTo="fileTarget" />
    </rules>
    
</nlog>

If I use builtin unity logging as below

    public void MyMethod()
    {
      Debug.LogWarning("Log stuff");
    }

We add the log assertions how you would expect and it just works

    [UnityTest]
    public IEnumerator MyTest()
    {
      yield return SceneSetup();
      LogAssert.Expect(LogType.Warning, "Log stuff");
      myClass.MyMethod();
    }

However if I use my custom logger as below

    public void MyMethod()
    {
      CustomLogger.LogWarning("Log stuff");
    }

Unity will then not find the log and the assertion will fail. In order to remedy these we can add a line at the end of the test to update the scene a single frame.

    [UnityTest]
    public IEnumerator MyTest()
    {
      yield return SceneSetup();
      LogAssert.Expect(LogType.Warning, "Log stuff");
      myClass.MyMethod();
      yield return null;
    }

The test now passes as the log gets registered now before the test fails. This was a short post, but I think I have had fights with logging before around this so it will serve as a good reminder at least next year when I hit the same issue.