.NET ラボ 2023/07/22 での発表資料
↓↓↓ 登壇内容をある程度文字起こししたブログ ↓↓↓ 【C#】明日から使える ASP.NET Core ロギング術!
明日から使えるASP.NET Core ロギング術!.NET ラボ 2023/07/22何縫ねの。
View Slide
自己紹介1• 所属: NTTコミュニケーションズイノベーションセンター• 趣味: C#, OSS, ドール, 一眼(α7 IV)• 執心領域• C# ⇔ TypeScript• SignalR何縫ねの。nenoNaninunenoMakeブログ https://blog.neno.devその他 https://neno.dev
OSS 紹介2属性を付与するだけTapper• C# の型定義から TypeScript の型定義を生成する .NET Tool/ library• JSON / MessagePack 対応!https://github.com/nenoNaninu/Tapper
OSS 紹介3• C# の SignalR Client を強く型付けするための Source GeneratorTypedSignalR.ClientBeforeAfter (using TypedSignalR.Client)こんな SignalR のHub と Receiver の interface があったとして…脱文字列!全てが強く型付け!https://github.com/nenoNaninu/TypedSignalR.Client
4• TypeScript の SignalR Client を強く型付けするための .NET Tool / libraryTypedSignalR.Client.TypeScriptBeforeAfter (using TypedSignalR.Client.TypeScript)脱文字列!全てが強く型付け!TypeScript 用の型をC# から自動生成MessagePack Hub Protocol 対応!https://github.com/nenoNaninu/TypedSignalR.Client.TypeScript属性を付与するだけ!OSS 紹介
5• SignalR 使ったアプリを快適に開発するための GUI を自動生成する library• 2 step で利用可能!• http pipeline に middleware の追加• Hub と Receiver を定義してるinterface に属性を付与• JWT 認証 サポート• パラメータのユーザ定義型サポート• JSON で入力!SignalR 版 SwaggerUITypedSignalR.Client.DevToolshttps://github.com/nenoNaninu/TypedSignalR.Client.DevToolsOSS 紹介
ConsoleFormatter6
ConsoleFormatter7• Microsoft.Extensions.Logging には以下のようなクラスが存在する。• SimpleConsoleFormatter• JsonConsoleFormatter• SystemdConsoleFormatterコンソールにログを出力際のフォーマットは複数ある。
ConsoleFormatter8• Microsoft.Extensions.Logging には以下のようなクラスが存在する。• SimpleConsoleFormatter• JsonConsoleFormatter• SystemdConsoleFormatterコンソールにログを出力際のフォーマットは複数ある。internal なクラス以下のように拡張メソッドで設定
ConsoleFormatter9• Microsoft.Extensions.Logging には以下のようなクラスが存在する。• SimpleConsoleFormatter• JsonConsoleFormatter• SystemdConsoleFormatterコンソールにログを出力際のフォーマットは複数ある。internal なクラス以下のように拡張メソッドで設定
ConsoleFormatter10• Microsoft.Extensions.Logging には以下のようなクラスが存在する。• SimpleConsoleFormatter• JsonConsoleFormatter• SystemdConsoleFormatterコンソールにログを出力際のフォーマットは複数ある。internal なクラス以下のように拡張メソッドで設定このセッション中での例は全てSimpleConsole
ConsoleFormatter11• Microsoft.Extensions.Logging には以下のようなクラスが存在する。• SimpleConsoleFormatter• JsonConsoleFormatter• SystemdConsoleFormatterコンソールにログを出力際のフォーマットは複数ある。スライドで JsonConsole のログ見せられても見辛いだけなのでinternal なクラス以下のように拡張メソッドで設定このセッション中での例は全てSimpleConsole
HttpLogging12
HttpLogging13• AddHttpLogging• 何をログに出力するかの設定を行う。• 特定のヘッダやクエリを出力したりも可能• UseHttpLogging• ログを出力するためのミドルウェアをrequest pipeline に追加HTTP のリクエスト/リスポンスに関するログを出力したい。
HttpLogging14• AddHttpLogging• 何をログに出力するかの設定を行う。• 特定のヘッダやクエリを出力したりも可能• UseHttpLogging• ログを出力するためのミドルウェアをrequest pipeline に追加HTTP のリクエスト/リスポンスに関するログを出力したい。HttpLoggingFields (enum) をビット演算でくっつけていく
HttpLogging15• AddHttpLogging• 何をログに出力するかの設定を行う。• 特定のヘッダやクエリを出力したりも可能• UseHttpLogging• ログを出力するためのミドルウェアをrequest pipeline に追加HTTP のリクエスト/リスポンスに関するログを出力したい。HttpLoggingFields (enum) をビット演算でくっつけていく
HttpLogging16• AddHttpLogging• 何をログに出力するかの設定を行う。• 特定のヘッダやクエリを出力したりも可能• UseHttpLogging• ログを出力するためのミドルウェアをrequest pipeline に追加HTTP のリクエスト/リスポンスに関するログを出力したい。HttpLoggingFields (enum) をビット演算でくっつけていく出し過ぎには注意パフォーマンス & GDPR
HttpLogging17• ログレベルの設定も必要• appsettings.json 等で Microsoft.AspNetCore.HttpLogging のログレベルを Information にしておくHTTP のリクエスト/リスポンスに関するログを出力したい。
HttpLogging18• なかなか良さそう。• 本当に?HttpLoggingMiddleware によって出力されるログ
HttpLogging19• 同じエンドポイントを同時に叩くと…HttpLoggingMiddleware によって出力されるログ
HttpLogging20• 同じエンドポイントを同時に叩くと…HttpLoggingMiddleware によって出力されるログリクエストが来たのは分かる。レスポンスを返したのも分かる。
HttpLogging21• 同じエンドポイントを同時に叩くと…HttpLoggingMiddleware によって出力されるログどのリクエストにどのリスポンスを返したのかは分からない…!リクエストが来たのは分かる。レスポンスを返したのも分かる。
HttpLogging22• 同じエンドポイントを同時に叩くと…HttpLoggingMiddleware によって出力されるログどのリクエストにどのリスポンスを返したのかは分からない…!リクエストが来たのは分かる。レスポンスを返したのも分かる。当然このままではビジネスロジックのログもリクエストとは無関係…!
ConsoleFormatterOptions.IncludeScopes23
ConsoleFormatterOptions.IncludeScopes24設定はいたって簡単
ConsoleFormatterOptions.IncludeScopes25設定はいたって簡単
ConsoleFormatterOptions.IncludeScopes26• SpanId , TraceId, ParentId がログに含まれるようになる。• これが嬉しい。• 他にも RequestPath とか ConnectionId とかいろいろ。IncludeScopes を true に設定した場合のログ
ConsoleFormatterOptions.IncludeScopes27• SpanId , TraceId, ParentId がログに含まれるようになる。• これが嬉しい。• 他にも RequestPath とか ConnectionId とかいろいろ。IncludeScopes を true に設定した場合のログ
ConsoleFormatterOptions.IncludeScopes28リクエスト毎のログを追えるようになる…!
ConsoleFormatterOptions.IncludeScopes29リクエスト毎のログを追えるようになる…!
ConsoleFormatterOptions.IncludeScopes30リクエスト毎のログを追えるようになる…!
ConsoleFormatterOptions.IncludeScopes31• 「ログにスコープを含める」かどうかのオプション。SpanId とか TraceId をログに出すためのオプションではない
ConsoleFormatterOptions.IncludeScopes32• 「ログにスコープを含める」かどうかのオプション。SpanId とか TraceId をログに出すためのオプションではない適当にログのスコープを切ってあげると..
ConsoleFormatterOptions.IncludeScopes33• 「ログにスコープを含める」かどうかのオプション。SpanId とか TraceId をログに出すためのオプションではない
ConsoleFormatterOptions.IncludeScopes34• 「ログにスコープを含める」かどうかのオプション。SpanId とか TraceId をログに出すためのオプションではない
ConsoleFormatterOptions.IncludeScopes35• 「ログにスコープを含める」かどうかのオプション。SpanId とか TraceId をログに出すためのオプションではないMyScope!!
W3C Trace Context36
W3C Trace Context37Span 1Span 3Span 5Span 2Span 4Service AService BService CTraceHTTP分散トレースのための仕組み。• ASP.NET Core 的には分散システムじゃなくても有益。
W3C Trace Context38Span 1Span 3Span 5Span 2Span 4Service AService BService CTraceHTTP分散トレースのための仕組み。• ASP.NET Core 的には分散システムじゃなくても有益。W3C Trace Context のより詳細は以下のブログで。【C#】ASP.NET Core とW3C Trace Context とお手軽ロギング。https://blog.neno.dev/entry/2023/07/04/181843
ExceptionHandler39
ExceptionHandler40• Development• DeveloperExceptionPageMiddleware が自動で追加される• 例外が起きたとき HTTP の Response に stack trace が含まれたりするのはこのミドルウェアがそういう仕事をしている• Staging / Production• 未処理の例外をハンドリングするためのミドルウェアは自動で追加されない• その結果どうなるかというと…ENVIRONMENT 次第で未処理の例外のハンドリングが変わる
ExceptionHandler41既定の構成 + ENVIRONMENT= Production で例外が発生した場合
ExceptionHandler42既定の構成 + ENVIRONMENT= Production で例外が発生した場合例外が Kestrel にまで突き抜けてしまっている..
ExceptionHandler43既定の構成 + ENVIRONMENT= Production で例外が発生した場合例外が Kestrel にまで突き抜けてしまっている..HttpLogging の Response に関するログも残らない…!
ExceptionHandler44• AddProblemDetails• RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを作成するためのサービスの追加• UseExceptionHandler• 未処理の例外をハンドリングするためのミドルウェアを追加• UseHttpLogging() の下に。UseExceptionHandler で未処理の例外をハンドリング
ExceptionHandler45UseExceptionHandler を利用した場合のログ
ExceptionHandler46UseExceptionHandler を利用した場合のログ例外が Kestrel にまで突き抜けてない
ExceptionHandler47UseExceptionHandler を利用した場合のログ例外が Kestrel にまで突き抜けてないHttpLogging の Response に関するログがしっかり残る…!
ExceptionHandler48• RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを返すようになる。• traceId が含まれるようになるのが嬉しい。かもしれない。例外発生時のレスポンス
DbDataSource49
DbDataSource50• Npgsql / MySqlConnector は対応済み。• https://github.com/npgsql/npgsql• https://github.com/mysql-net/MySqlConnector.NET 7 で追加された ADO.NET の新しい APIhttps://github.com/dotnet/runtime/issues/64812
DbDataSource51• Npgsql / MySqlConnector は対応済み。• https://github.com/npgsql/npgsql• https://github.com/mysql-net/MySqlConnector.NET 7 で追加された ADO.NET の新しい APIhttps://github.com/dotnet/runtime/issues/64812提案者はNpgsql の中の人(MS の中の人でもある)
DbDataSource52• Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する• UseLoggerFactory() で loggerFactory を渡す。• これだけで Command が叩かれた際によしなにログを出してくれるようにDbDataSource はロギングの観点でも嬉しい
DbDataSource53• Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する• UseLoggerFactory() で loggerFactory を渡す。• これだけで Command が叩かれた際によしなにログを出してくれるように少なくとも Npgsql ではDbDataSource はロギングの観点でも嬉しい
DbDataSource54• Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する• UseLoggerFactory() で loggerFactory を渡す。• これだけで Command が叩かれた際によしなにログを出してくれるように少なくとも Npgsql ではDbDataSource の提案者がNpgsql の中の人なだけに各実装でも Npgsql の実装に寄せてくると思われるDbDataSource はロギングの観点でも嬉しい
DbDataSource55実際に出力されるログ。
DbDataSource56実際に出力されるログ。
DbDataSource57実際に出力されるログ。SpanId / TraceId がちゃんとログに含まれているため、どのリクエストでどのクエリが発行されたのか一目瞭然
DbDataSource58実際に出力されるログ。SpanId / TraceId がちゃんとログに含まれているため、どのリクエストでどのクエリが発行されたのか一目瞭然親切に duration (ms) もよしなに表示してくれる
HttpClientFactory59
HttpClientFactory60• ASP.NET Core では HttpClient は直接 new してキャッシュせず、HttpClientFactory を使うのがそもそものベストプラクティス [1]HttpClientFactory はロギングの観点でも嬉しい[1] https://learn.microsoft.com/en-us/dotnet/architecture/microservices/implement-resilient-applications/use-httpclientfactory-to-implement-resilient-http-requests[2] https://github.com/nenoNaninu/TraceContextExample
HttpClientFactory61実際に出力されるログ。https://github.com/nenoNaninu/TraceContextExample
HttpClientFactory62実際に出力されるログ。https://github.com/nenoNaninu/TraceContextExample
HttpClientFactory63実際に出力されるログ。https://github.com/nenoNaninu/TraceContextExampleリクエストとレスポンスの双方をログに出力
HttpClientFactory64実際に出力されるログ。親切にレスポンスが返ってくるまでの時間もよしなに表示してくれるhttps://github.com/nenoNaninu/TraceContextExampleリクエストとレスポンスの双方をログに出力
まとめ65• AddHttpLogging / UseHttpLogging• Inbound HTTP request / response がログとして出力される• LoggingFields は RequestProperties | ResponseStatusCode がオススメ。• ログレベルの設定を忘れずに。• ConsoleFormatterOptions.IncludeScopes• ログのスコープが出力に含まれるようになる。• SpanId / TraceId / ParentId が表示されて嬉しい。• W3C Trace Context• 詳細はこちら : https://blog.neno.dev/entry/2023/07/04/181843• AddProblemDetails / UseExceptionHandler• 未処理の例外をハンドリング / RFC 7807• DbDataSource• Npgsql ではすべての Command がログとして出力される• HttpClientFactory• Outbound HTTP request / response がログとして出力される
References66• https://github.com/dotnet/runtime/tree/v7.0.8• https://github.com/dotnet/aspnetcore/tree/v7.0.8• https://github.com/dotnet/runtime/issues/64812• https://learn.microsoft.com/en-us/aspnet/core/fundamentals/http-logging/?view=aspnetcore-7.0• https://learn.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-7.0• https://learn.microsoft.com/en-us/aspnet/core/fundamentals/error-handling?view=aspnetcore-7.0• https://learn.microsoft.com/en-us/dotnet/architecture/microservices/implement-resilient-applications/use-httpclientfactory-to-implement-resilient-http-requests• https://learn.microsoft.com/en-us/dotnet/core/diagnostics/distributed-tracing-concepts• https://www.w3.org/TR/trace-context/