Pimp My Debug.Log()

This post describes a quick “tip” for improving how you work with logging in Unity. Share it with your team in case you find it useful :)

Console Window Mess

As developers we probably spend 50% of our time debugging code (it is my blog, so i get make up fake statistics). Any Unity developer who spends more than 5 minutes with the editor probably knows the Debug class, and more specifically the Debug.Log method that prints log messages to the Console window.

While it’s easy to log messages, the Console window can quickly get cluttered and it becomes super hard to find the exact trace message you’re looking for.

Rich text formatting seems to be one of Unity’s best kept secrets (haven’t seen people using it yet), but it can come in handy for tidying up the Console window.

Rich Text Formatting

Log messages passed to Debug.Log and its other variants (LogError, LogWarning, etc) can include special “tags” that provide formatting for the log message, for example:

Debug.Log("<color=green>This is a green message!</color>");

These tags control the visual properties of the displayed text, such as its size and color. For all the fine details check out the documentation here.

The only issue is that it can be tedious to manually format all log messages, which may drive you to not use this feature at all.

Luckily, there’s a better option. Enter the “Extension Method” solution.

String Extensions Class

Instead of manually formatting every log message and adding the required tags, we can create a static extensions class, and define a few extension methods on the string type.

The following code snippet adds a few extension methods on the string class:

This allows writing simple code, without having to manually add the formatting tags:

// Update is called once per frame
void Update ()
{
    var message = "Hello, World!";
    // Print the message in green.
    Debug.Log (message.Colored (Colors.green));

    // Compose different formatting together.
    Debug.Log (message.Bold().Sized(16));

    // Works with LogError as well.
    Debug.LogError (message.Italics());
}

The code snippet above prints out the following logs in the Console window, with the proper formatting:

Console window output

Console window output

Notes

  • Rich text formatting works with all Debug.LogXXX methods.
  • Editor GUI controls also support rich formatting, however it must be explicitly enabled.
GUIStyle style = new GUIStyle ();
style.richText = true;

Introduction to Unity Test Tools

Unity Test Tools is a package officially released by the folks at Unity in December 2013. It provides developers the components needed for creating and executing automated tests without leaving the comforts of the Unity editor. The package is available for download here: http://u3d.as/65h

This article serves as a high level overview of the tools rather than an in-depth drill-down. It covers the 3 components the package is comprised of:

  1. Unit tests
  2. Integration tests
  3. Assertion component

The package comes with detailed PDF documentation (in English and Japanese),  examples and the complete source code so you can modifications in case they are needed.

Unit Tests

There are many definitions to what a “unit test” is. In the context of this article it will be defined as a test that is:

  1. Written in code.
  2. Focuses on a single “thing” (method/class).
  3. Does not have “external dependencies” (e.g: does not rely on the Unity editor or needs to connect to an online service database).

Writing Unit Tests

To create unit tests, the package uses NUnit -  a very popular framework that helps with the creation and execution of unit tests.

Also included is NSubstitute - a mocking framework that can create “fake” objects. These fakes are objects that are passed to the method under test instead of a “real” object, in cases where the “real” object can’t be created for testing since it relies on external resources (files, databases, remote servers, etc). For more information check out the NSubstitute site.

The following example shows a simple script that manages player health:

// A simple component that keeps track of health for game objects.
public class HealthComponent : MonoBehaviour
{
    public float healthAmount;

    public void TakeDamage(float damageAmount)
    {
        healthAmount -= damageAmount;
    }
}

Here is an example of a simple unit test for it:

using NUnit.Framework;

[TestFixture]
public class HealthComponentTests
{
    [Test]
    public void TakeDamage_PositiveAmount_HealthUpdated()
    {
        // Create a health component with initial health = 50.
        HealthComponent health = new HealthComponent();
        health.healthAmount = 50f;

        health.TakeDamage(10f);

        // assert (verify) that healthAmount was updated.
        Assert.AreEqual(40f, health.healthAmount)
    }
}

