CoreLib Tracing Design Reference

Keyworks: Tracing Trace Listener Diagnostics Logging Log Debug

Conceitos

Trace

O Trace regista o que acontece numa aplicação tratando-se de uma ferramenta de diagnóstico que não está tipicamente ativa em sistemas em produção. O Trace é ativado quando existe a necessidade de perceber as condições que levam a determinado erro ou a razão pela qual uma dada operação demora determinado tempo.

Pressupostos

  • Não há necessidade de distinguir entre logging e tracing. Por essa razão o CoreLib apenas disponibiliza a API de tracing.
  • Tipicamente uma distinção deste tipo leva à construção de uma API mais complexa do que é necessário e, mais importante ainda, a uma confusão nos programadores quanto aos cenários em que deve ser utilizada uma ou outra e, no limite, a nenhuma das duas ser devidamente utilizada.
  • Apenas devem ser disponibilizados na API os métodos estritamente necessários para que a sua utilização seja simples e o mais uniforme possível entre todos os programadores.
  • O comportamento da API deve ser simples e a sua configuração mínima e completamente opcional.

Desenho

A API é disponibilizada pela classe Primavera.Core.Diagnostics.Tracing. Trata-se de uma classe estática que disponibiliza um conjunto de métodos para registar “eventos” de acordo com o nível de tracing. Estão ainda disponíveis outras classes que fornecem funcionalidades adicionais sobre essa API:

  • TracingCategory – permite registar um conjunto de eventos relacionados por uma categoria.
  • TracingTimer – permite medir o tempo de execução de um bloco de código, tipicamente um método.
  • TracingCondition – permite registar eventos de tracing dependendo de uma condição.
  • TracingEnumerator – permite registar eventos de tracing para a coleção de objetos (IEnumerable[T]).

Tracing

Este componente regista os eventos de acordo com um nível de tracing definido na invocação (de acordo com o método da API utilizado) e que, por configuração, pode ser ativado. Os níveis disponíveis são os seguintes:

  • Fatal – assinalam erros que causem que a aplicação deixe de funcionar completamente.
  • Error – assinalam erros relevantes ocorridos na aplicação.
  • Warning – assinalam erros menos importantes ou condições que podem causar comportamento inesperado na aplicação.
  • Information – assinalam passos normais da execução da aplicação que podem ser importantes para diagnosticar o seu comportamento.
  • Verbose – fornecem informação detalhada sobre a execução da aplicação, para ser usada em cenários mais complexos de diagnóstico.

O registo dos eventos é assíncrono por defeito, embora o programador tenha a possibilidade de o tornar síncrono por configuração, e é concretizado por um ou mais “tracing listeners” registados. Na prática o componente de tracing apenas mantém o registo dos listeners ativos, dos níveis de tracing que estão ativos e trata do envio assíncrono dos eventos para esses listeners. É responsabilidade dos tracing listeners efetuar o registo dos eventos no suporte adequado.

CoreLib Tracing

API

A API disponível é a seguinte:

  • Fatal(string)
  • Fatal(string, params object[])
  • Fatal(Exception, string)
  • Fatal(Exception, string, params object[])
  • Error(string)
  • Error(string, params object[])
  • Error(Exception, string)
  • Error(Exception, string, params object[])
  • Warning(string)
  • Warning(string, params object[])
  • Warning(Exception, string)
  • Warning(Exception, string, params object[])
  • Information(string)
  • Information(string, params object[])
  • Information(Exception, string)
  • Information(Exception, string, params object[])
  • Verbose(string)
  • Verbose(string, params object[])
  • Verbose(Exception, string)
  • Verbose(Exception, string, params object[])

Estes mesmos métodos estão disponíveis a partir da API que permite agrupar eventos numa categoria:

Tracing.Category(string).(…)

E na API condicional:

Tracing.Condition(Func<bool>).(…)

E ainda na API que permite registar um evento para cada elemento de uma coleção de objetos:

Tracing.ForEach<T>(IEnumerable<T>).(…)

Tracing Listeners

Um tracing listener deve implementar o interface Primavera.Core.Diagnostics.ITracingListener. A sua responsabilidade é a de registar um evento de tracing num suporte específico.

Estão disponíveis na CoreLib os seguintes listeners standard:

  • ConsoleTracingListener – regista os eventos na consola.
  • DebugTracingListener – regista os eventos através da API System.Diagnostics.Debug.
  • EventLogTracingListener – regista os eventos no Windows Event Log.
  • FileTracingListener – regista os eventos num ficheiro no disco (sem arquivamento).
  • LimitedFileTracingListener – regista os eventos num ficheiro no disco (reciclado quando atinge 100 MB).
  • MemoryTracingListener – regista os eventos em memória (o trace completo está disponível através da propriedade Output).
  • RollingFileTracingListener – regista os eventos num ficheiro no disco (arquivado quando atinge 100 MB).
  • TraceTracingListener – regista os eventos através da API System.Diagnostics.Trace.
  • TracingViewerTracingListener - regista os eventos para a ferramenta Tracing Viewer (do SDK).
  • TelemetryTracingListener - regista os eventos usando a API Primavera.Core.Telemetry.TelemetryWriter.

