Entity Framework - ログ出力でトランザクションを確認してみる

Entity Framework のトランザクションについて、前回と同じようにログを確認してみます。Entity Framework のトランザクションのデフォルトの動きやトランザクション自体の使い方はこちらが参考になります。

Entity Framework Working with Transactions (EF6 Onwards)

まずデフォルトでは、SaveChanges メソッドや Database.ExecuteSqlCommand メソッドの呼び出しが1つのトランザクションとして扱われます。

In all versions of Entity Framework, whenever you execute SaveChanges() to insert, update or delete on the database the framework will wrap that operation in a transaction.

...(略)...

Starting with EF6 Database.ExecuteSqlCommand() by default will wrap the command in a transaction if one was not already present.

またトランザクションは Database.BeginTransaction メソッドを使って開始できます。

Database.BeginTransaction() : An easier method for a user to start and complete transactions themselves within an existing DbContext –

...(略)...

このあたりをログで確認してみたいと思います。

いつものごとく Entity と DbContext を用意します。

class Sample {
    [DatabaseGenerated(DatabaseGeneratedOption.None)]
    public int Id { get; set; }
    public string Value { get; set; }
}

class AppDbContext : DbContext {
    private static readonly string _connectionString = new SqlConnectionStringBuilder {
        DataSource = ".",
        InitialCatalog = "ConsoleApp",
        IntegratedSecurity = true,
    }.ToString();

    public AppDbContext()
        : base(_connectionString) {
        // ログ出力
        Database.Log = Console.Write;
    }

    public DbSet<Sample> Samples { get; set; }
}

デフォルトの動きを確認

SaveChanges で2レコード追加し、ExecuteSqlCommand でも2レコード追加するコードとそのログです。

using (var context = new AppDbContext()) {
    // SaveChanges内でトランザクションが開始されコミットされる
    context.Samples.AddRange(new[] {
        new Sample { Id = 1, Value = "A" },
        new Sample { Id = 2, Value = "B" },
    });
    Console.WriteLine("# Pre SaveChanges");
    context.SaveChanges();
    Console.WriteLine("# Post SaveChanges");
    Console.WriteLine();

    // ExecuteSqlCommandも同様にトランザクションが開始されコミットされる
    Console.WriteLine("# Pre ExecuteSqlCommand");
    context.Database.ExecuteSqlCommand(@"
insert into Samples values(3, N'C');
insert into Samples values(4, N'D');");
    Console.WriteLine("# Post ExecuteSqlCommand");
}

ログ

# Pre SaveChanges
Opened connection at 2014/04/16 23:02:42 +09:00
Started transaction at 2014/04/16 23:02:42 +09:00
INSERT [dbo].[Samples]([Id], [Value])
VALUES (@0, @1)
-- @0: '1' (Type = Int32)
-- @1: 'A' (Type = String, Size = -1)
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 1

INSERT [dbo].[Samples]([Id], [Value])
VALUES (@0, @1)
-- @0: '2' (Type = Int32)
-- @1: 'B' (Type = String, Size = -1)
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 1

Committed transaction at 2014/04/16 23:02:42 +09:00
Closed connection at 2014/04/16 23:02:42 +09:00
# Post SaveChanges

# Pre ExecuteSqlCommand
Opened connection at 2014/04/16 23:02:42 +09:00
Started transaction at 2014/04/16 23:02:42 +09:00

insert into Samples values(3, N'C');
insert into Samples values(4, N'D');
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 2

Committed transaction at 2014/04/16 23:02:42 +09:00
Closed connection at 2014/04/16 23:02:42 +09:00
# Post ExecuteSqlCommand

SavaChanges メソッド内でトランザクションが開始され、コミットされていることが確認できます。 また、ExecuteSqlCommand メソッドも同じようにメソッド内で1つのトランザクションとして処理されています。

1つのトランザクションとして扱う

今度は先ほどの SaveChanges や ExecuteSqlCommand を1つのトランザクションとして処理してみます。トランザクションは DbContext.Database.BeginTransaction メソッドを使って開始します。

using (var context = new AppDbContext()) {
    // トランザクションを開始する
    Console.WriteLine("# Pre BeginTransaction");
    using (var transaction = context.Database.BeginTransaction()) {
        Console.WriteLine("# Post BeginTransaction");
        Console.WriteLine();

        // SaveChanges
        context.Samples.AddRange(new[] {
            new Sample { Id = 1, Value = "A" },
            new Sample { Id = 2, Value = "B" },
        });
        Console.WriteLine("# Pre SaveChanges");
        context.SaveChanges();
        Console.WriteLine("# Post SaveChanges");
        Console.WriteLine();

        // ExecuteSqlCommand
        Console.WriteLine("# Pre ExecuteSqlCommand");
        context.Database.ExecuteSqlCommand(@"
insert into Samples values(3, N'C');
insert into Samples values(4, N'D');");
        Console.WriteLine("# Post ExecuteSqlCommand");
        Console.WriteLine();

        // コミットする
        Console.WriteLine("# Pre Commit");
        transaction.Commit();
        Console.WriteLine("# Post Commit");
    }
}

ログ

# Pre BeginTransaction
Opened connection at 2014/04/16 23:02:42 +09:00
Started transaction at 2014/04/16 23:02:42 +09:00
# Post BeginTransaction

# Pre SaveChanges
INSERT [dbo].[Samples]([Id], [Value])
VALUES (@0, @1)
-- @0: '1' (Type = Int32)
-- @1: 'A' (Type = String, Size = -1)
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 1

INSERT [dbo].[Samples]([Id], [Value])
VALUES (@0, @1)
-- @0: '2' (Type = Int32)
-- @1: 'B' (Type = String, Size = -1)
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 1

# Post SaveChanges

# Pre ExecuteSqlCommand

insert into Samples values(3, N'C');
insert into Samples values(4, N'D');
-- Executing at 2014/04/16 23:02:42 +09:00
-- Completed in 0 ms with result: 2

# Post ExecuteSqlCommand

# Pre Commit
Committed transaction at 2014/04/16 23:02:42 +09:00
# Post Commit
Closed connection at 2014/04/16 23:02:42 +09:00

BeginTransaction メソッドでトランザクションが開始されて、Commit メソッドでコミットされてことが確認できます。コネクションのオープンとクローズも1回になっています。