In this unit test example, we can see that:

  1. A class containing tests should be decorated with the [TestFixture] attribute.
  2. A unit test method should be decorated with the [Test] attribute.
  3. The test constructs the class it is going to test, interacts with it (calls the TakeDamage method) and asserts (verifies) the expected results afterwards using NUnit’s Assert class.

*For more information on using NUnit, see the links section at the bottom of the article (Unit Testing Succinctly shows the usage of the NUnit API).

Unit Test Runner

After adding unit tests, we can run them using the unit test runner.

The included unit test runner is opened from the toolbar menu:

Unit Test Runner

It is a basic runner that allows executing a single test, all tests in the project or all previously failed tests. There are other more advanced options, such as setting it to run automatically on code compilation. The test runner window displays all the tests in your project by organizing them under the class in which they were defined and can also display exception or log messages from their execution.

Unit Test Runner

Unit Test Runner

The runner can also be invoked from code, making it possible to run all tests from the command line.

Unity.exe -projectPath PATH_TO_YOUR_PROJECT -batchmode -quit -executeMethod UnityTest.Batch.RunUnitTests -resultFilePath=C:\temp\results.xml

*The resultFilePath parameter is optional: It is used for specifying the path for storing the generated report of running all tests.

Integration Tests

Sometimes, unit tests are just too low-level. It is often desired to test multiple components, objects and the interaction between them. The package contains an Integration testing framework that allows creating and executing tests using real game objects and components in separate “test” scenes.

Writing Integration Tests

Integration tests, unlike unit tests, are not written in code. Instead, a new scene should be added to the project. This scene will contain test objects, each of which defines a single integration test.

Step by Step

Create a new scene used for testing (it can be helpful to have a naming convention for these scenes, so it’s easier to remove them later on when building the game).

Open the Integration Test Runner (from the toolbar menu).

Integration Test Runner

A new integration test is added using the + sign. When adding a test, a Test Runner object is also automatically added to the scene.

Integration Test Runner

Integration Test Runner

Pressing + adds a new test object to the scene hierarchy. Under this test object, all game objects that are needed for the integration test are added.

For example – a Sphere object was added under the new test:

IntegrationTestHierarchy

The CallTesting script is added to this sphere:

CallTesting

CallTesting script

Execution Flow

  1. The integration test runner will clean up the scene, and for every test, will create all game objects under that test (the Sphere in this case).
  2. The integration test runs in the scene with all the real game objects that were created.
  3. In this example, the Sphere uses the CallTesting helper script. This simply calls Testing.Pass() to pass the test. An integration test can pass/fail in other ways as well (see documentation).

The nice thing is that each test is run independently from others (the runner cleans up the scene before each test). Also, real game objects with their real logic can be used, making integration test a very strong way to test your game objects in a separate, isolated scene.

The integration test runner can also be invoked from code, making it possible to run all tests from the command line:

Unity.exe -batchmode -projectPath PATH_TO_YOUR_PROJECT -executeMethod UnityTest.Batch.RunIntegrationTests -testscenes=scene1,scene2 -targetPlatform=StandaloneWindows -resultsFileDirectory=C:\temp\

*See the documentation for the different parameters needed for command line execution.

Assertion Component

The assertion component is the final piece of the puzzle. While not being strictly related to testing per se, it can be extremely useful for debugging hard to trace issues. The way it works is by configuring assertions and when they should be tested.

An assertion is an equality comparison between two given arguments and in case it fails, an error is raised (the editor can be configured to pause if ‘Error Pause’ is set in the Console window). If you’re familiar with NUnit’s Assert class (demonstrated above), the assertion component provides a similar experience, without having to writing the code for it.

Working with Assertions

After adding the assertion component to a game object you should configure what is the comparison to be performed and when should it be performed.

Assertion Component

Assertion Component

