Enterprise Library Logging Application Block - część I 

Udostępnij na: Facebook

Autor: Piotr Zieliński

Opublikowano: 2013-07-02

Wprowadzenie

Microsoft Enterprise Library dostarcza wiele komponentów przydatnych w pisaniu zaawansowanych aplikacji. Poszczególne komponenty (nazywane blokami) napisane są w sposób elastyczny i rozszerzalny, co umożliwia dostosowanie ich do każdego typu aplikacji. Programiści mają do dyspozycji m.in. bloki, odpowiedzialne za obsługę błędów, walidację danych, wykonywanie logów, IoC czy wstrzykiwanie kodu (policy injection, przydatne w implementacji AoP).

Tematyka związana z Enterprise Library obejmuje swym zakresem wiele zagadnień, które omówione zostaną w kolejnych odcinkach cyklu.

Dlaczego wykonujemy logi?

Każda współczesna aplikacja wykonuje logi – przeważnie do pliku tekstowego. Zastanówmy się, co jest tego główną przyczyną i jakie informacje powinny znaleźć się w takim dzienniku. Przede wszystkim warto rozróżnić dwie rzeczy: obsługę błędów i logi. Logowanie nie służy wyłącznie do zapisywania informacji o nieobsłużonych wyjątkach – te informacje stanowią wyłącznie małą składową instrumentacji każdej aplikacji. Logi to przede wszystkim konfigurowalny opis procesów, jakie zachodzą w aplikacji. Za ich pomocą można prześledzić sposób działania aplikacji oraz funkcje, które zostały wykorzystane przez użytkownika. Takie informacje nasuwają kolejne zastosowanie logów, a mianowicie audyt. W przypadku włamania do systemu (lub próby) dobrze wykonywane logi powinny ułatwić dalszą analizę luki w zabezpieczeniach. W przypadku, gdy np. jeden z użytkowników wielokrotnie próbował się zalogować bez sukcesu, powinno to być znakiem ostrzegawczym dla administratora – te informacje będzie właśnie czerpał z tzw. audit log.

Kolejną przyczyną, dla której warto posiadać logi jest wydajność. W trakcie wykonywania operacji można w końcu zapisać informacje dotyczące przepustowości, liczby obsłużonych zapytań czy czasu potrzebnego na wykonywanie poszczególnych, krytycznych operacji.

System logów dostarczonych przez EntLib jest bardzo elastyczny i wspiera wiele różnych dzienników (EventLog, plik tekstowy itp.). Ponadto, logi można kategoryzować, filtrować lub dodawać do nich informacje zależne od kontekstu (np. stacktrace). Oczywiście zbyt szczegółowe informacje oraz zbyt duża ich ilość może znacząco spowolnić aplikację, dlatego EntLib wspiera dynamiczną konfigurację. W pliku konfiguracyjnym można określić, jakiego typu logi mają zostać wykonane.

Logging Application Block – zasada działania

Przed napisaniem jakiegokolwiek kodu warto poświęcić kilka chwil na zrozumienie, jak działa mechanizm logowania w EntLib. Najważniejszą klasą, punktem wejściowym jest LogWriter. Za pomocą tej klasy, można zapisywać wiadomości do dziennika. Wiadomość „wysłana” przez LogWriter przechodzi najpierw przez filtry (priorytet, kategoria), a następnie wybierana jest tzw. „trace source”, czyli źródło logu. Wybór dokonywany jest na podstawie kategorii i wcześniej zdefiniowanego mapowania. Następnie, dysponując źródłem logu, można wybrać „trace listeners”, czyli obiekty odpowiedzialne za zapisywanie danych do konkretnej lokalizacji – czynności tej nie wykonują bezpośrednio, ale na razie taki skrót myślowy powinien wystarczyć.

Podstawowa konfiguracja LogWriter

Najpierw należy zainstalować odpowiednie biblioteki – najprościej skorzystać z narzędzia NuGet:

Konfigurację LogWriter można przeprowadzić na dwa sposoby: przez plik konfiguracyjny albo za pomocą czystego C#. Konstruktor LogWriter przyjmuje obiekt klasy LoggingConfiguration jako jeden z parametrów:

var loggingConfiguration=new LoggingConfiguration();
…
var logWriter=new LogWriter(loggingConfiguration);

Oczywiście należy najpierw wypełnić prawidłowo obiekt LoggingConfiguration, w zależności od tego, w jaki sposób i gdzie chcemy przechowywać logi.

Jak już zostało wspomniane, zapisanie logu zależy od tzw. „trace source” oraz „trace listener”. Należy je zdefiniować w konfiguracji, np.:

