読者です 読者をやめる 読者になる 読者になる

Entity Framework - ログ出力を試してみる

entity-framework

Entity Framework 6でログ出力できるようになったことを知ったのでちょっと試してみました。

ログを出力するには DbContext.Database.Log プロパティに string を受けとる Action デリゲートを渡します。

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

    // ...
}

Entity Framework Logging and Intercepting Database Operations (EF6 Onwards)

ということで Entity と DbContext を用意して、とりあえず select、insert、update、delete を試してみます。

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) {
    }

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

select

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

    // Idで取得
    context.Samples.Find(1);
}
ログ
Opened connection at 2014/04/12 23:51:14 +09:00
SELECT TOP (2)
    [Extent1].[Id] AS [Id],
    [Extent1].[Value] AS [Value]
    FROM [dbo].[Samples] AS [Extent1]
    WHERE [Extent1].[Id] = @p0
-- p0: '1' (Type = Int32)
-- Executing at 2014/04/12 23:51:15 +09:00
-- Completed in 0 ms with result: SqlDataReader

Closed connection at 2014/04/12 23:51:15 +09:00

SQL やパラメータ、実行された時間などが確認できますね。

insert

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

    // 追加
    context.Entry(new Sample { Id = 1, Value = "A" }).State = EntityState.Added;
    //context.Samples.Add(new Sample{ Id = 1, Value = "A"}); でも同じ

    Console.WriteLine("# Pre SaveChanges");
    context.SaveChanges();
    Console.WriteLine("# Post SaveChanges");
}
ログ
# Pre SaveChanges
Opened connection at 2014/04/12 23:51:15 +09:00
Started transaction at 2014/04/12 23:51:15 +09:00
INSERT [dbo].[Samples]([Id], [Value])
VALUES (@0, @1)
-- @0: '1' (Type = Int32)
-- @1: 'A' (Type = String, Size = -1)
-- Executing at 2014/04/12 23:51:15 +09:00
-- Completed in 1 ms with result: 1

Committed transaction at 2014/04/12 23:51:15 +09:00
Closed connection at 2014/04/12 23:51:15 +09:00
# Post SaveChanges

SaveChanges メソッドで、

も確認できますね。(次の update、delete でも同じですが。)

update

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

    // Idが1のSample.Valueを"B"に更新
    context.Entry(new Sample { Id = 1, Value = "B" }).State = EntityState.Modified;

    Console.WriteLine("# Pre SaveChanges");
    context.SaveChanges();
    Console.WriteLine("# Post SaveChanges");
}
ログ
# Pre SaveChanges
Opened connection at 2014/04/12 23:51:15 +09:00
Started transaction at 2014/04/12 23:51:15 +09:00
UPDATE [dbo].[Samples]
SET [Value] = @0
WHERE ([Id] = @1)
-- @0: 'B' (Type = String, Size = -1)
-- @1: '1' (Type = Int32)
-- Executing at 2014/04/12 23:51:15 +09:00
-- Completed in 0 ms with result: 1

Committed transaction at 2014/04/12 23:51:15 +09:00
Closed connection at 2014/04/12 23:51:15 +09:00
# Post SaveChanges

delete

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

    // Idが1のSampleを削除
    context.Entry(new Sample { Id = 1 }).State = EntityState.Deleted;

    Console.WriteLine("# Pre SaveChanges");
    context.SaveChanges();
    Console.WriteLine("# Post SaveChanges");
}
ログ
# Pre SaveChanges
Opened connection at 2014/04/12 23:51:15 +09:00
Started transaction at 2014/04/12 23:51:15 +09:00
DELETE [dbo].[Samples]
WHERE ([Id] = @0)
-- @0: '1' (Type = Int32)
-- Executing at 2014/04/12 23:51:15 +09:00
-- Completed in 0 ms with result: 1

Committed transaction at 2014/04/12 23:51:15 +09:00
Closed connection at 2014/04/12 23:51:15 +09:00
# Post SaveChanges

ちなみに削除するときは、PK だけ(今回の場合は Id プロパティ)を設定したエンティティを生成して、状態に EntityState.Deleted を設定すればいいようです。

今度は トランザクションのログを確認してみようかなーと思います。