Por defeito nenhum tracing listenar estará ativo.

RollingFileTracingListener

Este listener permite registar os eventos num ficheiro que será reciclado sempre que atingir 100 MB.

A localização por defeito desse ficheiro é %temp%\ELEVATION\ELEVATION.trace mas pode ser alterada por configuração.

A reciclagem do ficheiro corresponde a criar uma cópia do ficheiro anterior na mesma pasta com o mesmo nome e com um sufixo com a data atual e reiniciar o ficheiro principal.

Ver também FileTracingListener e LimitedFileTracingListener.

TelemetryTracingListener

Este listener permite registar os eventos através da API Primavera.Core.Telemetry.TelemetryWriter. Na implementação atual essa API regista os eventos no Azure Application Insights.

Ver Telemetria/Insights.

TracingViewer

O Tracing Viewer é uma ferramenta do SDK que permite ativar o tracing para esta ferramenta e capturar os eventos em runtime.

Ver Ferramentas do SDK.

Configuração

A configuração é implementada pela classe Primavera.Core.Diagnostics.TracingConfiguration.

Pode ser efetuada programaticamente através da propriedade estática Tracing.Configuration ou no ficheiro de configuração. Estão disponíveis as seguintes definições:

  • Level (Off, Fatal, Error, Warning, Information, Verbose) – define o nível de trace mínimo ativo. Ou seja, se, por exemplo, o valor for Warning serão registadas todas as mensagens com os níveis Fatal, Error ou Warning e ignoradas todas as outras.
  • Asynchronous (true|false) – permite configurar se os eventos são registados síncrona ou assincronamente. O valor por defeito é true.
  • Conditions - contém a coleção de condições adicionais para definir o nível de trace ativo para uma determinada categoria e/ou subscrição e/ou utilizador.
  • Listeners – contém a coleção de tracing listeners ativos, que receberão todas as mensagens de trace não ignoradas (de acordo com o nível de tracing ativo).

Exemplos

Configuração em código:

private static void TestInitConcurrent(Type listenerType)
{
    Tracing.Configuration.Reset(false);
    Tracing.Configuration.Level = TracingLevelActive.Information;
    Tracing.Configuration.Asynchronous = true;
    Tracing.Configuration.AddListener(listenerType);
}

No ficheiro de configuração:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="tracingConfiguration" type="Primavera.Core.Configuration.TracingConfigurationSection, Primavera.CoreLib, Version=3.0.0.0, Culture=neutral, PublicKeyToken=33086db60a481256" />
  </configSections>
  <tracingConfiguration>
    <elements>
        <add name=”default” level="Verbose">
            <listeners>
              <add type="Primavera.CoreLib.Tests.Mocks.MockTracingListener, Primavera.CoreLib.Tests, Version=3.0.0.0, Culture=neutral, PublicKeyToken=33086db60a481256" />
            </listeners>
        </add>
    </elements>
  </tracingConfiguration>
</configuration>

Condições

A configuração, como já foi referido, permite definir um nível de trace ativo para a aplicação mas permite também configurar um nível diferente consoante a categoria, a subscrição ou o utilizador associado à mensagem de trace.

A configuração dessas condições é definida na lista Conditions como no exemplo seguinte:

<tracingConfiguration>
    <elements>
        <add name="default" level="Error">
            <conditions>
                <add category="Category1" level="Information" />
                <add category="Category2" level="Fatal" />
                <add subscriptionId="1000/1000" level="Information" />
                <add subscriptionId="2000/2000" level="Fatal" />
                <add userName="joe" level="Information" />
                <add userName="mary" level="Fatal" />
                <add category="MyCategory" subscriptionId="3333/3333" userName="rui" level="Fatal" />
                <add category="MyCategory" userName="pedro" level="Warning" />
                <add category="MyCategory" subscriptionId="3333/3333" level="Information" />
                <add category="MyCategory" level="Verbose" />
            </conditions>
            <listeners>
                <add type="Primavera.CoreLib.Tracing.Tests.MockTracingListener, Primavera.CoreLib.Tracing.Tests, Version=3.0.0.0, Culture=neutral, PublicKeyToken=33086db60a481256" />
            </listeners>
        </add>
    </elements>
</tracingConfiguration>

Considerando este exemplo, teríamos então o seguinte nível de tracing ativo consoante o contexto do evento de tracing:

  • Categoria = MyCategory, Subscrição = 3333/3333, Utilizador = Rui => Fatal
  • Categoria = MyCategory, Subscrição = 3333/3333, todos os outros utilizadores => Information
  • Categoria = MyCategory, todas as outras subscrições, Utilizador = Pedro => Warning
  • Categoria = MyCategory, todas as outras subscrições e todos os outros utilizadores => Fatal

Os seguintes aspetos do motor de avaliação destas condições são importantes:

  • A condição pode definir 1, 2 ou os três valores a que se aplica (categoria, subscrição, utilizador).
  • Aplica-se sempre a primeira condição que se aplique ao pedido de tracing em causa (quando se aplicar mais que uma).

