Rejestrowanie i przechwytywanie operacji bazy danych

Artykuł
09/12/2023

Uwaga

Tylko rozwiązanie EF6 i nowsze wersje — Funkcje, interfejsy API itp. omówione na tej stronie zostały wprowadzone w rozwiązaniu Entity Framework 6. Jeśli korzystasz ze starszej wersji, niektóre lub wszystkie podane informacje nie mają zastosowania.

Począwszy od programu Entity Framework 6, za każdym razem, gdy program Entity Framework wysyła polecenie do bazy danych, to polecenie może zostać przechwycone za pomocą kodu aplikacji. Jest to najczęściej używane do rejestrowania bazy danych SQL, ale może być również używane do modyfikowania lub przerwania polecenia.

W szczególności ef obejmuje:

Właściwość Log dla kontekstu podobnego do DataContext.Log w LINQ to SQL
Mechanizm dostosowywania zawartości i formatowania danych wyjściowych wysyłanych do dziennika
Bloki konstrukcyjne niskiego poziomu do przechwytywania dając większą kontrolę/elastyczność

Właściwość Dziennika kontekstu

Właściwość DbContext.Database.Log można ustawić na delegata dla dowolnej metody, która przyjmuje ciąg. Najczęściej jest używany z dowolną maszyną TextWriter, ustawiając ją na metodę "Write" tego textwritera. Wszystkie bazy danych SQL wygenerowane przez bieżący kontekst zostaną zarejestrowane w tym składniku zapisywania. Na przykład następujący kod spowoduje zarejestrowanie kodu SQL w konsoli:

using (var context = new BlogContext())
{
    context.Database.Log = Console.Write;

    // Your code here...
}

Zwróć uwagę na kontekst. Właściwość Database.Log jest ustawiona na Console.Write. To wszystko, co jest potrzebne do zarejestrowania bazy danych SQL w konsoli programu .

Dodajmy kilka prostych zapytań/wstawiania/aktualizowania kodu, aby zobaczyć dane wyjściowe:

using (var context = new BlogContext())
{
    context.Database.Log = Console.Write;

    var blog = context.Blogs.First(b => b.Title == "One Unicorn");

    blog.Posts.First().Title = "Green Eggs and Ham";

    blog.Posts.Add(new Post { Title = "I do not like them!" });

    context.SaveChanges();
}

Spowoduje to wygenerowanie następujących danych wyjściowych:

SELECT TOP (1)
    [Extent1].[Id] AS [Id],
    [Extent1].[Title] AS [Title]
    FROM [dbo].[Blogs] AS [Extent1]
    WHERE (N'One Unicorn' = [Extent1].[Title]) AND ([Extent1].[Title] IS NOT NULL)
-- Executing at 10/8/2013 10:55:41 AM -07:00
-- Completed in 4 ms with result: SqlDataReader

SELECT
    [Extent1].[Id] AS [Id],
    [Extent1].[Title] AS [Title],
    [Extent1].[BlogId] AS [BlogId]
    FROM [dbo].[Posts] AS [Extent1]
    WHERE [Extent1].[BlogId] = @EntityKeyValue1
-- EntityKeyValue1: '1' (Type = Int32)
-- Executing at 10/8/2013 10:55:41 AM -07:00
-- Completed in 2 ms with result: SqlDataReader

UPDATE [dbo].[Posts]
SET [Title] = @0
WHERE ([Id] = @1)
-- @0: 'Green Eggs and Ham' (Type = String, Size = -1)
-- @1: '1' (Type = Int32)
-- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
-- Completed in 12 ms with result: 1

INSERT [dbo].[Posts]([Title], [BlogId])
VALUES (@0, @1)
SELECT [Id]
FROM [dbo].[Posts]
WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()
-- @0: 'I do not like them!' (Type = String, Size = -1)
-- @1: '1' (Type = Int32)
-- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
-- Completed in 2 ms with result: SqlDataReader

