[連載]Clojureで作るAPIの8記事目です。
前回の記事はこちらです。
この記事ではロギングをできるようにしていきます。
Javaのロギングの歴史的経緯と現在
Clojureアプリケーションは多くの部分でJavaのライブラリに依存していることから、ClojureアプリケーションのロギングにJavaのロギングの歴史的経緯が関わってきます。
Javaのロギングの歴史的経緯は複雑です。この項ではそれを必要最低限理解するための情報を提供したいと思います。 この項を飛ばして進むことも可能です。興味のある方はお付き合いいただければと思います。
まずJavaのロギングライブラリの構造について理解するためには デザインパターン (ソフトウェア) - Wikipedia の1つである Facadeパターン について理解する必要があります。
リンク先を読んでいただけたけると、Facadeパターンとは実装の詳細を隠蔽し、簡単に使えるインターフェースを用意することだと理解いただけると思います。 理解いただけたという前提で本題のJavaのロギングライブラリの解説に移っていきますが、全てをこの記事に書き切ることはできないので、良い記事を2つ紹介します。
まずこちらの記事の図を見ながらイメージを掴んでいただければと思います。
次にこちらのスライドで登場するライブラリの名前をなんとなくでも頭に入れてください。
これらの記事からわかることをまとめます。
- よく名前を見るJavaのロギングライブラリにはFacadeと実装がある
- 今のデファクトスタンダードのFacadeはCommons LoggingではなくSLF4J
- SLF4Jはさまざまなログ出力実装へのbinding(2.0.0からはproviderと言われる)も同時に提供しており、それらのbindingはログ出力実装をSLF4Jを使用しているように変換し、SLF4J+自分が設定したログ出力実装の組み合わせに適合させてくれる
- LogbackはSLF4Jと一緒に使うログ出力実装としてSLF4Jの作者が作ったもので、SLF4JとLogbackの組み合わせは広く使われている。SLF4Jの公式にも次の記述がある
Logback's ch.qos.logback.classic.Logger class is a direct implementation of SLF4J's org.slf4j.Logger interface. Thus, using SLF4J in conjunction with logback involves strictly zero memory and computational overhead.
簡単ですがここまで理解できれば、実際にログ出力をするための知識としては十分です。
unilogを使って設定する
この連載では上記で説明したように最もスタンダードな組み合わせだと思われるSLF4JとLogbackの組み合わせを使っていきます。
Logbackはクラスパス上の logback.xml というXMLファイルで設定ファイルを記述します。
しかしXMLファイルの記述はちょっと大変です。
また各ログ実装のproviderを1つずつ調べて依存関係に入れていくのも手間です。
そこでClojureのデータとしてLogbackの設定を書けるようにしてくれ、また各ログ実装のproviderをまとめて依存関係に入れてくれるClojureライブラリであるunilogを使います。
いつもなら deps.edn に依存の記述を追加するところですが、実はunilogはすでにClojureで作るAPI Web サーバーを立ち上げる - Toyokumo Tech Blogで追加していました。
ですのでClojureのロギングのFacadeである clojure.tools.logging だけを新たに依存に加えます。
;; ./deps.edn {:paths ["src" "resources"] :deps {org.clojure/clojure {:mvn/version "1.11.1"} info.sunng/ring-jetty9-adapter {:mvn/version "0.17.6" :exclusions [org.slf4j/slf4j-api]} org.clojure/tools.logging {:mvn/version "1.2.4"} ;; 追加 spootnik/unilog {:mvn/version "0.7.30"} com.stuartsierra/component {:mvn/version "1.1.0"} aero/aero {:mvn/version "1.1.6"}} :aliases {:dev {:extra-paths ["dev"]} :build {:deps {io.github.clojure/tools.build {:git/tag "v0.8.2" :git/sha "ba1a2bf"}} :ns-default build}}}
つまり、clojure.tools.logging -> SLF4J -> Logbackという図式を作ります。
ログ出力の設定を config.edn に記載します。
;; ./resources/config.edn {:logging {:level #profile {:dev :debug :default :info} :console #profile {:prod {:encoder :json} :default true} :overrides {"org.eclipse.jetty" :info}} :server {:opts {:host "localhost" :port #long #profile {:default 5000 :dev 8000} :join? false}}}
:logging というキーのバリューに設定を定義してあります。
:levelログレベルです。開発中はdebugレベル以上、それ以外ではinfoレベル以上で出力されるようにしています。:console標準出力に出す設定です。本番ではJSONで出力し、それ以外ではデフォルトのフォーマットで出力されるようにしています。:overridesログレベルを特定のパッケージに対して設定しています。org.eclipse.jettyはWebサーバーですが、開発時にdebugレベルだとログが多すぎるので抑制しています。
Systemと統合する
それではSystemと統合してログ出力を足していきましょう。
;; ./src/cljapi/sytem.clj (ns cljapi.system (:require [cljapi.component.handler :as c.handler] [cljapi.component.server :as c.server] [cljapi.config :as config] [clojure.tools.logging :as log] [com.stuartsierra.component :as component] [unilog.config :as unilog])) (defn- new-system [config] (component/system-map :handler (c.handler/map->Handler {}) :server (component/using (c.server/map->Jetty9Server (:server config)) [:handler]))) (defn- init-logging! [config] (unilog/start-logging! (:logging config))) (defn start [profile] (let [config (config/read-config profile) system (new-system config) _ (init-logging! config) _ (log/info "system is ready to start") started-system (component/start system)] (log/info "system is started") started-system)) (defn stop [system] (component/stop system))
init-logging! でunilogを使ってロギングの初期化をしています。
これを start に組み込むことで開発時と本番環境のいずれにおいても初期化がされるようになります。
REPLを立ち上げて (go) を評価することで実際にログが出力されることを確かめてみましょう。
INFO [2022-07-01 15:49:00,546] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - cljapi.system system is ready to start
INFO [2022-07-01 15:49:00,582] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - org.eclipse.jetty.server.Server jetty-10.0.9; built: 2022-03-30T16:46:32.527Z; git: a9eaf8d5d73369acf610ce88f850c0d56c4b1113; jvm 11.0.15+9-LTS
INFO [2022-07-01 15:49:00,650] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - org.eclipse.jetty.server.handler.ContextHandler Started o.e.j.s.ServletContextHandler@27fdbafe{/,null,AVAILABLE}
INFO [2022-07-01 15:49:00,657] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - org.eclipse.jetty.server.AbstractConnector Started ServerConnector@1eb67498{HTTP/1.1, (http/1.1)}{localhost:8000}
INFO [2022-07-01 15:49:00,666] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - org.eclipse.jetty.server.Server Started Server@4b8e5772{STARTING}[10.0.9,sto=0] @6911ms
INFO [2022-07-01 15:49:00,666] nREPL-session-f03ea922-17bf-447e-987c-43ddca2b2d9d - cljapi.system system is started
Jettyが出すログと共に自分で記述したログが同じフォーマットで出力されていることが確認できます。
次にビルドしてJARを実行したときのログを見てみます。
$ make build $ java -jar target/cljapi.jar {"@timestamp":"2022-07-01T15:19:41.566+09:00","@version":"1","message":"system is ready to start","logger_name":"cljapi.system","thread_name":"main","level":"INFO","level_value":20000} {"@timestamp":"2022-07-01T15:19:41.608+09:00","@version":"1","message":"jetty-10.0.9; built: 2022-03-30T16:46:32.527Z; git: a9eaf8d5d73369acf610ce88f850c0d56c4b1113; jvm 11.0.15+9-LTS","logger_name":"org.eclipse.jetty.server.Server","thread_name":"main","level":"INFO","level_value":20000} {"@timestamp":"2022-07-01T15:19:41.672+09:00","@version":"1","message":"Started o.e.j.s.ServletContextHandler@76e3b45b{/,null,AVAILABLE}","logger_name":"org.eclipse.jetty.server.handler.ContextHandler","thread_name":"main","level":"INFO","level_value":20000} {"@timestamp":"2022-07-01T15:19:41.678+09:00","@version":"1","message":"Started ServerConnector@5d3b58ca{HTTP/1.1, (http/1.1)}{localhost:5000}","logger_name":"org.eclipse.jetty.server.AbstractConnector","thread_name":"main","level":"INFO","level_value":20000} {"@timestamp":"2022-07-01T15:19:41.687+09:00","@version":"1","message":"Started Server@7f2d31af{STARTING}[10.0.9,sto=0] @902ms","logger_name":"org.eclipse.jetty.server.Server","thread_name":"main","level":"INFO","level_value":20000} {"@timestamp":"2022-07-01T15:19:41.687+09:00","@version":"1","message":"system is started","logger_name":"cljapi.system","thread_name":"main","level":"INFO","level_value":20000}
設定通り、JSONで出力されていることが確認できます。
おわりに
ここまでで、ロギングのライブラリと設定を適切に行い、実際にログ出力できていることが確認できました。
コードはGitHubのリポジトリに上げてあります。 08_ロギングできるようにするというタグからご覧ください。
次はテストの設定を行い、簡単なテストを書いてみます。
トヨクモでは一緒に働いてくれる技術が好きなエンジニアを募集しております。
