ASP.NET Core2でSerilogを利用する

これまではNLogを利用することが多かったのですが、パフォーマンスやお手軽さからSerilog — simple .NET logging with fully-structured eventsを使用してみようと思います。

前提条件

対象のプロジェクトはASP.NET Core2で作成しました。

設定方法

ASP.NET Core2でserilog/serilog-aspnetcore: Serilog integration for ASP.NET Core 2+の設定は以下の通りとなります。

1. NuGetパッケージのインストール
2. Program.csの変更

NuGetパッケージのインストール

NuGetパッケージは以下のものをインストールします。

• Serilog.AspNetCore -DependencyVersion Highest
• Serilog.Sinks.Console
• Serilog.Sinks.RollingFile

インストール後のプロジェクトファイルは以下の通りとなります。

<Project Sdk="Microsoft.NET.Sdk.Web">
  <PropertyGroup>
    <TargetFramework>netcoreapp2.0</TargetFramework>
  </PropertyGroup>
  <ItemGroup>
    <Folder Include="wwwroot\" />
  </ItemGroup>
  <ItemGroup>
    <PackageReference Include="Microsoft.AspNetCore.All" Version="2.0.0" />
    <PackageReference Include="Microsoft.EntityFrameworkCore" Version="2.0.0" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.Design" Version="2.0.0" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.Tools" Version="2.0.0" />
    <PackageReference Include="Npgsql" Version="3.2.5" />
    <PackageReference Include="Npgsql.EntityFrameworkCore.PostgreSQL" Version="2.0.0" />
    <PackageReference Include="Serilog.AspNetCore" Version="2.0.0" />
    <PackageReference Include="Serilog.Sinks.Console" Version="3.1.1-dev-00757" />
    <PackageReference Include="Serilog.Sinks.RollingFile" Version="3.3.1-dev-00771" />
  </ItemGroup>
  <ItemGroup>
    <DotNetCliToolReference Include="Microsoft.EntityFrameworkCore.Tools.DotNet" Version="2.0.0" />
    <DotNetCliToolReference Include="Microsoft.VisualStudio.Web.CodeGeneration.Tools" Version="2.0.0" />
  </ItemGroup>
</Project>

Program.csの変更

Program.csは以下の通り変更します。

        public static int Main(string[] args)
        {
            Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Debug()
                .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
                .Enrich.FromLogContext()
                .WriteTo.Console()
                .WriteTo.RollingFile("logs/beagle-customer-{Date}.log")
                .CreateLogger();

            try
            {
                var host = BuildWebHost(args);
                host.Run();

                return 0;
            }
            catch (Exception ex)
            {
                Log.Fatal(ex, "Host terminated unexpectedly");
                return 1;
            }
            finally
            {
                Log.CloseAndFlush();
            }
        }

        public static IWebHost BuildWebHost(string[] args) =>
            WebHost.CreateDefaultBuilder(args)
                .UseStartup<Startup>()
               // ここでログの利用を宣言する
                .UseSerilog()
                .Build();
    }

ポイントはMainメソッド内でLoggerの設定を行い、例外がスローされたときにもログを出力するように設定していることです。

// ロガーの設定を行う
Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Debug()
                .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
                .Enrich.FromLogContext()
               // コンソールへの出力を行う
                .WriteTo.Console()
               // ファイルへの出力を行う
                .WriteTo.RollingFile("logs/beagle-customer-{Date}.log")
                .CreateLogger();

なお、出力先についてはNuGetで公開されているSink（NuGet Gallery | Packages matching Tags:"serilog"）を利用することで柔軟に対応ができます。

設定した内容はUseSerilog()メソッドを設定することで利用可能となります。

public static IWebHost BuildWebHost(string[] args) =>
            WebHost.CreateDefaultBuilder(args)
                .UseStartup<Startup>()
               // ここでログの利用を宣言する
                .UseSerilog()
                .Build();

感想

最初はASP.NET Core2についてもよく知らなかったので戸惑うことが多かった（特にテストプロジェクトでの出力とか）ですが、慣れてくるとログの出力先などSinkが色々とあって便利だなと感じました。

参考

Serilog vs NLog Benchmarks

Pro ASP.NET Core MVC 2

EF Core2で実行したSQLの引数をログに出力する

EntityFramework Coreで実行したクエリのログを出力する設定は以下の通りDbContextクラスのOnConfiguringをオーバーライドしてoptionsBuilder.EnableSensitiveDataLogging();を設定すればOKです。ただ、SensitiveDataLoggingというパラメーター名からも分かる通りログにパラメターが出力されることがNGなケースもあるのでそのへんは注意が必要ですね。

public class BeagleBaseContext : DbContext
 {
        protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        {
            // この設定により引数のログが出力される
            optionsBuilder.EnableSensitiveDataLogging();
        }
}

出力されるログ

出力されるログは正直あまり使い勝手がいいログではありません。せめてJSONとかならParseし易いのですが、そのままだと以下のように出力されます。

[14:56:28 INF] Executed DbCommand (0ms) [Parameters=[@__get_Item_0='b0d0d15e-8d35-4cf0-afcf-ffe3580ba264' (Size = 36)], CommandType='Text', CommandTimeout='30']
SELECT "e"."id", "e"."application_id", "e"."building_name", "e"."celler_phone_no", "e"."city_name", "e"."code", "e"."contractor_id", "e"."created_at", "e"."display_flg", "e"."email", "e"."fax_no", "e"."location", "e"."name", "e"."name_kana", "e"."phone_no", "e"."pref_code", "e"."street_name", "e"."town_name", "e"."unit_name", "e"."url", "e"."zip_code", "e"."xmin"
FROM "organizations" AS "e"
WHERE "e"."id" = @__get_Item_0
LIMIT 1

おそらく出力処理をカスタマイズできると思いますが、調査してみないとですね。

参考

c# - Lost parameter value during SQL trace in EF Core - Stack Overflow

DbContextOptionsBuilder Class (Microsoft.EntityFrameworkCore) | Microsoft Docs

実戦で役立つ C#プログラミングのイディオム/定石&パターン

migrationのテーブル名や列名をLowerSnakeCaseに設定する

EF Coreを利用してCodeFirstでMigrationによりデータベースのテーブルを作成するときですが、テーブル名と列名がC#のプロパティ名となるため、デフォルトではUpperCamelCaseになります。

これを変更するにはテーブル名であれば{Table("table_name")、列名であれば[Column("column_name")]とそれぞれに設定することで対応可能です。

しかし、このようにアノテーションを設定することは結構面倒です。特にPostgreSQLを使用している場合には列名に大文字を使用するとハマりどころとなったりします。

お手軽に列名をLowerSnakeCaseに変換する

少し調べてみたところ、EF CoreのIssueに以下のようにContextクラスのOnModelCreatingで列名とテーブル名を変換する方法が紹介されていましたので試してみました。

namespace Some.Models
{
    public class SomeContext:DbContext
    {
        public DbSet<...

        protected override void OnModelCreating(ModelBuilder modelBuilder)
        {
            ...
            base.OnModelCreating(modelBuilder);

            FixSnakeCaseNames(modelBuilder);
        }

        private static void FixSnakeCaseNames(ModelBuilder modelBuilder)
        {
            var mapper = new Npgsql.NpgsqlSnakeCaseNameTranslator();

            foreach (var entity in modelBuilder.Model.GetEntityTypes())
            {
                // modify column names
                foreach (var property in entity.GetProperties())
                {
                    property.Relational().ColumnName = mapper.TranslateMemberName(property.Relational().ColumnName);
                }

                // modify table name
                entity.Relational().TableName = mapper.TranslateMemberName(entity.Relational().TableName);

                // move asp_net tables into schema 'identity'
                if (entity.Relational().TableName.StartsWith("asp_net_"))
                {
                    entity.Relational().TableName = entity.Relational().TableName.Replace("asp_net_", string.Empty);
                    entity.Relational().Schema = "identity";
                }
            }
        }
    }
}

結果としてはこれで問題なくテーブル名と列名がLowerSnaleCaseになりましたので感謝感謝です。

参考

pluggable schemes for mapping c# names · Issue #5159 · aspnet/EntityFrameworkCore

このところPostgreSQLへC#から接続することを色々と試しているせいでしょうが、Shay Rojanskyさんには本当にお世話になっています。大抵の問題について回答されていてShay Rojanskyの回答からいろいろな人がいろいろな方法を紹介されている事が多いのでとても感謝しています。

C#実践開発手法 (マイクロソフト公式解説書)