Step by Step

  1. Select a comparer type (BoolComparer in the screenshot above,  but there are more out of the box). This affects the fields that can be compared (bool type in this case).
  2. Select what to compare – the dropdown automatically gets populated with all available fields, depending on the comparer that was selected. These may come from the game object the assertion component was added to, from other added components on the game object or other static fields.
  3. Select what to compare to – under “Compare to type” you can select another game object (whose fields will be used, again, according to the type of the chosen comparer) or a constant value to compare to.
  4. Select when to perform the comparison (in the screenshot above the comparison is performed in the On Destroy method). It is possible to have multiple selections as well.

When running the game, the configured assertion is executed (in the screenshot above – on every OnDestroy method, MainCamera.Camera.hdr will be checked that it matches Cube.gameObject.isStatic).

When setting up multiple assertions, the Assertion Explorer window provides a high level view of all configured assertions (accessed from the toolbar menu):

AssertionExplorer

Assertion Explorer

The assertion component, when mixed with “Error Pause” can be used as a “smart breakpoint” – complex assertions and comparisons can be set up in different methods. When these fail the execution will break. Performing this while the debugger is attached can be an extremely efficient way to debug hard to find errors in your code.

Conclusion

Unity Test Tools provides a solid framework for writing and executing unit tests. For the first time, the tools needed for automated testing are provided in a single package. The fact that these are released and used internally by Unity shows their commitment and the importance of automated testing. In case you don’t test your code and wanted to start out – now would be an awesome time to do so.

Links

Books

  • The Art of Unit Testing / Roy Osherove (Amazon)
  • Unit Testing Succinctly / SyncFusion (Free Download)
  • xUnit Test Patterns (Amazon)

Tools/Frameworks

This is a list of a few mocking frameworks worth checking out:

  • NUnit
  • NSubstitute
  • Moq
  • FakeItEasy

Blogs/Articles

Code Generation Fun with Unity

Many Unity code samples use a string identifier, such as the game object’s tag for various things (e.g: checking for a collision with “player”). In this post i will explore a different, safer and automated technique that achieves the same result, but does not require using strings.

The String Problem

Consider the following code:


var player = GameObject.FindWithTag("Player");

The code is not type safe: it relies on a string identifier to perform an object lookup. This identifier may change, making this code “out of sync” with the project, or be misspelled, making the code fail. In addition, this string might be used in many different locations of the code, increasing the risk of previous mentioned concerns.

A Solution “Sketch”

A possible solution to this issue is to create a static helper class that will expose all tags as public (static) fields. When needed, Instead of using a string, we’d use the class’s static fields:

public static class Tags
{
    public static readonly string Player = "Player";
}

Accessing this tag is safer now, since we’re not (directly) relying on the string representation of the tag:

var player = GameObject.FindWithTag(Tags.Player);

Effectively, the code will operate the same as before, but now we have a single location where the tag is declared.

There are 2 main issues with this approach:

  1. In case there are many tags defined in the project, creating the helper class can be a somewhat tedious task (creating a field per tag).
  2. In case a tag’s name changes in the Unity editor, you have to also remember to replace it’s corresponding value in the helper class.

It seems that this solution is a step in the right direction, but we need some extra “magic” to make it perfect.

Code Generation To The Rescue

Code generation is an (sometimes) overlooked practice, where code is being automatically generated by some other code, a template or some tool.

In particular, code generation really shines in cases where we want to generate long, repetitive code from an underlying data source.

Translating this to the problem described above, we would like to generate a static helper class with many static fields from an underlying data source (a collection with all of the project’s tags).

46974122

To achieve this, we’ll use one particular implementation of a code generation engine called T4:

T4 is a template engine that comes with Visual Studio (which also heavily relies on it for various tasks), and also comes out of the box with Mono (yes, the same one that is installed with Unity).

A T4 template is a file (with a .tt extension) that mixes a body of text with special directives. The template generates a single output file (usually, a code file, although it can generate any other file format).

T4 Templates

In order to add a T4 template to your project, right click on your code project in MonoDevelop, and select: Add->New File. T4 Templates can be found under Text Templating on the left:

t4

T4 Template Types