var loggingConfiguration=new LoggingConfiguration();
            
var flatFileListener = new FlatFileTraceListener(@"c:\temp\1.txt");
loggingConfiguration.AddLogSource("Important", SourceLevels.All, true).AddTraceListener(flatFileListener);            
var logWriter=new LogWriter(loggingConfiguration);

Powyższy kod definiuje źródło logu (trace source) o nazwie „Important”, który z kolei kojarzony jest z obiektem FlatFileTraceListener. FlatFileTraceListener po prostu zapisze logi w zwykłym pliku tekstowym. Każde źródło może zawierać kilka listenerów. Istnieje wiele klas reprezentujących różne typy logów, m.in.: XML, EventLog, e-mail, baza danych, pliki tekstowe z ustawionym limitem rozmiaru, Msmq. Ponadto, istnieje możliwość napisania własnej implementacji.

Przy definiowaniu źródła można określić filtr za pomocą poziomów. Powyższy przykład dopuści wszystkie wiadomości (SourceLevels.All). Jeśli zachodzi potrzeba bardziej szczegółowej filtracji, można przekazać jedną z następujących wartości SourceLevels: ActivityTracing, All, Critical, Error, Information, Off, Verbose, Warning.

Trzeci parametr metody AddLogSource to autoflush. Domyślnie ustawiony jest na true, co powoduje, że przy każdym zapisie logu (metoda Write) zawartość bufora zapisywana jest automatycznie we wskazanych lokalizacjach (np. w pliku tekstowym) – w przeciwnym przypadku trzeba samodzielnie wywołać Flush.

Drugim sposobem jest użycie pliku konfiguracyjnego. W celu ułatwienia procesu warto skorzystać z gotowych narzędzi, które wygenerują plik za nas. Ze strony EntLib (CodePlex) można ściągnąć pakiet instalacyjny, który zawiera m.in. program EntLibConfig.exe:

Następnie, w celu wygenerowania pliku należy:

  1. Z menu głównego wybrać Blocks->Add Logging Settings.

  2. W oknie pojawią się nowe elementy, m.in. Logging target Listeners, Categories oraz Log Message Formatters. Następnie, trzeba dodać drugą kategorię – „Important”:
    Po zakończeniu powinny istnieć dwie kategorie: „General” oraz „Important”.

  3. Kolejnym etapem jest dodanie nowych listenerów. Jak widać na powyższym screenie, domyślny jest tylko Event Log Listener. W celu dodania FlatFileTraceListener wystarczy kliknąć na przycisku w kształcie plusa. Następnie można skonfigurować obiekt, np. ustawić prawidłową lokalizację pliku:

  4. Później można przejść znów do kategorii i z lity Listeners wybrać właśnie dodany obiekt:

Po zapisaniu zmian zaktualizowany zostanie plik konfiguracyjny (np. App.Config) – teraz w kodzie nie trzeba już samodzielnie tworzyć obiektu LoggingConfiguration. W celu inicjalizacji LogWriter należy skorzystać z fabryki LogWriterFactory:

var logWriterFactory = new LogWriterFactory();
var logWriter = logWriterFactory.Create();

if (logWriter.IsLoggingEnabled())
{
    logWriter.Write("Test", "Important");
}

Plik konfiguracyjny załadowany zostanie automatycznie, a następnie utworzony prawidłowy LogWriter.

Zapis logu

Powyższa konfiguracja umożliwi wykonanie pierwszego logu do pliku tekstowego. LogWriter posiada kilka przeładowanych metod Write. Przykład:

class Program
{
    private static void Main(string[] args)
    {
        var logWriter = new LogWriter(BuildConfiguration());

         if (logWriter.IsLoggingEnabled())
        {
              logWriter.Write("Test 1");
              logWriter.Write("Test 2 z kategorią.", "Important");
              logWriter.Write("Test 3 z kategorią, priorytetem oraz event id.", "Important", 1, 5);

              logWriter.Write("Test 4 z kategorią, priorytetem, event id, severity.", "Important", 2, 6,
             TraceEventType.Error);

             logWriter.Write("Test 5 z kategorią, priorytetem, event id, severity oraz tytułem.",             
            "Important", 3,7, TraceEventType.Error, "Tytuł logu");
        }
    }
    private static LoggingConfiguration BuildConfiguration()
    {
        var loggingConfiguration = new LoggingConfiguration();
        var flatFileListener = new FlatFileTraceListener(@"c:\temp\1.txt");
        loggingConfiguration.AddLogSource("Important", SourceLevels.All, true).
        AddTraceListener(flatFileListener);
        return loggingConfiguration;
    }
}

