Logging in Unity

Logging is an essential part of a development setup and very useful in production to monitor app health. Unity is a popular cross-device game engine that uses Mono to run scripts written in C#. In this article, we will see how you can enable logging for unhandled exceptions and debug messages in a Unity application. Some of the behavior is the same as for general Mono applications but Unity adds more steps to the lifecycle of the application that needs to be taken into account. In the end we also look at how we can use this to log from a Unity application to elmah.io.

Existing logging solutions

The easiest method for logging in a local setting is definitely just to use the Unity IDE where you will then see any logs or exceptions in the console window. You can also build a version of your application that prints the console output directly in the app. These options are nice but not always possible or practical. If it is not possible to attach the debugger to the place that you run the application then you can't use the Unity IDE to log errors. Then our other option is to add the in-app console log but this can fill much of the interface and you might not want the user to see your error log. Another problem is that we also want to do more than just see the errors separately. We want to collect the errors in our logging system.

Unity already has a system for cloud logging called Cloud Diagnostics. This is well-integrated into the Unity platform. But we would probably rather have the errors be logged to our existing error logging service instead of adding another platform to monitor our applications.

Application Lifecycle

Mono itself has the same entry point as the applications that we can create in .NET.

public class HelloWorld
{
    // Method is called when application is started.
    public static void Main(string[] args)
    {
        // Setup logging here.
    }
}

But Unity is a component-based framework and does not make it possible to create a Main function.

Instead, we need to add an empty component to the scene that we work with. It is a good idea to have the logging in a separate component so that you know that the component is alive throughout the whole lifetime of the application.

Then we can add a script to the component where we will set up logging.

In this, we can add the following methods that will get called during different lifecycle events in the component.

using UnityEngine;

public class Logging : MonoBehaviour
{
    // This function is always called before any Start functions
    void Awake()
    {
        
    }

    // Start is called before the first frame update
    void Start()
    {
        
    }

    // Update is called once per frame
    void Update()
    {
        
    }

    // This function is called after all frame updates for the last frame of the object’s existence
    void OnDestroy()
    {
        
    }
}

The important thing to note is that Awake is called before any Start function is called. So we will want to add the logging to the application in the Awake function. Doing this means that we can catch any error that is thrown in Start or Update where most of the workload is normally done. We can't make any promises for what order Awake functions in different components are called, so it is generally a good idea to delay code that could throw errors from Awake until Start if possible.

Standard error handling in Unity

The code that you run in the Start and Update functions can tell the program that something went wrong in multiple ways. If the error is not critical to the further execution of the program then you can log an error with

Debug.LogError("Something went wrong");
Debug.LogWarning("Something went wrong");
Debug.LogException(new Exception("Something went wrong"));

If the execution is critical or if you want to enable the caller to handle exceptions through the call stack then you can throw an exception instead.

throw new Exception("Something really went wrong");

Often you don't go around and create a lot of the logic yourself when developing Unity apps. But instead, use some implementation from the standard libraries. These standard libraries are a mix of wrappers for C++ libraries and natively developed .NET packages. There is not a universal rule for when a library uses either logging method so we will have to handle both scenarios.

Event Handler for Debug logs

We can subscribe to an event that is triggered every time something is logged with Debug like so.

void Awake()
{
    Application.logMessageReceivedThreaded += Application_logMessageReceivedThreaded;
}

private void Application_logMessageReceivedThreaded(string condition, string stackTrace, LogType type)
{
    // Log log to your logging system.
}

Then we can handle every time something logs an error of one of the following types (severities): Assert, Error, Exception, Log, Warning. We could even filter on this if we e.g only want to log Assert or Exception errors. This can be useful as the same error can occur in the body of the Update function every time it is called which can quickly run into the thousands when it is called every frame.

Event Handler for Unhandled Exceptions

We can also subscribe to the event of an unhandled error occurring. This can also be done in the Awake function.

void Awake()
{
    TaskScheduler.UnobservedTaskException += TaskScheduler_UnobservedTaskException;
}

private void TaskScheduler_UnobservedTaskException(object sender, UnobservedTaskExceptionEventArgs e)
{
    // Log `e.Exception` to you logging system
}

We can get much more detail about the exception and the context that it occurred in when we have an Exception object. It looks like Unity catches all Exceptions that are thrown in non-async threads. So these will be handled by the Debug logger, but all Exceptions that are thrown in a Task will instead be caught by the UnobservedTaskException event handler.

Unsubscribing events

It is a good idea to also unsubscribe to events once the application closes but not strictly necessary as the application is about to close anyway. We do this in the counterpart to the Awake function in the lifecycle which is OnDestroy.

