【Laravel】HTTPクライアント使用時、リクエストとレスポンスのログを取得する



## 環境
```
$ sail php -v
PHP 8.2.13 (cli) (built: Nov 24 2023 08:47:18) (NTS)
```

```
$ sail artisan --version
Laravel Framework 10.39.0
```

## 目的
* 外部サービスとの連携時にリクエストとレスポンスのログを取得したい
* リクエスト、レスポンス毎にログを出力する/しないを制御したい、ログレベルによる出力制御もしたい


## 前提
* [Illuminate/Support/Facades/Http](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Support/Facades/Http.php) を利用する
    * ログ取得には以下のイベントを利用する
        * [Illuminate/Http/Client/Events/RequestSending](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Http/Client/Events/RequestSending.php)
        * [Illuminate/Http/Client/Events/ResponseReceived](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Http/Client/Events/ResponseReceived.php)
* リクエスト、レスポンスともに Content-Type が application/json である

## やり方

### ログチャンネルを作成

```php:config/logging.php
    // 略
    
    'http_client' => [
        'driver' => 'daily',
        'path' => storage_path('logs/http_client.log'), // ログの出力場所
        'level' => env('HTTP_CLIENT_LOG_LEVEL', 'debug'),
        'days' => 14,
        'replace_placeholders' => true,
    ],

    // 略
```

### .env と config
* 以下の通り、.envの設定を変えることでログを出力する/しないを切り替え可能

```text:.env
###############################################################################
# HTTPクライアントのログ出力設定
#     ENABLE_LOG_REQUEST_SENDING : リクエスト送信時のログを出力するかどうか
#         true : 出力する, false : 出力しない
#         キーまたは値がない or 不正なときは false とみなす
#     ENABLE_LOG_RESPONSE_RECEIVED : レスポンス受信時のログを出力するかどうか
#         true : 出力する, false : 出力しない
#         キーまたは値がない or 不正なときは false とみなす
#     HTTP_CLIENT_LOG_LEVEL : ログレベル
###############################################################################
ENABLE_LOG_REQUEST_SENDING=true
ENABLE_LOG_RESPONSE_RECEIVED=true
HTTP_CLIENT_LOG_LEVEL=debug
```

```php:config/http_client.php
<?php

return [
    'enable_log_request_sending'   => env('ENABLE_LOG_REQUEST_SENDING'  , false),
    'enable_log_response_received' => env('ENABLE_LOG_RESPONSE_RECEIVED', false),
];
```

### イベントサブスクライバ & ログ取得の処理

```php:app/Listeners/HttpClientLogSubscriber.php
<?php

namespace App\Listeners;

use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Events\Dispatcher;
use Illuminate\Http\Client\Events\RequestSending;
use Illuminate\Http\Client\Events\ResponseReceived;
use Illuminate\Http\Client\Request;
use Illuminate\Http\Client\Response;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Support\Str;
use Symfony\Component\HttpFoundation\Request as SymfonyRequest;

class HttpClientLogSubscriber
{
    // リクエストとレスポンスを紐付けるためのUUID
    protected string $uuid = '';

    // リクエスト送信時のログを出力するかどうか
    protected bool $enableLogRequestSending   = false;
    // リクエスト受信時のログを出力するかどうか
    protected bool $enableLogResponseReceived = false;

    /**
     * Create the event listener.
     */
    public function __construct()
    {
        $this->uuid = Str::uuid();

        $this->enableLogRequestSending   = config('http_client.enable_log_request_sending');
        $this->enableLogResponseReceived = config('http_client.enable_log_response_received');
    }

    /**
     * subscribe
     *
     * @param  Dispatchers $events
     * @return array<string, string>
     */
    public function subscribe(Dispatcher $events) : array
    {
        return [
            RequestSending::class   => 'logRequestSending',
            ResponseReceived::class => 'logResponseReceived',
        ];
    }

    /**
     * リクエスト送信時のログを出力する
     *
     * @param  RequestSending $event
     * @return void
     */
    public function logRequestSending(RequestSending $event) : void
    {
        if(!$this->enableLogRequestSending) {
            return;
        }

        // ログの内容
        $request = $event->request;
        $data = [
            'uuid'    => $this->uuid,
            'event'   => RequestSending::class,
            'request' => $this->requestLog($request),
        ];

        // ログ出力
        $this->writeLog($data);
    }

    /**
     * レスポンス受信時のログを出力する
     *
     * @param  ResponseReceived $event
     * @return void
     */
    public function logResponseReceived(ResponseReceived $event) : void
    {
        if(!$this->enableLogResponseReceived) {
            return;
        }

        // ログの内容
        $request  = $event->request;
        $response = $event->response;
        $data = [
            'uuid'     => $this->uuid,
            'event'    => ResponseReceived::class,
            'request'  => $this->requestLog($request),
            'response' => $this->responseLog($response),
        ];

        // ログ出力
        $response->successful()
            ? $this->writeLog($data)
            : $this->writeLog($data, as:'error');
    }

    /**
     * リクエスト送信時のログ
     *
     * @param  Request $request
     * @return array
     */
    protected function requestLog(Request $request) : array
    {
        return [
            'method'  => $request->method(),
            'url'     => $request->url(),
            'headers' => $request->headers(),
            'body'    => json_decode($request->body(), true),
            'query'   => $request->method() === SymfonyRequest::METHOD_GET
                            ? $request->data()
                            : null,
        ];
    }

    /**
     * レスポンス受信時のログ
     *
     * @param  Response $response
     * @return array
     */
    protected function responseLog(Response $response) : array
    {
        return [
            'status' => $response->status(),
            'body'   => json_decode($response->body(), true),
        ];
    }

    /**
     * ログ出力
     *
     * @param  array $logData
     * @param  string $as
     * @return void
     */
    protected function writeLog(array $logData, string $as = 'info'): void
    {
        logs()->channel('http_client')->{$as}( json_encode($logData, JSON_UNESCAPED_UNICODE) );
    }
}
```

