Boas práticas para uso de logs na Unity

Neste post quero compartilhar algumas dicas e boas práticas para uso do Debug.Log() na Unity. Pode parecer intuitivo utilizar a API da Unity para registrar todo tipo de ação que o jogador fizer, mas existem algumas maneiras de fazer isso que podem tornar o processo de debug e teste mais fácil, além de registrar logs apenas do que realmente é necessário.

Em um jogo publicado não faz sentido ter chamadas para o Debug.Log(), pois que utilidade existe em registar uma mensagem do tipo "Item found!" se isso não é relevante para o jogador e você não poderá ver esta mensagem no aparelho dele? O uso do Debug.Log() pode ser muito útil enquanto está desenvolvendo e testando um jogo. Mas, mesmo assim, as mensagens precisam ser úteis e ter um contexto que ajude a entender o que está acontecendo.

Mensagens relevantes

Vamos analisar a seguinte sequencia de mensagens:

Button pressed!
Button pressed!
Player killed monster
Monster drops: 2

Apesar de ser possível entender o que aconteceu, estas mensagens são bem pobres em informações. Nas mensagens acima não é possível saber qual botão foi pressionado, qual monstro foi derrotado, e qual item o monstro largou. Perceba que nem é possível ver se o jogador pegou o item a partir destes logs, e se algum erro acontecer será bem difícil de reproduzir e corrigir. Por isso, é importante registrar mensagens relevantes e com contexto suficiente para entender o que aconteceu. Vamos analisar agora a mesma sequencia, porém com mais detalhes:

State changed: EXPLORING -> START_BATTLE
Player attacked monster blue and caused 10 damage (critical). Monster blue has 5HP
Player attacked monster blue and caused 7 damage. Monster blue has 0HP
Monster blue was defeated. Drops: {"potion": "potion_red","gold": 10}. Experience: +2XP
State changed: START_BATTLE -> END_BATTLE
Player picked up items: {"potion": "potion_red","gold": 10}
Player received 2XP. Now has 32/50
State changed: END_BATTLE -> EXPLORING

Ao invés de registrar um botão foi pressionado, é registrada a ação desencadeada pelo botão, o ataque e qual a consequência da ação, que foi causar dano no monstro blue. Na mesma linha do log é possível ver quanto dano foi causado, se foi um ataque crítico e quanta vida resta para o monstro. Após ser derrotado, é possível ver quais itens o monstro derrubou e quanta experiência deu ao jogador.

Podemos ver também que o jogador pegou os itens, recebeu a experiência, quanta experiência tem no momento (32), e quanto precisará para o próximo nível (50). Um detalhe a mais são os registros de mudança de estado: a batalha inicia e tem um fim. Assim, fica fácil ver que todas aquelas ações aconteceram em uma batalha, o que torna mais simples de entender e reproduzir um determinado comportamento para corrigir um erro ou até ajustar o balanceamento do jogo.

Mensagens seletivas

Apesar das mensagens acima terem contexto e serem relevantes, ainda assim, podem criar uma quantidade desnecessária de logs em uma sessão de jogo. Em alguns momentos vamos querer ver os logs da batalha em detalhes, porém em outros, vamos querer ver apenas os logs de mudança de estados. E em outros nenhum log, apenas erros (quando acontecerem).

Uma das maneiras de escolher quais logs devem ser exibidos no jogo é utilizar Scripting Define Symbols no código e habilitá-los no Player Settings da Unity para a plataforma desejada. Assim, é possível habilitar determinados logs para determinadas situações. Uma solução bem prática é criar uma classe estática responsável por chamar a API de logs da Unity, e fazer o jogo utilizá-la ao invés de chamar Debug.Log() diretamente.

public static class Logger
{
    [System.Diagnostics.Conditional("ENABLE_LOG_BATTLE")]
    public static void LogBattle(string message)
    {
        UnityEngine.Debug.Log(message);
    }

    [System.Diagnostics.Conditional("ENABLE_LOG_STATE")]
    public static void LogChangeState(string message)
    {
        UnityEngine.Debug.Log(message);
    }

    public static void LogWarn(string message)
    {
        UnityEngine.Debug.LogWarning(message);
    }

    public static void LogError(string message)
    {
        UnityEngine.Debug.LogError(message);
    }
}

Os métodos LogBattle() e LogChangeState() possuem o atributo Conditional com os define symbols "ENABLE_LOG_BATTLE" e "ENABLE_LOG_STATE", respectivamente. Desta maneira, é possível chamar ambos os métodos a qualquer momento no jogo, mas eles só serão executados se os respectivos define symbols estiverem habilitados no Player Settings, conforme imagem abaixo. Adicionei também métodos para Warnings e Errors, assim todos os logs podem ser concentrados nesta classe. Outra vantagem de centralizar tudo em uma classe é poder customizar as mensagens adicionando qualquer tipo de informação ou formatação.

Vale lembrar que os define symbols são por plataforma, ou seja, é necessário defini-los para cada plataforma que será utilizada. Uma maneira bem prática de adicionar e remover os define symbols é criando um script que faça isso. Este script pode ser usado a partir de um menu, ou até em um sistema de build. Isso é muito útil para gerar builds em um CI como o Jenkins, por exemplo, parametrizando a build para ter ou não determinados logs.

Utilizar uma classe como a Logger causa um efeito colateral e pode ser visto no Editor: ao clicar duas vezes em uma mensagem de log será aberto o script do Logger ao invés do script que executou o método, como acontece quando usamos diretamente o Debug.Log(). Isto pode ser corrigido modificando o código e adicionando um delegate.

public static class Logger
{
  public static class Logger
  {
      public delegate void LogHandler(string message);

  #if ENABLE_LOG_BATTLE
      public static LogHandler LogBattle = UnityEngine.Debug.Log;
  #else
      public static LogHandler LogBattle = (message) => { };
  #endif

  #if ENABLE_LOG_STATE
      public static LogHandler LogChangeState = UnityEngine.Debug.Log;
  #else
      public static LogHandler LogChangeState = (message) => { };
  #endif

      public static LogHandler LogWarn = UnityEngine.Debug.LogWarning;
      public static LogHandler LogError = UnityEngine.Debug.LogError;
  }
}

O código fica um pouco mais complexo, porém agora ao clicar duas vezes em uma mensagem de log no Editor o script que executou o Logger será aberto. Infelizmente, não é possível utilizar o atributo Conditional, pois estamos usando uma propriedade ao invés de um método, por isso é necessário utilizar o #if ... #else ... #endif. Quando o define symbol não estiver no Player Settings, nada acontece.

Existem outras coisas que podemos fazer para melhorar os logs em um jogo, desde cores e formatação até um sistema mais robusto para ligar e desligar mensagens em determinado tipo de build. Meu objetivo neste post foi mostrar algumas coisas que considero boas práticas e muito úteis para um projeto. Logs são muito importantes para um jogo, e devem ser tratados como tal. Gaste um minuto a mais para escrever uma mensagem útil, com informações que vão realmente te ajudar a entender o que está acontecendo.

Minha sugestão de centralizar os logs em uma classe e combinar com define symbols ajudam, porém muitas mensagens podem poluir e esconder informações úteis e até causar problemas de performance no jogo sem perceber. Seja bem crítico para não deixar seu projeto se tornar um mar de mensagens inúteis e planeje um tempo para revisar as mensagens de tempos em tempos.