# ロギング

Source: https://docs.sisk-framework.org/ja/docs/features/logging.html

Sisk を構成して、アクセスログとエラーログを自動的に書き込むことができます。ログのローテーション、拡張子、書き込み頻度を定義することも可能です。

[LogStream](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.md) クラスは、非同期でログを書き込み、await 可能な書き込みキューに保持する方法を提供します。`LogStream` クラスは `IAsyncDisposable` を実装しており、ストリームが閉じられる前に保留中のすべてのログが書き込まれることを保証します。

本稿では、アプリケーションのロギングを設定する方法を示します。

## ファイルベースのアクセスログ

ファイルへのログは、ファイルを開き、行テキストを書き込み、書き込んだ行ごとにファイルを閉じます。この手順は、ログの書き込み応答性を維持するために採用されています。

```cs {title="Program.cs"}
class Program
{
    static async Task Main(string[] args)
    {
        using var app = HttpServer.CreateBuilder()
            .UseConfiguration(config => {
                config.AccessLogsStream = new LogStream("logs/access.log");
            })
            .Build();
        
        ...
        
        await app.StartAsync();
    }
}
```

上記のコードは、すべての受信リクエストを `logs/access.log` ファイルに書き込みます。ファイルが存在しない場合は自動的に作成されますが、フォルダーは自動で作成されません。`LogStream` クラスがフォルダーを自動的に作成するため、`logs/` ディレクトリを事前に作成する必要はありません。

## ストリームベースのロギング

コンストラクターに `TextWriter` オブジェクトを渡すことで、`Console.Out` などの `TextWriter` インスタンスにログファイルを書き込むことができます。

```cs {title="Program.cs"}
using var app = HttpServer.CreateBuilder()
    .UseConfiguration(config => {
        config.AccessLogsStream = new LogStream(Console.Out);
    })
    .Build();
```

ストリームベースのログに書き込まれるたびに、`TextWriter.Flush()` メソッドが呼び出されます。

## アクセスログのフォーマット

事前定義された変数でアクセスログのフォーマットをカスタマイズできます。以下の行を例にしてください。

```cs
config.AccessLogsFormat = "%dd/%dmm/%dy %tH:%ti:%ts %tz %ls %ri %rs://%ra%rz%rq [%sc %sd] %lin -> %lou in %lmsms [%{user-agent}]";
```

次のようなメッセージが書き込まれます。

    29/mar./2023 15:21:47 -0300 Executed ::1 http://localhost:5555/ [200 OK] 689B -> 707B in 84ms [Mozilla/5.0 (Windows NT 10.0; Win64; x64) Chrome/111.0.0.0 Safari/537.36]

以下の表に示すフォーマットでログファイルを整形できます。

| Value | What it represents | Example |
|--------|--------------------|---------|
| %dd | 月の日付 (2桁) | 05 |
| %dmmm | 月の完全名 | July |
| %dmm | 月の省略名 (3文字) | Jul |
| %dm | 月番号 (2桁) | 07 |
| %dy | 年 (4桁) | 2023 |
| %th | 12時間制の時 | 03 |
| %tH | 24時間制の時 (HH) | 15 |
| %ti | 分 (2桁) | 30 |
| %ts | 秒 (2桁) | 45 |
| %tm | ミリ秒 (3桁) | 123 |
| %tz | タイムゾーンオフセット (UTC の合計時間) | +03:00 |
| %ri | リクエスト開始時に解決されたクライアントのリモート IP アドレス | 192.168.1.100 |
| %rm | HTTP メソッド (大文字) | GET |
| %rs | URI スキーム (http/https) | https |
| %ra | URI 権限部 (ドメイン) | example.com |
| %rh | リクエストのホスト | www.example.com |
| %rp | リクエストのポート | 443 |
| %rz | リクエストのパス | /path/to/resource |
| %rq | クエリ文字列 | ?key=value&another=123 |
| %sc | HTTP 応答ステータスコード | 200 |
| %sd | HTTP 応答ステータスの説明 | OK |
| %lin | リクエストの人間が読めるサイズ | 1.2 KB |
| %linr | リクエストの生サイズ (バイト) | 1234 |
| %lou | レスポンスの人間が読めるサイズ | 2.5 KB |
| %lour | レスポンスの生サイズ (バイト) | 2560 |
| %lms | 経過時間 (ミリ秒) | 120 |
| %ls | 実行ステータス | Executed |
| %{header-name} | リクエストの `header-name` ヘッダーを表す | `Mozilla/5.0 (platform; rv:gecko [...]` |
| %{:header-name} | レスポンスの `header-name` ヘッダーを表す | `application/json` |
| %{$key} | [HttpContext.RequestBag] に格納された `key` の値を `ToString()` で変換したものを表す。キーが設定されていない場合は空 | `42` |

