Upgrade to Pro — share decks privately, control downloads, hide ads and more …

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

neno
July 22, 2023

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

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

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

neno

July 22, 2023
Tweet

More Decks by neno

Other Decks in Technology

Transcript

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

    View full-size slide

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

    View full-size slide

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

    View full-size 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 full-size 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 full-size 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 full-size slide

  7. ConsoleFormatter
    6

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

  13. HttpLogging
    12

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

  24. ConsoleFormatterOptions
    .IncludeScopes
    23

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

  37. W3C Trace Context
    36

    View full-size 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 full-size 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 full-size slide

  40. ExceptionHandler
    39

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

  50. DbDataSource
    49

    View full-size 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 full-size 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 full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

  60. HttpClientFactory
    59

    View full-size 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 full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size slide

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

    View full-size 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 full-size 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 full-size slide