(Należy pamiętać, że jest to dane wyjściowe przy założeniu, że zainicjowanie bazy danych zostało już wykonane. Jeśli inicjowanie bazy danych nie zostało jeszcze wykonane, będzie o wiele więcej danych wyjściowych pokazujących wszystkie zadania Migracje wykonywane w ramach okładek, aby sprawdzić lub utworzyć nową bazę danych.

Co zostanie zarejestrowane?

Po ustawieniu właściwości Log zostaną zarejestrowane wszystkie następujące elementy:

Sql dla wszystkich różnych rodzajów poleceń. Na przykład:
- Zapytania, w tym zwykłe zapytania LINQ, zapytania eSQL i nieprzetworzone zapytania z metod, takich jak SqlQuery
- Wstawia, aktualizuje i usuwa wygenerowane w ramach funkcji SaveChanges
- Zapytania ładowania relacji, takie jak zapytania generowane przez ładowanie z opóźnieniem
Parametry
Czy polecenie jest wykonywane asynchronicznie
Sygnatura czasowa wskazująca, kiedy polecenie zaczęło wykonywać
Niezależnie od tego, czy polecenie zostało ukończone pomyślnie, nie powiodło się, zgłaszając wyjątek, czy w przypadku asynchronicznego polecenia zostało anulowane
Niektóre wskazania wartości wyniku
Przybliżony czas wykonywania polecenia. Należy pamiętać, że jest to czas od wysłania polecenia w celu odzyskania obiektu wyniku. Nie zawiera czasu na odczytanie wyników.

Patrząc na przykładowe dane wyjściowe powyżej, każde z czterech zarejestrowanych poleceń to:

Zapytanie wynikające z wywołania do kontekstu. Blogi.First
- Zwróć uwagę, że metoda ToString pobierania kodu SQL nie działała dla tego zapytania, ponieważ "First" nie udostępnia elementu IQueryable, na którym można wywołać metodę ToString
Zapytanie wynikające z opóźnionego ładowania bloga. Posty
- Zwróć uwagę na szczegóły parametru dla wartości klucza, dla której odbywa się ładowanie z opóźnieniem
- Rejestrowane są tylko właściwości parametru, które są ustawione na wartości inne niż domyślne. Na przykład właściwość Size jest wyświetlana tylko wtedy, gdy jest inna niż zero.
Dwa polecenia wynikające z polecenia SaveChangesAsync; jeden dla aktualizacji, aby zmienić tytuł wpisu, drugi dla wstawiania w celu dodania nowego wpisu
- Zwróć uwagę na szczegóły parametru właściwości FK i Title
- Zwróć uwagę, że te polecenia są wykonywane asynchronicznie

Rejestrowanie w różnych miejscach

Jak pokazano powyżej, rejestrowanie w konsoli jest bardzo proste. Można również łatwo logować się do pamięci, pliku itp. przy użyciu różnych rodzajów textwritera.

Jeśli znasz linQ to SQL, możesz zauważyć, że w linQ to SQL właściwość Log jest ustawiona na rzeczywisty obiekt TextWriter (na przykład Console.Out), podczas gdy w programie EF właściwość Log jest ustawiona na metodę, która akceptuje ciąg (na przykład Console.Write lub Console.Out.Write). Przyczyną tego jest oddzielenie ef od textwriter, akceptując dowolnego delegata, który może działać jako ujście dla ciągów. Załóżmy na przykład, że masz już pewną strukturę rejestrowania i definiuje metodę rejestrowania w następujący sposób:

public class MyLogger
{
    public void Log(string component, string message)
    {
        Console.WriteLine("Component: {0} Message: {1} ", component, message);
    }
}

Można to podłączyć do właściwości dziennika EF, w następujący sposób:

var logger = new MyLogger();
context.Database.Log = s => logger.Log("EFApp", s);

Rejestrowanie wyników

Domyślny rejestrator rejestruje tekst polecenia (SQL), parametry i wiersz "Wykonywanie" ze znacznikiem czasu przed wysłaniem polecenia do bazy danych. Wiersz "ukończony" zawierający czas, który upłynął, jest rejestrowany po wykonaniu polecenia.

Należy pamiętać, że w przypadku poleceń asynchronicznych wiersz "ukończony" nie jest rejestrowany, dopóki zadanie asynchroniczne nie zostanie ukończone, nie powiedzie się lub zostanie anulowane.

Wiersz "completed" zawiera różne informacje w zależności od typu polecenia i tego, czy wykonanie zakończyło się pomyślnie.

Pomyślne wykonanie

W przypadku poleceń, które zakończyły się pomyślnie, dane wyjściowe to "Ukończono w x ms z wynikiem: ", a następnie pewne wskazanie, jaki był wynik. W przypadku poleceń, które zwracają czytnik danych, wskazanie wyniku jest typem zwracanego elementu DbDataReader . W przypadku poleceń, które zwracają wartość całkowitą, taką jak polecenie aktualizacji pokazane powyżej pokazanego wyniku, jest to liczba całkowita.

Wykonywanie nie powiodło się

W przypadku poleceń, które kończą się niepowodzeniem przez zgłoszenie wyjątku, dane wyjściowe zawierają komunikat z wyjątku. Na przykład użycie zapytania SqlQuery do wykonywania zapytań względem tabeli, która istnieje, spowoduje wyświetlenie danych wyjściowych dziennika w następujący sposób:

SELECT * from ThisTableIsMissing
-- Executing at 5/13/2013 10:19:05 AM
-- Failed in 1 ms with error: Invalid object name 'ThisTableIsMissing'.

Anulowane wykonanie

W przypadku poleceń asynchronicznych, w których zadanie zostało anulowane, wynik może być niepowodzeniem z wyjątkiem, ponieważ jest to, co dostawca ADO.NET bazowych często wykonuje po podjęciu próby anulowania. Jeśli tak się nie stanie, a zadanie zostanie anulowane w sposób czysty, dane wyjściowe będą wyglądać mniej więcej tak:

update Blogs set Title = 'No' where Id = -1
-- Executing asynchronously at 5/13/2013 10:21:10 AM
-- Canceled in 1 ms

Zmienianie zawartości dziennika i formatowania

W obszarze obejmuje właściwość Database.Log używa obiektu DatabaseLogFormatter. Ten obiekt skutecznie wiąże implementację IDbCommandInterceptor (patrz poniżej) z pełnomocnikiem, który akceptuje ciągi i dbContext. Oznacza to, że metody w bazie danych DatabaseLogFormatter są wywoływane przed i po wykonaniu poleceń przez program EF. Te metody DatabaseLogFormatter zbierają i formatują dane wyjściowe dziennika i wysyłają je do delegata.

Dostosowywanie databaseLogFormatter

Zmiana rejestrowanych elementów i sposobu ich formatowania można osiągnąć, tworząc nową klasę, która pochodzi z klasy DatabaseLogFormatter i zastępuje odpowiednie metody. Najbardziej typowe metody zastąpienia to:

LogCommand — zastąpij to, aby zmienić sposób rejestrowania poleceń przed ich wykonaniem. Domyślnie LogCommand wywołuje parametr LogParameter dla każdego parametru; Zamiast tego możesz wykonać to samo w zastąpieniu lub obsłużyć parametry inaczej.
LogResult — przesłoń to, aby zmienić sposób rejestrowania wyniku wykonywania polecenia.
LogParameter — przesłoń to, aby zmienić formatowanie i zawartość rejestrowania parametrów.

Załóżmy na przykład, że chcemy zarejestrować tylko jeden wiersz przed wysłaniem każdego polecenia do bazy danych. Można to zrobić za pomocą dwóch przesłonięć:

Zastąpij polecenie LogCommand w celu sformatowania i zapisania pojedynczego wiersza kodu SQL
Zastąpij metodę LogResult, aby nic nie robić.

Kod będzie wyglądać mniej więcej tak:

public class OneLineFormatter : DatabaseLogFormatter
{
    public OneLineFormatter(DbContext context, Action<string> writeAction)
        : base(context, writeAction)
    {
    }

    public override void LogCommand<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        Write(string.Format(
            "Context '{0}' is executing command '{1}'{2}",
            Context.GetType().Name,
            command.CommandText.Replace(Environment.NewLine, ""),
            Environment.NewLine));
    }

    public override void LogResult<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
    }
}