Notas

  • A secção de configuração permite a definição de várias configurações alternativas e a sua seleção com base num override nos app settings (ver CoreLib Configuration.
  • A definição “Asynchronous” (ou “Async” no ficheiro de configuração) é opcional e o seu valor por defeito é true.
  • Os tracing listeners podem requerer configuração também. Nesse caso o valor da configuração pode ser definido pela propriedade Configuration do listener ou pela propriedade settings na coleção de listeners do ficheiro de configuração.
  • Os listeners para ficheiro (FileTracingListener, LimitedTracingListener e RollingFileTracingListener) aceitam na sua configuração o nome completo do ficheiro onde devem ser registados os eventos. Se não for definido dessa forma, será usada a localização por defeito para o ficheiro de tracing.
  • A configuração pode ser reinicializada através do método Tracing.Configuration.Reset. Esse método aceita um parâmetro para indicar se o ficheiro de configuração deve ser lido ou não.
  • A coleção de listeners pode ser reinicializada através do método Tracing.Configuration.ClearListeners.

Tracing Categories

Em determinados cenários será necessário relacionar eventos de tracing. Por exemplo, quando se pretender que os eventos de um determinado componente seja facilmente identificados no output do trace.

A classe Primavera.Core.Diagnostics.TracingCategory permite esse comportamento relacionando todos os eventos despoletados pela mesma instância da classe (a categoria).

A forma mais simples do utilizar essa classe é a seguinte:

public class MyClass
{
    (...)

    public void MyMethod()
    {
        (...)
        Tracing.Category(nameof(MyClass)).Verbose("...");
        (...)
    }
}

A categoria é anexada à mensagem de tracing e estará presente no registo de duas formas:

  • Como um prefixo da mensagem de tracing registada.
  • Nas propriedades da mensagem. Dependendo do listener ativo esta propriedade poderá ter um tratamento especial.

No caso do TelemetryTracingListener a categoria é registada nas "custom dimensions" do registo no Application Insights.

TracingTimer

A classe Primavera.Core.Diagnostics.TracingTimer utiliza a funcionalidade de tracing para medir o tempo de execução de um determinado bloco de código.

A sua utilização é muito prática:

public void MyMethod()
{
    using (new TracingTimer(TracingLevel.Verbose))
    {
        (...)
    }
}

E resulta nas seguintes entradas no output do tracing:

ELEVATION Tracing: Verbose: MyClass.MyMethod started.
ELEVATION Tracing: Verbose: MyClass.MyMethod ended. 100 ms.

Questões em Aberto

  • Não foram testados todos os cenários potenciais de concorrência sobre o ASP.NET e o Azure por não ser possível replicá-los no ambiente de desenvolvimento.
  • Seria interessante conseguir que o output de System.Diagnostics.Trace fosse apresentado num pane autónomo da output windo para ser mais fácil de distinguir os eventos despoletados por este componente de outros. Até ao momento não foi encontrada uma forma viável de o conseguir.

FAQ

  • P: Há uma mensagem que eu sei que está a ser registada mas não aparece no output do trace. Porquê?
    • R: O nível de trace ativo por defeito é Error se não existir ficheiro de configuração ou não tiver sido ativado outro através de Tracing.Configuration. Por outro lado, o nível ativo é incremental. Ou seja, se estiver ativo o nível Error serão apresentadas apenas as mensagens desse nível ou superior (Error ou Fatal). Portanto é necessário ver se o nível de tracing ativo inclui o nível com que a mensagem está a ser registada.
  • P: Os eventos são enviados para todos os listeners?
    • R: Sim. Para todos os que estiverem ativos no momento.
  • P: É possível que eventos de níveis diferentes sejam enviados para listeners diferentes?
    • R: Não. Todos os listeners recebem todos os eventos de acordo com o nível de tracing ativo.
  • P: Onde fica guardado por defeito o output do RollingFileTracingListener? Posso mudar a localização desse ficheiro?
    • R: Em %user%\temp\ELEVATION\ELEVATION.trace. Para alterar o caminho deve adicionar-se a propriedade setting no ficheiro de configuração com o caminho completo pretendido (ver Referências) (podem ser utilizadas variáveis de ambiente no nome do ficheiro).
  • P: Como posso tornar o tracing síncrono?
    • R: Definir a propriedade async no ficheiro de configuração com o valor false ou, programaticamente, desativando a propriedade Tracing.Configuration.Asynchronous.
  • P: Como posso criar um tracing listener?
    • R: Basta criar uma classe que implemente Primavera.Core.Diagnostics.ITracingListener e registá-la na lista de tracing listeners ativos.
  • P: É possível desligar o tracing completamente?
    • R: Sim. Tracing.Configuration.Level = TracingLevelActive.Off (ou no ficheiro de configuração).

Referências

<add type="Primavera.CoreLib.Diagnostics.TracingListeners.RollingFileTracingListener, Primavera.CoreLib, Version=3.0.0.0, Culture=neutral, PublicKeyToken=33086db60a481256" settings="~\App_Data\Output.trace" />