明日から使える ASP.NET Core ロギング術！

.NET ラボ 2023/07/22 での発表資料

↓↓↓ 登壇内容をある程度文字起こししたブログ ↓↓↓
【C#】明日から使える ASP.NET Core ロギング術！

Transcript

1. 明日から使える ASP.NET Core ロギング術！ .NET ラボ 2023/07/22 何縫ねの。
2. 自己紹介 1 • 所属: NTTコミュニケーションズ イノベーションセンター • 趣味: C#, OSS, ドール, 一眼(α7 IV) • 執心領域 • C# ⇔ TypeScript • SignalR 何縫ねの。 nenoNaninu nenoMake ブログ https://blog.neno.dev その他 https://neno.dev
3. OSS 紹介 2 属性を付与するだけ Tapper • C# の型定義から TypeScript の型定義を生成する .NET Tool/ library • JSON / MessagePack 対応！ https://github.com/nenoNaninu/Tapper
4. OSS 紹介 3 • C# の SignalR Client を強く型付けするための Source Generator TypedSignalR.Client Before After (using TypedSignalR.Client) こんな SignalR の Hub と Receiver の interface が あったとして… 脱文字列！ 全てが強く型付け！ https://github.com/nenoNaninu/TypedSignalR.Client
5. 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 紹介
6. 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 紹介
7. ConsoleFormatter 6
8. ConsoleFormatter 7 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。
9. ConsoleFormatter 8 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定
10. ConsoleFormatter 9 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定
11. ConsoleFormatter 10 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 internal なクラス 以下のように拡張メソッドで設定 このセッション中での 例は全て SimpleConsole
12. ConsoleFormatter 11 • Microsoft.Extensions.Logging には以下のようなクラスが存在する。 • SimpleConsoleFormatter • JsonConsoleFormatter • SystemdConsoleFormatter コンソールにログを出力際のフォーマットは複数ある。 スライドで JsonConsole の ログ見せられても 見辛いだけなので internal なクラス 以下のように拡張メソッドで設定 このセッション中での 例は全て SimpleConsole
13. HttpLogging 12
14. HttpLogging 13 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。
15. HttpLogging 14 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく
16. HttpLogging 15 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく
17. HttpLogging 16 • AddHttpLogging • 何をログに出力するかの設定を行う。 • 特定のヘッダやクエリを出力したりも可能 • UseHttpLogging • ログを出力するためのミドルウェアを request pipeline に追加 HTTP のリクエスト/リスポンスに関するログを出力したい。 HttpLoggingFields (enum) を ビット演算でくっつけていく 出し過ぎには注意 パフォーマンス & GDPR
18. HttpLogging 17 • ログレベルの設定も必要 • appsettings.json 等で Microsoft.AspNetCore.HttpLogging の ログレベルを Information にしておく HTTP のリクエスト/リスポンスに関するログを出力したい。
19. HttpLogging 18 • なかなか良さそう。 • 本当に？ HttpLoggingMiddleware によって出力されるログ
20. HttpLogging 19 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ
21. HttpLogging 20 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。
22. HttpLogging 21 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ どのリクエストに どのリスポンスを 返したのかは分からない…! リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。
23. HttpLogging 22 • 同じエンドポイントを同時に叩くと… HttpLoggingMiddleware によって出力されるログ どのリクエストに どのリスポンスを 返したのかは分からない…! リクエストが 来たのは分かる。 レスポンスを 返したのも分かる。 当然このままでは ビジネスロジックのログも リクエストとは無関係…!
24. ConsoleFormatterOptions .IncludeScopes 23
25. ConsoleFormatterOptions.IncludeScopes 24 設定はいたって簡単
26. ConsoleFormatterOptions.IncludeScopes 25 設定はいたって簡単
27. ConsoleFormatterOptions.IncludeScopes 26 • SpanId , TraceId, ParentId がログに含まれるようになる。 • これが嬉しい。 • 他にも RequestPath とか ConnectionId とかいろいろ。 IncludeScopes を true に設定した場合のログ
28. ConsoleFormatterOptions.IncludeScopes 27 • SpanId , TraceId, ParentId がログに含まれるようになる。 • これが嬉しい。 • 他にも RequestPath とか ConnectionId とかいろいろ。 IncludeScopes を true に設定した場合のログ
29. ConsoleFormatterOptions.IncludeScopes 28 リクエスト毎のログを追えるようになる…!
30. ConsoleFormatterOptions.IncludeScopes 29 リクエスト毎のログを追えるようになる…!
31. ConsoleFormatterOptions.IncludeScopes 30 リクエスト毎のログを追えるようになる…!
32. ConsoleFormatterOptions.IncludeScopes 31 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない
33. ConsoleFormatterOptions.IncludeScopes 32 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない 適当にログのスコープを 切ってあげると..
34. ConsoleFormatterOptions.IncludeScopes 33 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない
35. ConsoleFormatterOptions.IncludeScopes 34 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない
36. ConsoleFormatterOptions.IncludeScopes 35 • 「ログにスコープを含める」かどうかのオプション。 SpanId とか TraceId をログに出すためのオプションではない MyScope!!
37. W3C Trace Context 36
38. 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 的には分散システムじゃなくても有益。
39. 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
40. ExceptionHandler 39
41. ExceptionHandler 40 • Development • DeveloperExceptionPageMiddleware が自動で追加される • 例外が起きたとき HTTP の Response に stack trace が含まれたりするのは このミドルウェアがそういう仕事をしている • Staging / Production • 未処理の例外をハンドリングするためのミドルウェアは自動で追加されない • その結果どうなるかというと… ENVIRONMENT 次第で未処理の例外のハンドリングが変わる
42. ExceptionHandler 41 既定の構成 + ENVIRONMENT= Production で例外が発生した場合
43. ExceptionHandler 42 既定の構成 + ENVIRONMENT= Production で例外が発生した場合 例外が Kestrel にまで 突き抜けてしまっている..
44. ExceptionHandler 43 既定の構成 + ENVIRONMENT= Production で例外が発生した場合 例外が Kestrel にまで 突き抜けてしまっている.. HttpLogging の Response に 関するログも残らない…!
45. ExceptionHandler 44 • AddProblemDetails • RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを作成する ためのサービスの追加 • UseExceptionHandler • 未処理の例外をハンドリングするためのミドルウェアを追加 • UseHttpLogging() の下に。 UseExceptionHandler で未処理の例外をハンドリング
46. ExceptionHandler 45 UseExceptionHandler を利用した場合のログ
47. ExceptionHandler 46 UseExceptionHandler を利用した場合のログ 例外が Kestrel にまで 突き抜けてない
48. ExceptionHandler 47 UseExceptionHandler を利用した場合のログ 例外が Kestrel にまで 突き抜けてない HttpLogging の Response に 関するログがしっかり残る…!
49. ExceptionHandler 48 • RFC 7807 “Problem Details for HTTP APIs” に準拠したレスポンスを 返すようになる。 • traceId が含まれるようになるのが嬉しい。かもしれない。 例外発生時のレスポンス
50. DbDataSource 49
51. 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
52. 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 の中の人でもある)
53. DbDataSource 52 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように DbDataSource はロギングの観点でも嬉しい
54. DbDataSource 53 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように 少なくとも Npgsql では DbDataSource はロギングの観点でも嬉しい
55. DbDataSource 54 • Npgsql の場合、NpgsqlDataSourceBuilder で DbDataSource を作成する • UseLoggerFactory() で loggerFactory を渡す。 • これだけで Command が叩かれた際によしなにログを出してくれるように 少なくとも Npgsql では DbDataSource の提案者が Npgsql の中の人なだけに 各実装でも Npgsql の 実装に寄せてくると 思われる DbDataSource はロギングの観点でも嬉しい
56. DbDataSource 55 実際に出力されるログ。
57. DbDataSource 56 実際に出力されるログ。
58. DbDataSource 57 実際に出力されるログ。 SpanId / TraceId がちゃんとログに 含まれているため、どのリクエストで どのクエリが発行されたのか一目瞭然
59. DbDataSource 58 実際に出力されるログ。 SpanId / TraceId がちゃんとログに 含まれているため、どのリクエストで どのクエリが発行されたのか一目瞭然 親切に duration (ms) も よしなに表示してくれる
60. HttpClientFactory 59
61. 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
62. HttpClientFactory 61 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample
63. HttpClientFactory 62 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample
64. HttpClientFactory 63 実際に出力されるログ。 https://github.com/nenoNaninu/TraceContextExample リクエストとレスポンスの 双方をログに出力
65. HttpClientFactory 64 実際に出力されるログ。 親切にレスポンスが 返ってくるまでの時間も よしなに表示してくれる https://github.com/nenoNaninu/TraceContextExample リクエストとレスポンスの 双方をログに出力
66. まとめ 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 がログとして出力される
67. 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/