Przede wszystkim należy sprawdzić, czy logi są włączone. Nie ma sensu wywoływać metod Write, jeżeli wiadomo, że nie przyniosą one żadnego skutku. Następnie można skorzystać z różnych przeładowań Write. W zależności od potrzeb, możliwe jest przekazywanie priorytetu, kategorii, nazwy lub srogości wpisu. Zaglądając do wygenerowanego pliku można przekonać się, w jaki sposób formatter, skojarzony z FlatFileTraceListener, generuje zawartość:

Important Information: 1 : Timestamp: 2013-06-22 12:42:32Message: Test 1Category: ImportantPriority: -1EventId: 1Severity: InformationTitle:Machine: PIOTR-PCApp Domain: ConsoleApplication4.exeProcessId: 7408Process Name: C:\Users\Piotr\documents\visual studio 11\Projects\ConsoleApplication4\ConsoleApplication4\bin\Release\ConsoleApplication4.exeThread Name:Win32 ThreadId:7688Extended Properties:

Jeżeli nie przekaże się któreś z wartości (np. eventid), wówczas używana jest wartość domyślna.

Zróbmy mały eksperyment potwierdzający filtrację na podstawie nazwy. W tej chwili zdefiniowano tylko jedno źródło o nazwie „Important”. Próbując zapisać jakąś wiadomość do innej kategorii, nic nie zostanie przekazane do dziennika:

class Program
{
    private static void Main(string[] args)
    {
        var logWriter = new LogWriter(BuildConfiguration());

         if (logWriter.IsLoggingEnabled())
        {
            logWriter.Write("Ta wiadomość nie powinna zostać zapisana.", "General");      
        }
    }
    private static LoggingConfiguration BuildConfiguration()
    {
         var loggingConfiguration = new LoggingConfiguration();
         var flatFileListener = new FlatFileTraceListener(@"c:\temp\1.txt");
         loggingConfiguration.AddLogSource("Important", SourceLevels.All, true).AddTraceListener(flatFileListener);

         return loggingConfiguration;
    }
}

Można zdefiniować kilka źródeł. Poniższy przykład definiuje źródło „Generals” i „Important”. Pierwsza grupa będzie zapisywana w pliku tekstowym, z kolei druga w dzienniku Windows:

class Program
{
    private static void Main(string[] args)
    {
        var logWriter = new LogWriter(BuildConfiguration());

        if (logWriter.IsLoggingEnabled())
        {                
            logWriter.Write("Ta wiadomość zostanie zapisana w pliku tekstowym.", "Important");
            logWriter.Write("Ta wiadomość zostanie zapisana w dzienniku Windows.", "General");
        }
    }
    private static LoggingConfiguration BuildConfiguration()
    {
        var loggingConfiguration = new LoggingConfiguration();

        var flatFileListener = new FlatFileTraceListener(@"c:\temp\1.txt");
        loggingConfiguration.AddLogSource("Important", SourceLevels.All, true).AddTraceListener(flatFileListener);
        loggingConfiguration.AddLogSource("General", SourceLevels.All, true).AddTraceListener(new EventLogTraceListener("Application"));

        return loggingConfiguration;
    }
}

Plik tekstowy będzie wyglądał następująco:

Important Information: 1 : Timestamp: 2013-06-22 12:57:52 Message: Ta wiadomość zostanie zapisana w pliku tekstowym. Category: Important Priority: -1 EventId: 1 Severity: Information Title: Machine: PIOTR-PC App Domain: ConsoleApplication4.exe ProcessId: 7720 Process Name: C:\Users\Piotr\documents\visual studio 11\Projects\ConsoleApplication4\ConsoleApplication4\bin\Release\ConsoleApplication4.exe Thread Name: Win32 ThreadId:5636 Extended Properties:

Z kolei dziennik Windows wygląda tak:

Przeładowania Write również umożliwiają przekazanie listy kategorii – oznacza to, że ta sama wiadomość może zostać zapisana pod różnymi kategoriami.

Oprócz zapisu standardowych danych, takich jak wiadomość, tytuł czy kategoria, istnieje możliwość zapisania własnych informacji, zależnych już od konkretnej aplikacji. Wystarczy przekazać słownik zawierający pary (nazwa zmiennej, wartość):

var logWriter = new LogWriter(BuildConfiguration());
if (logWriter.IsLoggingEnabled())
{
    var customData = new Dictionary<string, object>();
    customData.Add("Jakas zmienna","Hello World");
    customData.Add("Zmienna II", 5);
    customData.Add("Zmienna III", true);
    logWriter.Write("Wiadomosc", customData);
}