Aby rejestrować dane wyjściowe, po prostu wywołaj metodę Write, która będzie wysyłać dane wyjściowe do skonfigurowanego delegata zapisu.

(Należy pamiętać, że ten kod upraszcza usuwanie podziałów wierszy, tak jak na przykład. Prawdopodobnie nie będzie dobrze działać w przypadku wyświetlania złożonego kodu SQL).

Ustawianie parametru DatabaseLogFormatter

Po utworzeniu nowej klasy DatabaseLogFormatter należy ją zarejestrować w programie EF. Odbywa się to przy użyciu konfiguracji opartej na kodzie. W skrócie oznacza to utworzenie nowej klasy pochodzącej z klasy DbConfiguration w tym samym zestawie co klasa DbContext, a następnie wywołanie metody SetDatabaseLogFormatter w konstruktorze tej nowej klasy. Przykład:

public class MyDbConfiguration : DbConfiguration
{
    public MyDbConfiguration()
    {
        SetDatabaseLogFormatter(
            (context, writeAction) => new OneLineFormatter(context, writeAction));
    }
}

Korzystanie z nowego elementu DatabaseLogFormatter

Ten nowy element DatabaseLogFormatter będzie teraz używany w dowolnym momencie ustawienia Database.Log. Dlatego uruchomienie kodu z części 1 spowoduje teraz wykonanie następujących danych wyjściowych:

Context 'BlogContext' is executing command 'SELECT TOP (1) [Extent1].[Id] AS [Id], [Extent1].[Title] AS [Title]FROM [dbo].[Blogs] AS [Extent1]WHERE (N'One Unicorn' = [Extent1].[Title]) AND ([Extent1].[Title] IS NOT NULL)'
Context 'BlogContext' is executing command 'SELECT [Extent1].[Id] AS [Id], [Extent1].[Title] AS [Title], [Extent1].[BlogId] AS [BlogId]FROM [dbo].[Posts] AS [Extent1]WHERE [Extent1].[BlogId] = @EntityKeyValue1'
Context 'BlogContext' is executing command 'update [dbo].[Posts]set [Title] = @0where ([Id] = @1)'
Context 'BlogContext' is executing command 'insert [dbo].[Posts]([Title], [BlogId])values (@0, @1)select [Id]from [dbo].[Posts]where @@rowcount > 0 and [Id] = scope_identity()'

Przechwycenie bloków konstrukcyjnych

Do tej pory przyjrzeliśmy się, jak używać elementu DbContext.Database.Log do rejestrowania bazy danych SQL wygenerowanej przez program EF. Ale ten kod jest w rzeczywistości stosunkowo cienką fasadą nad niektórymi blokami konstrukcyjnymi niskiego poziomu w celu bardziej ogólnego przechwycenia.

Interfejsy przechwytywania

Kod przechwytywania jest oparty na koncepcji interfejsów przechwytywania. Te interfejsy dziedziczą z klasy IDbInterceptor i definiują metody wywoływane, gdy program EF wykonuje jakąś akcję. Intencją jest posiadanie jednego interfejsu na typ przechwyconego obiektu. Na przykład interfejs IDbCommandInterceptor definiuje metody wywoływane przed wykonaniem wywołania funkcji ExecuteNonQuery, ExecuteScalar, ExecuteReader i powiązanych metod. Podobnie interfejs definiuje metody, które są wywoływane po zakończeniu każdej z tych operacji. Klasa DatabaseLogFormatter, którą omówiliśmy powyżej, implementuje ten interfejs w celu rejestrowania poleceń.

Kontekst przechwytywania

Patrząc na metody zdefiniowane na dowolnym z interfejsów przechwytywania, widać, że każde wywołanie ma obiekt typu DbInterceptionContext lub jakiś typ pochodzący z tego typu, taki jak DbCommandInterceptionContext<>. Ten obiekt zawiera kontekstowe informacje o akcji, która jest wykonywana przez program EF. Jeśli na przykład akcja jest wykonywana w imieniu obiektu DbContext, tekst DbContext jest uwzględniony w obiekcie DbInterceptionContext. Podobnie w przypadku poleceń, które są wykonywane asynchronicznie, flaga IsAsync jest ustawiona na DbCommandInterceptionContext.

Obsługa wyników

Klasa DbCommandInterceptionContext<> zawiera właściwości o nazwie Result, OriginalResult, Exception i OriginalException. Te właściwości są ustawione na wartość null/zero dla wywołań metod przechwytywania, które są wywoływane przed wykonaniem operacji — czyli dla ... Wykonywanie metod. Jeśli operacja zostanie wykonana i powiedzie się, wynik i właściwość OriginalResult zostaną ustawione na wynik operacji. Te wartości można następnie zaobserwować w metodach przechwytywania, które są wywoływane po wykonaniu operacji — czyli na ... Wykonane metody. Podobnie, jeśli operacja zgłasza, zostanie ustawiona właściwość Exception i OriginalException.

Pomijanie wykonywania

Jeśli przechwytujący ustawia właściwość Result przed wykonaniem polecenia (w jednym z ... Wykonywanie metod), a następnie ef nie podejmie próby wykonania polecenia, ale zamiast tego użyje tylko zestawu wyników. Innymi słowy, przechwytujący może pominąć wykonywanie polecenia, ale program EF nadal działa tak, jakby polecenie zostało wykonane.