`HttpServerConfiguration.DefaultAccessLogFormat` を使用して、デフォルトのアクセスログフォーマットを利用することもできます。

`%{$key}` 項目を使用すると、リクエストハンドラやルートが独自の値をアクセスログに追加できます。

```cs
config.AccessLogsFormat = "%dd/%dmm/%dy %tH:%ti:%ts %rm %rz [%sc] user=%{$UserId}";

router.MapGet("/profile", request =>
{
    request.Bag["UserId"] = "42";
    return new HttpResponse("ok");
});
```

## ログのローテーション

HTTP サーバーを構成して、一定サイズに達したときにログファイルを圧縮された .gz ファイルにローテーションできます。サイズは定義したしきい値で定期的にチェックされます。

```cs
LogStream errorLog = new LogStream("logs/error.log")
    .ConfigureRotatingPolicy(
        maximumSize: 64 * SizeHelper.UnitMb,
        dueTime: TimeSpan.FromHours(6));
```

上記のコードは、6 時間ごとに `LogStream` のファイルが 64 MB の上限に達しているかを確認します。上限に達していれば、ファイルは .gz に圧縮され、`access.log` がクリーンアップされます。

この処理中は、ファイルへの書き込みはロックされ、圧縮とクリーンアップが完了するまで待機します。この期間に書き込まれた行はすべてキューに入れられ、圧縮完了を待ちます。

この機能はファイルベースの LogStream のみで動作します。

## エラーロギング

サーバーがデバッガーに例外を送出しない場合、エラーが存在すればログに転送されます。エラー書き込みは次のように構成できます。

```cs
config.ThrowExceptions = false;
config.ErrorsLogsStream = new LogStream("error.log");
```

このプロパティは、エラーがコールバックまたは [Router.CallbackErrorHandler](https://docs.sisk-framework.org/api/Sisk.Core.Routing.Router.CallbackErrorHandler.md) プロパティで捕捉されなかった場合にのみログに書き込みます。

サーバーが書き込むエラーは常に日時、リクエストヘッダー（ボディは除く）、エラートレース、内部例外トレース（存在する場合）を含みます。

## その他のロギングインスタンス

アプリケーションは 0 個または複数の LogStream を持つことができ、チャネル数に制限はありません。したがって、デフォルトの AccessLog や ErrorLog 以外のファイルにアプリケーションのログを出力することが可能です。

```cs
LogStream appMessages = new LogStream("messages.log");
appMessages.WriteLine("Application started at {0}", DateTime.Now);
```

## ファイルの安全な書き込み

ログストリーム以外のファイル（レポートや状態ダンプなど）については、[LogStream](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.md) が静的ヘルパーを提供し、欠落している親ディレクトリを作成し、同一プロセス内で同じファイルへの同時書き込みをシリアライズし、失敗時には例外を投げずに `false` を返します。

- [LogStream.SafeWriteToFile](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.SafeWriteToFile.md) と [LogStream.SafeWriteToFileAsync](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.SafeWriteToFileAsync.md) はファイル内容を置き換えます。
- [LogStream.SafeAppendToFile](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.SafeAppendToFile.md) と [LogStream.SafeAppendToFileAsync](https://docs.sisk-framework.org/api/Sisk.Core.Http.LogStream.SafeAppendToFileAsync.md) はファイルに追記します。

各メソッドは文字列または文字列配列を受け取り、`Encoding` を受け取るオーバーロードも用意されています。

```cs
bool written = await LogStream.SafeAppendToFileAsync("logs/audit.log", $"{DateTime.Now:s} user signed in\n");

if (!written)
{
    Console.WriteLine("Could not write the audit entry.");
}
```

ロックはプロセス単位です。他プロセスから同じファイルへの書き込みは調整されません。ディレクトリが存在することだけを確認したい場合は、[PathHelper.EnsureDirectoryExistance](https://docs.sisk-framework.org/api/Sisk.Core.Helpers.PathHelper.EnsureDirectoryExistance.md) または [PathHelper.EnsureFileDirectoryExistance](https://docs.sisk-framework.org/api/Sisk.Core.Helpers.PathHelper.EnsureFileDirectoryExistance.md) を使用してください。これらはディレクトリが既に存在すれば `true`、作成した場合は `false` を返します。

## LogStream の拡張

`LogStream` クラスを拡張して、現在の Sisk ログエンジンと互換性のあるカスタムフォーマットを書き込むことができます。以下の例は Spectre.Console ライブラリを使用してコンソールにカラー付きメッセージを書き込む方法を示しています。

```cs {title="CustomLogStream.cs"}
public class CustomLogStream : LogStream
{
    protected override void WriteLineInternal(string line)
    {
        base.WriteLineInternal($"[{DateTime.Now:g}] {line}");
    }
}
```

各リクエスト/レスポンスごとにカスタムログを自動的に書き込む別の方法として、[HttpServerHandler](https://docs.sisk-framework.org/api/Sisk.Core.Http.Handlers.HttpServerHandler.md) を作成します。以下の例はやや完全な形です。リクエストとレスポンスの本文を JSON 形式でコンソールに出力します。リクエスト全体のデバッグに役立ちます。この例は ContextBag と HttpServerHandler を利用しています。

```cs {title="Program.cs"}
class Program
{
    static async Task Main(string[] args)
    {
        var app = HttpServer.CreateBuilder(host =>
        {
            host.UseListeningPort(5555);
            host.UseHandler<JsonMessageHandler>();
        });

        app.Router.MapAny("/json", request =>
        {
            return new HttpResponse()
                .WithContent(JsonContent.Create(new
                {
                    method = request.Method.Method,
                    path = request.Path,
                    specialMessage = "Hello, world!!"
                }));
        });

        await app.StartAsync();
    }
}
```

```cs {title="JsonMessageHandler.cs"}
class JsonMessageHandler : HttpServerHandler
{
    protected override void OnHttpRequestOpen(HttpRequest request)
    {
        if (request.Method != HttpMethod.Get && request.Headers["Content-Type"]?.Contains("json", StringComparison.InvariantCultureIgnoreCase) == true)
        {
            // この時点で接続はオープンしており、クライアントはコンテンツが JSON であることを示すヘッダーを送信しています。
            // 以下の行でコンテンツを読み取り、リクエストに保持させます。
            //
            // リクエスト処理でコンテンツを読み取らない場合、GC がコンテンツを回収してしまい、クライアントへのレスポンス送信後にコンテンツが利用できなくなる可能性があります。
            //
            _ = request.RawBody;

            // コンテキストにヒントを追加し、このリクエストが JSON ボディを持つことを示します
            request.Bag.Add("IsJsonRequest", true);
        }
    }

    protected override async void OnHttpRequestClose(HttpServerExecutionResult result)
    {
        string? requestJson = null,
                responseJson = null,
                responseMessage;

        if (result.Request.Bag.ContainsKey("IsJsonRequest"))
        {
            // CypherPotato.LightJson ライブラリを使用して JSON を整形します
            var content = result.Request.Body;
            requestJson = JsonValue.Deserialize(content, new JsonOptions() { WriteIndented = true }).ToString();
        }
        
        if (result.Response is { } response)
        {
            var content = response.Content;
            responseMessage = $"{(int)response.Status} {HttpStatusInformation.GetStatusCodeDescription(response.Status)}";
            
            if (content is HttpContent httpContent &&
                // レスポンスが JSON かどうかをチェック
                httpContent.Headers.ContentType?.MediaType?.Contains("json", StringComparison.InvariantCultureIgnoreCase) == true)
            {
                string json = await httpContent.ReadAsStringAsync();
                responseJson = JsonValue.Deserialize(json, new JsonOptions() { WriteIndented = true }).ToString();
            }
        }
        else
        {
            // 内部サーバーの処理ステータスを取得
            responseMessage = result.Status.ToString();
        }
        
        StringBuilder outputMessage = new StringBuilder();

        if (requestJson != null)
        {
            outputMessage.AppendLine("-----");
            outputMessage.AppendLine($">>> {result.Request.Method} {result.Request.Path}");

            if (requestJson is not null)
                outputMessage.AppendLine(requestJson);
        }

        outputMessage.AppendLine($"<<< {responseMessage}");

        if (responseJson is not null)
            outputMessage.AppendLine(responseJson);

        outputMessage.AppendLine("-----");

        await Console.Out.WriteLineAsync(outputMessage.ToString());
    }
}
```