明日から使える ASP.NET Core ロギング術！ .NET ラボ 2023/07/22 何縫ねの。

自己紹介 1 • 所属: NTTコミュニケーションズ イノベーションセンター • 趣味: C#, OSS, ドール, 一眼(α7 IV) • 執心領域 • C# ⇔ TypeScript • SignalR 何縫ねの。 nenoNaninu nenoMake ブログ 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 Generator TypedSignalR.Client Before After (using TypedSignalR.Client) こんな SignalR の Hub と Receiver の interface が あったとして… 脱文字列！ 全てが強く型付け！ https://github.com/nenoNaninu/TypedSignalR.Client

4 • TypeScript の SignalR Client を強く型付けするための .NET Tool / library TypedSignalR.Client.TypeScript Before After (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 版 SwaggerUI TypedSignalR.Client.DevTools https://github.com/nenoNaninu/TypedSignalR.Client.DevTools OSS 紹介

ConsoleFormatter 6

ConsoleFormatter 7 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。

ConsoleFormatter 8 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定

ConsoleFormatter 9 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定

ConsoleFormatter 10 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定 このセッション中での 例は全て SimpleConsole

ConsoleFormatter 11 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 スライドで JsonConsole の ログ見せられても 見辛いだけなので internal なクラス 以下のように拡張メソッドで設定 このセッション中での 例は全て SimpleConsole

HttpLogging 12

HttpLogging 13 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。

HttpLogging 14 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく

HttpLogging 15 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく

HttpLogging 16 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく 出し過ぎには注意 パフォーマンス & GDPR

HttpLogging 17 • ログレベルの設定も必要 • appsettings.json 等で Microsoft.AspNetCore.HttpLogging の ログレベルを Information にしておく HTTP のリクエスト/リスポンスに関するログを出力したい。

HttpLogging 18 • なかなか良さそう。 • 本当に？ HttpLoggingMiddleware によって出力されるログ

HttpLogging 19 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ

HttpLogging 20 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。

HttpLogging 21 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ どのリクエストに どのリスポンスを 返したのかは分からない…! リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。

HttpLogging 22 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ どのリクエストに どのリスポンスを 返したのかは分からない…! リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。 当然このままでは ビジネスロジックのログも リクエストとは無関係…!

ConsoleFormatterOptions .IncludeScopes 23

ConsoleFormatterOptions.IncludeScopes 24 設定はいたって簡単

ConsoleFormatterOptions.IncludeScopes 25 設定はいたって簡単

ConsoleFormatterOptions.IncludeScopes 26 • SpanId , TraceId, ParentId がログに含まれるようになる。 • これが嬉しい。 • 他にも RequestPath とか ConnectionId とかいろいろ。 IncludeScopes を true に設定した場合のログ

ConsoleFormatterOptions.IncludeScopes 27 • SpanId , TraceId, ParentId がログに含まれるようになる。 • これが嬉しい。 • 他にも RequestPath とか ConnectionId とかいろいろ。 IncludeScopes を true に設定した場合のログ

ConsoleFormatterOptions.IncludeScopes 28 リクエスト毎のログを追えるようになる…!

ConsoleFormatterOptions.IncludeScopes 29 リクエスト毎のログを追えるようになる…!

ConsoleFormatterOptions.IncludeScopes 30 リクエスト毎のログを追えるようになる…!

ConsoleFormatterOptions.IncludeScopes 31 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない

ConsoleFormatterOptions.IncludeScopes 32 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない 適当にログのスコープを 切ってあげると..

ConsoleFormatterOptions.IncludeScopes 33 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない

ConsoleFormatterOptions.IncludeScopes 34 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない

ConsoleFormatterOptions.IncludeScopes 35 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない MyScope!!

W3C Trace Context 36

W3C Trace Context 37 Span 1 Span 3 Span 5 Span 2 Span 4 Service A Service B Service C Trace HTTP 分散トレースのための仕組み。 • ASP.NET Core 的には分散システムじゃなくても有益。

W3C Trace Context 38 Span 1 Span 3 Span 5 Span 2 Span 4 Service A Service B Service C Trace HTTP 分散トレースのための仕組み。 • ASP.NET Core 的には分散システムじゃなくても有益。 W3C Trace Context のより詳細は以下のブログで。 【C#】ASP.NET Core と W3C Trace Context とお手軽ロギング。 https://blog.neno.dev/entry/2023/07/04/181843

ExceptionHandler 39

ExceptionHandler 40 • Development • DeveloperExceptionPageMiddleware が自動で追加される • 例外が起きたとき HTTP の Response に stack trace が含まれたりするのは このミドルウェアがそういう仕事をしている • Staging / Production • 未処理の例外をハンドリングするためのミドルウェアは自動で追加されない • その結果どうなるかというと… ENVIRONMENT 次第で未処理の例外のハンドリングが変わる

ExceptionHandler 41 既定の構成 + ENVIRONMENT= Production で例外が発生した場合

ExceptionHandler 42 既定の構成 + ENVIRONMENT= Production で例外が発生した場合 例外が Kestrel にまで 突き抜けてしまっている..

ExceptionHandler 43 既定の構成 + ENVIRONMENT= Production で例外が発生した場合 例外が Kestrel にまで 突き抜けてしまっている.. HttpLogging の Response に 関するログも残らない…!

ExceptionHandler 44 • AddProblemDetails • RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを作成する ためのサービスの追加 • UseExceptionHandler • 未処理の例外をハンドリングするためのミドルウェアを追加 • UseHttpLogging() の下に。 UseExceptionHandler で未処理の例外をハンドリング

ExceptionHandler 45 UseExceptionHandler を利用した場合のログ

ExceptionHandler 46 UseExceptionHandler を利用した場合のログ 例外が Kestrel にまで 突き抜けてない

ExceptionHandler 47 UseExceptionHandler を利用した場合のログ 例外が Kestrel にまで 突き抜けてない HttpLogging の Response に 関するログがしっかり残る…!

ExceptionHandler 48 • RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを 返すようになる。 • traceId が含まれるようになるのが嬉しい。かもしれない。 例外発生時のレスポンス

DbDataSource 49

DbDataSource 50 • Npgsql / MySqlConnector は対応済み。 • https://github.com/npgsql/npgsql • https://github.com/mysql-net/MySqlConnector .NET 7 で追加された ADO.NET の新しい API https://github.com/dotnet/runtime/issues/64812

DbDataSource 51 • Npgsql / MySqlConnector は対応済み。 • https://github.com/npgsql/npgsql • https://github.com/mysql-net/MySqlConnector .NET 7 で追加された ADO.NET の新しい API https://github.com/dotnet/runtime/issues/64812 提案者は Npgsql の中の人 (MS の中の人でもある)

DbDataSource 52 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように DbDataSource はロギングの観点でも嬉しい

DbDataSource 53 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように 少なくとも Npgsql では DbDataSource はロギングの観点でも嬉しい

DbDataSource 54 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように 少なくとも Npgsql では DbDataSource の提案者が Npgsql の中の人なだけに 各実装でも Npgsql の 実装に寄せてくると 思われる DbDataSource はロギングの観点でも嬉しい

DbDataSource 55 実際に出力されるログ。

DbDataSource 56 実際に出力されるログ。

DbDataSource 57 実際に出力されるログ。 SpanId / TraceId がちゃんとログに 含まれているため、どのリクエストで どのクエリが発行されたのか一目瞭然

DbDataSource 58 実際に出力されるログ。 SpanId / TraceId がちゃんとログに 含まれているため、どのリクエストで どのクエリが発行されたのか一目瞭然 親切に duration (ms) も よしなに表示してくれる

HttpClientFactory 59

HttpClientFactory 60 • 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

HttpClientFactory 61 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample

HttpClientFactory 62 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample

HttpClientFactory 63 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample リクエストとレスポンスの 双方をログに出力

HttpClientFactory 64 実際に出力されるログ。 親切にレスポンスが 返ってくるまでの時間も よしなに表示してくれる 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 がログとして出力される

References 66 • 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/