There are 2 types of available templates (ignore Razor templates as they’re irrelevant for this discussion):

  1. T4 Template – a template file that gets transformed during compilation time into the output file. This type of template is used to generate code files that are needed at design time (e.g: think of Microsoft’s Entity Framework, where a set of classes can be generated at design time from a database, instead of being created manually by the developer).
  2. Preprocessed T4 Template – a template file that creates an “intermediate” class that can later be used to generate the output code file.

Unity currently does not support adding T4 templates (.tt files) to scripting code – after compilation, all .tt files will be dropped from the code project (I reported this bug here: T4 Bug)

This forces us to use option #2 – creating a one-time “intermediate” class. This class will be used by a Unity edior extension, from which we can generate the class we want and add it to the project.

Show Me the Code!

Here is the preprocessed T4 template that will generate the Tags class for us (although the provided sample uses the same template to generate a Layers class in exactly the same manner):

t4_example

A few things that should be noted:

  1. Any text that not contained within <# #> tags is being output as is.
  2. The template is a preprocessed template. This means it does not generate an output code file directly. Instead, it generates an intermediate (partial) class with a TransformText() method that returns the template final output (the text with the generated class).
  3. The code prints out a header (the class declaration with some comments), then it iterates all elements in source and outputs a public static readonly field for each item (does a small manipulation to make sure the field name does not have spaces in it).
  4. The variables classname, item and source are actually implemented in a code file (a partial class with the same name as the template class. Remember I said the template generates a partial class? this allows mixing the template with some custom code. For more clarity, see the full code in the link below).

In Conclusion

This post aimed to open a hatch to the wonderful world of code generation (and T4 in specific), while showing how it can solve real world problems in a short and simple way.

I did not dive into T4 syntax or more advanced topics (leaving it for you to explore, or as a subject for future posts). For more information regarding T4 – see the links below.

Links

Bug Hunting: Unity throws an ArgumentException when building for Android

What can be done when Unity mysteriously throws an ArgumentException when building a project for Android? In this post I’ll describe the techniques and tools I used to track down the root cause for this issue.

Prologue

When using a tool such as Unity, a simple click of a “Build” button often hides a long and complex process involving different modules and tools. When this process fails, it may be hard to determine the exact reason. One approach would be to try looking for what you did wrong (what did I install? did I pass the wrong parameters somewhere?).

A different approach – the one we’ll explore today,  is to dig deeper under the surface to look for the cause of error.

Reproduction

The first stop when attempting to fix an issue is to reproduce it at will. Since the original issue was reported by another user, I started by attempting to get the same exception on my machine: I launched Unity, and tried to build an empty project for Android.

Lucky for me, the stars aligned, and I got the exception on the first attempt, without doing anything special. Many times, reproducing another user’s problem won’t be that easy, and in that case these steps should be performed directly on the machine that demonstrated the error.

How did I get here? (Getting context)

As a developer, you are in control of what errors are shown to your users. This means that internal errors and exceptions may be caught internally (“swallowed”) and silenced or replaced by some other, more friendly message.

In our case, the only piece of information at hand is this message displayed in the Unity console:

ArgumentException when building

Unfortunately, this doesn’t reveal any information as to where this happened, nor what Unity attempted to do at that time.

Getting a proper context is important for understanding what went wrong.

Since this exception looks like it comes from internal Unity code written in C# (Mono), we can use the debugger and break execution when this specific exception occurs.

Breaking on a specific exception

This is a very useful debugger feature that allows breaking execution when particular exception types are thrown (similar to setting a breakpoint).

We need to configure the debugger to break on ArgumentException. This is done by launching MonoDevelop and running these steps:

  1. Attach to the running Unity process (Run –> Attach to Process)
  2. Open the Exceptions menu (Run –> Exceptions)
  3. Add System.ArgumentException to Stop in exceptions:

Configuring Stop in exceptions in MonoDevelop

After hitting OK, the debugger is properly configured, and indeed when repeating the build in Unity, the debugger breaks exactly as the ArgumentException is thrown,  and we can examine the stack trace:

Stack trace

At this point, we have the first piece of information we need – the exception is thrown after calling Path.Combine with some weird first argument (see path1).

Going in reverse

With the stack trace in hand, we must dig a bit deeper to understand how unity got that weird looking path that was used for the call to Path.Combine.

Decompiling

Using a C# decompiler (Reflector, dotPeek), we can peek at the code in the UnityEditor.Android.dll assembly (located under the Unity installation folder).

Looking at the method at the top of the stack trace, we can see the call to Path.Combine:

reflector_path_combine

Since the first argument to Path.Combine is the interesting one, we’d like to know how does SDKBuildToolsDir receive its value. This is pretty easy using the decompiler, and we can see that this is how it gets its value:

reflector_sdkbuildtoolsdir

It appears that Unity is running some external command whose output is captured and is assigned to SDKBulidToolsDir. We can now attempt to see how the code assembles the command line and invokes the tool, but there’s a better and easier option.

Sniffing for processes

Process Monitor (procmon) is a nifty little tool that acts as a “sniffer” for various real-time machine wide activities (process information, networking, registry access, file access). It is particularly useful for figuring out what processes were invoked (by Unity), and what were their arguments.

Running procmon and then starting a new build gives us a nice capture of the data we need. After the build fails we can stop procmon from capturing (CTRL-E) to keep the captured trace clean and focused on the issue at hand. The trace will probably contain information from many running processes, but we can filter it to show events originating from Unity.exe. This is done by right-clicking a trace line from Unity.exe and selecting “Include Unity.exe”):

Filter by process in Procmon

We should further filter the results for showing only process/thread activities (from the toolbar), as seen in this image:

Viewing only process/thread activity

This gets us only Unity.exe  traces of process and thread events. From this point it’s pretty straightforward to find that Unity creates a new Java process with the following details (paths may vary on your machine):

“C:\Program Files\Java\jdk1.7.0_17\bin\java.exe” -Xmx1024M -Dcom.android.sdkmanager.toolsdir=“D:/Android/sdk\tools” -Dfile.encoding=UTF8 -jar “D:/Unity/Editor/Data/BuildTargetTools/AndroidPlayer\sdktools.jar” -

Running this exact command from a command prompt generates this output:

picked_up

Eureka!

Putting it all together, from all we’ve learned it looks like Unity is using a custom Java based tool, captures its output in a variable and uses that information as part of the build process. In cases where _JAVA_OPTIONS environment variable is defined, Java will print out the options used to the console (this will happen also when invoking java with no arguments), however Unity’s build process does not deal with this scenario very well.

The issue was reported and acknowledged by Unity in this Bug Report

Takeaways

  1. Reproduce the issue before attempting to fix it
  2. Determine a context for the failure (e.g: stack trace)
  3. Reverse engineering can be your friend

Tools Used

Setting up Continuous Integration with Unity

A recent question about Continuous Integration and Unity led me to try and get something up and running.

The motivation was to see how hard it is to setup a basic CI system for auto building Unity projects and later on be used for running automated testing as well.

Here are my observations.

Disclaimer: although I consider myself to be a Unity noob, I am well experienced with CI, build servers, unit tests and other fancy software engineering practices.

Continuous Integration

The term “Continuous Integration” as I see it is actually an umbrella term for a few things:

  1. Code Integration – Building your code quickly that is triggered on every check in to the source control system.
  2. Automated Builds – Your code gets built automatically (and repeatedly) in a single automated step.
  3. Automated Testing – Automated tests (whether unit tests or other types) that validate various pieces of functionality of your code.

Although many CI products are available today (free and commercial), i will focus on TeamCity out of 2 reasons:

  1. It is absolutely FREE (with some limitations).
  2. There is an open source project that offers building Unity projects from it directly.

Let’s get started!

Ingredients

In order to get started you will need to get the following:

  1. TeamCity 7.0.1
  2. Unity3d Build Runner

Setup