Przykładem sposobu użycia tego polecenia jest przetwarzanie wsadowe poleceń, które tradycyjnie zostało wykonane z dostawcą opakowującym. Przechwytywanie będzie przechowywać polecenie do późniejszego wykonania jako partii, ale "udaj" ef, że polecenie zostało wykonane normalnie. Należy pamiętać, że wymaga to więcej niż w celu zaimplementowania przetwarzania wsadowego, ale jest to przykład sposobu użycia zmiany wyniku przechwytywania.

Wykonywanie można również pominąć, ustawiając właściwość Exception w jednym z ... Wykonywanie metod. Powoduje to kontynuowanie działania ef tak, jakby wykonanie operacji nie powiodło się, zgłaszając dany wyjątek. Może to oczywiście spowodować awarię aplikacji, ale może to być również wyjątek przejściowy lub inny wyjątek obsługiwany przez program EF. Na przykład może to być używane w środowiskach testowych do testowania zachowania aplikacji w przypadku niepowodzenia wykonywania polecenia.

Zmiana wyniku po wykonaniu

Jeśli przechwytujący ustawia właściwość Result po wykonaniu polecenia (w jednym z ... Wykonane metody) następnie EF użyje zmienionego wyniku zamiast wyniku, który został rzeczywiście zwrócony z operacji. Podobnie, jeśli przechwytnik ustawi właściwość Exception po wykonaniu polecenia, program EF zgłosi wyjątek zestawu tak, jakby operacja zgłosiła wyjątek.

Przechwytnik może również ustawić właściwość Exception na null, aby wskazać, że nie należy zgłaszać wyjątku. Może to być przydatne, jeśli wykonanie operacji nie powiodło się, ale przechwytujący chce, aby program EF kontynuował działanie tak, jakby operacja zakończyła się pomyślnie. Zwykle wiąże się to również z ustawieniem parametru Result (Wynik), aby program EF miał pewną wartość wyniku do pracy w miarę jego kontynuowania.

OriginalResult i OriginalException

Po wykonaniu operacji EF ustawi właściwości Result i OriginalResult, jeśli wykonanie nie nie powiedzie się, lub właściwości Exception i OriginalException, jeśli wykonanie nie powiedzie się z wyjątkiem.

Właściwości OriginalResult i OriginalException są tylko do odczytu i są ustawiane tylko przez program EF po wykonaniu operacji. Tych właściwości nie można ustawić przez przechwytniki. Oznacza to, że każdy przechwytywanie może odróżnić wyjątek lub wynik, który został ustawiony przez inny przechwytnik, w przeciwieństwie do rzeczywistego wyjątku lub wyniku, który wystąpił podczas wykonywania operacji.

Rejestrowanie przechwytujących

Po utworzeniu klasy implementujące co najmniej jeden interfejs przechwytywania można go zarejestrować w programie EF przy użyciu klasy DbInterception. Przykład:

DbInterception.Add(new NLogCommandInterceptor());

Przechwytuje można również zarejestrować na poziomie domeny aplikacji przy użyciu mechanizmu konfiguracji opartego na kodzie DbConfiguration.

Przykład: rejestrowanie w NLog

Połączmy to wszystko w przykładzie, w ramach którego użyjemy polecenia IDbCommandInterceptor i NLog do:

Rejestrowanie ostrzeżenia dla dowolnego polecenia, które jest wykonywane nie asynchronicznie
Rejestrowanie błędu dla dowolnego polecenia zgłaszanego podczas wykonywania

Oto klasa, która wykonuje rejestrowanie, które powinno być zarejestrowane, jak pokazano powyżej:

public class NLogCommandInterceptor : IDbCommandInterceptor
{
    private static readonly Logger Logger = LogManager.GetCurrentClassLogger();

    public void NonQueryExecuting(
        DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void NonQueryExecuted(
        DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    public void ReaderExecuting(
        DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void ReaderExecuted(
        DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    public void ScalarExecuting(
        DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void ScalarExecuted(
        DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    private void LogIfNonAsync<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        if (!interceptionContext.IsAsync)
        {
            Logger.Warn("Non-async command used: {0}", command.CommandText);
        }
    }

    private void LogIfError<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        if (interceptionContext.Exception != null)
        {
            Logger.Error("Command {0} failed with exception {1}",
                command.CommandText, interceptionContext.Exception);
        }
    }
}

Zwróć uwagę, że ten kod używa kontekstu przechwytywania do odnajdywania, gdy polecenie jest wykonywane nie asynchronicznie i wykrywa, kiedy wystąpił błąd podczas wykonywania polecenia.

Udostępnij za pośrednictwem