### イベントサブスクライバの登録

```php:app/Providers/EventServiceProvider.php

use App\Listeners\HttpClientLogSubscriber;

// 略

/**
 * The subscribers to register.
 *
 * @var array
 */
protected $subscribe = [
    HttpClientLogSubscriber::class,
];

// 略
```


## ログの出力例
### リクエストのログ
```
{
  "uuid": "c8e17134-01b5-4f73-b783-4a0953bdb278",
  "event": "Illuminate\\Http\\Client\\Events\\RequestSending",
  "request": {
    "method": "POST",
    "url": "https://httpbin.org/post",
    "headers": {
      "Content-Length": [
        "33"
      ],
      "User-Agent": [
        "GuzzleHttp/7"
      ],
      "Host": [
        "httpbin.org"
      ],
      "Content-Type": [
        "application/json"
      ]
    },
    "body": {
      "key1": "value1",
      "key2": "value2"
    },
    "query": null
  }
}
```

### レスポンスのログ
* 'request' の内容は上記の「リクエストのログ」の 'request' の内容と同じ

```text:レスポンスのログ
{
  "uuid": "ec0992e7-c250-444f-8699-f5e5fce097fa",
  "event": "Illuminate\\Http\\Client\\Events\\ResponseReceived",
  "request": {
    "method": "POST",
    "url": "https://httpbin.org/post",
    "headers": {
      "Content-Length": [
        "33"
      ],
      "User-Agent": [
        "GuzzleHttp/7"
      ],
      "Host": [
        "httpbin.org"
      ],
      "Content-Type": [
        "application/json"
      ]
    },
    "body": {
      "key1": "value1",
      "key2": "value2"
    },
    "query": null
  },
  "response": {
    "status": 200,
    "body": {
      "args": [],
      "data": "{\"key1\":\"value1\",\"key2\":\"value2\"}",
      "files": [],
      "form": [],
      "headers": {
        "Content-Length": "33",
        "Content-Type": "application/json",
        "Host": "httpbin.org",
        "User-Agent": "GuzzleHttp/7",
        "X-Amzn-Trace-Id": "Root=1-659a2ebb-3ca17ff01bc9bb6f54211166"
      },
      "json": {
        "key1": "value1",
        "key2": "value2"
      },
      "origin": "hogehoge",
      "url": "https://httpbin.org/post"
    }
  }
}
```

## 課題・残件
* Contetn-Type が application/json 以外への対応
* .env にてログ出力しないように設定した場合でも、イベント(RequestSending, ResponseReceived)は発火してしまう
    * ログを取得しないときは、イベント発火 → (ログ取得処理の開始直後に)即リターン、という流れ
    * ログを取得しないならそもそもイベントの発火自体が不要
* 2つ以上の外部サービスと連携する際のログの出し分けを考慮していない
    * 外部サービスAのログは出力するが、外部サービスBのログは出力しない、といった設定はできない 
* パラメータのマスク
    * 現状、ログに残すべきではない内容があっても全て出力してしまう
    * そういう意味では当記事のログ取得処理はあくまでも開発用である(本番環境で用いるべきではない)

## 今回のコード
* [https://github.com/orange-alien/laravel-blog/pull/7](https://github.com/orange-alien/laravel-blog/pull/7)


## 参考
* [laravel/framework](https://github.com/laravel/framework)
    * [Illuminate/Support/Facades/Http](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Support/Facades/Http.php)
    * [Illuminate/Http/Client/Events/RequestSending](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Http/Client/Events/RequestSending.php)
    * [Illuminate/Http/Client/Events/ResponseReceived](https://github.com/laravel/framework/blob/10.x/src/Illuminate/Http/Client/Events/ResponseReceived.php)
* [ReadDouble](https://readouble.com/)
    * [HTTPクライアント](https://readouble.com/laravel/10.x/ja/http-client.html)
    * [イベント](https://readouble.com/laravel/10.x/ja/events.html)
    * [ログ](https://readouble.com/laravel/10.x/ja/logging.html)