// This function is called after all frame updates for the last frame of the object’s existence
void OnDestroy()
{
    Application.logMessageReceivedThreaded -= Application_logMessageReceivedThreaded;
    TaskScheduler.UnobservedTaskException -= TaskScheduler_UnobservedTaskException;
}

Logging to elmah.io from Unity

We have the capability to get all relevant information about logs and exceptions. So now, we just have to log it to our cloud logging service of choice. Not to be biased but for me, that's elmah.io. So let's see how we can do that. The following will use the newest preview version of the Elmah.Io.Client package.

You can't add packages from Nuget to a Unity project directly but you can download the dll files and add them manually. So I simply went to
https://nuget.org/packages/Elmah.Io.Client selected the newest preview version and clicked Download package.
This gives us a .nupkg file that we can simply rename to .zip and open using the file explorer. In this, we will see a lib folder that contains all the versions that this package targets. We need the netstandard2.0 version as Unity is compatible with this version. So we just copy the files in that folder and paste them into a new folder Libraries in the Assets folder of our Unity project. Elmah.Io.Client almost only uses the standard libraries but still has a single dependency on Newtonsoft.Json. So we just need to do the same for the Newtonsoft.Json package and add its dll's to the Libraries folder. When dll's are placed within the Assets folder then Unity will automatically add them during the build process.

Now that we have the package installed then we can begin to log messages.

We first add an IElmahIoAPI property to the component so that we don't need to instantiate a new every time we log.

private IElmahioAPI api;

Then we can start by logging Debug logs

private void Application_logMessageReceivedThreaded(string condition, string stackTrace, LogType type)
{
    if (api == null)
    {
        api = ElmahioAPI.Create("API_KEY");
    }

    Severity severity = Severity.Debug;
    switch (type)
    {
        case LogType.Assert:
            severity = Severity.Information;
            break;
        case LogType.Error:
            severity = Severity.Error;
            break;
        case LogType.Exception:
            severity = Severity.Error;
            break;
        case LogType.Log:
            severity = Severity.Verbose;
            break;
        case LogType.Warning:
            severity = Severity.Warning;
            break;
    }

    var message = new CreateMessage()
    {
        Title = condition,
        Detail = stackTrace,
        Severity = severity.ToString(),
        Url = Application.absoluteURL
    };

    api.Messages.Create("log-id", message);
}

We don't really have a lot of information when logging from Debug but we do have a log type that is somewhat equivalent to our log severity, so we switch on the log types and assign each a severity. This is only an attempt at mapping but it still gives a lot of information.

Next, we also want to log unhandled exceptions and we do this like like the following which is very close to how we would log Exceptions manually in other frameworks:

private void TaskScheduler_UnobservedTaskException(object sender, UnobservedTaskExceptionEventArgs e)
{
    if (api == null)
    {
        api = ElmahioAPI.Create("API_KEY");
    }

    var exception = e.Exception;
    var baseException = exception?.GetBaseException();

    var message = new CreateMessage()
    {
        Data = exception?.ToDataList(),
        DateTime = DateTime.UtcNow,
        Detail = exception?.ToString(),
        Severity = "Error",
        Source = baseException?.Source,
        Title = baseException?.Message ?? "Unhandled Unity exception",
        Type = baseException?.GetType().FullName,
    };

    api.Messages.Create("log-id", message);
}

Testing the integration

Now let's provoke one of the most common errors Object reference not set to an instance of an object which we have also blogged about before Debugging System.NullReferenceException - Object reference not set to an instance of an object

We provoke the Exception with the following in our Start function.

private List<string> list { get; set; }

// Start is called before the first frame update
void Start()
{
    list.Add("Hello");
}

There will be thrown an Exception when we try to add "Hello" to the list as the list is not initialized yet.
This Exception is not thrown in an asynchronous thread so the Debug logger will observe it and we will log the error through the logMessageReceivedThreaded event handler.

This example can be found at https://github.com/elmahio-blog/Elmah.Io.UnityExample.

If we instead change the Start function to be asynchronous in a Task then we would see it be handled by the UnobservedTaskException event handler

private List<string> list { get; set; }

// Start is called before the first frame update
async Task Start()
{
    list.Add("Hello");
}

So now we have successfully added logging to elmah.io from a Unity application and seen that it works.

Conclusion

In this article, we have looked at existing Unity logging solutions. Then we have seen how we can log errors for the full life time of an application in general. In the end, we looked at how we can use this to log Exceptions and Debug Messages to elmah.io.