W pliku pojawi się:

Important Information: 1 : Timestamp: 2013-06-22 20:10:46 Message: Wiadomosc Category: Important Priority: -1 EventId: 1 Severity: Information Title: Machine: PIOTR-PC App Domain: ConsoleApplication4.exe ProcessId: 1416 Process Name: C:\Users\Piotr\documents\visual studio 11\Projects\ConsoleApplication4\ConsoleApplication4\bin\Release\ConsoleApplication4.exe Thread Name: Win32 ThreadId:2232 Extended Properties: Jakas zmienna - Hello World Zmienna II - 5 Zmienna III - True

Istnieje jeszcze inny sposób zapisywania logów. Powyższy opis dotyczy różnych przeładowań metody Write. Można również stworzyć obiekt LogEntry, a następnie przekazać go do LowWriter::Write. LogEntry – to nic innego jak kontener na dane. Ten sposób jest szczególnie przydatny, gdy w kodzie znajduje się jedna metoda odpowiedzialna za tworzenie wpisów. Wtedy ta metoda może zwracać LogEntry – w zależności od sytuacji, będzie ona odpowiednio wypełniać LogeEntry danymi. Czasami bezpośrednie przekazywanie parametrów do LogWriter:Write jest zbyt skomplikowane, wówczas lepiej napisać wrapper w formie własnej metody.

Przykład użycia LogEntry:

private static void Main(string[] args)
{
    var logWriter = new LogWriter(BuildConfiguration());

    if (logWriter.IsLoggingEnabled())
    {
        LogEntry entry = new LogEntry
        {
            Categories = new string[] {"Important"},
            EventId = 1,
            Message = "Test.",
            Priority = 2,
            Severity = TraceEventType.Warning,
            Title = "Tytul"
        };
        logWriter.Write(entry);
    }
}

Formatowanie wpisów

Listener nie odpowiada sam w sobie za formatowanie zawartości dzienników. Definiuje on jedynie typ dziennika, jak np. plik na dysku twardym, baza danych czy dziennik Windows. W EntLib istnieją dodatkowe obiekty, tzw. formattery, które odpowiedzialne są za generowanie czystej treści. W celu zapisania logów w pliku, ale w formie XML, należy ustawić wspomniany formatter:

private static LoggingConfiguration BuildConfiguration()
{
    var loggingConfiguration = new LoggingConfiguration();            

    var flatFileListener = new FlatFileTraceListener(@"c:\temp\1.txt");
    flatFileListener.Formatter=new XmlLogFormatter();

    loggingConfiguration.AddLogSource("Important",SourceLevels.All,true).
    AddTraceListener(flatFileListener); 
 
    return loggingConfiguration;
}

Istnieje wiele typów, m.in.: Json, Binary, Xml czy Text. Jeżeli chce się zapisywać dane w niestandardowym formacie, można oczywiście napisać własny.

Zakończenie

Logging Application Block to tylko początek biblioteki EntLib. W następnych częściach opiszę kolejne komponenty (bloki), m.in. obsługę błędów. Tematyka logów również nie została wyczerpana w tym artykule, dlatego będzie ona kontynuowana w następnych częściach. Warto przeznaczyć trochę czasu zagadnieniu instrumentacji, ponieważ bardzo często jest ona ignorowana i ograniczana do minimum, np. logowania wyjątków, ignorując kompletnie inne dane, jak audyt czy wydajność.

 


     

Piotr Zieliński

Absolwent informatyki o specjalizacji inżynieria oprogramowania Uniwersytetu Zielonogórskiego. Posiada szereg certyfikatów z technologii Microsoft (MCP, MCTS, MCPD). W 2011 roku wyróżniony nagrodą MVP w kategorii Visual C#. Aktualnie pracuje w General Electric pisząc oprogramowanie wykorzystywane w monitorowaniu transformatorów . Platformę .NET zna od wersji 1.1 – wcześniej wykorzystywał głównie MFC oraz C++ Builder. Interesuje się wieloma technologiami m.in. ASP.NET MVC, WPF, PRISM, WCF, WCF Data Services, WWF, Azure, Silverlight, WCF RIA Services, XNA, Entity Framework, nHibernate. Oprócz czystych technologii zajmuje się również wzorcami projektowymi, bezpieczeństwem aplikacji webowych i testowaniem oprogramowania od strony programisty. W wolnych chwilach prowadzi blog o .NET i tzw. patterns & practices.