Installing TeamCity

Installation of TeamCity is pretty straightforward, just “Next, Next” your way through it.

TeamCity uses a concept of “Build Agents”, which are basically a piece of software that does the actual building of the game.

The free version of TeamCity supports up to 3 build agents. For the sake of this example we are installing the server + agent on the same machine.

Note that for larger setups, Unity must be installed on each machine that  the agent will be installed on.

Installing Unity Build Runner

Unity build runner is an open source project of a TeamCity custom build runner.
Special thanks goes to Mind Candy for creating it and sharing it as an open source project).
It wraps Unity’s command line interface into an easy to operate menu. It is also responsible for reporting errors and sending logs back to TeamCity.
The build runner must be compiled from its sources, as it is only available as source code.
Luckily i have already done that, and the compiled output (.zip file) can be found here: unityRunner.zip
In case you would like to build the runner yourself (loads of fun!), you’ll need IntelliJ (free):

Configuring a new project

Here are the basic steps for configuring a new TeamCity project and 2 build configurations, that will build the “AngryBots” demo that comes with unity in 2 flavors (Web and Windows).

  1. Create a new project in TeamCity: Administration menu -> Create Project
  2. Add build configurations per platform you’d like to build (One for Windows and another for Web Player)
  3. Per configuration, add a build step with “Unity build runner”

    Example of a windows build

    Example configuration of a Web player build

That’s all there is to it! We have a basic CI system running that can automatically build Unity games in different flavors.

Optionally, A build trigger can be set per each configuration to start a build upon a source control check in. For the sake of our example the build will be started on demand from the TeamCity UI.

Caveats

Here’s a list of issues I’ve come across:

  1. In case of certain errors during the build, Unity build runner will fail to report these to the build log. I have already contacted the owner of this project, although i may attempt to fix it myself.
  2. When building a Windows version of the game, the path given to the build runner should be the .exe file’s full path. When building a web player project, the path should be a folder name.
  3. There are no mobile platforms (iOS/Android) available in the build runner dropdown. These are also not documented in Unity’s command line reference page (not sure if they are available).
  4. Unity enforces a single running instance per project. The command line mode runs the same executable, and so it will fail to work when an instance of the engine is running and has the project being built open.
  5. Unity doesn’t have a separate compiler/builder platform. The engine’s executable needs to be loaded to build the game, which can be CPU and memory intensive.
In the next post i will attempt to start exploring options of building upon this setup to add some basic automated testing of our built project, and show how it all integrates with TeamCity.

Additional Resources

Insights from Global Gam Jam 2012

This year was my first time at Global Game Jam.

The idea of this event is simple – imagine a traditional game project with developers, designers and artists. Now press the “Fast Forward” button a bunch of times till you hit warp drive.

During the course of the weekend we had roughly 48 hours to come up with an idea for a game, and to actually develop it.

The result was Magic Ring – a (partly) working 2D game.

image

Here are some of my insights from the event.

These should assist fellow Global Game Jam noobs like me or any other aspiring developer that attends the event:

What Went Right:

  1. Finished a simple game – There’s nothing more rewarding than working for 2 days with little sleep and getting something done!
  2. Met new people – in such an environment, it is very hard not to hook up with new people and collaborate.
  3. Game Ideas – while we worked on a single game, other game concepts were born, which may actually turn into real projects.
  4. Experienced a real “Jam” – This is a must for anyone who wants to do game development! great atmosphere + great people.

What Went Wrong:

  1. Precious time wasted on getting tools/syncing between team members – internet connection speed is poor. All tools/engines/whatever needed should be brought on a storage device.
  2. We had no detailed “Game plan” – A 48 hour project should be simple enough to breakdown into all fine details upfront. This could’ve helped us spot potential issues that we ran into when it was getting too late.
  3. We did not stay focused enough – We had many ideas for extending and improving the game. Looking back, the most important thing is to create the basic functionality first before moving on to improving/adding new features and complexity.

Overall, it was a great event.

Looking forward for next year!