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

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

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

Transcript

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

   View Slide

2. 自己紹介
   1
   • 所属: NTTコミュニケーションズ
   イノベーションセンター
   • 趣味: C#, OSS, ドール, 一眼(α7 IV)
   • 執心領域
   • C# ⇔ TypeScript
   • SignalR
   何縫ねの。
   nenoNaninu
   nenoMake
   ブログ https://blog.neno.dev
   その他 https://neno.dev
   

   View Slide

3. OSS 紹介
   2
   属性を付与するだけ
   Tapper
   • C# の型定義から TypeScript の型定義を生成する .NET Tool/ library
   • JSON / MessagePack 対応！
   https://github.com/nenoNaninu/Tapper
   

   View Slide

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
   

   View Slide

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 紹介
   

   View Slide

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 紹介
   

   View Slide

7. ConsoleFormatter
   6
   

   View Slide

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

   View Slide

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

   View Slide

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

    View Slide

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

    View Slide

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

    View Slide

13. HttpLogging
    12
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

24. ConsoleFormatterOptions
    .IncludeScopes
    23
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

37. W3C Trace Context
    36
    

    View Slide

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 的には分散システムじゃなくても有益。
    

    View Slide

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
    

    View Slide

40. ExceptionHandler
    39
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

50. DbDataSource
    49
    

    View Slide

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
    

    View Slide

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 の中の人でもある)
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

60. HttpClientFactory
    59
    

    View Slide

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
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

65. HttpClientFactory
    64
    実際に出力されるログ。
    親切にレスポンスが
    返ってくるまでの時間も
    よしなに表示してくれる
    https://github.com/nenoNaninu/TraceContextExample
    リクエストとレスポンスの
    双方をログに出力
    

    View Slide

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 がログとして出力される
    

    View Slide

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/
    

    View Slide