Clojure: RingでTodoアプリを作る - logging

![advent_calendar_2024.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2985550/f4cd8ce0-6352-a1d8-4cae-f39dd44f4def.png)

[*Advent Calendar 2024 Day 17*](https://qiita.com/advent-calendar/2024/clojure)

昨日でTodoアプリのベースが完成しました。
今日はHttpログを出せるようにしていきます

## 目標

以下ログを出せるようにしたいと思います

- リクエストログ
    - type("request")
    - timestamp
    - request_uri
    - request_method
- レスポンスログ
    - type("response")
    - timestamp
    - status code
    - request_uri
    - request_method
    - response_time

## SLF4J・logback

SLF4J（Simple Logging Facade for Java）は、Javaアプリケーション向けのロギングAPIの統一インターフェースです。

今回は `clojure.tools.logging` を使うつもりですが、
こちらが`SLF4J`に依存しているため、プロジェクトに依存を追加します。


`SLF4J`を実装しているバックエンドとして、`logback` を`project.clj` に追加していきます

```clojure:project.clj
  :dependencies [[org.clojure/clojure "1.11.1"]
                 [...]
                 [ch.qos.logback/logback-classic "1.4.11"]]
```

これでprojectに`logback`を追加できました

次にlogbackの設定ファイル `resources/logback.xml` を作成します

```xml
<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} %-5level - %msg%n</pattern>
        </encoder>
    </appender>
    <root level="info">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>
```

`2020-01-01 12:00:00 INFO - {"type": "request", ... }`

この設定で↑のような形で出力できるはずです

## clojure.tools.logging

次にlogを出力するために、`clojure.tools.logging` を追加します

```clojure:project.clj
  :dependencies [[org.clojure/clojure "1.11.1"]
                 [...]
                 [ch.qos.logback/logback-classic "1.4.11"]
                 [org.clojure/tools.logging "1.3.0"]]
```

これでログを出す準備ができました。

## ミドルウェアで実装

### リクエストログ

もう一度リクエストログの目標を確認します

- リクエストログ
    - type("request")
    - timestamp
    - request_uri
    - request_method

以上を実現するためのミドルウェアを作成してみました。

```clojure:core.clj
(ns todo.core
  (:require [ring.adapter.jetty :as jetty]
            [ring.util.response :as res]
            [ring.middleware.json :refer [wrap-json-response wrap-json-body]]
            [...]
            [clojure.data.json :as json]
            [clojure.tools.logging :as log]))

(defn- wrap-log-request
  [handler]
  (fn [req]
    (let [current-timestamp (-> (java.time.Instant/now)
                                (.toString))]
      (log/info (json/write-str {:type "request"
                                 :timestamp current-timestamp
                                 :request_uri (:uri req)
                                 :request_method (:request-method req)})))
    (handler req)))

(def handler
  (-> handler'
      (wrap-json-response)
      (wrap-json-body {:keywords? true})
      (wrap-log-request)))

```

logを出力する部分は `clojure.tools.logging`を使用し、
jsonに変換する部分は `ring.middleware.json` を使いました。

実際にリクエストを送ってみます

```bash
$ lein run
2024-12-14 23:50:55 INFO  - {"type":"request","timestamp":"2024-12-14T14:50:55.825355298Z","request_uri":"\/v1\/todos","request_method":"get"
```

うまくログを出力することができました :thumbsup: 

### レスポンスログ

レスポンスログも一度目標を確認しておきます

- レスポンスログ
    - type("response")
    - timestamp
    - status code
    - request_uri
    - request_method
    - response_time

こちらのログを実現するために先ほど作成したミドルウェアを修正します

```clojure:core.clj
(ns todo.core
  (:require [ring.adapter.jetty :as jetty]
            [ring.util.response :as res]
            [ring.middleware.json :refer [wrap-json-response wrap-json-body]]
            [...]
            [clojure.data.json :as json]
            [clojure.tools.logging :as log]))

(defn- wrap-log-response
  [handler]
  (fn [req]
    (let [start-time (System/nanoTime)
          response (handler req)
          end-time (System/nanoTime)
          response-time (/ (- end-time start-time) 1e6)
          current-timestamp (-> (java.time.Instant/now)
                                (.toString))]
      (log/info (json/write-str {:type "response"
                                 :timestamp current-timestamp
                                 :status (:status response)
                                 :request_uri (:uri req)
                                 :request_method (:request-method req)
                                 :response_time response-time}))
      response)))

(def handler
  (-> handler'
      (wrap-log-response)
      (wrap-json-response)
      (wrap-json-body {:keywords? true})
      (wrap-log-request)))
```

こんな感じで実装してみました。

こちらも実際にリクエストを送ってみます

```bash
$ lein run
2024-12-15 00:09:09 INFO  - {"type":"response","timestamp":"2024-12-14T15:09:09.195763764Z","status":200,"request_uri":"\/v1\/todos","request_method":"get","response_time":108.078736}
```

いい感じで出力できました :thumbsup: 

## ライブラリを使う

https://github.com/nberger/ring-logger

このライブラリを使っても簡単に実装できます

```clojure:core.clj
(ns todo.core
  (:require [ring.adapter.jetty :as jetty]
            [ring.util.response :as res]
            [ring.middleware.json :refer [wrap-json-response wrap-json-body]]
            [compojure.core :refer [defroutes GET POST PUT DELETE]]
            [compojure.route :as route]
            [todo.handler :as handler]
            [ring.logger :as logger]))

(def handler
  (-> handler'
      (logger/wrap-log-response)
      (wrap-json-body {:keywords? true})
      (wrap-json-response)
      (logger/wrap-log-request-start)))

(defn -main []
  (jetty/run-jetty handler {:port 3000}))
```

これでリクエストを送ってみます

```bash
$ lein run
2024-12-16 12:13:38 INFO  - {:request-method :get, :uri "/v1/todos", :server-name "localhost", :ring.logger/type :starting}
2024-12-16 12:13:38 INFO  - {:request-method :get, :uri "/v1/todos", :server-name "localhost", :ring.logger/type :finish, :status 200, :ring.logger/ms 126}
```

いい感じですね

自分で作ってカスタマイズしてもいいし、ライブラリを使っても良さそうです :thumbsup: